[HttpKernel] LoggerDataCollector: splitting logs on different sub-requests

This commit is contained in:
Vladimir Tsykun 2017-07-29 03:08:59 +03:00 committed by Nicolas Grekas
parent 4b66721658
commit d0cb1de9a5
9 changed files with 183 additions and 19 deletions

View File

@ -12,6 +12,7 @@
namespace Symfony\Bridge\Monolog; namespace Symfony\Bridge\Monolog;
use Monolog\Logger as BaseLogger; use Monolog\Logger as BaseLogger;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpKernel\Log\DebugLoggerInterface; use Symfony\Component\HttpKernel\Log\DebugLoggerInterface;
/** /**
@ -24,10 +25,10 @@ class Logger extends BaseLogger implements DebugLoggerInterface
/** /**
* {@inheritdoc} * {@inheritdoc}
*/ */
public function getLogs() public function getLogs(/* Request $request = null */)
{ {
if ($logger = $this->getDebugLogger()) { if ($logger = $this->getDebugLogger()) {
return $logger->getLogs(); return \call_user_func_array(array($logger, 'getLogs'), \func_get_args());
} }
return array(); return array();
@ -36,10 +37,10 @@ class Logger extends BaseLogger implements DebugLoggerInterface
/** /**
* {@inheritdoc} * {@inheritdoc}
*/ */
public function countErrors() public function countErrors(/* Request $request = null */)
{ {
if ($logger = $this->getDebugLogger()) { if ($logger = $this->getDebugLogger()) {
return $logger->countErrors(); return \call_user_func_array(array($logger, 'countErrors'), \func_get_args());
} }
return 0; return 0;

View File

@ -12,16 +12,26 @@
namespace Symfony\Bridge\Monolog\Processor; namespace Symfony\Bridge\Monolog\Processor;
use Monolog\Logger; use Monolog\Logger;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpFoundation\RequestStack;
use Symfony\Component\HttpKernel\Log\DebugLoggerInterface; use Symfony\Component\HttpKernel\Log\DebugLoggerInterface;
class DebugProcessor implements DebugLoggerInterface class DebugProcessor implements DebugLoggerInterface
{ {
private $records = array(); private $records = array();
private $errorCount = 0; private $errorCount = array();
private $requestStack;
public function __construct(RequestStack $requestStack = null)
{
$this->requestStack = $requestStack;
}
public function __invoke(array $record) public function __invoke(array $record)
{ {
$this->records[] = array( $hash = $this->requestStack && ($request = $this->requestStack->getCurrentRequest()) ? spl_object_hash($request) : '';
$this->records[$hash][] = array(
'timestamp' => $record['datetime']->getTimestamp(), 'timestamp' => $record['datetime']->getTimestamp(),
'message' => $record['message'], 'message' => $record['message'],
'priority' => $record['level'], 'priority' => $record['level'],
@ -29,12 +39,17 @@ class DebugProcessor implements DebugLoggerInterface
'context' => $record['context'], 'context' => $record['context'],
'channel' => isset($record['channel']) ? $record['channel'] : '', 'channel' => isset($record['channel']) ? $record['channel'] : '',
); );
if (!isset($this->errorCount[$hash])) {
$this->errorCount[$hash] = 0;
}
switch ($record['level']) { switch ($record['level']) {
case Logger::ERROR: case Logger::ERROR:
case Logger::CRITICAL: case Logger::CRITICAL:
case Logger::ALERT: case Logger::ALERT:
case Logger::EMERGENCY: case Logger::EMERGENCY:
++$this->errorCount; ++$this->errorCount[$hash];
} }
return $record; return $record;
@ -43,17 +58,25 @@ class DebugProcessor implements DebugLoggerInterface
/** /**
* {@inheritdoc} * {@inheritdoc}
*/ */
public function getLogs() public function getLogs(/* Request $request = null */)
{ {
return $this->records; if (1 <= \func_num_args() && null !== ($request = \func_get_arg(0)) && isset($this->records[$hash = spl_object_hash($request)])) {
return $this->records[$hash];
}
return $this->records ? \call_user_func_array('array_merge', $this->records) : array();
} }
/** /**
* {@inheritdoc} * {@inheritdoc}
*/ */
public function countErrors() public function countErrors(/* Request $request = null */)
{ {
return $this->errorCount; if (1 <= \func_num_args() && null !== ($request = \func_get_arg(0)) && isset($this->errorCount[$hash = spl_object_hash($request)])) {
return $this->errorCount[$hash];
}
return array_sum($this->errorCount);
} }
/** /**
@ -62,6 +85,6 @@ class DebugProcessor implements DebugLoggerInterface
public function clear() public function clear()
{ {
$this->records = array(); $this->records = array();
$this->errorCount = 0; $this->errorCount = array();
} }
} }

View File

@ -15,6 +15,7 @@ use Monolog\Handler\TestHandler;
use PHPUnit\Framework\TestCase; use PHPUnit\Framework\TestCase;
use Symfony\Bridge\Monolog\Processor\DebugProcessor; use Symfony\Bridge\Monolog\Processor\DebugProcessor;
use Symfony\Bridge\Monolog\Logger; use Symfony\Bridge\Monolog\Logger;
use Symfony\Component\HttpFoundation\Request;
class LoggerTest extends TestCase class LoggerTest extends TestCase
{ {
@ -79,6 +80,21 @@ class LoggerTest extends TestCase
$this->assertEquals(Logger::INFO, $record['priority']); $this->assertEquals(Logger::INFO, $record['priority']);
} }
public function testGetLogsWithDebugProcessor3()
{
$request = new Request();
$processor = $this->getMockBuilder(DebugProcessor::class)->getMock();
$processor->expects($this->once())->method('getLogs')->with($request);
$processor->expects($this->once())->method('countErrors')->with($request);
$handler = new TestHandler();
$logger = new Logger('test', array($handler));
$logger->pushProcessor($processor);
$logger->getLogs($request);
$logger->countErrors($request);
}
public function testClear() public function testClear()
{ {
$handler = new TestHandler(); $handler = new TestHandler();

View File

@ -0,0 +1,67 @@
<?php
/*
* This file is part of the Symfony package.
*
* (c) Fabien Potencier <fabien@symfony.com>
*
* For the full copyright and license information, please view the LICENSE
* file that was distributed with this source code.
*/
namespace Symfony\Bridge\Monolog\Tests\Processor;
use Monolog\Logger;
use PHPUnit\Framework\TestCase;
use Symfony\Bridge\Monolog\Processor\DebugProcessor;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpFoundation\RequestStack;
class DebugProcessorTest extends TestCase
{
public function testDebugProcessor()
{
$processor = new DebugProcessor();
$processor($this->getRecord());
$processor($this->getRecord(Logger::ERROR));
$this->assertCount(2, $processor->getLogs());
$this->assertSame(1, $processor->countErrors());
}
public function testWithRequestStack()
{
$stack = new RequestStack();
$processor = new DebugProcessor($stack);
$processor($this->getRecord());
$processor($this->getRecord(Logger::ERROR));
$this->assertCount(2, $processor->getLogs());
$this->assertSame(1, $processor->countErrors());
$request = new Request();
$stack->push($request);
$processor($this->getRecord());
$processor($this->getRecord(Logger::ERROR));
$this->assertCount(4, $processor->getLogs());
$this->assertSame(2, $processor->countErrors());
$this->assertCount(2, $processor->getLogs($request));
$this->assertSame(1, $processor->countErrors($request));
}
private function getRecord($level = Logger::WARNING, $message = 'test')
{
return array(
'message' => $message,
'context' => array(),
'level' => $level,
'level_name' => Logger::getLevelName($level),
'channel' => 'test',
'datetime' => new \DateTime(),
'extra' => array(),
);
}
}

View File

@ -671,6 +671,7 @@ class FrameworkExtension extends Extension
if ($debug && class_exists(DebugProcessor::class)) { if ($debug && class_exists(DebugProcessor::class)) {
$definition = new Definition(DebugProcessor::class); $definition = new Definition(DebugProcessor::class);
$definition->setPublic(false); $definition->setPublic(false);
$definition->addArgument(new Reference('request_stack'));
$container->setDefinition('debug.log_processor', $definition); $container->setDefinition('debug.log_processor', $definition);
} }
} }

View File

@ -35,6 +35,7 @@
<tag name="monolog.logger" channel="profiler" /> <tag name="monolog.logger" channel="profiler" />
<argument type="service" id="logger" on-invalid="ignore" /> <argument type="service" id="logger" on-invalid="ignore" />
<argument>%kernel.cache_dir%/%kernel.container_class%</argument> <argument>%kernel.cache_dir%/%kernel.container_class%</argument>
<argument type="service" id="request_stack" on-invalid="ignore" />
</service> </service>
<service id="data_collector.time" class="Symfony\Component\HttpKernel\DataCollector\TimeDataCollector"> <service id="data_collector.time" class="Symfony\Component\HttpKernel\DataCollector\TimeDataCollector">

View File

@ -13,6 +13,7 @@ namespace Symfony\Component\HttpKernel\DataCollector;
use Symfony\Component\Debug\Exception\SilencedErrorContext; use Symfony\Component\Debug\Exception\SilencedErrorContext;
use Symfony\Component\HttpFoundation\Request; use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpFoundation\RequestStack;
use Symfony\Component\HttpFoundation\Response; use Symfony\Component\HttpFoundation\Response;
use Symfony\Component\HttpKernel\Log\DebugLoggerInterface; use Symfony\Component\HttpKernel\Log\DebugLoggerInterface;
@ -25,14 +26,17 @@ class LoggerDataCollector extends DataCollector implements LateDataCollectorInte
{ {
private $logger; private $logger;
private $containerPathPrefix; private $containerPathPrefix;
private $currentRequest;
private $requestStack;
public function __construct($logger = null, string $containerPathPrefix = null) public function __construct($logger = null, string $containerPathPrefix = null, RequestStack $requestStack = null)
{ {
if (null !== $logger && $logger instanceof DebugLoggerInterface) { if (null !== $logger && $logger instanceof DebugLoggerInterface) {
$this->logger = $logger; $this->logger = $logger;
} }
$this->containerPathPrefix = $containerPathPrefix; $this->containerPathPrefix = $containerPathPrefix;
$this->requestStack = $requestStack;
} }
/** /**
@ -40,7 +44,7 @@ class LoggerDataCollector extends DataCollector implements LateDataCollectorInte
*/ */
public function collect(Request $request, Response $response, \Exception $exception = null) public function collect(Request $request, Response $response, \Exception $exception = null)
{ {
// everything is done as late as possible $this->currentRequest = $this->requestStack && $this->requestStack->getMasterRequest() !== $request ? $request : null;
} }
/** /**
@ -63,9 +67,10 @@ class LoggerDataCollector extends DataCollector implements LateDataCollectorInte
$containerDeprecationLogs = $this->getContainerDeprecationLogs(); $containerDeprecationLogs = $this->getContainerDeprecationLogs();
$this->data = $this->computeErrorsCount($containerDeprecationLogs); $this->data = $this->computeErrorsCount($containerDeprecationLogs);
$this->data['compiler_logs'] = $this->getContainerCompilerLogs(); $this->data['compiler_logs'] = $this->getContainerCompilerLogs();
$this->data['logs'] = $this->sanitizeLogs(array_merge($this->logger->getLogs(), $containerDeprecationLogs)); $this->data['logs'] = $this->sanitizeLogs(array_merge($this->logger->getLogs($this->currentRequest), $containerDeprecationLogs));
$this->data = $this->cloneVar($this->data); $this->data = $this->cloneVar($this->data);
} }
$this->currentRequest = null;
} }
/** /**
@ -229,14 +234,14 @@ class LoggerDataCollector extends DataCollector implements LateDataCollectorInte
{ {
$silencedLogs = array(); $silencedLogs = array();
$count = array( $count = array(
'error_count' => $this->logger->countErrors(), 'error_count' => $this->logger->countErrors($this->currentRequest),
'deprecation_count' => 0, 'deprecation_count' => 0,
'warning_count' => 0, 'warning_count' => 0,
'scream_count' => 0, 'scream_count' => 0,
'priorities' => array(), 'priorities' => array(),
); );
foreach ($this->logger->getLogs() as $log) { foreach ($this->logger->getLogs($this->currentRequest) as $log) {
if (isset($count['priorities'][$log['priority']])) { if (isset($count['priorities'][$log['priority']])) {
++$count['priorities'][$log['priority']]['count']; ++$count['priorities'][$log['priority']]['count'];
} else { } else {

View File

@ -11,6 +11,8 @@
namespace Symfony\Component\HttpKernel\Log; namespace Symfony\Component\HttpKernel\Log;
use Symfony\Component\HttpFoundation\Request;
/** /**
* DebugLoggerInterface. * DebugLoggerInterface.
* *
@ -25,16 +27,20 @@ interface DebugLoggerInterface
* timestamp, message, priority, and priorityName. * timestamp, message, priority, and priorityName.
* It can also have an optional context key containing an array. * It can also have an optional context key containing an array.
* *
* @param Request|null $request The request to get logs for
*
* @return array An array of logs * @return array An array of logs
*/ */
public function getLogs(); public function getLogs(/* Request $request = null */);
/** /**
* Returns the number of errors. * Returns the number of errors.
* *
* @param Request|null $request The request to count logs for
*
* @return int The number of errors * @return int The number of errors
*/ */
public function countErrors(); public function countErrors(/* Request $request = null */);
/** /**
* Removes all log records. * Removes all log records.

View File

@ -13,7 +13,11 @@ namespace Symfony\Component\HttpKernel\Tests\DataCollector;
use PHPUnit\Framework\TestCase; use PHPUnit\Framework\TestCase;
use Symfony\Component\Debug\Exception\SilencedErrorContext; use Symfony\Component\Debug\Exception\SilencedErrorContext;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpFoundation\RequestStack;
use Symfony\Component\HttpFoundation\Response;
use Symfony\Component\HttpKernel\DataCollector\LoggerDataCollector; use Symfony\Component\HttpKernel\DataCollector\LoggerDataCollector;
use Symfony\Component\HttpKernel\Log\DebugLoggerInterface;
class LoggerDataCollectorTest extends TestCase class LoggerDataCollectorTest extends TestCase
{ {
@ -41,6 +45,46 @@ class LoggerDataCollectorTest extends TestCase
), $compilerLogs['Unknown Compiler Pass']); ), $compilerLogs['Unknown Compiler Pass']);
} }
public function testWithMasterRequest()
{
$masterRequest = new Request();
$stack = new RequestStack();
$stack->push($masterRequest);
$logger = $this
->getMockBuilder(DebugLoggerInterface::class)
->setMethods(array('countErrors', 'getLogs', 'clear'))
->getMock();
$logger->expects($this->once())->method('countErrors')->with(null);
$logger->expects($this->exactly(2))->method('getLogs')->with(null)->will($this->returnValue(array()));
$c = new LoggerDataCollector($logger, __DIR__.'/', $stack);
$c->collect($masterRequest, new Response());
$c->lateCollect();
}
public function testWithSubRequest()
{
$masterRequest = new Request();
$subRequest = new Request();
$stack = new RequestStack();
$stack->push($masterRequest);
$stack->push($subRequest);
$logger = $this
->getMockBuilder(DebugLoggerInterface::class)
->setMethods(array('countErrors', 'getLogs', 'clear'))
->getMock();
$logger->expects($this->once())->method('countErrors')->with($subRequest);
$logger->expects($this->exactly(2))->method('getLogs')->with($subRequest)->will($this->returnValue(array()));
$c = new LoggerDataCollector($logger, __DIR__.'/', $stack);
$c->collect($subRequest, new Response());
$c->lateCollect();
}
/** /**
* @dataProvider getCollectTestData * @dataProvider getCollectTestData
*/ */