Skip to content

Commit

Permalink
bug #23007 [HttpKernel][Debug] Fix missing trace on deprecations coll…
Browse files Browse the repository at this point in the history 
…ected during bootstrapping & silenced errors (ogizanagi)

This PR was merged into the 3.3 branch.

Discussion
----------

[HttpKernel][Debug] Fix missing trace on deprecations collected during bootstrapping & silenced errors

| Q             | A
| ------------- | ---
| Branch?       | 3.3 <!-- see comment below -->
| Bug fix?      | yes
| New feature?  | no <!-- don't forget updating src/**/CHANGELOG.md files -->
| BC breaks?    | no
| Deprecations? | no <!-- don't forget updating UPGRADE-*.md files -->
| Tests pass?   | yes
| Fixed tickets | #22958 <!-- #-prefixed issue number(s), if any -->
| License       | MIT
| Doc PR        | N/A

|Before|After|
|--|--|
|<img width="1086" alt="screenshot 2017-06-01 a 10 12 07" src="https://cloud.githubusercontent.com/assets/2211145/26670940/feb51b52-46b3-11e7-806f-e23e2eb248c1.PNG">|<img width="1094" alt="screenshot 2017-06-01 a 10 13 39" src="https://cloud.githubusercontent.com/assets/2211145/26670941/feb8bd66-46b3-11e7-8e54-cc4959487b7a.PNG">|

(failures unrelated or deps=high fixed when merged in upper branches)

Commits
-------

21ef065 [HttpKernel][Debug] Fix missing trace on deprecations collected during bootstrapping & silenced errors
  • Loading branch information
@fabpot
fabpot committed Jun 6, 2017
2 parents f322107 + 21ef065 commit 1006959
Show file tree
Hide file tree
Showing 6 changed files with 124 additions and 33 deletions.
54 changes: 40 additions & 14 deletions src/Symfony/Component/Debug/ErrorHandler.php
View file
Expand Up @@ -100,6 +100,8 @@ class ErrorHandler
private static $stackedErrors = array();
private static $stackedErrorLevels = array();
private static $toStringException = null;
private static $silencedErrorCache = array();
private static $silencedErrorCount = 0;
private static $exitCode = 0;

/**
Expand Down Expand Up @@ -407,7 +409,24 @@ public function handleError($type, $message, $file, $line)
$errorAsException = self::$toStringException;
self::$toStringException = null;
} elseif (!$throw && !($type & $level)) {
$errorAsException = new SilencedErrorContext($type, $file, $line);
if (isset(self::$silencedErrorCache[$message])) {
$lightTrace = null;
$errorAsException = self::$silencedErrorCache[$message];
++$errorAsException->count;
} else {
$lightTrace = $this->tracedErrors & $type ? $this->cleanTrace(debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS), $type, $file, $line, false) : array();
$errorAsException = new SilencedErrorContext($type, $file, $line, $lightTrace);
}

if (100 < ++self::$silencedErrorCount) {
self::$silencedErrorCache = $lightTrace = array();
self::$silencedErrorCount = 1;
}
self::$silencedErrorCache[$message] = $errorAsException;

if (null === $lightTrace) {
return;
}
} else {
if ($scope) {
$errorAsException = new ContextErrorException($logMessage, 0, $type, $file, $line, $context);
Expand All @@ -418,19 +437,7 @@ public function handleError($type, $message, $file, $line)
// Clean the trace by removing function arguments and the first frames added by the error handler itself.
if ($throw || $this->tracedErrors & $type) {
$backtrace = $backtrace ?: $errorAsException->getTrace();
$lightTrace = $backtrace;

for ($i = 0; isset($backtrace[$i]); ++$i) {
if (isset($backtrace[$i]['file'], $backtrace[$i]['line']) && $backtrace[$i]['line'] === $line && $backtrace[$i]['file'] === $file) {
$lightTrace = array_slice($lightTrace, 1 + $i);
break;
}
}
if (!($throw || $this->scopedErrors & $type)) {
for ($i = 0; isset($lightTrace[$i]); ++$i) {
unset($lightTrace[$i]['args']);
}
}
$lightTrace = $this->cleanTrace($backtrace, $type, $file, $line, $throw);
$this->traceReflector->setValue($errorAsException, $lightTrace);
} else {
$this->traceReflector->setValue($errorAsException, array());
Expand Down Expand Up @@ -687,4 +694,23 @@ protected function getFatalErrorHandlers()
new ClassNotFoundFatalErrorHandler(),
);
}

private function cleanTrace($backtrace, $type, $file, $line, $throw)
{
$lightTrace = $backtrace;

for ($i = 0; isset($backtrace[$i]); ++$i) {
if (isset($backtrace[$i]['file'], $backtrace[$i]['line']) && $backtrace[$i]['line'] === $line && $backtrace[$i]['file'] === $file) {
$lightTrace = array_slice($lightTrace, 1 + $i);
break;
}
}
if (!($throw || $this->scopedErrors & $type)) {
for ($i = 0; isset($lightTrace[$i]); ++$i) {
unset($lightTrace[$i]['args']);
}
}

return $lightTrace;
}
}
14 changes: 13 additions & 1 deletion src/Symfony/Component/Debug/Exception/SilencedErrorContext.php
View file
Expand Up @@ -18,15 +18,20 @@
*/
class SilencedErrorContext implements \JsonSerializable
{
public $count = 1;

private $severity;
private $file;
private $line;
private $trace;

public function __construct($severity, $file, $line)
public function __construct($severity, $file, $line, array $trace = array(), $count = 1)
{
$this->severity = $severity;
$this->file = $file;
$this->line = $line;
$this->trace = $trace;
$this->count = $count;
}

public function getSeverity()
Expand All @@ -44,12 +49,19 @@ public function getLine()
return $this->line;
}

