Skip to content

Commit 1006959

Browse files
fabpotfabpot
committed
bug symfony#23007 [HttpKernel][Debug] Fix missing trace on deprecations collected 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 | symfony#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
2 parents f322107 + 21ef065 commit 1006959

File tree

6 files changed

+124
-33
lines changed

6 files changed

+124
-33
lines changed

‎src/Symfony/Component/Debug/ErrorHandler.php

Lines changed: 40 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -100,6 +100,8 @@ class ErrorHandler
100100
private static $stackedErrors = array();
101101
private static $stackedErrorLevels = array();
102102
private static $toStringException = null;
103+
private static $silencedErrorCache = array();
104+
private static $silencedErrorCount = 0;
103105
private static $exitCode = 0;
104106

105107
/**
@@ -407,7 +409,24 @@ public function handleError($type, $message, $file, $line)
407409
$errorAsException = self::$toStringException;
408410
self::$toStringException = null;
409411
} elseif (!$throw && !($type & $level)) {
410-
$errorAsException = new SilencedErrorContext($type, $file, $line);
412+
if (isset(self::$silencedErrorCache[$message])) {
413+
$lightTrace = null;
414+
$errorAsException = self::$silencedErrorCache[$message];
415+
++$errorAsException->count;
416+
} else {
417+
$lightTrace = $this->tracedErrors & $type ? $this->cleanTrace(debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS), $type, $file, $line, false) : array();
418+
$errorAsException = new SilencedErrorContext($type, $file, $line, $lightTrace);
419+
}
420+
421+
if (100 < ++self::$silencedErrorCount) {
422+
self::$silencedErrorCache = $lightTrace = array();
423+
self::$silencedErrorCount = 1;
424+
}
425+
self::$silencedErrorCache[$message] = $errorAsException;
426+
427+
if (null === $lightTrace) {
428+
return;
429+
}
411430
} else {
412431
if ($scope) {
413432
$errorAsException = new ContextErrorException($logMessage, 0, $type, $file, $line, $context);
@@ -418,19 +437,7 @@ public function handleError($type, $message, $file, $line)
418437
// Clean the trace by removing function arguments and the first frames added by the error handler itself.
419438
if ($throw || $this->tracedErrors & $type) {
420439
$backtrace = $backtrace ?: $errorAsException->getTrace();
421-
$lightTrace = $backtrace;
422-
423-
for ($i = 0; isset($backtrace[$i]); ++$i) {
424-
if (isset($backtrace[$i]['file'], $backtrace[$i]['line']) && $backtrace[$i]['line'] === $line && $backtrace[$i]['file'] === $file) {
425-
$lightTrace = array_slice($lightTrace, 1 + $i);
426-
break;
427-
}
428-
}
429-
if (!($throw || $this->scopedErrors & $type)) {
430-
for ($i = 0; isset($lightTrace[$i]); ++$i) {
431-
unset($lightTrace[$i]['args']);
432-
}
433-
}
440+
$lightTrace = $this->cleanTrace($backtrace, $type, $file, $line, $throw);
434441
$this->traceReflector->setValue($errorAsException, $lightTrace);
435442
} else {
436443
$this->traceReflector->setValue($errorAsException, array());
@@ -687,4 +694,23 @@ protected function getFatalErrorHandlers()
687694
new ClassNotFoundFatalErrorHandler(),
688695
);
689696
}
697+
698+
private function cleanTrace($backtrace, $type, $file, $line, $throw)
699+
{
700+
$lightTrace = $backtrace;
701+
702+
for ($i = 0; isset($backtrace[$i]); ++$i) {
703+
if (isset($backtrace[$i]['file'], $backtrace[$i]['line']) && $backtrace[$i]['line'] === $line && $backtrace[$i]['file'] === $file) {
704+
$lightTrace = array_slice($lightTrace, 1 + $i);
705+
break;
706+
}
707+
}
708+
if (!($throw || $this->scopedErrors & $type)) {
709+
for ($i = 0; isset($lightTrace[$i]); ++$i) {
710+
unset($lightTrace[$i]['args']);
711+
}
712+
}
713+
714+
return $lightTrace;
715+
}
690716
}

‎src/Symfony/Component/Debug/Exception/SilencedErrorContext.php

Lines changed: 13 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -18,15 +18,20 @@
1818
*/
1919
class SilencedErrorContext implements \JsonSerializable
2020
{
21+
public $count = 1;
22+
2123
private $severity;
2224
private $file;
2325
private $line;
26+
private $trace;
2427

25-
public function __construct($severity, $file, $line)
28+
public function __construct($severity, $file, $line, array $trace = array(), $count = 1)
2629
{
2730
$this->severity = $severity;
2831
$this->file = $file;
2932
$this->line = $line;
33+
$this->trace = $trace;
34+
$this->count = $count;
3035
}
3136

3237
public function getSeverity()
@@ -44,12 +49,19 @@ public function getLine()
4449
return $this->line;
4550
}
4651

