diff --git a/core/config.class.inc.php b/core/config.class.inc.php index c806c05b5..58f7ebee7 100644 --- a/core/config.class.inc.php +++ b/core/config.class.inc.php @@ -113,6 +113,14 @@ class Config 'source_of_value' => '', 'show_in_conf_sample' => false, ], + 'log_level_min.write_in_db' => [ + 'type' => 'array', + 'description' => 'Additional configuration that enable "in DB" logs for Exception on compatible code.', + 'default' => [ 'Exception' => 'Error', ], + 'value' => [ 'Exception' => 'Error', ], + 'source_of_value' => '', + 'show_in_conf_sample' => false, + ], 'app_env_label' => [ 'type' => 'string', 'description' => 'Label displayed to describe the current application environment, defaults to the environment name (e.g. "production")', diff --git a/core/log.class.inc.php b/core/log.class.inc.php index dbdd7168c..21b9e57c8 100644 --- a/core/log.class.inc.php +++ b/core/log.class.inc.php @@ -653,9 +653,9 @@ abstract class LogAPI * @throws \ConfigException if log wrongly configured * @uses GetMinLogLevel */ - final public static function IsLogLevelEnabled(string $sLevel, string $sChannel): bool + final public static function IsLogLevelEnabled(string $sLevel, string $sChannel, string $code = 'log_level_min'): bool { - $sMinLogLevel = self::GetMinLogLevel($sChannel); + $sMinLogLevel = self::GetMinLogLevel($sChannel, $code); if ($sMinLogLevel === false || $sMinLogLevel === 'false') { return false; @@ -694,14 +694,14 @@ abstract class LogAPI * * @link https://www.itophub.io/wiki/page?id=3_0_0%3Aadmin%3Alog iTop log reference */ - protected static function GetMinLogLevel($sChannel) + protected static function GetMinLogLevel($sChannel, $code = 'log_level_min') { $oConfig = static::GetConfig(); if (!$oConfig instanceof Config) { return static::GetLevelDefault(); } - $sLogLevelMin = $oConfig->Get('log_level_min'); + $sLogLevelMin = $oConfig->Get($code); if (empty($sLogLevelMin)) { return static::GetLevelDefault(); @@ -1099,3 +1099,146 @@ class LogFileRotationProcess implements iScheduledProcess throw new ProcessException(self::class.' : The configured filename builder is invalid (log_filename_builder_impl="'.$sLogFileNameBuilder.'")'); } } + +/** + * Log exceptions using dedicated API and logic. + * + * Please use @see ExceptionLog::FromException() to log exceptions + * + * @Since 3.0.0 + */ +class ExceptionLog extends LogAPI +{ + const CHANNEL_DEFAULT = 'Exception'; + + private static $oLastEventIssue = null; + + protected static $m_oFileLog = null; + + /** + * This method should be used to write logs. + * + * As it encapsulate the operations performed using the Exception, you should prefer it to the standard API inherited from LogApi `ExceptionLog::Error($oException->getMessage(), get_class($oException), ['exception' => $oException]);` + * The parameter order is not standard, but in our use case, the resulting API is way more convenient this way. + */ + public static function FromException(Exception $oException, $aContext = array(), $sLevel = self::LEVEL_WARNING) + { + if (empty($aContext['exception'])) { + $aContext['exception'] = $oException; + } + + if (empty($aContext['exception class'])) { + $aContext['exception class'] = get_class($oException); + } + + return self::Log($sLevel, $oException->getMessage(), get_class($oException), $aContext); + } + + /** + * @throws \ConfigException if log wrongly configured + */ + public static function Log($sLevel, $sMessage, $sClass = null, $aContext = array()) + { + if (!static::$m_oFileLog) { + return; + } + + if (!isset(self::$aLevelsPriority[$sLevel])) { + IssueLog::Error("invalid log level '{$sLevel}'"); + + return; + } + + + $sChannel = self::FindClassChannel($sClass); + if (static::IsLogLevelEnabled($sLevel, $sChannel)) { + static::$m_oFileLog->$sLevel($sMessage, $sChannel, $aContext); + } + + $sDbChannel = self::FindClassChannel($sClass, 'log_level_min.write_in_db'); + if (static::IsLogLevelEnabled($sLevel, $sDbChannel, 'log_level_min.write_in_db')) { + self::WriteToDb($aContext); + } + + } + + + protected static function FindClassChannel($sClass, $code = 'log_level_min') + { + $oConfig = static::GetConfig(); + if (!$oConfig instanceof Config) { + return static::GetLevelDefault(); + } + + $sLogLevelMin = $oConfig->Get($code); + + if (empty($sLogLevelMin)) { + return $sClass; + } + + if (!is_array($sLogLevelMin)) { + return $sClass; + } + + $sParentClass = $sClass; + while ( + (!isset($sLogLevelMin[$sParentClass])) + && + ($sParentClass !== false) + ) + { + $sParentClass = get_parent_class($sParentClass); + } + + if (isset($sLogLevelMin[$sParentClass])) { + return $sParentClass; + } + + return $sClass; + } + + public static function Enable($sTargetFile = null) + { + if (empty($sTargetFile)) + { + $sTargetFile = APPROOT.'log/error.log'; + } + parent::Enable($sTargetFile); + } + + private static function WriteToDb(array $aContext): void + { + $exception = $aContext['exception']; + if (MetaModel::IsLogEnabledIssue()) { + if (MetaModel::IsValidClass('EventIssue')) { + try { + self::$oLastEventIssue = new EventIssue(); + + $sIssue = ($exception instanceof CoreException) ? $exception->GetIssue() : 'PHP Exception'; + $sErrorStackTrace = ($exception instanceof CoreException) ? $exception->getFullStackTraceAsString() : $exception->getTraceAsString(); + $aContextData = ($exception instanceof CoreException) ? $exception->getContextData() : []; + + + self::$oLastEventIssue->Set('message', $exception->getMessage()); + self::$oLastEventIssue->Set('userinfo', ''); + self::$oLastEventIssue->Set('issue', $sIssue); + self::$oLastEventIssue->Set('impact', ''); + self::$oLastEventIssue->Set('callstack', $sErrorStackTrace); + self::$oLastEventIssue->Set('data', array_merge($aContextData, $aContext)); + self::$oLastEventIssue->DBInsertNoReload(); + } + catch (Exception $e) { + IssueLog::Error("Failed to log issue into the DB"); + } + } + } + } + + /** + * used by the tests + */ + private static function getLastEventIssue() + { + return self::$oLastEventIssue; + } +} diff --git a/core/metamodel.class.php b/core/metamodel.class.php index e9695baaf..5e58e3b4c 100644 --- a/core/metamodel.class.php +++ b/core/metamodel.class.php @@ -6545,6 +6545,7 @@ abstract class MetaModel ToolsLog::Enable(APPROOT.'log/tools.log'); DeadLockLog::Enable(); DeprecatedCallsLog::Enable(); + ExceptionLog::Enable(); } else { diff --git a/datamodels/2.x/itop-portal-base/portal/src/EventListener/ExceptionListener.php b/datamodels/2.x/itop-portal-base/portal/src/EventListener/ExceptionListener.php index 302f91f76..869be3383 100644 --- a/datamodels/2.x/itop-portal-base/portal/src/EventListener/ExceptionListener.php +++ b/datamodels/2.x/itop-portal-base/portal/src/EventListener/ExceptionListener.php @@ -86,7 +86,7 @@ class ExceptionListener implements ContainerAwareInterface } // Log exception in iTop log - IssueLog::Error($sErrorTitle.': '.$sErrorMessage); + \ExceptionLog::FromException($oException, ['uri' => $oEvent->getRequest()->getUri()]); // Prepare data for template $aData = array( @@ -104,8 +104,7 @@ class ExceptionListener implements ContainerAwareInterface else { $oResponse = new Response(); - $oResponse->setContent($this->oContainer->get('twig')->render('itop-portal-base/portal/templates/errors/layout.html.twig', - $aData)); + $oResponse->setContent($this->oContainer->get('twig')->render('itop-portal-base/portal/templates/errors/layout.html.twig', $aData)); } $oResponse->setStatusCode($iStatusCode); diff --git a/test/core/Log/ExceptionLogTest.php b/test/core/Log/ExceptionLogTest.php new file mode 100644 index 000000000..6cc94c334 --- /dev/null +++ b/test/core/Log/ExceptionLogTest.php @@ -0,0 +1,203 @@ +Set('developer_mode.enabled', false); + + $this->mockFileLog = $this->createMock('FileLog'); + $this->oMetaModelConfig = $this->createMock('Config'); + } + + /** + * @dataProvider logProvider + */ + public function testLogInFile($aLevels, $aExceptions, $sChannel, $aExpectedWriteNumber, $logLevelMin, $aExpectedDbWriteNumber, $logLevelMinWriteInDb) + { + ExceptionLog::Enable(); + + $this->oMetaModelConfig + ->method("Get") + ->willReturnCallback(function ($code) use ($logLevelMin, $logLevelMinWriteInDb) { + switch ($code) { + case 'log_level_min': + + if (is_null($logLevelMin)) + { + $oConf = \MetaModel::GetConfig(); + $logLevelMin = $oConf->Get('log_level_min'); + } + + return $logLevelMin; + case 'log_level_min.write_in_db': + + if (is_null($logLevelMinWriteInDb)) + { + $oConf = \MetaModel::GetConfig(); + $logLevelMinWriteInDb = $oConf->Get('log_level_min.write_in_db'); + } + + return $logLevelMinWriteInDb; + } + return ''; + }); + + $aContext = ['contextKey1' => 'value']; + + foreach ($aLevels as $i => $sLevel) { + $oException = $aExceptions[$i]; + $iExpectedWriteNumber = $aExpectedWriteNumber[$i]; + $iExpectedDbWriteNumber = $aExpectedDbWriteNumber[$i]; + $aExpectedContext = array_merge($aContext, ['exception' => $oException, 'exception class' => get_class($oException)]); //The context is preserved, and, if the key 'exception' is not yet in the array, it is added + $this->mockFileLog->expects($this->exactly($iExpectedWriteNumber)) + ->method($sLevel) + ->with($oException->GetMessage(), $sChannel, $aExpectedContext) + ; + + ExceptionLog::MockStaticObjects($this->mockFileLog, $this->oMetaModelConfig); + + ExceptionLog::FromException($oException, $aContext, $sLevel); + + $oExpectedLastEventIssue = $this->InvokeNonPublicStaticMethod('ExceptionLog', 'getLastEventIssue', []); + + if (0 == $iExpectedDbWriteNumber) { + $this->assertNull($oExpectedLastEventIssue); + } else { + $this->assertInstanceOf(\EventIssue::class, $oExpectedLastEventIssue); + $this->assertEquals($aExpectedContext, $oExpectedLastEventIssue->Get('data')); + } + } + } + + public function logProvider() + { + require_once (__DIR__.'/ExceptionLogTest/Exceptions.php'); + + return [ + 'use parent' => [ + 'aLevels' => ['Debug'], + 'aExceptions' => [new \GrandChildException('Foo')], + 'sChannel' => 'Exception', + 'aExpectedWriteNumber' => [1], + 'logLevelMin' => ['Exception' => 'Debug'], + 'iExpectedDbWriteNumber' => [1], + 'logLevelMinWriteInDb' => ['Exception' => 'Debug'], + ], + 'flat configuration' => [ + 'aLevels' => ['Debug'], + 'aExceptions' => [new \GrandChildException('Foo')], + 'sChannel' => 'GrandChildException', + 'aExpectedWriteNumber' => [1], + 'logLevelMin' => 'Debug', + 'iExpectedDbWriteNumber' => [1], + 'logLevelMinWriteInDb' => 'Debug', + ], + 'Default conf has expected levels' => [ + 'aLevels' => ['Debug', 'Warning'], + 'aExceptions' => [new \GrandChildException('I am first'), new \GrandChildException('I am 2d')], + 'sChannel' => 'GrandChildException', + 'aExpectedWriteNumber' => [0, 1], + 'logLevelMin' => null, + 'iExpectedDbWriteNumber' => [0, 0], + 'logLevelMinWriteInDb' => null, + ], + 'use correct order in inheritance tree' => [ + 'aLevels' => ['Trace', 'Debug', 'Info', 'Error'], + 'aExceptions' => [new \GrandChildException('I am first'), new \GrandChildException('I am 2d'), new \GrandChildException('I am 3rd'), new \GrandChildException('I am 4th')], + 'sChannel' => 'GrandChildException', + 'aExpectedWriteNumber' => [0, 1, 1, 1], + 'logLevelMin' => ['ChildException' => 'Error', 'GrandChildException' => 'Debug', ], + 'iExpectedDbWriteNumber' => [0, 1, 1, 1], + 'logLevelMinWriteInDb' => ['ChildException' => 'Error', 'GrandChildException' => 'Debug', ], + ], + 'handle namespaced classes' => [ + 'aLevels' => ['Debug'], + 'aExceptions' => [new \Namespaced\Exception\ExceptionInNamespace('Foo')], + 'sChannel' => 'Namespaced\Exception\ExceptionInNamespace', + 'aExpectedWriteNumber' => [1], + 'logLevelMin' => ['Namespaced\Exception\ExceptionInNamespace' => 'Debug'], + 'iExpectedDbWriteNumber' => [1], + 'logLevelMinWriteInDb' => ['Namespaced\Exception\ExceptionInNamespace' => 'Debug'], + ], + 'not enabled by default' => [ + 'aLevels' => ['Debug'], + 'aExceptions' => [new \Exception('Foo')], + 'sChannel' => 'Exception', + 'aExpectedWriteNumber' => [0], + 'logLevelMin' => null, + 'iExpectedDbWriteNumber' => [0], + 'logLevelMinWriteInDb' => null, + ], + 'explicitly disabled' => [ + 'aLevels' => ['Info'], + 'aExceptions' => [new \Exception('Foo')], + 'sChannel' => 'Exception', + 'aExpectedWriteNumber' => [0], + 'logLevelMin' => ['Exception' => 'Error'], + 'iExpectedDbWriteNumber' => [0], + 'logLevelMinWriteInDb' => ['Exception' => 'Error'], + ], + 'default channel, default conf' => [ + 'aLevels' => ['Warning'], + 'aExceptions' => [new \Exception('Foo')], + 'sChannel' => 'Exception', + 'aExpectedWriteNumber' => [1], + 'logLevelMin' => null, + 'iExpectedDbWriteNumber' => [0], + 'logLevelMinWriteInDb' => null, + ], + 'enabled' => [ + 'aLevels' => ['Debug'], + 'aExceptions' => [new \Exception('Foo')], + 'sChannel' => 'Exception', + 'aExpectedWriteNumber' => [1], + 'logLevelMin' => ['Exception' => 'Debug'], + 'iExpectedDbWriteNumber' => [1], + 'logLevelMinWriteInDb' => ['Exception' => 'Debug'], + ], + 'file: 2 enabled, 2 filtered, db: 1 enabled, 3 filtered' => [ + 'aLevels' => ['Debug', 'Trace', 'Warning', 'Error'], + 'aExceptions' => [new \Exception('I am first'), new \Exception('I am 2d'), new \Exception('I am 3rd'), new \Exception('I am 4th')], + 'sChannel' => 'Exception', + 'aExpectedWriteNumber' => [0, 0, 1, 1], + 'logLevelMin' => null, + 'iExpectedDbWriteNumber' => [0, 0, 0, 1], + 'logLevelMinWriteInDb' => null, + ], + ]; + } + +} + + + diff --git a/test/core/Log/ExceptionLogTest/Exceptions.php b/test/core/Log/ExceptionLogTest/Exceptions.php new file mode 100644 index 000000000..bba62c3ce --- /dev/null +++ b/test/core/Log/ExceptionLogTest/Exceptions.php @@ -0,0 +1,23 @@ +