feature #19568 [Debug] Better error handling (lyrixx)

This PR was merged into the 3.2-dev branch.

Discussion
----------

[Debug] Better error handling

| Q             | A
| ------------- | ---
| Branch?       | master
| Bug fix?      | no
| New feature?  | yes
| BC breaks?    | no
| Deprecations? | no
| Tests pass?   | -
| Fixed tickets | -
| License       | MIT
| Doc PR        | https://github.com/symfony/symfony-docs/pull/6870

1. Send the raw exception in the log context instead of custom formatting
2. Add config option to log/throw in Symfony all PHP errors
3. Always use an exception when a PHP error occurs
4. Expand exception in the log context in the web developer toolbar
5. Use the dumper to dump log context in the web developer toolbar

---

I used the following code to produce screenshots:

```php
public function indexAction(Request $request)
    {
        $this->get('logger')->info('A log message with an exception', ['exception' => new \Exception('this exception will be logged')]);

        error_reporting(0);
        for ($i=0; $i < 15; $i++) {
            if ($i == 5) {
                error_reporting(E_ALL);
            }
            if ($i == 10) {
                error_reporting(0);
            }

            trigger_error("Trigger error avec E_USER_NOTICE", E_USER_NOTICE);
        }

        error_reporting(E_ALL);

        @trigger_error("trigger_error avec E_USER_DEPRECATED", E_USER_DEPRECATED);
        trigger_error("trigger_error avec E_USER_DEPRECATED (not silent)", E_USER_DEPRECATED);
// ...
```

![screenshot16](https://cloud.githubusercontent.com/assets/408368/17582279/2c4239b0-5fab-11e6-8428-2eaa7372cce3.png)

![screenshot17](https://cloud.githubusercontent.com/assets/408368/17582287/30cad1ea-5fab-11e6-9b0b-de0fa9f3913b.png)

![screenshot18](https://cloud.githubusercontent.com/assets/408368/17582291/348bb574-5fab-11e6-83b0-5bfaac080838.png)

Commits
-------

8f24549 [Debug] Better error handling
This commit is contained in:
Nicolas Grekas 2016-08-17 17:35:28 +02:00
commit f2200f7cad
13 changed files with 381 additions and 223 deletions

View File

@ -117,10 +117,12 @@ FrameworkBundle
* The `framework.serializer.cache` option and the services
`serializer.mapping.cache.apc` and `serializer.mapping.cache.doctrine.apc`
have been removed. APCu should now be automatically used when available.
* The `Controller::getUser()` method has been removed in favor of the ability
to typehint the security user object in the action.
* The default value of the `framework.php_errors.log` configuration key is set to true.
HttpKernel
----------

View File

@ -116,6 +116,7 @@ class Configuration implements ConfigurationInterface
$this->addPropertyAccessSection($rootNode);
$this->addPropertyInfoSection($rootNode);
$this->addCacheSection($rootNode);
$this->addPhpErrorsSection($rootNode);
return $treeBuilder;
}
@ -692,4 +693,28 @@ class Configuration implements ConfigurationInterface
->end()
;
}
private function addPhpErrorsSection(ArrayNodeDefinition $rootNode)
{
$rootNode
->children()
->arrayNode('php_errors')
->info('PHP errors handling configuration')
->addDefaultsIfNotSet()
->children()
->booleanNode('log')
->info('Use the app logger instead of the PHP logger for logging PHP errors.')
->defaultValue(false)
->treatNullLike(false)
->end()
->booleanNode('throw')
->info('Throw PHP errors as \ErrorException instances.')
->defaultValue($this->debug)
->treatNullLike($this->debug)
->end()
->end()
->end()
->end()
;
}
}

View File

