Skip to content

Commit 15fd270

Browse files
lyrixxlyrixx
committed
[Debug] Better error handling
1. Send the raw exception in the log context instead of custom formatting 2. Add config option to log in Symfony all PHP errors
1 parent 3696e61 commit 15fd270

File tree

3 files changed

+144
-85
lines changed

3 files changed

+144
-85
lines changed

‎DataCollector/LoggerDataCollector.php

Lines changed: 69 additions & 33 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@
1111

1212
namespace Symfony\Component\HttpKernel\DataCollector;
1313

14+
use Symfony\Component\Debug\Exception\SilencedErrorContext;
1415
use Symfony\Component\HttpFoundation\Request;
1516
use Symfony\Component\HttpFoundation\Response;
1617
use Symfony\Component\HttpKernel\Log\DebugLoggerInterface;
@@ -119,45 +120,64 @@ private function sanitizeLogs($logs)
119120
$sanitizedLogs = array();
120121

121122
foreach ($logs as $log) {
122-
$context = $this->sanitizeContext($log['context']);
123+
if (!$this->isSilencedOrDeprecationErrorLog($log)) {
124+
$log['context'] = $this->sanitizeContext($log['context']);
125+
$sanitizedLogs[] = $log;
123126

124-
if (isset($context['type'], $context['file'], $context['line'], $context['level'])) {
125-
$errorId = md5("{$context['type']}/{$context['line']}/{$context['file']}\x00{$log['message']}", true);
126-
$silenced = !($context['type'] & $context['level']);
127-
if (isset($this->errorNames[$context['type']])) {
128-
$context = array_merge(array('name' => $this->errorNames[$context['type']]), $context);
129-
}
127+
continue;
128+
}
130129

131-
if (isset($errorContextById[$errorId])) {
132-
if (isset($errorContextById[$errorId]['errorCount'])) {
133-
++$errorContextById[$errorId]['errorCount'];
134-
} else {
135-
$errorContextById[$errorId]['errorCount'] = 2;
136-
}
130+
$exception = $log['context']['exception'];
137131

138-
if (!$silenced && isset($errorContextById[$errorId]['scream'])) {
139-
unset($errorContextById[$errorId]['scream']);
140-
$errorContextById[$errorId]['level'] = $context['level'];
141-
}
132+
$context = array(
133+
'type' => isset($this->errorNames[$exception->getSeverity()]) ? $this->errorNames[$exception->getSeverity()] : $exception->getSeverity(),
134+
'file' => $exception->getFile(),
135+
'line' => $exception->getLine(),
136+
'errorCount' => 0,
137+
'scream' => $exception instanceof SilencedErrorContext,
138+
);
142139

143-
continue;
144-
}
140+
if ($exception instanceof \Exception) {
141+
$context['trace'] = array_map(function ($call) {
142+
unset($call['args']);
145143

146-
$errorContextById[$errorId] = &$context;
147-
if ($silenced) {
148-
$context['scream'] = true;
149-
}
144+
return $call;
145+
}, $exception->getTrace());
146+
}
150147

151-
$log['context'] = &$context;
152-
unset($context);
153-
} else {
154-
$log['context'] = $context;
148+
$errorId = md5("{$context['type']}/{$context['line']}/{$context['file']}\x00{$log['message']}", true);
149+
150+
if (!isset($errorContextById[$errorId])) {
151+
$errorContextById[$errorId] = $context;
155152
}
156153

157-
$sanitizedLogs[] = $log;
154+
$context['errorCount'] = ++$errorContextById[$errorId]['errorCount'];
155+
156+
$log['context'] = $this->sanitizeContext($context);
157+
158+
$sanitizedLogs[$errorId] = $log;
158159
}
159160

160-
return $sanitizedLogs;
161+
return array_values($sanitizedLogs);
162+
}
163+
164+
private function isSilencedOrDeprecationErrorLog(array $log)
165+
{
166+
if (!isset($log['context']['exception'])) {
167+
return false;
168+
}
169+
170+
$exception = $log['context']['exception'];
171+
172+
if ($exception instanceof SilencedErrorContext) {
173+
return true;
174+
}
175+
176+
if ($exception instanceof \ErrorException && in_array($exception->getSeverity(), array(E_DEPRECATED, E_USER_DEPRECATED), true)) {
177+
return true;
178+
}
179+
180+
return false;
161181
}
162182

