From 8d3fe62389469347f7ebc551ee36f4527655b804 Mon Sep 17 00:00:00 2001 From: diosmosis Date: Mon, 18 Feb 2019 06:02:29 -0800 Subject: Enable fingers crossed handler via INI config and show backtrace in logs/archive api output (#13923) * Add config to use FringersCrossedHandler (untested) * Get to work in different contexts. * Add changelog note. * Make sure more exceptions make it to the logs, make backtrace include previous exceptions, do not use screen writer if in cli mode, always print backtrace if in CLI mode and archivephp triggered. * Add log capturing handler. * Remove options from global.ini.php sibnce they may be temporary. * Add UI test triggering an error w/ the screen handler. * Add some more log statements, ignore logs in screen writer, replace part of message in ExceptionToTextProcessor instead of whole message. * Add missing license. * Update changelog, move new item to 3.9 * Fixing some integration tests. * Fix another unit test. * One more test fix. * Try to get rid of xss testing warning. * Try again to get rid of warning. * Try again to get rid of warning. * Try again to get rid of warning. --- plugins/CoreConsole/Commands/ClearCaches.php | 1 - plugins/CustomVariables/Model.php | 7 ++- plugins/Monolog/Handler/LogCaptureHandler.php | 34 +++++++++++++ plugins/Monolog/Handler/WebNotificationHandler.php | 9 ++++ .../Monolog/Processor/ExceptionToTextProcessor.php | 55 +++++++++++++++++++--- plugins/Monolog/config/config.php | 42 ++++++++++++++++- .../ScheduledReports/tests/Integration/ApiTest.php | 3 +- plugins/UserCountry/GeoIPAutoUpdater.php | 19 ++++++-- 8 files changed, 154 insertions(+), 16 deletions(-) create mode 100644 plugins/Monolog/Handler/LogCaptureHandler.php (limited to 'plugins') diff --git a/plugins/CoreConsole/Commands/ClearCaches.php b/plugins/CoreConsole/Commands/ClearCaches.php index b88680812f..1e8439ca0b 100644 --- a/plugins/CoreConsole/Commands/ClearCaches.php +++ b/plugins/CoreConsole/Commands/ClearCaches.php @@ -12,7 +12,6 @@ namespace Piwik\Plugins\CoreConsole\Commands; use Piwik\Filesystem; use Piwik\Plugin\ConsoleCommand; use Symfony\Component\Console\Input\InputInterface; -use Symfony\Component\Console\Input\InputOption; use Symfony\Component\Console\Output\OutputInterface; /** diff --git a/plugins/CustomVariables/Model.php b/plugins/CustomVariables/Model.php index 5abb327f0e..7ab4605489 100644 --- a/plugins/CustomVariables/Model.php +++ b/plugins/CustomVariables/Model.php @@ -9,10 +9,12 @@ namespace Piwik\Plugins\CustomVariables; use Piwik\Common; +use Piwik\Container\StaticContainer; use Piwik\DataTable; use Piwik\Db; use Piwik\Log; use Piwik\Piwik; +use Psr\Log\LoggerInterface; class Model { @@ -194,7 +196,10 @@ class Model $model->addCustomVariable(); } } catch (\Exception $e) { - Log::error('Failed to add custom variable: ' . $e->getMessage()); + StaticContainer::get(LoggerInterface::class)->error('Failed to add custom variable: {exception}', [ + 'exception' => $e, + 'ignoreInScreenWriter' => true, + ]); } } } diff --git a/plugins/Monolog/Handler/LogCaptureHandler.php b/plugins/Monolog/Handler/LogCaptureHandler.php new file mode 100644 index 0000000000..fbe4acad29 --- /dev/null +++ b/plugins/Monolog/Handler/LogCaptureHandler.php @@ -0,0 +1,34 @@ +allLogs[] = $record; + } + + /** + * Returns all records. The records should be processed, so one could just use $record['message']. + * + * @return array[] + */ + public function getAllRecords() + { + return $this->allLogs; + } +} \ No newline at end of file diff --git a/plugins/Monolog/Handler/WebNotificationHandler.php b/plugins/Monolog/Handler/WebNotificationHandler.php index 5f0de1bb8c..9ff76958aa 100644 --- a/plugins/Monolog/Handler/WebNotificationHandler.php +++ b/plugins/Monolog/Handler/WebNotificationHandler.php @@ -20,6 +20,15 @@ use Zend_Session_Exception; */ class WebNotificationHandler extends AbstractProcessingHandler { + public function isHandling(array $record) + { + if (!empty($record['context']['ignoreInScreenWriter'])) { + return false; + } + + return parent::isHandling($record); + } + protected function write(array $record) { switch ($record['level']) { diff --git a/plugins/Monolog/Processor/ExceptionToTextProcessor.php b/plugins/Monolog/Processor/ExceptionToTextProcessor.php index daaaee479e..0a947a9f23 100644 --- a/plugins/Monolog/Processor/ExceptionToTextProcessor.php +++ b/plugins/Monolog/Processor/ExceptionToTextProcessor.php @@ -25,34 +25,75 @@ class ExceptionToTextProcessor /** @var \Exception $exception */ $exception = $record['context']['exception']; - $record['message'] = sprintf( + $exceptionStr = sprintf( "%s(%d): %s\n%s", - $exception->getFile(), - $exception->getLine(), + $exception instanceof \Exception ? $exception->getFile() : $exception['file'], + $exception instanceof \Exception ? $exception->getLine() : $exception['line'], $this->getMessage($exception), $this->getStackTrace($exception) ); + if (!isset($record['message']) + || strpos($record['message'], '{exception}') === false + ) { + $record['message'] = $exceptionStr; + } else { + $record['message'] = str_replace('{exception}', $exceptionStr, $record['message']); + } + return $record; } private function contextContainsException($record) { return isset($record['context']['exception']) - && $record['context']['exception'] instanceof \Exception; + && ($record['context']['exception'] instanceof \Exception + || $this->isLooksLikeFatalErrorArray($record['context']['exception'])); + } + + private function isLooksLikeFatalErrorArray($exception) + { + return is_array($exception) && isset($exception['message']) && isset($exception['file']) && isset($exception['line']); } - private function getMessage(\Exception $exception) + private function getMessage($exception) { if ($exception instanceof \ErrorException) { return ErrorHandler::getErrNoString($exception->getSeverity()) . ' - ' . $exception->getMessage(); } + if (is_array($exception) && isset($exception['message'])) { + return $exception['message']; + } + return $exception->getMessage(); } - private function getStackTrace(\Exception $exception) + private function getStackTrace($exception) { - return Log::$debugBacktraceForTests ?: $exception->getTraceAsString(); + if (is_array($exception) && isset($exception['backtrace'])) { + return $exception['backtrace']; + } + + return Log::$debugBacktraceForTests ?: self::getWholeBacktrace($exception); + } + + public static function getWholeBacktrace(\Exception $exception, $shouldPrintBacktrace = true) + { + $message = ""; + + $e = $exception; + do { + if ($e !== $exception) { + $message .= ",\ncaused by: "; + } + + $message .= $e->getMessage(); + if ($shouldPrintBacktrace) { + $message .= "\n" . $e->getTraceAsString(); + } + } while ($e = $e->getPrevious()); + + return $message; } } diff --git a/plugins/Monolog/config/config.php b/plugins/Monolog/config/config.php index 19e7752479..b9e9e0c62f 100644 --- a/plugins/Monolog/config/config.php +++ b/plugins/Monolog/config/config.php @@ -4,6 +4,7 @@ use Interop\Container\ContainerInterface; use Monolog\Logger; use Piwik\Log; use Piwik\Plugins\Monolog\Handler\FileHandler; +use Piwik\Plugins\Monolog\Handler\LogCaptureHandler; return array( @@ -17,7 +18,7 @@ return array( 'screen' => 'Piwik\Plugins\Monolog\Handler\WebNotificationHandler', 'database' => 'Piwik\Plugins\Monolog\Handler\DatabaseHandler', ), - 'log.handlers' => DI\factory(function (ContainerInterface $c) { + 'log.handlers' => DI\factory(function (\DI\Container $c) { if ($c->has('ini.log.log_writers')) { $writerNames = $c->get('ini.log.log_writers'); } else { @@ -26,13 +27,50 @@ return array( $classes = $c->get('log.handler.classes'); + $logConfig = $c->get(\Piwik\Config::class)->log; + $enableFingersCrossed = isset($logConfig['enable_fingers_crossed_handler']) && $logConfig['enable_fingers_crossed_handler'] == 1; + $fingersCrossedStopBuffering = isset($logConfig['fingers_crossed_stop_buffering_on_activation']) && $logConfig['fingers_crossed_stop_buffering_on_activation'] == 1; + $enableLogCaptureHandler = isset($logConfig['enable_log_capture_handler']) && $logConfig['enable_log_capture_handler'] == 1; + + $isLogBufferingAllowed = !\Piwik\Common::isPhpCliMode() + || \Piwik\SettingsServer::isArchivePhpTriggered() + || \Piwik\CliMulti::isCliMultiRequest(); + $writerNames = array_map('trim', $writerNames); $writers = array(); foreach ($writerNames as $writerName) { + if ($writerName === 'screen' && \Piwik\Common::isPhpCliMode()) { + continue; // screen writer is only valid for web requests + } + if (isset($classes[$writerName])) { - $writers[$writerName] = $c->get($classes[$writerName]); + // wrap the handler in FingersCrossedHandler if we can and this isn't the screen handler + + /** @var \Monolog\Handler\HandlerInterface $handler */ + $handler = $c->make($classes[$writerName]); + if ($enableFingersCrossed + && $writerName !== 'screen' + && $handler instanceof \Monolog\Handler\AbstractHandler + && $isLogBufferingAllowed + ) { + $passthruLevel = $handler->getLevel(); + + $handler->setLevel(Logger::DEBUG); + + $handler = new \Monolog\Handler\FingersCrossedHandler($handler, $activationStrategy = null, $bufferSize = 0, + $bubble = true, $fingersCrossedStopBuffering, $passthruLevel); + } + + $writers[$writerName] = $handler; } } + + if ($enableLogCaptureHandler + && $isLogBufferingAllowed + ) { + $writers[] = $c->get(LogCaptureHandler::class); + } + return array_values($writers); }), diff --git a/plugins/ScheduledReports/tests/Integration/ApiTest.php b/plugins/ScheduledReports/tests/Integration/ApiTest.php index fa7168c7e4..11ffcdba77 100644 --- a/plugins/ScheduledReports/tests/Integration/ApiTest.php +++ b/plugins/ScheduledReports/tests/Integration/ApiTest.php @@ -9,6 +9,7 @@ namespace Piwik\Plugins\ScheduledReports\tests; use Piwik\API\Proxy; +use Piwik\Container\StaticContainer; use Piwik\DataTable; use Piwik\Date; use Piwik\Plugins\MobileMessaging\API as APIMobileMessaging; @@ -460,7 +461,7 @@ class ApiTest extends IntegrationTestCase throw new \Exception("Unexpected method $className::$methodName."); } }); - Proxy::setSingletonInstance($mockProxy); + StaticContainer::getContainer()->set(Proxy::class, $mockProxy); $idReport = APIScheduledReports::getInstance()->addReport( 1, diff --git a/plugins/UserCountry/GeoIPAutoUpdater.php b/plugins/UserCountry/GeoIPAutoUpdater.php index db47feb063..9d2ab6af92 100644 --- a/plugins/UserCountry/GeoIPAutoUpdater.php +++ b/plugins/UserCountry/GeoIPAutoUpdater.php @@ -28,6 +28,7 @@ use Piwik\Scheduler\Schedule\Monthly; use Piwik\Scheduler\Schedule\Weekly; use Piwik\SettingsPiwik; use Piwik\Unzip; +use Psr\Log\LoggerInterface; /** * Used to automatically update installed GeoIP databases, and manages the updater's @@ -113,7 +114,10 @@ class GeoIPAutoUpdater extends Task } } catch (Exception $ex) { // message will already be prefixed w/ 'GeoIPAutoUpdater: ' - Log::error($ex); + StaticContainer::get(LoggerInterface::class)->error('Auto-update failed: {exception}', [ + 'exception' => $ex, + 'ignoreInScreenWriter' => true, + ]); $this->performRedundantDbChecks(); throw $ex; } @@ -572,9 +576,16 @@ class GeoIPAutoUpdater extends Task if (self::$unzipPhpError !== null) { list($errno, $errstr, $errfile, $errline) = self::$unzipPhpError; - if($logErrors) { - Log::error("GeoIPAutoUpdater: Encountered PHP error when performing redundant tests on GeoIP " - . "%s database: %s: %s on line %s of %s.", $type, $errno, $errstr, $errline, $errfile); + if ($logErrors) { + StaticContainer::get(LoggerInterface::class)->error("GeoIPAutoUpdater: Encountered PHP error when performing redundant tests on GeoIP " + . "{type} database: {errno}: {errstr} on line {errline} of {errfile}.", [ + 'ignoreInScreenWriter' => true, + 'type' => $type, + 'errno' => $errno, + 'errstr' => $errstr, + 'errline' => $errline, + 'errfile' => $errfile, + ]); } // get the current filename for the DB and an available new one to rename it to -- cgit v1.2.3