52+
public function getTrace()
53+
{
54+
return $this->trace;
55+
}
56+
4757
public function JsonSerialize()
4858
{
4959
return array(
5060
'severity' => $this->severity,
5161
'file' => $this->file,
5262
'line' => $this->line,
63+
'trace' => $this->trace,
64+
'count' => $this->count,
5365
);
5466
}
5567
}

‎src/Symfony/Component/Debug/Tests/ErrorHandlerTest.php

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -221,12 +221,17 @@ public function testHandleError()
221221

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

224-
$logArgCheck = function ($level, $message, $context) {
224+
$line = null;
225+
$logArgCheck = function ($level, $message, $context) use (&$line) {
225226
$this->assertEquals('Notice: Undefined variable: undefVar', $message);
226227
$this->assertArrayHasKey('exception', $context);
227228
$exception = $context['exception'];
228229
$this->assertInstanceOf(SilencedErrorContext::class, $exception);
229230
$this->assertSame(E_NOTICE, $exception->getSeverity());
231+
$this->assertSame(__FILE__, $exception->getFile());
232+
$this->assertSame($line, $exception->getLine());
233+
$this->assertNotEmpty($exception->getTrace());
234+
$this->assertSame(1, $exception->count);
230235
};
231236

232237
$logger
@@ -239,6 +244,7 @@ public function testHandleError()
239244
$handler->setDefaultLogger($logger, E_NOTICE);
240245
$handler->screamAt(E_NOTICE);
241246
unset($undefVar);
247+
$line = __LINE__ + 1;
242248
@$undefVar++;
243249

244250
restore_error_handler();

‎src/Symfony/Component/HttpKernel/DataCollector/LoggerDataCollector.php

Lines changed: 36 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -49,10 +49,8 @@ public function collect(Request $request, Response $response, \Exception $except
4949
public function lateCollect()
5050
{
5151
if (null !== $this->logger) {
52-
$this->data = $this->computeErrorsCount();
53-
5452
$containerDeprecationLogs = $this->getContainerDeprecationLogs();
55-
$this->data['deprecation_count'] += count($containerDeprecationLogs);
53+
$this->data = $this->computeErrorsCount($containerDeprecationLogs);
5654
$this->data['compiler_logs'] = $this->getContainerCompilerLogs();
5755
$this->data['logs'] = $this->sanitizeLogs(array_merge($this->logger->getLogs(), $containerDeprecationLogs));
5856
$this->data = $this->cloneVar($this->data);
@@ -113,11 +111,10 @@ private function getContainerDeprecationLogs()
113111
return array();
114112
}
115113

116-
$stubs = array();
117114
$bootTime = filemtime($file);
118115
$logs = array();
119116
foreach (unserialize(file_get_contents($file)) as $log) {
120-
$log['context'] = array('exception' => new SilencedErrorContext($log['type'], $log['file'], $log['line']));
117+
$log['context'] = array('exception' => new SilencedErrorContext($log['type'], $log['file'], $log['line'], $log['trace'], $log['count']));
121118
$log['timestamp'] = $bootTime;
122119
$log['priority'] = 100;
123120
$log['priorityName'] = 'DEBUG';
@@ -159,15 +156,34 @@ private function sanitizeLogs($logs)
159156
continue;
160157
}
161158

159+
$message = $log['message'];
162160
$exception = $log['context']['exception'];
163-
$errorId = md5("{$exception->getSeverity()}/{$exception->getLine()}/{$exception->getFile()}\0{$log['message']}", true);
161+
162+
if ($exception instanceof SilencedErrorContext) {
163+
if (isset($silencedLogs[$h = spl_object_hash($exception)])) {
164+
continue;
165+
}
166+
$silencedLogs[$h] = true;
167+
168+
if (!isset($sanitizedLogs[$message])) {
169+
$sanitizedLogs[$message] = $log + array(
170+
'errorCount' => 0,
171+
'scream' => true,
172+
);
173+
}
174+
$sanitizedLogs[$message]['errorCount'] += $exception->count;
175+
176+
continue;
177+
}
178+
179+
$errorId = md5("{$exception->getSeverity()}/{$exception->getLine()}/{$exception->getFile()}\0{$message}", true);
164180

165181
if (isset($sanitizedLogs[$errorId])) {
166182
++$sanitizedLogs[$errorId]['errorCount'];
167183
} else {
168184
$log += array(
169185
'errorCount' => 1,
170-
'scream' => $exception instanceof SilencedErrorContext,
186+
'scream' => false,
171187
);
172188

173189
$sanitizedLogs[$errorId] = $log;
@@ -196,8 +212,9 @@ private function isSilencedOrDeprecationErrorLog(array $log)
196212
return false;
197213
}
198214

199-
private function computeErrorsCount()
215+
private function computeErrorsCount(array $containerDeprecationLogs)
200216
{
217+
$silencedLogs = array();
201218
$count = array(
202219
'error_count' => $this->logger->countErrors(),
203220
'deprecation_count' => 0,
@@ -220,14 +237,23 @@ private function computeErrorsCount()
220237
}
221238

222239
if ($this->isSilencedOrDeprecationErrorLog($log)) {
223-
if ($log['context']['exception'] instanceof SilencedErrorContext) {
224-
++$count['scream_count'];
240+
$exception = $log['context']['exception'];
241+
if ($exception instanceof SilencedErrorContext) {
242+
if (isset($silencedLogs[$h = spl_object_hash($exception)])) {
243+
continue;
244+
}
245+
$silencedLogs[$h] = true;
246+
$count['scream_count'] += $exception->count;
225247
} else {
226248
++$count['deprecation_count'];
227249
}
228250
}
229251
}
230252

253+
foreach ($containerDeprecationLogs as $deprecationLog) {
254+
$count['deprecation_count'] += $deprecationLog['count'];
255+
}
256+
231257
ksort($count['priorities']);
232258

233259
return $count;

‎src/Symfony/Component/HttpKernel/Kernel.php

Lines changed: 19 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -545,11 +545,28 @@ protected function initializeContainer()
545545
return $previousHandler ? $previousHandler($type, $message, $file, $line) : false;
546546
}
547547

548-
$collectedLogs[] = array(
548+
if (isset($collectedLogs[$message])) {
549+
++$collectedLogs[$message]['count'];
550+
551+
return;
552+
}
553+
554+
$backtrace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
555+
// Clean the trace by removing first frames added by the error handler itself.
556+
for ($i = 0; isset($backtrace[$i]); ++$i) {
557+
if (isset($backtrace[$i]['file'], $backtrace[$i]['line']) && $backtrace[$i]['line'] === $line && $backtrace[$i]['file'] === $file) {
558+
$backtrace = array_slice($backtrace, 1 + $i);
559+
break;
560+
}
561+
}
562+
563+
$collectedLogs[$message] = array(
549564
'type' => $type,
550565
'message' => $message,
551566
'file' => $file,
552567
'line' => $line,
568+
'trace' => $backtrace,
569+
'count' => 1,
553570
);
554571
});
555572
}
@@ -562,7 +579,7 @@ protected function initializeContainer()
562579
if ($this->debug) {
563580
restore_error_handler();
564581

565-
file_put_contents($this->getCacheDir().'/'.$class.'Deprecations.log', serialize($collectedLogs));
582+
file_put_contents($this->getCacheDir().'/'.$class.'Deprecations.log', serialize(array_values($collectedLogs)));
566583
file_put_contents($this->getCacheDir().'/'.$class.'Compiler.log', null !== $container ? implode("\n", $container->getCompiler()->getLog()) : '');
567584
}
568585
}