163183
private function sanitizeContext($context)
@@ -174,6 +194,22 @@ private function sanitizeContext($context)
174194
return sprintf('Resource(%s)', get_resource_type($context));
175195
}
176196

197+
if ($context instanceof \Exception) {
198+
$trace = array_map(function ($call) {
199+
unset($call['args']);
200+
201+
return $call;
202+
}, $context->getTrace());
203+
204+
return array(
205+
'class' => get_class($context),
206+
'message' => $context->getMessage(),
207+
'file' => $context->getFile(),
208+
'line' => $context->getLine(),
209+
'trace' => $trace,
210+
);
211+
}
212+
177213
if (is_object($context)) {
178214
return sprintf('Object(%s)', get_class($context));
179215
}
@@ -200,11 +236,11 @@ private function computeErrorsCount()
200236
);
201237
}
202238

203-
if (isset($log['context']['type'], $log['context']['level'])) {
204-
if (E_DEPRECATED === $log['context']['type'] || E_USER_DEPRECATED === $log['context']['type']) {
205-
++$count['deprecation_count'];
206-
} elseif (!($log['context']['type'] & $log['context']['level'])) {
239+
if ($this->isSilencedOrDeprecationErrorLog($log)) {
240+
if ($log['context']['exception'] instanceof SilencedErrorContext) {
207241
++$count['scream_count'];
242+
} else {
243+
++$count['deprecation_count'];
208244
}
209245
}
210246
}

‎EventListener/DebugHandlersListener.php

Lines changed: 13 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -35,6 +35,7 @@ class DebugHandlersListener implements EventSubscriberInterface
3535
private $throwAt;
3636
private $scream;
3737
private $fileLinkFormat;
38+
private $scope;
3839
private $firstCall = true;
3940

4041
/**
@@ -44,15 +45,17 @@ class DebugHandlersListener implements EventSubscriberInterface
4445
* @param int|null $throwAt Thrown errors in a bit field of E_* constants, or null to keep the current value
4546
* @param bool $scream Enables/disables screaming mode, where even silenced errors are logged
4647
* @param string $fileLinkFormat The format for links to source files
48+
* @param bool $scope Enables/disables scoping mode
4749
*/
48-
public function __construct(callable $exceptionHandler = null, LoggerInterface $logger = null, $levels = E_ALL, $throwAt = E_ALL, $scream = true, $fileLinkFormat = null)
50+
public function __construct(callable $exceptionHandler = null, LoggerInterface $logger = null, $levels = E_ALL, $throwAt = E_ALL, $scream = true, $fileLinkFormat = null, $scope = true)
4951
{
5052
$this->exceptionHandler = $exceptionHandler;
5153
$this->logger = $logger;
5254
$this->levels = null === $levels ? E_ALL : $levels;
5355
$this->throwAt = is_numeric($throwAt) ? (int) $throwAt : (null === $throwAt ? null : ($throwAt ? E_ALL : null));
5456
$this->scream = (bool) $scream;
5557
$this->fileLinkFormat = $fileLinkFormat ?: ini_get('xdebug.file_link_format') ?: get_cfg_var('xdebug.file_link_format');
58+
$this->scope = (bool) $scope;
5659
}
5760

5861
/**
@@ -74,15 +77,20 @@ public function configure(Event $event = null)
7477
if ($this->logger) {
7578
$handler->setDefaultLogger($this->logger, $this->levels);
7679
if (is_array($this->levels)) {
77-
$scream = 0;
80+
$levels = 0;
7881
foreach ($this->levels as $type => $log) {
79-
$scream |= $type;
82+
$levels |= $type;
8083
}
8184
} else {
82-
$scream = $this->levels;
85+
$levels = $this->levels;
8386
}
8487
if ($this->scream) {
85-
$handler->screamAt($scream);
88+
$handler->screamAt($levels);
89+
}
90+
if ($this->scope) {
91+
$handler->scopeAt($this->levels);
92+
} else {
93+
$handler->scopeAt(0, true);
8694
}
8795
$this->logger = $this->levels = null;
8896
}

‎Tests/DataCollector/LoggerDataCollectorTest.php

Lines changed: 62 additions & 47 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@
1111

1212
namespace Symfony\Component\HttpKernel\Tests\DataCollector;
1313

14+
use Symfony\Component\Debug\Exception\SilencedErrorContext;
1415
use Symfony\Component\HttpKernel\DataCollector\LoggerDataCollector;
1516

1617
class LoggerDataCollectorTest extends \PHPUnit_Framework_TestCase
@@ -27,11 +28,18 @@ public function testCollect($nb, $logs, $expectedLogs, $expectedDeprecationCount
2728
$c = new LoggerDataCollector($logger);
2829
$c->lateCollect();
2930

30-
$this->assertSame('logger', $c->getName());
31-
$this->assertSame($nb, $c->countErrors());
32-
$this->assertSame($expectedLogs ?: $logs, $c->getLogs());
33-
$this->assertSame($expectedDeprecationCount, $c->countDeprecations());
34-
$this->assertSame($expectedScreamCount, $c->countScreams());
31+
// Remove the trace from the real logs, to ease fixtures creation.
32+
$logs = array_map(function ($log) {
33+
unset($log['context']['trace'], $log['context']['exception']['trace']);
34+
35+
return $log;
36+
}, $c->getLogs());
37+
38+
$this->assertEquals('logger', $c->getName());
39+
$this->assertEquals($nb, $c->countErrors());
40+
$this->assertEquals($expectedLogs, $logs);
41+
$this->assertEquals($expectedDeprecationCount, $c->countDeprecations());
42+
$this->assertEquals($expectedScreamCount, $c->countScreams());
3543

3644
if (isset($expectedPriorities)) {
3745
$this->assertSame($expectedPriorities, $c->getPriorities());
@@ -40,56 +48,63 @@ public function testCollect($nb, $logs, $expectedLogs, $expectedDeprecationCount
4048

4149
public function getCollectTestData()
4250
{
43-
return array(
44-
array(
45-
1,
46-
array(array('message' => 'foo', 'context' => array(), 'priority' => 100, 'priorityName' => 'DEBUG')),
47-
null,
48-
0,
49-
0,
50-
),
51-
array(
52-
1,
53-
array(array('message' => 'foo', 'context' => array('foo' => fopen(__FILE__, 'r')), 'priority' => 100, 'priorityName' => 'DEBUG')),
54-
array(array('message' => 'foo', 'context' => array('foo' => 'Resource(stream)'), 'priority' => 100, 'priorityName' => 'DEBUG')),
55-
0,
56-
0,
57-
),
51+
yield 'simple log' => array(
52+
1,
53+
array(array('message' => 'foo', 'context' => array(), 'priority' => 100, 'priorityName' => 'DEBUG')),
54+
array(array('message' => 'foo', 'context' => array(), 'priority' => 100, 'priorityName' => 'DEBUG')),
55+
0,
56+
0,
57+
);
58+
59+
yield 'log with a resource' => array(
60+
1,
61+
array(array('message' => 'foo', 'context' => array('foo' => fopen(__FILE__, 'r')), 'priority' => 100, 'priorityName' => 'DEBUG')),
62+
array(array('message' => 'foo', 'context' => array('foo' => 'Resource(stream)'), 'priority' => 100, 'priorityName' => 'DEBUG')),
63+
0,
64+
0,
65+
);
66+
67+
yield 'log with an object' => array(
68+
1,
69+
array(array('message' => 'foo', 'context' => array('foo' => new \stdClass()), 'priority' => 100, 'priorityName' => 'DEBUG')),
70+
array(array('message' => 'foo', 'context' => array('foo' => 'Object(stdClass)'), 'priority' => 100, 'priorityName' => 'DEBUG')),
71+
0,
72+
0,
73+
);
74+
75+
if (!class_exists(SilencedErrorContext::class)) {
76+
return;
77+
}
78+
79+
yield 'logs with some deprecations' => array(
80+
1,
5881
array(
59-
1,
60-
array(array('message' => 'foo', 'context' => array('foo' => new \stdClass()), 'priority' => 100, 'priorityName' => 'DEBUG')),
61-
array(array('message' => 'foo', 'context' => array('foo' => 'Object(stdClass)'), 'priority' => 100, 'priorityName' => 'DEBUG')),
62-
0,
63-
0,
82+
array('message' => 'foo3', 'context' => array('exception' => new \ErrorException('warning', 0, E_USER_WARNING)), 'priority' => 100, 'priorityName' => 'DEBUG'),
83+
array('message' => 'foo', 'context' => array('exception' => new \ErrorException('deprecated', 0, E_DEPRECATED)), 'priority' => 100, 'priorityName' => 'DEBUG'),
84+
array('message' => 'foo2', 'context' => array('exception' => new \ErrorException('deprecated', 0, E_USER_DEPRECATED)), 'priority' => 100, 'priorityName' => 'DEBUG'),
6485
),
6586
array(
66-
1,
67-
array(
68-
array('message' => 'foo', 'context' => array('type' => E_DEPRECATED, 'level' => E_ALL), 'priority' => 100, 'priorityName' => 'DEBUG'),
69-
array('message' => 'foo2', 'context' => array('type' => E_USER_DEPRECATED, 'level' => E_ALL), 'priority' => 100, 'priorityName' => 'DEBUG'),
70-
),
71-
null,
72-
2,
73-
0,
74-
array(100 => array('count' => 2, 'name' => 'DEBUG')),
87+
array('message' => 'foo3', 'context' => array('exception' => array('file' => __FILE__, 'line' => 82, 'class' => \ErrorException::class, 'message' => 'warning')), 'priority' => 100, 'priorityName' => 'DEBUG'),
88+
array('message' => 'foo', 'context' => array('type' => 'E_DEPRECATED', 'file' => __FILE__, 'line' => 83, 'errorCount' => 1, 'scream' => false), 'priority' => 100, 'priorityName' => 'DEBUG'),
89+
array('message' => 'foo2', 'context' => array('type' => 'E_USER_DEPRECATED', 'file' => __FILE__, 'line' => 84, 'errorCount' => 1, 'scream' => false), 'priority' => 100, 'priorityName' => 'DEBUG'),
7590
),
91+
2,
92+
0,
93+
array(100 => array('count' => 3, 'name' => 'DEBUG')),
94+
);
95+
96+
yield 'logs with some silent errors' => array(
97+
1,
7698
array(
77-
1,
78-
array(array('message' => 'foo3', 'context' => array('name' => 'E_USER_WARNING', 'type' => E_USER_WARNING, 'level' => 0, 'file' => __FILE__, 'line' => 123), 'priority' => 100, 'priorityName' => 'DEBUG')),
79-
array(array('message' => 'foo3', 'context' => array('name' => 'E_USER_WARNING', 'type' => E_USER_WARNING, 'level' => 0, 'file' => __FILE__, 'line' => 123, 'scream' => true), 'priority' => 100, 'priorityName' => 'DEBUG')),
80-
0,
81-
1,
99+
array('message' => 'foo3', 'context' => array('exception' => new \ErrorException('warning', 0, E_USER_WARNING)), 'priority' => 100, 'priorityName' => 'DEBUG'),
100+
array('message' => 'foo3', 'context' => array('exception' => new SilencedErrorContext(E_USER_WARNING, __FILE__, __LINE__)), 'priority' => 100, 'priorityName' => 'DEBUG'),
82101
),
83102
array(
84-
1,
85-
array(
86-
array('message' => 'foo3', 'context' => array('type' => E_USER_WARNING, 'level' => 0, 'file' => __FILE__, 'line' => 123), 'priority' => 100, 'priorityName' => 'DEBUG'),
87-
array('message' => 'foo3', 'context' => array('type' => E_USER_WARNING, 'level' => -1, 'file' => __FILE__, 'line' => 123), 'priority' => 100, 'priorityName' => 'DEBUG'),
88-
),
89-
array(array('message' => 'foo3', 'context' => array('name' => 'E_USER_WARNING', 'type' => E_USER_WARNING, 'level' => -1, 'file' => __FILE__, 'line' => 123, 'errorCount' => 2), 'priority' => 100, 'priorityName' => 'DEBUG')),
90-
0,
91-
1,
103+
array('message' => 'foo3', 'context' => array('exception' => array('file' => __FILE__, 'line' => 99, 'class' => \ErrorException::class, 'message' => 'warning')), 'priority' => 100, 'priorityName' => 'DEBUG'),
104+
array('message' => 'foo3', 'context' => array('type' => 'E_USER_WARNING', 'file' => __FILE__, 'line' => 100, 'errorCount' => 1, 'scream' => true), 'priority' => 100, 'priorityName' => 'DEBUG'),
92105
),
106+
0,
107+
1,
93108
);
94109
}
95110
}

0 commit comments

Comments
 (0)