N°4261 - New log handler dedicated to Exceptions & use of it in the portal's Exception listener

Such Exceptions are triggered with a Warning level and default the minimum default level in order to write in DB is above, so the behavior is not modified:
 - logs are written in errors.log (with a warning elvel instead of an error)
 - logs are not written in DB unless `log_level_min.write_in_db` is changed

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")',

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;
+	}
+}

core/metamodel.class.php

@@ -6545,6 +6545,7 @@ abstract class MetaModel
 			ToolsLog::Enable(APPROOT.'log/tools.log');
 			DeadLockLog::Enable();
 			DeprecatedCallsLog::Enable();
+			ExceptionLog::Enable();
 		}
 		else
 		{

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);
 

test/core/Log/ExceptionLogTest.php

@@ -0,0 +1,203 @@
+<?php
+/*
+ * Copyright (C) 2013-2021 Combodo SARL
+ * This file is part of iTop.
+ * iTop is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU Affero General Public License as published by
+ * the Free Software Foundation, either version 3 of the License, or
+ * (at your option) any later version.
+ * iTop is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU Affero General Public License for more details.
+ * You should have received a copy of the GNU Affero General Public License
+ */
+
+namespace Combodo\iTop\Test\UnitTest\Core\Log;
+
+use Combodo\iTop\Test\UnitTest\ItopDataTestCase;
+use Combodo\iTop\Test\UnitTest\ItopTestCase;
+use ExceptionLog;
+
+
+
+
+class ExceptionLogTest extends ItopDataTestCase
+{
+	private $mockFileLog;
+	private $oMetaModelConfig;
+
+	protected function setUp()
+	{
+		require_once (__DIR__.'/ExceptionLogTest/Exceptions.php');
+		parent::setUp();
+
+		$oConfig = \MetaModel::GetConfig();
+		$oConfig->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,
+			],
+		];
+	}
+
+}
+
+
+

test/core/Log/ExceptionLogTest/Exceptions.php

@@ -0,0 +1,23 @@
+<?php
+/*
+ * Copyright (C) 2013-2021 Combodo SARL
+ * This file is part of iTop.
+ * iTop is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU Affero General Public License as published by
+ * the Free Software Foundation, either version 3 of the License, or
+ * (at your option) any later version.
+ * iTop is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU Affero General Public License for more details.
+ * You should have received a copy of the GNU Affero General Public License
+ */
+
+namespace {
+	class ChildException extends Exception {};
+	class GrandChildException extends ChildException {};
+}
+
+namespace Namespaced\Exception {
+	class ExceptionInNamespace extends \ChildException {}
+}