‎src/Symfony/Component/VarDumper/Caster/ExceptionCaster.php

Lines changed: 9 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -83,7 +83,6 @@ public static function castThrowingCasterException(ThrowingCasterException $e, a
8383
public static function castSilencedErrorContext(SilencedErrorContext $e, array $a, Stub $stub, $isNested)
8484
{
8585
$sPrefix = "\0".SilencedErrorContext::class."\0";
86-
$xPrefix = "\0Exception\0";
8786

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

96-
$trace = array(
95+
$trace = array(array(
9796
'file' => $a[$sPrefix.'file'],
9897
'line' => $a[$sPrefix.'line'],
99-
);
100-
unset($a[$sPrefix.'file'], $a[$sPrefix.'line']);
101-
$a[Caster::PREFIX_VIRTUAL.'trace'] = new TraceStub(array($trace));
98+
));
99+
100+
if (isset($a[$sPrefix.'trace'])) {
101+
$trace = array_merge($trace, $a[$sPrefix.'trace']);
102+
}
103+
104+
unset($a[$sPrefix.'file'], $a[$sPrefix.'line'], $a[$sPrefix.'trace']);
105+
$a[Caster::PREFIX_VIRTUAL.'trace'] = new TraceStub($trace);
102106

103107
return $a;
104108
}

0 commit comments

Comments
 (0)