@ -131,6 +131,7 @@ class FrameworkExtension extends Extension
$this->registerProfilerConfiguration($config['profiler'], $container, $loader);
$this->registerCacheConfiguration($config['cache'], $container);
$this->registerWorkflowConfiguration($config['workflows'], $container, $loader);
$this->registerDebugConfiguration($config['php_errors'], $container, $loader);
if ($this->isConfigEnabled($container, $config['router'])) {
$this->registerRouterConfiguration($config['router'], $container, $loader);
@ -147,27 +148,6 @@ class FrameworkExtension extends Extension
$this->registerPropertyInfoConfiguration($config['property_info'], $container, $loader);
}
$loader->load('debug_prod.xml');
$definition = $container->findDefinition('debug.debug_handlers_listener');
if ($container->hasParameter('templating.helper.code.file_link_format')) {
$definition->replaceArgument(5, '%templating.helper.code.file_link_format%');
}
if ($container->getParameter('kernel.debug')) {
$definition->replaceArgument(2, E_ALL & ~(E_COMPILE_ERROR | E_PARSE | E_ERROR | E_CORE_ERROR | E_RECOVERABLE_ERROR));
$loader->load('debug.xml');
// replace the regular event_dispatcher service with the debug one
$definition = $container->findDefinition('event_dispatcher');
$definition->setPublic(false);
$container->setDefinition('debug.event_dispatcher.parent', $definition);
$container->setAlias('event_dispatcher', 'debug.event_dispatcher');
} else {
$definition->replaceArgument(1, null);
}
$this->addAnnotatedClassesToCompile(array(
'**Bundle\\Controller\\',
'**Bundle\\Entity\\',
@ -417,6 +397,48 @@ class FrameworkExtension extends Extension
}
}
/**
* Loads the debug configuration.
*
* @param array $config A php errors configuration array
* @param ContainerBuilder $container A ContainerBuilder instance
* @param XmlFileLoader $loader An XmlFileLoader instance
*/
private function registerDebugConfiguration(array $config, ContainerBuilder $container, XmlFileLoader $loader)
{
$loader->load('debug_prod.xml');
$debug = $container->getParameter('kernel.debug');
if ($debug) {
$loader->load('debug.xml');
// replace the regular event_dispatcher service with the debug one
$definition = $container->findDefinition('event_dispatcher');
$definition->setPublic(false);
$container->setDefinition('debug.event_dispatcher.parent', $definition);
$container->setAlias('event_dispatcher', 'debug.event_dispatcher');
}
$definition = $container->findDefinition('debug.debug_handlers_listener');
if (!$config['log']) {
$definition->replaceArgument(1, null);
}
if (!$config['throw']) {
$container->setParameter('debug.error_handler.throw_at', 0);
}
$definition->replaceArgument(4, $debug);
if ($container->hasParameter('templating.helper.code.file_link_format')) {
$definition->replaceArgument(5, '%templating.helper.code.file_link_format%');
}
$definition->replaceArgument(6, $debug);
}
/**
* Loads the router configuration.
*

View File

@ -6,7 +6,6 @@
<parameters>
<parameter key="debug.container.dump">%kernel.cache_dir%/%kernel.container_class%.xml</parameter>
<parameter key="debug.error_handler.throw_at">-1</parameter>
</parameters>
<services>

View File

@ -5,7 +5,7 @@
xsi:schemaLocation="http://symfony.com/schema/dic/services http://symfony.com/schema/dic/services/services-1.0.xsd">
<parameters>
<parameter key="debug.error_handler.throw_at">0</parameter>
<parameter key="debug.error_handler.throw_at">-1</parameter>
</parameters>
<services>
@ -14,10 +14,11 @@
<tag name="monolog.logger" channel="php" />
<argument>null</argument><!-- Exception handler -->
<argument type="service" id="logger" on-invalid="null" />
<argument>null</argument><!-- Log levels map for enabled error levels -->
<argument>null</argument>
<argument>-1</argument><!-- Log levels map for enabled error levels -->
<argument>%debug.error_handler.throw_at%</argument>
<argument>true</argument>
<argument>null</argument><!-- %templating.helper.code.file_link_format% -->
<argument>true</argument>
</service>
<service id="debug.stopwatch" class="Symfony\Component\Stopwatch\Stopwatch" />

View File

@ -274,6 +274,10 @@ class ConfigurationTest extends \PHPUnit_Framework_TestCase
'default_redis_provider' => 'redis://localhost',
),
'workflows' => array(),
'php_errors' => array(
'log' => false,
'throw' => true,
),
);
}
}

View File

@ -6,7 +6,7 @@
{% if collector.counterrors or collector.countdeprecations or collector.countscreams %}
{% set icon %}
{% set status_color = collector.counterrors ? 'red' : collector.countdeprecations ? 'yellow' : '' %}
{% set error_count = collector.counterrors + collector.countdeprecations + collector.countscreams %}
{% set error_count = collector.counterrors + collector.countdeprecations %}
{{ include('@WebProfiler/Icon/logger.svg') }}
<span class="sf-toolbar-value">{{ error_count }}</span>
{% endset %}
@ -55,7 +55,7 @@
{# sort collected logs in groups #}
{% set deprecation_logs, debug_logs, info_and_error_logs, silenced_logs = [], [], [], [] %}
{% for log in collector.logs %}
{% if log.context.level is defined and log.context.type is defined and log.context.type in [constant('E_DEPRECATED'), constant('E_USER_DEPRECATED')] %}
{% if log.context.errorCount is defined and log.context.type is defined and log.context.type in ['E_DEPRECATED', 'E_USER_DEPRECATED'] %}
{% set deprecation_logs = deprecation_logs|merge([log]) %}
{% elseif log.context.scream is defined and log.context.scream == true %}
{% set silenced_logs = silenced_logs|merge([log]) %}
@ -170,21 +170,22 @@
{% macro render_log_message(category, log_index, log, is_deprecation = false) %}
{{ log.message }}
{% if log.context.errorCount is defined and log.context.errorCount > 1 %}
<span class="text-small text-bold">({{ log.context.errorCount }} times)</span>
{% endif %}
{% if is_deprecation %}
{% set stack = log.context.stack|default([]) %}
{% set stack_id = 'sf-call-stack-' ~ category ~ '-' ~ log_index %}
{% set trace = log.context.trace|default([]) %}
{% set trace_id = 'sf-call-trace-' ~ category ~ '-' ~ log_index %}
{% if log.context.errorCount is defined %}
<span class="text-small text-bold">({{ log.context.errorCount }} times)</span>
{% if trace %}
<button class="btn-link text-small sf-toggle" data-toggle-selector="#{{ trace_id }}" data-toggle-alt-content="Hide stack trace">Show stack trace</button>
{% endif %}
{% if stack %}
<button class="btn-link text-small sf-toggle" data-toggle-selector="#{{ stack_id }}" data-toggle-alt-content="Hide stack trace">Show stack trace</button>
{% endif %}
{% for index, call in stack if index > 1 %}
{% for index, call in trace if index > 1 %}
{% if index == 2 %}
<ul class="sf-call-stack hidden" id="{{ stack_id }}">
<ul class="sf-call-trace hidden" id="{{ trace_id }}">
{% endif %}
{% if call.class is defined %}
@ -206,7 +207,7 @@
{% endif %}
</li>
{% if index == stack|length - 1 %}
{% if index == trace|length - 1 %}
</ul>
{% endif %}
{% endfor %}
@ -224,7 +225,7 @@
<a class="btn-link text-small sf-toggle" data-toggle-selector="#{{ context_id }}" data-toggle-alt-content="Hide full context">Show full context</a>
<div id="{{ context_id }}" class="context">
<pre>{{ context_dump }}</pre>
{{ dump(log.context) }}
</div>
{% else %}
{{ context_dump }}

View File

@ -17,6 +17,7 @@ use Symfony\Component\Debug\Exception\ContextErrorException;
use Symfony\Component\Debug\Exception\FatalErrorException;
use Symfony\Component\Debug\Exception\FatalThrowableError;
use Symfony\Component\Debug\Exception\OutOfMemoryException;
use Symfony\Component\Debug\Exception\SilencedErrorContext;
use Symfony\Component\Debug\FatalErrorHandler\UndefinedFunctionFatalErrorHandler;
use Symfony\Component\Debug\FatalErrorHandler\UndefinedMethodFatalErrorHandler;
use Symfony\Component\Debug\FatalErrorHandler\ClassNotFoundFatalErrorHandler;
@ -29,7 +30,7 @@ use Symfony\Component\Debug\FatalErrorHandler\FatalErrorHandlerInterface;
* - thrownErrors: errors thrown as \ErrorException
* - loggedErrors: logged errors, when not @-silenced
* - scopedErrors: errors thrown or logged with their local context
* - tracedErrors: errors logged with their stack trace, only once for repeated errors
* - tracedErrors: errors logged with their stack trace
* - screamedErrors: never @-silenced errors
*
* Each error level can be logged by a dedicated PSR-3 logger object.
@ -43,6 +44,7 @@ use Symfony\Component\Debug\FatalErrorHandler\FatalErrorHandlerInterface;
* can see them and weight them as more important to fix than others of the same level.
*
* @author Nicolas Grekas <p@tchwork.com>
* @author Grégoire Pineau <lyrixx@lyrixx.info>
*/
class ErrorHandler
{
@ -88,7 +90,6 @@ class ErrorHandler
private $screamedErrors = 0x55; // E_ERROR + E_CORE_ERROR + E_COMPILE_ERROR + E_PARSE
private $loggedErrors = 0;
private $loggedTraces = array();
private $isRecursive = 0;
private $isRoot = false;
private $exceptionHandler;
@ -221,7 +222,7 @@ class ErrorHandler
if ($flush) {
foreach ($this->bootstrappingLogger->cleanLogs() as $log) {
$type = $log[2]['type'];
$type = $log[2]['exception']->getSeverity();
if (!isset($flush[$type])) {
$this->bootstrappingLogger->log($log[0], $log[1], $log[2]);
} elseif ($this->loggers[$type][0]) {
@ -361,6 +362,8 @@ class ErrorHandler
*/
public function handleError($type, $message, $file, $line, array $context, array $backtrace = null)
{
// Level is the current error reporting level to manage silent error.
// Strong errors are not authorized to be silenced.
$level = error_reporting() | E_RECOVERABLE_ERROR | E_USER_ERROR | E_DEPRECATED | E_USER_DEPRECATED;
$log = $this->loggedErrors & $type;
$throw = $this->thrownErrors & $type & $level;
@ -379,18 +382,22 @@ class ErrorHandler
return true;
}
if ($throw) {
if (null !== self::$toStringException) {
$throw = self::$toStringException;
self::$toStringException = null;
} elseif (($this->scopedErrors & $type) && class_exists(ContextErrorException::class)) {
$throw = new ContextErrorException($this->levels[$type].': '.$message, 0, $type, $file, $line, $context);
} else {
$throw = new \ErrorException($this->levels[$type].': '.$message, 0, $type, $file, $line);
}
$logMessage = $this->levels[$type].': '.$message;
if (null !== self::$toStringException) {
$errorAsException = self::$toStringException;
self::$toStringException = null;
} elseif (!$throw && !($type & $level)) {
$errorAsException = new SilencedErrorContext($type, $file, $line);
} elseif ($this->scopedErrors & $type) {
$errorAsException = new ContextErrorException($logMessage, 0, $type, $file, $line, $context);
} else {
$errorAsException = new \ErrorException($logMessage, 0, $type, $file, $line);
}
if ($throw) {
if (E_USER_ERROR & $type) {
$backtrace = $backtrace ?: $throw->getTrace();
$backtrace = $backtrace ?: $errorAsException->getTrace();
for ($i = 1; isset($backtrace[$i]); ++$i) {
if (isset($backtrace[$i]['function'], $backtrace[$i]['type'], $backtrace[$i - 1]['function'])
@ -410,7 +417,7 @@ class ErrorHandler
if (($e instanceof \Exception || $e instanceof \Throwable) && $e->__toString() === $message) {
if (1 === $i) {
// On HHVM
$throw = $e;
$errorAsException = $e;
break;
}
self::$toStringException = $e;
@ -421,7 +428,7 @@ class ErrorHandler
if (1 < $i) {
// On PHP (not on HHVM), display the original error message instead of the default one.
$this->handleException($throw);
$this->handleException($errorAsException);
// Stop the process by giving back the error to the native handler.
return false;
@ -430,47 +437,31 @@ class ErrorHandler
}
}
throw $throw;
throw $errorAsException;
}
// For duplicated errors, log the trace only once
$e = md5("{$type}/{$line}/{$file}\x00{$message}", true);
$trace = true;
if (!($this->tracedErrors & $type) || isset($this->loggedTraces[$e])) {
$trace = false;
} else {
$this->loggedTraces[$e] = 1;
}
$e = compact('type', 'file', 'line', 'level');
if ($type & $level) {
if ($this->scopedErrors & $type) {
$e['scope_vars'] = $context;
if ($trace) {
$e['stack'] = $backtrace ?: debug_backtrace(DEBUG_BACKTRACE_PROVIDE_OBJECT);
}
} elseif ($trace) {
if (null === $backtrace) {
$e['stack'] = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
} else {
foreach ($backtrace as &$frame) {
unset($frame['args'], $frame);
}
$e['stack'] = $backtrace;
}
if (!($this->tracedErrors & $type) && $errorAsException instanceof \Exception) {
static $freeTrace = null;
if (null === $freeTrace) {
$freeTrace = \Closure::bind(function ($e) { $e->trace = array(); }, null, \Exception::class);
}
$freeTrace($errorAsException);
}
if ($this->isRecursive) {
$log = 0;
} elseif (self::$stackedErrorLevels) {
self::$stackedErrors[] = array($this->loggers[$type][0], ($type & $level) ? $this->loggers[$type][1] : LogLevel::DEBUG, $message, $e);
self::$stackedErrors[] = array(
$this->loggers[$type][0],
($type & $level) ? $this->loggers[$type][1] : LogLevel::DEBUG,
$logMessage,
array('exception' => $errorAsException),
);
} else {
try {
$this->isRecursive = true;
$this->loggers[$type][0]->log(($type & $level) ? $this->loggers[$type][1] : LogLevel::DEBUG, $message, $e);
$level = ($type & $level) ? $this->loggers[$type][1] : LogLevel::DEBUG;
$this->loggers[$type][0]->log($level, $logMessage, array('exception' => $errorAsException));
} finally {
$this->isRecursive = false;
}
@ -495,20 +486,13 @@ class ErrorHandler
$type = $exception instanceof FatalErrorException ? $exception->getSeverity() : E_ERROR;
if (($this->loggedErrors & $type) || $exception instanceof FatalThrowableError) {
$e = array(
'type' => $type,
'file' => $exception->getFile(),
'line' => $exception->getLine(),
'level' => error_reporting(),
'stack' => $exception->getTrace(),
);
if ($exception instanceof FatalErrorException) {
if ($exception instanceof FatalThrowableError) {
$error = array(
'type' => $type,
'message' => $message = $exception->getMessage(),
'file' => $e['file'],
'line' => $e['line'],
'file' => $exception->getFile(),
'line' => $exception->getLine(),
);
} else {
$message = 'Fatal '.$exception->getMessage();
@ -523,7 +507,7 @@ class ErrorHandler
}
}
if ($this->loggedErrors & $type) {
$this->loggers[$type][0]->log($this->loggers[$type][1], $message, $e);
$this->loggers[$type][0]->log($this->loggers[$type][1], $message, array('exception' => $exception));
}
if ($exception instanceof FatalErrorException && !$exception instanceof OutOfMemoryException && $error) {
foreach ($this->getFatalErrorHandlers() as $handler) {
@ -629,10 +613,10 @@ class ErrorHandler
$level = array_pop(self::$stackedErrorLevels);
if (null !== $level) {
$e = error_reporting($level);
if ($e !== ($level | E_PARSE | E_ERROR | E_CORE_ERROR | E_COMPILE_ERROR)) {
$errorReportingLevel = error_reporting($level);
if ($errorReportingLevel !== ($level | E_PARSE | E_ERROR | E_CORE_ERROR | E_COMPILE_ERROR)) {
// If the user changed the error level, do not overwrite it
error_reporting($e);
error_reporting($errorReportingLevel);
}
}
@ -640,8 +624,8 @@ class ErrorHandler
$errors = self::$stackedErrors;
self::$stackedErrors = array();
foreach ($errors as $e) {
$e[0]->log($e[1], $e[2], $e[3]);
foreach ($errors as $error) {
$error[0]->log($error[1], $error[2], $error[3]);
}
}
}

View File

@ -0,0 +1,55 @@
<?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\Component\Debug\Exception;
/**
* Data Object that represents a Silenced Error.
*
* @author Grégoire Pineau <lyrixx@lyrixx.info>
*/
class SilencedErrorContext implements \JsonSerializable
{
private $severity;
private $file;
private $line;
public function __construct($severity, $file, $line)
{
$this->severity = $severity;
$this->file = $file;
$this->line = $line;
}
public function getSeverity()
{
return $this->severity;
}
public function getFile()
{
return $this->file;
}
public function getLine()
{
return $this->line;
}
public function JsonSerialize()
{
return array(
'severity' => $this->severity,
'file' => $this->file,
'line' => $this->line,
);
}
}

View File

@ -12,9 +12,10 @@
namespace Symfony\Component\Debug\Tests;
use Psr\Log\LogLevel;
use Symfony\Component\Debug\ErrorHandler;
use Symfony\Component\Debug\BufferingLogger;
use Symfony\Component\Debug\ErrorHandler;
use Symfony\Component\Debug\Exception\ContextErrorException;
use Symfony\Component\Debug\Exception\SilencedErrorContext;
/**
* ErrorHandlerTest.
@ -202,11 +203,12 @@ class ErrorHandlerTest extends \PHPUnit_Framework_TestCase
$warnArgCheck = function ($logLevel, $message, $context) {
$this->assertEquals('info', $logLevel);
$this->assertEquals('foo', $message);
$this->assertArrayHasKey('type', $context);
$this->assertEquals($context['type'], E_USER_DEPRECATED);
$this->assertArrayHasKey('stack', $context);
$this->assertInternalType('array', $context['stack']);
$this->assertEquals('User Deprecated: foo', $message);
$this->assertArrayHasKey('exception', $context);
$exception = $context['exception'];
$this->assertInstanceOf(\ErrorException::class, $exception);
$this->assertSame('User Deprecated: foo', $exception->getMessage());
$this->assertSame(E_USER_DEPRECATED, $exception->getSeverity());
};
$logger
@ -225,9 +227,11 @@ class ErrorHandlerTest extends \PHPUnit_Framework_TestCase
$logger = $this->getMock('Psr\Log\LoggerInterface');
$logArgCheck = function ($level, $message, $context) {
$this->assertEquals('Undefined variable: undefVar', $message);
$this->assertArrayHasKey('type', $context);
$this->assertEquals($context['type'], E_NOTICE);
$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());
};
$logger
@ -278,9 +282,10 @@ class ErrorHandlerTest extends \PHPUnit_Framework_TestCase
{
$logArgCheck = function ($level, $message, $context) {
$this->assertEquals(LogLevel::INFO, $level);
$this->assertArrayHasKey('level', $context);
$this->assertEquals(E_RECOVERABLE_ERROR | E_USER_ERROR | E_DEPRECATED | E_USER_DEPRECATED, $context['level']);
$this->assertArrayHasKey('stack', $context);
$this->assertArrayHasKey('exception', $context);
$exception = $context['exception'];
$this->assertInstanceOf(\ErrorException::class, $exception);
$this->assertSame('User Deprecated: Foo deprecation', $exception->getMessage());
};
$logger = $this->getMock('Psr\Log\LoggerInterface');
@ -305,9 +310,9 @@ class ErrorHandlerTest extends \PHPUnit_Framework_TestCase
$logger = $this->getMock('Psr\Log\LoggerInterface');
$logArgCheck = function ($level, $message, $context) {
$this->assertEquals('Uncaught Exception: foo', $message);
$this->assertArrayHasKey('type', $context);
$this->assertEquals($context['type'], E_ERROR);
$this->assertSame('Uncaught Exception: foo', $message);
$this->assertArrayHasKey('exception', $context);
$this->assertInstanceOf(\Exception::class, $context['exception']);
};
$logger
@ -349,7 +354,7 @@ class ErrorHandlerTest extends \PHPUnit_Framework_TestCase
->method('log')
->withConsecutive(
array($this->equalTo(LogLevel::WARNING), $this->equalTo('Dummy log')),
array($this->equalTo(LogLevel::DEBUG), $this->equalTo('Silenced warning'))
array($this->equalTo(LogLevel::DEBUG), $this->equalTo('User Warning: Silenced warning'))
)
;
@ -391,19 +396,27 @@ class ErrorHandlerTest extends \PHPUnit_Framework_TestCase
$this->assertSame($loggers, $handler->setLoggers(array()));
$handler->handleError(E_DEPRECATED, 'Foo message', __FILE__, 123, array());
$expectedLog = array(LogLevel::INFO, 'Foo message', array('type' => E_DEPRECATED, 'file' => __FILE__, 'line' => 123, 'level' => error_reporting()));
$logs = $bootLogger->cleanLogs();
unset($logs[0][2]['stack']);
$this->assertSame(array($expectedLog), $logs);
$this->assertCount(1, $logs);
$log = $logs[0];
$this->assertSame('info', $log[0]);
$this->assertSame('Deprecated: Foo message', $log[1]);
$this->assertArrayHasKey('exception', $log[2]);
$exception = $log[2]['exception'];
$this->assertInstanceOf(\ErrorException::class, $exception);
$this->assertSame('Deprecated: Foo message', $exception->getMessage());
$this->assertSame(__FILE__, $exception->getFile());
$this->assertSame(123, $exception->getLine());
$this->assertSame(E_DEPRECATED, $exception->getSeverity());
$bootLogger->log($expectedLog[0], $expectedLog[1], $expectedLog[2]);
$bootLogger->log(LogLevel::WARNING, 'Foo message', array('exception' => $exception));
$mockLogger = $this->getMock('Psr\Log\LoggerInterface');
$mockLogger->expects($this->once())
->method('log')
->with(LogLevel::WARNING, 'Foo message', $expectedLog[2]);
->with(LogLevel::WARNING, 'Foo message', array('exception' => $exception));
$handler->setLoggers(array(E_DEPRECATED => array($mockLogger, LogLevel::WARNING)));
}
@ -424,8 +437,8 @@ class ErrorHandlerTest extends \PHPUnit_Framework_TestCase
$logArgCheck = function ($level, $message, $context) {
$this->assertEquals('Fatal Parse Error: foo', $message);
$this->assertArrayHasKey('type', $context);
$this->assertEquals($context['type'], E_PARSE);
$this->assertArrayHasKey('exception', $context);
$this->assertInstanceOf(\Exception::class, $context['exception']);
};
$logger
@ -477,14 +490,7 @@ class ErrorHandlerTest extends \PHPUnit_Framework_TestCase
->method('log')
->with(
$this->equalTo(LogLevel::CRITICAL),
$this->equalTo('Fatal Error: foo'),
$this->equalTo(array(
'type' => 1,
'file' => 'bar',
'line' => 123,
'level' => -1,
'stack' => array(456),
))
$this->equalTo('Fatal Error: foo')
)
;

View File

@ -11,6 +11,7 @@
namespace Symfony\Component\HttpKernel\DataCollector;
use Symfony\Component\Debug\Exception\SilencedErrorContext;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpFoundation\Response;
use Symfony\Component\HttpKernel\Log\DebugLoggerInterface;
@ -119,45 +120,64 @@ class LoggerDataCollector extends DataCollector implements LateDataCollectorInte
$sanitizedLogs = array();
foreach ($logs as $log) {
$context = $this->sanitizeContext($log['context']);
if (!$this->isSilencedOrDeprecationErrorLog($log)) {
$log['context'] = $this->sanitizeContext($log['context']);
$sanitizedLogs[] = $log;
if (isset($context['type'], $context['file'], $context['line'], $context['level'])) {
$errorId = md5("{$context['type']}/{$context['line']}/{$context['file']}\x00{$log['message']}", true);
$silenced = !($context['type'] & $context['level']);
if (isset($this->errorNames[$context['type']])) {
$context = array_merge(array('name' => $this->errorNames[$context['type']]), $context);
}
if (isset($errorContextById[$errorId])) {
if (isset($errorContextById[$errorId]['errorCount'])) {
++$errorContextById[$errorId]['errorCount'];
} else {
$errorContextById[$errorId]['errorCount'] = 2;
}
if (!$silenced && isset($errorContextById[$errorId]['scream'])) {
unset($errorContextById[$errorId]['scream']);
$errorContextById[$errorId]['level'] = $context['level'];
}
continue;
}
$errorContextById[$errorId] = &$context;
if ($silenced) {
$context['scream'] = true;
}
$log['context'] = &$context;
unset($context);
} else {
$log['context'] = $context;
continue;
}
$sanitizedLogs[] = $log;
$exception = $log['context']['exception'];
$context = array(
'type' => isset($this->errorNames[$exception->getSeverity()]) ? $this->errorNames[$exception->getSeverity()] : $exception->getSeverity(),
'file' => $exception->getFile(),
'line' => $exception->getLine(),
'errorCount' => 0,
'scream' => $exception instanceof SilencedErrorContext,
);
if ($exception instanceof \Exception) {
$context['trace'] = array_map(function ($call) {
unset($call['args']);
return $call;
}, $exception->getTrace());
}
$errorId = md5("{$context['type']}/{$context['line']}/{$context['file']}\x00{$log['message']}", true);
if (!isset($errorContextById[$errorId])) {
$errorContextById[$errorId] = $context;
}
$context['errorCount'] = ++$errorContextById[$errorId]['errorCount'];
$log['context'] = $this->sanitizeContext($context);
$sanitizedLogs[$errorId] = $log;
}
return $sanitizedLogs;
return array_values($sanitizedLogs);
}
private function isSilencedOrDeprecationErrorLog(array $log)
{
if (!isset($log['context']['exception'])) {
return false;
}
$exception = $log['context']['exception'];
if ($exception instanceof SilencedErrorContext) {
return true;
}
if ($exception instanceof \ErrorException && in_array($exception->getSeverity(), array(E_DEPRECATED, E_USER_DEPRECATED), true)) {
return true;
}
return false;
}
private function sanitizeContext($context)
@ -174,6 +194,22 @@ class LoggerDataCollector extends DataCollector implements LateDataCollectorInte
return sprintf('Resource(%s)', get_resource_type($context));
}
if ($context instanceof \Exception) {
$trace = array_map(function ($call) {
unset($call['args']);
return $call;
}, $context->getTrace());
return array(
'class' => get_class($context),
'message' => $context->getMessage(),
'file' => $context->getFile(),
'line' => $context->getLine(),
'trace' => $trace,
);
}
if (is_object($context)) {
return sprintf('Object(%s)', get_class($context));
}
@ -200,11 +236,11 @@ class LoggerDataCollector extends DataCollector implements LateDataCollectorInte
);
}
if (isset($log['context']['type'], $log['context']['level'])) {
if (E_DEPRECATED === $log['context']['type'] || E_USER_DEPRECATED === $log['context']['type']) {
++$count['deprecation_count'];
} elseif (!($log['context']['type'] & $log['context']['level'])) {
if ($this->isSilencedOrDeprecationErrorLog($log)) {
if ($log['context']['exception'] instanceof SilencedErrorContext) {
++$count['scream_count'];
} else {
++$count['deprecation_count'];
}
}
}

View File

@ -35,6 +35,7 @@ class DebugHandlersListener implements EventSubscriberInterface
private $throwAt;
private $scream;
private $fileLinkFormat;
private $scope;
private $firstCall = true;
/**
@ -44,8 +45,9 @@ class DebugHandlersListener implements EventSubscriberInterface
* @param int|null $throwAt Thrown errors in a bit field of E_* constants, or null to keep the current value
* @param bool $scream Enables/disables screaming mode, where even silenced errors are logged
* @param string $fileLinkFormat The format for links to source files
* @param bool $scope Enables/disables scoping mode
*/
public function __construct(callable $exceptionHandler = null, LoggerInterface $logger = null, $levels = E_ALL, $throwAt = E_ALL, $scream = true, $fileLinkFormat = null)
public function __construct(callable $exceptionHandler = null, LoggerInterface $logger = null, $levels = E_ALL, $throwAt = E_ALL, $scream = true, $fileLinkFormat = null, $scope = true)
{
$this->exceptionHandler = $exceptionHandler;
$this->logger = $logger;
@ -53,6 +55,7 @@ class DebugHandlersListener implements EventSubscriberInterface
$this->throwAt = is_numeric($throwAt) ? (int) $throwAt : (null === $throwAt ? null : ($throwAt ? E_ALL : null));
$this->scream = (bool) $scream;
$this->fileLinkFormat = $fileLinkFormat ?: ini_get('xdebug.file_link_format') ?: get_cfg_var('xdebug.file_link_format');
$this->scope = (bool) $scope;
}
/**
@ -74,15 +77,20 @@ class DebugHandlersListener implements EventSubscriberInterface
if ($this->logger) {
$handler->setDefaultLogger($this->logger, $this->levels);
if (is_array($this->levels)) {
$scream = 0;
$levels = 0;
foreach ($this->levels as $type => $log) {
$scream |= $type;
$levels |= $type;
}
} else {
$scream = $this->levels;
$levels = $this->levels;
}
if ($this->scream) {
$handler->screamAt($scream);
$handler->screamAt($levels);
}
if ($this->scope) {
$handler->scopeAt($this->levels);
} else {
$handler->scopeAt(0, true);
}
$this->logger = $this->levels = null;
}

View File

@ -11,6 +11,7 @@
namespace Symfony\Component\HttpKernel\Tests\DataCollector;
use Symfony\Component\Debug\Exception\SilencedErrorContext;
use Symfony\Component\HttpKernel\DataCollector\LoggerDataCollector;
class LoggerDataCollectorTest extends \PHPUnit_Framework_TestCase
@ -27,11 +28,18 @@ class LoggerDataCollectorTest extends \PHPUnit_Framework_TestCase
$c = new LoggerDataCollector($logger);
$c->lateCollect();
$this->assertSame('logger', $c->getName());
$this->assertSame($nb, $c->countErrors());
$this->assertSame($expectedLogs ?: $logs, $c->getLogs());
$this->assertSame($expectedDeprecationCount, $c->countDeprecations());
$this->assertSame($expectedScreamCount, $c->countScreams());
// Remove the trace from the real logs, to ease fixtures creation.
$logs = array_map(function ($log) {
unset($log['context']['trace'], $log['context']['exception']['trace']);
return $log;
}, $c->getLogs());
$this->assertEquals('logger', $c->getName());
$this->assertEquals($nb, $c->countErrors());
$this->assertEquals($expectedLogs, $logs);
$this->assertEquals($expectedDeprecationCount, $c->countDeprecations());
$this->assertEquals($expectedScreamCount, $c->countScreams());
if (isset($expectedPriorities)) {
$this->assertSame($expectedPriorities, $c->getPriorities());
@ -40,56 +48,63 @@ class LoggerDataCollectorTest extends \PHPUnit_Framework_TestCase
public function getCollectTestData()
{
return array(
yield 'simple log' => array(
1,
array(array('message' => 'foo', 'context' => array(), 'priority' => 100, 'priorityName' => 'DEBUG')),
array(array('message' => 'foo', 'context' => array(), 'priority' => 100, 'priorityName' => 'DEBUG')),
0,
0,
);
yield 'log with a resource' => array(
1,
array(array('message' => 'foo', 'context' => array('foo' => fopen(__FILE__, 'r')), 'priority' => 100, 'priorityName' => 'DEBUG')),
array(array('message' => 'foo', 'context' => array('foo' => 'Resource(stream)'), 'priority' => 100, 'priorityName' => 'DEBUG')),
0,
0,
);
yield 'log with an object' => array(
1,
array(array('message' => 'foo', 'context' => array('foo' => new \stdClass()), 'priority' => 100, 'priorityName' => 'DEBUG')),
array(array('message' => 'foo', 'context' => array('foo' => 'Object(stdClass)'), 'priority' => 100, 'priorityName' => 'DEBUG')),
0,
0,
);
if (!class_exists(SilencedErrorContext::class)) {
return;
}
yield 'logs with some deprecations' => array(
1,
array(
1,
array(array('message' => 'foo', 'context' => array(), 'priority' => 100, 'priorityName' => 'DEBUG')),
null,
0,
0,
array('message' => 'foo3', 'context' => array('exception' => new \ErrorException('warning', 0, E_USER_WARNING)), 'priority' => 100, 'priorityName' => 'DEBUG'),
array('message' => 'foo', 'context' => array('exception' => new \ErrorException('deprecated', 0, E_DEPRECATED)), 'priority' => 100, 'priorityName' => 'DEBUG'),
array('message' => 'foo2', 'context' => array('exception' => new \ErrorException('deprecated', 0, E_USER_DEPRECATED)), 'priority' => 100, 'priorityName' => 'DEBUG'),
),
array(
1,
array(array('message' => 'foo', 'context' => array('foo' => fopen(__FILE__, 'r')), 'priority' => 100, 'priorityName' => 'DEBUG')),
array(array('message' => 'foo', 'context' => array('foo' => 'Resource(stream)'), 'priority' => 100, 'priorityName' => 'DEBUG')),
0,
0,
array('message' => 'foo3', 'context' => array('exception' => array('file' => __FILE__, 'line' => 82, 'class' => \ErrorException::class, 'message' => 'warning')), 'priority' => 100, 'priorityName' => 'DEBUG'),
array('message' => 'foo', 'context' => array('type' => 'E_DEPRECATED', 'file' => __FILE__, 'line' => 83, 'errorCount' => 1, 'scream' => false), 'priority' => 100, 'priorityName' => 'DEBUG'),
array('message' => 'foo2', 'context' => array('type' => 'E_USER_DEPRECATED', 'file' => __FILE__, 'line' => 84, 'errorCount' => 1, 'scream' => false), 'priority' => 100, 'priorityName' => 'DEBUG'),
),
2,
0,
array(100 => array('count' => 3, 'name' => 'DEBUG')),
);
yield 'logs with some silent errors' => array(
1,
array(
array('message' => 'foo3', 'context' => array('exception' => new \ErrorException('warning', 0, E_USER_WARNING)), 'priority' => 100, 'priorityName' => 'DEBUG'),
array('message' => 'foo3', 'context' => array('exception' => new SilencedErrorContext(E_USER_WARNING, __FILE__, __LINE__)), 'priority' => 100, 'priorityName' => 'DEBUG'),
),
array(
1,
array(array('message' => 'foo', 'context' => array('foo' => new \stdClass()), 'priority' => 100, 'priorityName' => 'DEBUG')),
array(array('message' => 'foo', 'context' => array('foo' => 'Object(stdClass)'), 'priority' => 100, 'priorityName' => 'DEBUG')),
0,
0,
),
array(
1,
array(
array('message' => 'foo', 'context' => array('type' => E_DEPRECATED, 'level' => E_ALL), 'priority' => 100, 'priorityName' => 'DEBUG'),
array('message' => 'foo2', 'context' => array('type' => E_USER_DEPRECATED, 'level' => E_ALL), 'priority' => 100, 'priorityName' => 'DEBUG'),
),
null,
2,
0,
array(100 => array('count' => 2, 'name' => 'DEBUG')),
),
array(
1,
array(array('message' => 'foo3', 'context' => array('name' => 'E_USER_WARNING', 'type' => E_USER_WARNING, 'level' => 0, 'file' => __FILE__, 'line' => 123), 'priority' => 100, 'priorityName' => 'DEBUG')),
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')),
0,
1,
),
array(
1,
array(
array('message' => 'foo3', 'context' => array('type' => E_USER_WARNING, 'level' => 0, 'file' => __FILE__, 'line' => 123), 'priority' => 100, 'priorityName' => 'DEBUG'),
array('message' => 'foo3', 'context' => array('type' => E_USER_WARNING, 'level' => -1, 'file' => __FILE__, 'line' => 123), 'priority' => 100, 'priorityName' => 'DEBUG'),
),
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')),
0,
1,
array('message' => 'foo3', 'context' => array('exception' => array('file' => __FILE__, 'line' => 99, 'class' => \ErrorException::class, 'message' => 'warning')), 'priority' => 100, 'priorityName' => 'DEBUG'),
array('message' => 'foo3', 'context' => array('type' => 'E_USER_WARNING', 'file' => __FILE__, 'line' => 100, 'errorCount' => 1, 'scream' => true), 'priority' => 100, 'priorityName' => 'DEBUG'),
),
0,
1,
);
}
}