public function getTrace()
{
return $this->trace;
}

public function JsonSerialize()
{
return array(
'severity' => $this->severity,
'file' => $this->file,
'line' => $this->line,
'trace' => $this->trace,
'count' => $this->count,
);
}
}
8 changes: 7 additions & 1 deletion src/Symfony/Component/Debug/Tests/ErrorHandlerTest.php
View file
Expand Up @@ -221,12 +221,17 @@ public function testHandleError()

$logger = $this->getMockBuilder('Psr\Log\LoggerInterface')->getMock();

$logArgCheck = function ($level, $message, $context) {
$line = null;
$logArgCheck = function ($level, $message, $context) use (&$line) {
$this->assertEquals('Notice: Undefined variable: undefVar', $message);
$this->assertArrayHasKey('exception', $context);
$exception = $context['exception'];
$this->assertInstanceOf(SilencedErrorContext::class, $exception);
$this->assertSame(E_NOTICE, $exception->getSeverity());
$this->assertSame(__FILE__, $exception->getFile());
$this->assertSame($line, $exception->getLine());
$this->assertNotEmpty($exception->getTrace());
$this->assertSame(1, $exception->count);
};

$logger
Expand All @@ -239,6 +244,7 @@ public function testHandleError()
$handler->setDefaultLogger($logger, E_NOTICE);
$handler->screamAt(E_NOTICE);
unset($undefVar);
$line = __LINE__ + 1;
@$undefVar++;

restore_error_handler();
Expand Down
46 changes: 36 additions & 10 deletions src/Symfony/Component/HttpKernel/DataCollector/LoggerDataCollector.php
View file
Expand Up @@ -49,10 +49,8 @@ public function collect(Request $request, Response $response, \Exception $except
public function lateCollect()
{
if (null !== $this->logger) {
$this->data = $this->computeErrorsCount();

$containerDeprecationLogs = $this->getContainerDeprecationLogs();
$this->data['deprecation_count'] += count($containerDeprecationLogs);
$this->data = $this->computeErrorsCount($containerDeprecationLogs);
$this->data['compiler_logs'] = $this->getContainerCompilerLogs();
$this->data['logs'] = $this->sanitizeLogs(array_merge($this->logger->getLogs(), $containerDeprecationLogs));
$this->data = $this->cloneVar($this->data);
Expand Down Expand Up @@ -113,11 +111,10 @@ private function getContainerDeprecationLogs()
return array();
}

$stubs = array();
$bootTime = filemtime($file);
$logs = array();
foreach (unserialize(file_get_contents($file)) as $log) {
$log['context'] = array('exception' => new SilencedErrorContext($log['type'], $log['file'], $log['line']));
$log['context'] = array('exception' => new SilencedErrorContext($log['type'], $log['file'], $log['line'], $log['trace'], $log['count']));
$log['timestamp'] = $bootTime;
$log['priority'] = 100;
$log['priorityName'] = 'DEBUG';
Expand Down Expand Up @@ -159,15 +156,34 @@ private function sanitizeLogs($logs)
continue;
}

$message = $log['message'];
$exception = $log['context']['exception'];
$errorId = md5("{$exception->getSeverity()}/{$exception->getLine()}/{$exception->getFile()}\0{$log['message']}", true);

if ($exception instanceof SilencedErrorContext) {
if (isset($silencedLogs[$h = spl_object_hash($exception)])) {
continue;
}
$silencedLogs[$h] = true;

if (!isset($sanitizedLogs[$message])) {
$sanitizedLogs[$message] = $log + array(
'errorCount' => 0,
'scream' => true,
);
}
$sanitizedLogs[$message]['errorCount'] += $exception->count;

continue;
}

$errorId = md5("{$exception->getSeverity()}/{$exception->getLine()}/{$exception->getFile()}\0{$message}", true);

if (isset($sanitizedLogs[$errorId])) {
++$sanitizedLogs[$errorId]['errorCount'];
} else {
$log += array(
'errorCount' => 1,
'scream' => $exception instanceof SilencedErrorContext,
'scream' => false,
);

$sanitizedLogs[$errorId] = $log;
Expand Down Expand Up @@ -196,8 +212,9 @@ private function isSilencedOrDeprecationErrorLog(array $log)
return false;
}

private function computeErrorsCount()
private function computeErrorsCount(array $containerDeprecationLogs)
{
$silencedLogs = array();
$count = array(
'error_count' => $this->logger->countErrors(),
'deprecation_count' => 0,
Expand All @@ -220,14 +237,23 @@ private function computeErrorsCount()
}

if ($this->isSilencedOrDeprecationErrorLog($log)) {
if ($log['context']['exception'] instanceof SilencedErrorContext) {
++$count['scream_count'];
$exception = $log['context']['exception'];
if ($exception instanceof SilencedErrorContext) {
if (isset($silencedLogs[$h = spl_object_hash($exception)])) {
continue;
}
$silencedLogs[$h] = true;
$count['scream_count'] += $exception->count;
} else {
++$count['deprecation_count'];
}
}
}

foreach ($containerDeprecationLogs as $deprecationLog) {
$count['deprecation_count'] += $deprecationLog['count'];
}

ksort($count['priorities']);

return $count;
Expand Down
21 changes: 19 additions & 2 deletions src/Symfony/Component/HttpKernel/Kernel.php
View file
Expand Up @@ -545,11 +545,28 @@ protected function initializeContainer()
return $previousHandler ? $previousHandler($type, $message, $file, $line) : false;
}

$collectedLogs[] = array(
if (isset($collectedLogs[$message])) {
++$collectedLogs[$message]['count'];

return;
}

$backtrace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
// Clean the trace by removing first frames added by the error handler itself.
for ($i = 0; isset($backtrace[$i]); ++$i) {
if (isset($backtrace[$i]['file'], $backtrace[$i]['line']) && $backtrace[$i]['line'] === $line && $backtrace[$i]['file'] === $file) {
$backtrace = array_slice($backtrace, 1 + $i);
break;
}
}

$collectedLogs[$message] = array(
'type' => $type,
'message' => $message,
'file' => $file,
'line' => $line,
'trace' => $backtrace,
'count' => 1,
);
});
}
Expand All @@ -562,7 +579,7 @@ protected function initializeContainer()
if ($this->debug) {
restore_error_handler();

file_put_contents($this->getCacheDir().'/'.$class.'Deprecations.log', serialize($collectedLogs));
file_put_contents($this->getCacheDir().'/'.$class.'Deprecations.log', serialize(array_values($collectedLogs)));
file_put_contents($this->getCacheDir().'/'.$class.'Compiler.log', null !== $container ? implode("\n", $container->getCompiler()->getLog()) : '');
}
}
Expand Down
14 changes: 9 additions & 5 deletions src/Symfony/Component/VarDumper/Caster/ExceptionCaster.php
View file
Expand Up @@ -83,7 +83,6 @@ public static function castThrowingCasterException(ThrowingCasterException $e, a
public static function castSilencedErrorContext(SilencedErrorContext $e, array $a, Stub $stub, $isNested)
{
$sPrefix = "\0".SilencedErrorContext::class."\0";
$xPrefix = "\0Exception\0";

if (!isset($a[$s = $sPrefix.'severity'])) {
return $a;
Expand All @@ -93,12 +92,17 @@ public static function castSilencedErrorContext(SilencedErrorContext $e, array $
$a[$s] = new ConstStub(self::$errorTypes[$a[$s]], $a[$s]);
}

$trace = array(
$trace = array(array(
'file' => $a[$sPrefix.'file'],
'line' => $a[$sPrefix.'line'],
);
unset($a[$sPrefix.'file'], $a[$sPrefix.'line']);
$a[Caster::PREFIX_VIRTUAL.'trace'] = new TraceStub(array($trace));
));

if (isset($a[$sPrefix.'trace'])) {
$trace = array_merge($trace, $a[$sPrefix.'trace']);
}

unset($a[$sPrefix.'file'], $a[$sPrefix.'line'], $a[$sPrefix.'trace']);
$a[Caster::PREFIX_VIRTUAL.'trace'] = new TraceStub($trace);

return $a;
}
Expand Down

0 comments on commit 1006959

Please sign in to comment.