Skip to content

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

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Apr 20, 2018
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 5 additions & 4 deletions src/Symfony/Bridge/Monolog/Logger.php
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@
namespace Symfony\Bridge\Monolog;

use Monolog\Logger as BaseLogger;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpKernel\Log\DebugLoggerInterface;

/**
Expand All @@ -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();
Expand All @@ -36,10 +37,10 @@ public function getLogs()
/**
* {@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;
Expand Down
39 changes: 31 additions & 8 deletions src/Symfony/Bridge/Monolog/Processor/DebugProcessor.php
Original file line number Diff line number Diff line change
Expand Up @@ -12,29 +12,44 @@
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'],
'priorityName' => $record['level_name'],
'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;
Expand All @@ -43,17 +58,25 @@ public function __invoke(array $record)
/**
* {@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);
}

/**
Expand All @@ -62,6 +85,6 @@ public function countErrors()
public function clear()
{
$this->records = array();
$this->errorCount = 0;
$this->errorCount = array();
}
}
16 changes: 16 additions & 0 deletions src/Symfony/Bridge/Monolog/Tests/LoggerTest.php
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@
use PHPUnit\Framework\TestCase;
use Symfony\Bridge\Monolog\Processor\DebugProcessor;
use Symfony\Bridge\Monolog\Logger;
use Symfony\Component\HttpFoundation\Request;

class LoggerTest extends TestCase
{
Expand Down Expand Up @@ -79,6 +80,21 @@ public function testGetLogsWithDebugProcessor2()
$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();
Expand Down
67 changes: 67 additions & 0 deletions src/Symfony/Bridge/Monolog/Tests/Processor/DebugProcessorTest.php
Original file line number Diff line number Diff line change
@@ -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(),
);
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -671,6 +671,7 @@ private function registerDebugConfiguration(array $config, ContainerBuilder $con
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);
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,7 @@
<tag name="monolog.logger" channel="profiler" />
<argument type="service" id="logger" on-invalid="ignore" />
<argument>%kernel.cache_dir%/%kernel.container_class%</argument>
<argument type="service" id="request_stack" on-invalid="ignore" />
</service>

<service id="data_collector.time" class="Symfony\Component\HttpKernel\DataCollector\TimeDataCollector">
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@

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;

Expand All @@ -25,22 +26,25 @@ 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;
}

/**
* {@inheritdoc}
*/
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;
}

/**
Expand All @@ -63,9 +67,10 @@ public function lateCollect()
$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;
}

/**
Expand Down Expand Up @@ -229,14 +234,14 @@ private function computeErrorsCount(array $containerDeprecationLogs)
{
$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 {
Expand Down
10 changes: 8 additions & 2 deletions src/Symfony/Component/HttpKernel/Log/DebugLoggerInterface.php
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,8 @@

namespace Symfony\Component\HttpKernel\Log;

use Symfony\Component\HttpFoundation\Request;

/**
* DebugLoggerInterface.
*
Expand All @@ -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.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,11 @@

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
{
Expand Down Expand Up @@ -41,6 +45,46 @@ public function testCollectWithUnexpectedFormat()
), $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
*/
Expand Down