From d0cb1de9a586bb15ba011641dd6bfca1882f3cbe Mon Sep 17 00:00:00 2001 From: Vladimir Tsykun Date: Sat, 29 Jul 2017 03:08:59 +0300 Subject: [PATCH] [HttpKernel] LoggerDataCollector: splitting logs on different sub-requests --- src/Symfony/Bridge/Monolog/Logger.php | 9 +-- .../Monolog/Processor/DebugProcessor.php | 39 ++++++++--- .../Bridge/Monolog/Tests/LoggerTest.php | 16 +++++ .../Tests/Processor/DebugProcessorTest.php | 67 +++++++++++++++++++ .../FrameworkExtension.php | 1 + .../Resources/config/collectors.xml | 1 + .../DataCollector/LoggerDataCollector.php | 15 +++-- .../HttpKernel/Log/DebugLoggerInterface.php | 10 ++- .../DataCollector/LoggerDataCollectorTest.php | 44 ++++++++++++ 9 files changed, 183 insertions(+), 19 deletions(-) create mode 100644 src/Symfony/Bridge/Monolog/Tests/Processor/DebugProcessorTest.php diff --git a/src/Symfony/Bridge/Monolog/Logger.php b/src/Symfony/Bridge/Monolog/Logger.php index d4771f2894..2f60299881 100644 --- a/src/Symfony/Bridge/Monolog/Logger.php +++ b/src/Symfony/Bridge/Monolog/Logger.php @@ -12,6 +12,7 @@ namespace Symfony\Bridge\Monolog; use Monolog\Logger as BaseLogger; +use Symfony\Component\HttpFoundation\Request; use Symfony\Component\HttpKernel\Log\DebugLoggerInterface; /** @@ -24,10 +25,10 @@ class Logger extends BaseLogger implements DebugLoggerInterface /** * {@inheritdoc} */ - public function getLogs() + public function getLogs(/* Request $request = null */) { if ($logger = $this->getDebugLogger()) { - return $logger->getLogs(); + return \call_user_func_array(array($logger, 'getLogs'), \func_get_args()); } return array(); @@ -36,10 +37,10 @@ class Logger extends BaseLogger implements DebugLoggerInterface /** * {@inheritdoc} */ - public function countErrors() + public function countErrors(/* Request $request = null */) { if ($logger = $this->getDebugLogger()) { - return $logger->countErrors(); + return \call_user_func_array(array($logger, 'countErrors'), \func_get_args()); } return 0; diff --git a/src/Symfony/Bridge/Monolog/Processor/DebugProcessor.php b/src/Symfony/Bridge/Monolog/Processor/DebugProcessor.php index 8774045192..7346d4ee94 100644 --- a/src/Symfony/Bridge/Monolog/Processor/DebugProcessor.php +++ b/src/Symfony/Bridge/Monolog/Processor/DebugProcessor.php @@ -12,16 +12,26 @@ namespace Symfony\Bridge\Monolog\Processor; use Monolog\Logger; +use Symfony\Component\HttpFoundation\Request; +use Symfony\Component\HttpFoundation\RequestStack; use Symfony\Component\HttpKernel\Log\DebugLoggerInterface; class DebugProcessor implements DebugLoggerInterface { 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) { - $this->records[] = array( + $hash = $this->requestStack && ($request = $this->requestStack->getCurrentRequest()) ? spl_object_hash($request) : ''; + + $this->records[$hash][] = array( 'timestamp' => $record['datetime']->getTimestamp(), 'message' => $record['message'], 'priority' => $record['level'], @@ -29,12 +39,17 @@ class DebugProcessor implements DebugLoggerInterface 'context' => $record['context'], 'channel' => isset($record['channel']) ? $record['channel'] : '', ); + + if (!isset($this->errorCount[$hash])) { + $this->errorCount[$hash] = 0; + } + switch ($record['level']) { case Logger::ERROR: case Logger::CRITICAL: case Logger::ALERT: case Logger::EMERGENCY: - ++$this->errorCount; + ++$this->errorCount[$hash]; } return $record; @@ -43,17 +58,25 @@ class DebugProcessor implements DebugLoggerInterface /** * {@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} */ - 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() { $this->records = array(); - $this->errorCount = 0; + $this->errorCount = array(); } } diff --git a/src/Symfony/Bridge/Monolog/Tests/LoggerTest.php b/src/Symfony/Bridge/Monolog/Tests/LoggerTest.php index aeb3b55fdc..be60fc2789 100644 --- a/src/Symfony/Bridge/Monolog/Tests/LoggerTest.php +++ b/src/Symfony/Bridge/Monolog/Tests/LoggerTest.php @@ -15,6 +15,7 @@ use Monolog\Handler\TestHandler; use PHPUnit\Framework\TestCase; use Symfony\Bridge\Monolog\Processor\DebugProcessor; use Symfony\Bridge\Monolog\Logger; +use Symfony\Component\HttpFoundation\Request; class LoggerTest extends TestCase { @@ -79,6 +80,21 @@ class LoggerTest extends TestCase $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() { $handler = new TestHandler(); diff --git a/src/Symfony/Bridge/Monolog/Tests/Processor/DebugProcessorTest.php b/src/Symfony/Bridge/Monolog/Tests/Processor/DebugProcessorTest.php new file mode 100644 index 0000000000..e85ded5b48 --- /dev/null +++ b/src/Symfony/Bridge/Monolog/Tests/Processor/DebugProcessorTest.php @@ -0,0 +1,67 @@ + + * + * 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(), + ); + } +} diff --git a/src/Symfony/Bundle/FrameworkBundle/DependencyInjection/FrameworkExtension.php b/src/Symfony/Bundle/FrameworkBundle/DependencyInjection/FrameworkExtension.php index 826d4f0fae..7aa8f508d8 100644 --- a/src/Symfony/Bundle/FrameworkBundle/DependencyInjection/FrameworkExtension.php +++ b/src/Symfony/Bundle/FrameworkBundle/DependencyInjection/FrameworkExtension.php @@ -671,6 +671,7 @@ class FrameworkExtension extends Extension if ($debug && class_exists(DebugProcessor::class)) { $definition = new Definition(DebugProcessor::class); $definition->setPublic(false); + $definition->addArgument(new Reference('request_stack')); $container->setDefinition('debug.log_processor', $definition); } } diff --git a/src/Symfony/Bundle/FrameworkBundle/Resources/config/collectors.xml b/src/Symfony/Bundle/FrameworkBundle/Resources/config/collectors.xml index 6d3870c31f..93005e07ac 100644 --- a/src/Symfony/Bundle/FrameworkBundle/Resources/config/collectors.xml +++ b/src/Symfony/Bundle/FrameworkBundle/Resources/config/collectors.xml @@ -35,6 +35,7 @@ %kernel.cache_dir%/%kernel.container_class% + diff --git a/src/Symfony/Component/HttpKernel/DataCollector/LoggerDataCollector.php b/src/Symfony/Component/HttpKernel/DataCollector/LoggerDataCollector.php index 3f6fc32e04..6218c0c246 100644 --- a/src/Symfony/Component/HttpKernel/DataCollector/LoggerDataCollector.php +++ b/src/Symfony/Component/HttpKernel/DataCollector/LoggerDataCollector.php @@ -13,6 +13,7 @@ namespace Symfony\Component\HttpKernel\DataCollector; 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\Log\DebugLoggerInterface; @@ -25,14 +26,17 @@ class LoggerDataCollector extends DataCollector implements LateDataCollectorInte { private $logger; 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) { $this->logger = $logger; } $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) { - // 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(); $this->data = $this->computeErrorsCount($containerDeprecationLogs); $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->currentRequest = null; } /** @@ -229,14 +234,14 @@ class LoggerDataCollector extends DataCollector implements LateDataCollectorInte { $silencedLogs = array(); $count = array( - 'error_count' => $this->logger->countErrors(), + 'error_count' => $this->logger->countErrors($this->currentRequest), 'deprecation_count' => 0, 'warning_count' => 0, 'scream_count' => 0, 'priorities' => array(), ); - foreach ($this->logger->getLogs() as $log) { + foreach ($this->logger->getLogs($this->currentRequest) as $log) { if (isset($count['priorities'][$log['priority']])) { ++$count['priorities'][$log['priority']]['count']; } else { diff --git a/src/Symfony/Component/HttpKernel/Log/DebugLoggerInterface.php b/src/Symfony/Component/HttpKernel/Log/DebugLoggerInterface.php index 1d955c4829..2a27992e20 100644 --- a/src/Symfony/Component/HttpKernel/Log/DebugLoggerInterface.php +++ b/src/Symfony/Component/HttpKernel/Log/DebugLoggerInterface.php @@ -11,6 +11,8 @@ namespace Symfony\Component\HttpKernel\Log; +use Symfony\Component\HttpFoundation\Request; + /** * DebugLoggerInterface. * @@ -25,16 +27,20 @@ interface DebugLoggerInterface * timestamp, message, priority, and priorityName. * 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 */ - public function getLogs(); + public function getLogs(/* Request $request = null */); /** * Returns the number of errors. * + * @param Request|null $request The request to count logs for + * * @return int The number of errors */ - public function countErrors(); + public function countErrors(/* Request $request = null */); /** * Removes all log records. diff --git a/src/Symfony/Component/HttpKernel/Tests/DataCollector/LoggerDataCollectorTest.php b/src/Symfony/Component/HttpKernel/Tests/DataCollector/LoggerDataCollectorTest.php index 3dec3bd7f8..b5c7057fd6 100644 --- a/src/Symfony/Component/HttpKernel/Tests/DataCollector/LoggerDataCollectorTest.php +++ b/src/Symfony/Component/HttpKernel/Tests/DataCollector/LoggerDataCollectorTest.php @@ -13,7 +13,11 @@ namespace Symfony\Component\HttpKernel\Tests\DataCollector; use PHPUnit\Framework\TestCase; 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\Log\DebugLoggerInterface; class LoggerDataCollectorTest extends TestCase { @@ -41,6 +45,46 @@ class LoggerDataCollectorTest extends TestCase ), $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 */