🔊 better debug level

Co-authored-by: Molkobain <lajarige.guillaume@free.fr>

core/config.class.inc.php

@@ -584,14 +584,6 @@ class Config
 			'source_of_value'     => '',
 			'show_in_conf_sample' => true,
 		],
-		'cron_task_max_execution_time' => [
-			'type' => 'integer',
-			'description' => 'Background tasks will use this value (integer) multiplicated by its periodicity (in seconds) as max duration per cron execution. 0 is unlimited time',
-			'default' => 0,
-			'value' => 0,
-			'source_of_value' => '',
-			'show_in_conf_sample' => false,
-		],
 		'cron_sleep' => [
 			'type' => 'integer',
 			'description' => 'Duration (seconds) before cron.php checks again if something must be done',
@@ -600,6 +592,14 @@ class Config
 			'source_of_value' => '',
 			'show_in_conf_sample' => false,
 		],
+		'cron.max_processes' => [
+			'type' => 'integer',
+			'description' => 'Maximum number of cron processes to run',
+			'default' => 10,
+			'value' => 10,
+			'source_of_value' => '',
+			'show_in_conf_sample' => true,
+		],
 		'async_task_retries' => [
 			'type' => 'array',
 			'description' => 'Automatic retries of asynchronous tasks in case of failure (per class)',

lib/composer/autoload_classmap.php

@@ -494,6 +494,7 @@ return array(
     'Combodo\\iTop\\Service\\Base\\ObjectRepository' => $baseDir . '/sources/Service/Base/ObjectRepository.php',
     'Combodo\\iTop\\Service\\Base\\iDataPostProcessor' => $baseDir . '/sources/Service/Base/iDataPostProcessor.php',
     'Combodo\\iTop\\Service\\Cache\\DataModelDependantCache' => $baseDir . '/sources/Service/Cache/DataModelDependantCache.php',
+    'Combodo\\iTop\\Service\\Cron\\CronLog' => $baseDir . '/sources/Service/Cron/CronLog.php',
     'Combodo\\iTop\\Service\\Events\\Description\\EventDataDescription' => $baseDir . '/sources/Service/Events/Description/EventDataDescription.php',
     'Combodo\\iTop\\Service\\Events\\Description\\EventDescription' => $baseDir . '/sources/Service/Events/Description/EventDescription.php',
     'Combodo\\iTop\\Service\\Events\\EventData' => $baseDir . '/sources/Service/Events/EventData.php',
@@ -3230,5 +3231,5 @@ return array(
     'privUITransactionFile' => $baseDir . '/application/transaction.class.inc.php',
     'privUITransactionSession' => $baseDir . '/application/transaction.class.inc.php',
     'utils' => $baseDir . '/application/utils.inc.php',
-    '<EFBFBD>' => $vendorDir . '/symfony/cache/Traits/ValueWrapper.php',
+    '©' => $vendorDir . '/symfony/cache/Traits/ValueWrapper.php',
 );

lib/composer/autoload_static.php

@@ -884,6 +884,7 @@ class ComposerStaticInit7f81b4a2a468a061c306af5e447a9a9f
         'Combodo\\iTop\\Service\\Base\\ObjectRepository' => __DIR__ . '/../..' . '/sources/Service/Base/ObjectRepository.php',
         'Combodo\\iTop\\Service\\Base\\iDataPostProcessor' => __DIR__ . '/../..' . '/sources/Service/Base/iDataPostProcessor.php',
         'Combodo\\iTop\\Service\\Cache\\DataModelDependantCache' => __DIR__ . '/../..' . '/sources/Service/Cache/DataModelDependantCache.php',
+        'Combodo\\iTop\\Service\\Cron\\CronLog' => __DIR__ . '/../..' . '/sources/Service/Cron/CronLog.php',
         'Combodo\\iTop\\Service\\Events\\Description\\EventDataDescription' => __DIR__ . '/../..' . '/sources/Service/Events/Description/EventDataDescription.php',
         'Combodo\\iTop\\Service\\Events\\Description\\EventDescription' => __DIR__ . '/../..' . '/sources/Service/Events/Description/EventDescription.php',
         'Combodo\\iTop\\Service\\Events\\EventData' => __DIR__ . '/../..' . '/sources/Service/Events/EventData.php',
@@ -3620,7 +3621,7 @@ class ComposerStaticInit7f81b4a2a468a061c306af5e447a9a9f
         'privUITransactionFile' => __DIR__ . '/../..' . '/application/transaction.class.inc.php',
         'privUITransactionSession' => __DIR__ . '/../..' . '/application/transaction.class.inc.php',
         'utils' => __DIR__ . '/../..' . '/application/utils.inc.php',
-        '<EFBFBD>' => __DIR__ . '/..' . '/symfony/cache/Traits/ValueWrapper.php',
+        '©' => __DIR__ . '/..' . '/symfony/cache/Traits/ValueWrapper.php',
     );
 
     public static function getInitializer(ClassLoader $loader)

setup/compiler.class.inc.php

@@ -317,10 +317,12 @@ class MFCompiler
 
 		try
 		{
+			SetupLog::Info("Compiling $sTempTargetDir...");
 			$this->DoCompile($sTempTargetDir, $sFinalTargetDir, $oP = null, $bUseSymbolicLinks);
 		}
 		catch (Exception $e)
 		{
+			SetupLog::Info("Compiling error: ".$e->getMessage());
 			if ($sTempTargetDir != $sFinalTargetDir)
 			{
 				// Cleanup the temporary directory

setup/setuputils.class.inc.php

@@ -2038,36 +2038,47 @@ JS
 	 */
 	private static function WaitCronTermination($oConfig, $sMode)
 	{
-		try
+		$iMaxDuration = $oConfig->Get('cron_max_execution_time');
-		{
+		// Avoid PHP stopping while waiting the cron
+		set_time_limit($iMaxDuration);
+		try {
 			// Wait for cron to stop
 			if (is_null($oConfig) || ContextTag::Check(ContextTag::TAG_CRON)) {
 				return;
 			}
-			// Use mutex to check if cron is running
+			// Limit the number of cron process to run in parallel
-			$oMutex = new iTopMutex(
+			$iMaxCronProcess = $oConfig->Get('cron.max_processes');
-				'cron'.$oConfig->Get('db_name').$oConfig->Get('db_subname'),
-				$oConfig->Get('db_host'),
-				$oConfig->Get('db_user'),
-				$oConfig->Get('db_pwd'),
-				$oConfig->Get('db_tls.enabled'),
-				$oConfig->Get('db_tls.ca')
-			);
 			$iCount = 1;
-			$iStarted = time();
+			$iTimeLimit = time() + $iMaxDuration;
-			$iMaxDuration = $oConfig->Get('cron_max_execution_time');
+			do {
-			$iTimeLimit = $iStarted + $iMaxDuration;
+				$bIsRunning = false;
-			while ($oMutex->IsLocked())
+				// Use all mutexes to check if cron is running
-			{
+				for ($i = 0; $i < $iMaxCronProcess; $i++) {
-				SetupLog::Info("Waiting for cron to stop ($iCount)");
+					$sName = "cron#$i";
-				$iCount++;
+
-				sleep(1);
+					$oMutex = new iTopMutex(
-				if (time() > $iTimeLimit)
+						$sName.$oConfig->Get('db_name').$oConfig->Get('db_subname'),
-				{
+						$oConfig->Get('db_host'),
-					throw new Exception("Cannot enter $sMode mode, consider stopping the cron temporarily");
+						$oConfig->Get('db_user'),
+						$oConfig->Get('db_pwd'),
+						$oConfig->Get('db_tls.enabled'),
+						$oConfig->Get('db_tls.ca')
+					);
+					if ($oMutex->IsLocked()) {
+						$bIsRunning = true;
+						SetupLog::Info("Waiting for cron to stop ($iCount)");
+						$iCount++;
+						sleep(1);
+						if (time() > $iTimeLimit) {
+							SetupLog::Error("Cannot enter $sMode mode, consider stopping the cron temporarily");
+							throw new Exception("Cannot enter $sMode mode, consider stopping the cron temporarily");
+						}
+						break;
+					}
 				}
-			}
+			} while ($bIsRunning);
-		} catch (Exception $e) {
+		}
+		catch (Exception $e) {
 			// Ignore errors
 		}
 	}

sources/Service/Cron/CronLog.php

@@ -0,0 +1,70 @@
+<?php
+/*
+ * @copyright   Copyright (C) 2010-2022 Combodo SARL
+ * @license     http://opensource.org/licenses/AGPL-3.0
+ */
+
+namespace Combodo\iTop\Service\Cron;
+
+use LogAPI;
+use Page;
+use utils;
+
+/**
+ * @since 3.1.0
+ */
+class CronLog extends LogAPI
+{
+	public static int $iProcessNumber = 0;
+	private static int $iDebugLevel = 0;
+	private static ?Page $oP = null;
+
+	const CHANNEL_DEFAULT = 'Cron';
+	/**
+	 * @inheritDoc
+	 *
+	 * As this object is used during setup, without any conf file available, customizing the level can be done by changing this constant !
+	 */
+	const LEVEL_DEFAULT = self::LEVEL_INFO;
+
+	protected static $m_oFileLog = null;
+
+	public static function Log($sLevel, $sMessage, $sChannel = null, $aContext = []): void
+	{
+		$sMessage = 'cron'.str_pad(static::$iProcessNumber, 3).$sMessage;
+		parent::Log($sLevel, $sMessage, $sChannel, $aContext);
+	}
+
+	public static function Debug($sMessage, $sChannel = null, $aContext = []): void
+	{
+		if (self::$iDebugLevel > 0 && self::$oP) {
+			self::$oP->p('cron'.str_pad(static::$iProcessNumber, 3).$sMessage);
+		}
+		parent::Debug($sMessage, $sChannel, $aContext);
+	}
+
+	public static function Trace($sMessage, $sChannel = null, $aContext = []): void
+	{
+		if (self::$iDebugLevel > 1 && self::$oP) {
+			self::$oP->p('cron'.str_pad(static::$iProcessNumber, 3).$sMessage);
+		}
+		parent::Trace($sMessage, $sChannel, $aContext);
+	}
+
+	public static function SetDebug(Page $oP, int $iDebugLevel): void
+	{
+		self::$oP = $oP;
+		self::$iDebugLevel = $iDebugLevel;
+	}
+
+	public static function GetDebugClassName($sTaskClass): string
+	{
+		if (utils::StartsWith($sTaskClass, 'Combodo\\iTop\\Service\\')) {
+			return substr($sTaskClass, strlen('Combodo\\iTop\\Service\\'));
+		}
+		if (utils::StartsWith($sTaskClass, 'Combodo\\iTop\\')) {
+			return substr($sTaskClass, strlen('Combodo\\iTop\\'));
+		}
+		return $sTaskClass;
+	}
+}

webservices/cron.php

@@ -18,17 +18,20 @@
  */
 
 use Combodo\iTop\Application\WebPage\CLIPage;
-use Combodo\iTop\Application\WebPage\Page;
 use Combodo\iTop\Application\WebPage\WebPage;
+use Combodo\iTop\Service\Cron\CronLog;
 use Combodo\iTop\Service\InterfaceDiscovery\InterfaceDiscovery;
 
+if (!defined('__DIR__')) {
+	define('__DIR__', dirname(__FILE__));
+}
+
 require_once(__DIR__.'/../approot.inc.php');
 
 const EXIT_CODE_ERROR = -1;
 const EXIT_CODE_FATAL = -2;
 // early exit
-if (file_exists(READONLY_MODE_FILE))
+if (file_exists(READONLY_MODE_FILE)) {
-{
 	echo "iTop is read-only. Exiting...\n";
 	exit(EXIT_CODE_ERROR);
 }
@@ -37,8 +40,7 @@ require_once(APPROOT.'/application/application.inc.php');
 require_once(APPROOT.'/core/background.inc.php');
 
 $sConfigFile = APPCONF.ITOP_DEFAULT_ENV.'/'.ITOP_CONFIG_FILE;
-if (!file_exists($sConfigFile))
+if (!file_exists($sConfigFile)) {
-{
 	echo "iTop is not yet installed. Exiting...\n";
 	exit(EXIT_CODE_ERROR);
 }
@@ -50,8 +52,7 @@ $oCtx = new ContextTag(ContextTag::TAG_CRON);
 function ReadMandatoryParam($oP, $sParam, $sSanitizationFilter = 'parameter')
 {
 	$sValue = utils::ReadParam($sParam, null, true, $sSanitizationFilter);
-	if (is_null($sValue))
+	if (is_null($sValue)) {
-	{
 		$oP->p("ERROR: Missing argument '$sParam'\n");
 		UsageAndExit($oP);
 	}
@@ -63,13 +64,10 @@ function UsageAndExit($oP)
 {
 	$bModeCLI = ($oP instanceof CLIPage);
 
-	if ($bModeCLI)
+	if ($bModeCLI) {
-	{
 		$oP->p("USAGE:\n");
-		$oP->p("php cron.php --auth_user=<login> --auth_pwd=<password> [--param_file=<file>] [--verbose=1] [--debug=1] [--status_only=1]\n");
+		$oP->p("php cron.php --auth_user=<login> --auth_pwd=<password> [--param_file=<file>] [--verbose=0] [--status_only=1]\n");
-	}
+	} else {
-	else
-	{
 		$oP->p("Optional parameters: verbose, param_file, status_only\n");
 	}
 	$oP->output();
@@ -96,92 +94,64 @@ function RunTask(BackgroundTask $oTask, $iTimeLimit)
 	$oProcess = new $TaskClass;
 	$oRefClass = new ReflectionClass(get_class($oProcess));
 	$oDateStarted = new DateTime();
-	$oDatePlanned = new DateTime($oTask->Get('next_run_date'));
 	$fStart = microtime(true);
 	$oCtx = new ContextTag('CRON:Task:'.$TaskClass);
 
 	$sMessage = '';
 	$oExceptionToThrow = null;
-	try
+	try {
-	{
 		// Record (when starting) that this task was started, just in case it crashes during the execution
+		if ($oTask->Get('total_exec_count') == 0) {
+			// First execution
+			$oTask->Set('first_run_date', $oDateStarted->format('Y-m-d H:i:s'));
+		}
 		$oTask->Set('latest_run_date', $oDateStarted->format('Y-m-d H:i:s'));
 		// Record the current user running the cron
 		$oTask->Set('system_user', utils::GetCurrentUserName());
 		$oTask->Set('running', 1);
-		$oTask->DBUpdate();
+		// Compute the next run date
-		// Time in seconds allowed to the task
+		if ($oRefClass->implementsInterface('iScheduledProcess')) {
-		$iCurrTimeLimit = $iTimeLimit;
+			// Schedules process do repeat at specific moments
-		// Compute allowed time
+			$oPlannedStart = $oProcess->GetNextOccurrence();
-		if ($oRefClass->implementsInterface('iScheduledProcess') === false)
+		} else {
-		{
+			// Background processes do repeat periodically
-			// Periodic task, allow only X times ($iMaxTaskExecutionTime) its periodicity (GetPeriodicity())
+			$oDatePlanned = new DateTime($oTask->Get('next_run_date'));
-			$iMaxTaskExecutionTime = MetaModel::GetConfig()->Get('cron_task_max_execution_time');
+			$oPlannedStart = clone $oDatePlanned;
-			$iTaskLimit = time() + $oProcess->GetPeriodicity() * $iMaxTaskExecutionTime;
+			// Let's schedule from the previous planned date of execution to avoid shift
-			// If our proposed time limit is less than cron limit, and cron_task_max_execution_time is > 0
+			$oPlannedStart->modify('+'.$oProcess->GetPeriodicity().' seconds');
-			if ($iTaskLimit < $iTimeLimit && $iMaxTaskExecutionTime > 0)
+			$oNow = new DateTime();
-			{
+			while ($oPlannedStart->format('U') <= $oNow->format('U')) {
-				$iCurrTimeLimit = $iTaskLimit;
+				// Next planned start is already in the past, increase it again by a period
+				$oPlannedStart = $oPlannedStart->modify('+'.$oProcess->GetPeriodicity().' seconds');
 			}
 		}
-		$sMessage = $oProcess->Process($iCurrTimeLimit);
+		$oTask->Set('next_run_date', $oPlannedStart->format('Y-m-d H:i:s'));
-		$oTask->Set('running', 0);
+		$oTask->DBUpdate();
+
+		$sMessage = $oProcess->Process($iTimeLimit);
 	}
-	catch (MySQLHasGoneAwayException $e)
+	catch (MySQLHasGoneAwayException $e) {
-	{
 		throw $e;
 	}
-	catch (ProcessFatalException $e)
+	catch (ProcessFatalException $e) {
-	{
 		$oExceptionToThrow = $e;
 	}
 	catch (Exception $e) // we shouldn't get so much exceptions... but we need to handle legacy code, and cron.php has to keep running
 	{
-		if ($oTask->IsDebug())
+		if ($oTask->IsDebug()) {
-		{
+			$sMessage = 'Processing failed with message: '.$e->getMessage().'. '.$e->getTraceAsString();
-			$sMessage = 'Processing failed with message: '. $e->getMessage() . '. ' . $e->getTraceAsString();
+		} else {
-		}
+			$sMessage = 'Processing failed with message: '.$e->getMessage();
-		else
-		{
-			$sMessage = 'Processing failed with message: '. $e->getMessage();
 		}
 	}
-	$fDuration = microtime(true) - $fStart;
+	finally {
-	if ($oTask->Get('total_exec_count') == 0)
+		$oTask->Set('running', 0);
-	{
+		$fDuration = microtime(true) - $fStart;
-		// First execution
+		$oTask->ComputeDurations($fDuration); // does increment the counter and compute statistics
-		$oTask->Set('first_run_date', $oDateStarted->format('Y-m-d H:i:s'));
+		$oTask->DBUpdate();
-	}
-	$oTask->ComputeDurations($fDuration); // does increment the counter and compute statistics
-
-	// Update the timestamp since we want to be able to re-order the tasks based on the time they finished
-	$oDateEnded = new DateTime();
-	$oTask->Set('latest_run_date', $oDateEnded->format('Y-m-d H:i:s'));
-
-	if ($oRefClass->implementsInterface('iScheduledProcess'))
-	{
-		// Schedules process do repeat at specific moments
-		$oPlannedStart = $oProcess->GetNextOccurrence();
-	}
-	else
-	{
-		// Background processes do repeat periodically
-		$oPlannedStart = clone $oDatePlanned;
-		// Let's schedule from the previous planned date of execution to avoid shift
-		$oPlannedStart->modify($oProcess->GetPeriodicity().' seconds');
-		$oEnd = new DateTime();
-		while ($oPlannedStart->format('U') < $oEnd->format('U'))
-		{
-			// Next planned start is already in the past, increase it again by a period
-			$oPlannedStart = $oPlannedStart->modify('+'.$oProcess->GetPeriodicity().' seconds');
-		}
 	}
 
-	$oTask->Set('next_run_date', $oPlannedStart->format('Y-m-d H:i:s'));
+	if ($oExceptionToThrow) {
-	$oTask->DBUpdate();
-
-	if ($oExceptionToThrow)
-	{
 		throw $oExceptionToThrow;
 	}
 
@@ -191,8 +161,6 @@ function RunTask(BackgroundTask $oTask, $iTimeLimit)
 }
 
 /**
- * @param CLIPage|WebPage $oP
- * @param boolean $bVerbose
  *
  * @param bool $bDebug
  *
@@ -207,24 +175,31 @@ function RunTask(BackgroundTask $oTask, $iTimeLimit)
  * @throws \OQLException
  * @throws \ReflectionException
  */
-function CronExec($oP, $bVerbose, $bDebug=false)
+function CronExec($bDebug)
 {
 	$iStarted = time();
 	$iMaxDuration = MetaModel::GetConfig()->Get('cron_max_execution_time');
 	$iTimeLimit = $iStarted + $iMaxDuration;
 	$iCronSleep = MetaModel::GetConfig()->Get('cron_sleep');
+	$iMaxCronProcess = max(MetaModel::GetConfig()->Get('cron.max_processes'), 1);
 
-	if ($bVerbose)
+	// Allow a time slot for every task
-	{
+	// knowing that there are $iMaxCronProcess running in parallel for the amount of tasks
-		$oP->p("Planned duration = $iMaxDuration seconds");
+	$oSearch = new DBObjectSearch('BackgroundTask');
-		$oP->p("Loop pause = $iCronSleep seconds");
+	$oSearch->AddCondition('status', 'active');
-	}
+	$oTasks = new DBObjectSet($oSearch);
+	$iCount = $oTasks->Count();
+	$iTotalAvailableTime = $iMaxDuration * $iMaxCronProcess;
+	$iTimeSlot = (int)($iTotalAvailableTime / max($iCount, 1));
 
-	ReSyncProcesses($oP, $bVerbose, $bDebug);
+	CronLog::Trace("Planned duration = $iMaxDuration seconds");
+	CronLog::Trace("Planned duration per task = $iTimeSlot seconds");
+	CronLog::Trace("Loop pause = $iCronSleep seconds");
 
-	while (time() < $iTimeLimit)
+	ReSyncProcesses($bDebug);
-	{
+
-		CheckMaintenanceMode($oP);
+	while (time() < $iTimeLimit) {
+		CheckMaintenanceMode();
 
 		$oNow = new DateTime();
 		$sNow = $oNow->format('Y-m-d H:i:s');
@@ -232,120 +207,109 @@ function CronExec($oP, $bVerbose, $bDebug=false)
 		$oSearch->AddCondition('next_run_date', $sNow, '<=');
 		$oSearch->AddCondition('status', 'active');
 		$oTasks = new DBObjectSet($oSearch, ['next_run_date' => true]);
-		$bWorkDone = false;
 
-		if ($oTasks->CountExceeds(0))
+		$aTasks = [];
-		{
+		if ($oTasks->CountExceeds(0)) {
-			$bWorkDone = true;
+			$aDebugMessages = [];
-			$aTasks = array();
+			while ($oTask = $oTasks->Fetch()) {
-			if ($bVerbose)
+				$sTaskName = $oTask->Get('class_name');
-			{
+				$oTaskMutex = new iTopMutex("cron_$sTaskName");
-				$sCount = $oTasks->Count();
+				if ($oTaskMutex->IsLocked()) {
-				$oP->p("$sCount Tasks planned to run now ($sNow):");
+					// Already running, ignore
-				$oP->p('+---------------------------+---------+---------------------+---------------------+');
+					continue;
-				$oP->p('| Task Class                | Status  | Last Run            | Next Run            |');
-				$oP->p('+---------------------------+---------+---------------------+---------------------+');
-			}
-			while ($oTask = $oTasks->Fetch())
-			{
-				$aTasks[$oTask->Get('class_name')] = $oTask;
-				if ($bVerbose)
-				{
-					$sTaskName = $oTask->Get('class_name');
-					$sStatus = $oTask->Get('status');
-					$sLastRunDate = $oTask->Get('latest_run_date');
-					$sNextRunDate = $oTask->Get('next_run_date');
-					$oP->p(sprintf('| %1$-25.25s | %2$-7s | %3$-19s | %4$-19s |', $sTaskName, $sStatus, $sLastRunDate, $sNextRunDate));
 				}
+				$aTasks[] = $oTask;
+				$sStatus = $oTask->Get('status');
+				$sLastRunDate = $oTask->Get('latest_run_date');
+				$sNextRunDate = $oTask->Get('next_run_date');
+				$aDebugMessages[] = sprintf('Task Class: %1$-25.25s Status: %2$-7s Last Run: %3$-19s Next Run: %4$-19s', $sTaskName, $sStatus, $sLastRunDate, $sNextRunDate);
 			}
-			if ($bVerbose)
+			$sCount = count($aDebugMessages);
-			{
+			CronLog::Trace("$sCount Tasks planned to run now ($sNow):");
-				$oP->p('+---------------------------+---------+---------------------+---------------------+');
+			foreach ($aDebugMessages as $sDebugMessage) {
+				CronLog::Trace($sDebugMessage);
 			}
 			$aRunTasks = [];
-			foreach ($aTasks as $oTask)
+			while (count($aTasks) > 0) {
-			{
+				$oTask = array_shift($aTasks);
+
 				$sTaskClass = $oTask->Get('class_name');
+
+				// Check if the current task is running
+				$oTaskMutex = new iTopMutex("cron_$sTaskClass");
+				if (!$oTaskMutex->TryLock()) {
+					// Task is already running, try next one
+					continue;
+				}
+
 				$aRunTasks[] = $sTaskClass;
 
 				// N°3219 for each process will use a specific CMDBChange object with a specific track info
-				// Any BackgroundProcess can overrides this as needed
+				// Any BackgroundProcess can override this as needed
 				CMDBObject::SetCurrentChangeFromParams("Background task ($sTaskClass)");
 
 				// Run the task and record its next run time
-				if ($bVerbose)
+				$sDebugTaskClass = CronLog::GetDebugClassName($sTaskClass);
-				{
+				$oNow = new DateTime();
-					$oNow = new DateTime();
+				CronLog::Debug(sprintf("> Starting >>> %-'>49s", $sDebugTaskClass.' '));
-					$oP->p(">> === ".$oNow->format('Y-m-d H:i:s').sprintf(" Starting:%-'=49s", ' '.$sTaskClass.' '));
+				try {
+					// The limit of time for this task corresponds to the time slot allowed for every task
+					// but limited to the cron job time limit
+					$sMessage = RunTask($oTask, min($iTimeLimit, time() + $iTimeSlot));
 				}
-				try
+				catch (MySQLHasGoneAwayException $e) {
-				{
+					CronLog::Error("ERROR : 'MySQL has gone away' thrown when processing $sDebugTaskClass  (error_code=".$e->getCode().")", CronLog::CHANNEL_DEFAULT, ['stack' => $e->getTraceAsString()]);
-					$sMessage = RunTask($aTasks[$sTaskClass], $iTimeLimit);
-				} catch (MySQLHasGoneAwayException $e)
-				{
-					$oP->p("ERROR : 'MySQL has gone away' thrown when processing $sTaskClass  (error_code=".$e->getCode().")");
 					exit(EXIT_CODE_FATAL);
-				} catch (ProcessFatalException $e)
-				{
-					$oP->p("ERROR : an exception was thrown when processing '$sTaskClass' (".$e->getInfoLog().")");
-					IssueLog::Error("Cron.php error : an exception was thrown when processing '$sTaskClass' (".$e->getInfoLog().')');
 				}
-				if ($bVerbose)
+				catch (ProcessFatalException $e) {
-				{
+					CronLog::Error("ERROR : an exception was thrown when processing '$sDebugTaskClass' (".$e->getInfoLog().")", CronLog::CHANNEL_DEFAULT, ['stack' => $e->getTraceAsString()]);
-					if (!empty($sMessage))
-					{
-						$oP->p("$sTaskClass: $sMessage");
-					}
-					$oEnd = new DateTime();
-					$sNextRunDate = $oTask->Get('next_run_date');
-					$oP->p("<< === ".$oEnd->format('Y-m-d H:i:s').sprintf(" End of:  %-'=42s", ' '.$sTaskClass.' ')." Next: $sNextRunDate");
 				}
-				if (time() > $iTimeLimit)
+				finally {
-				{
+					$oTaskMutex->Unlock();
+				}
+				if (!empty($sMessage)) {
+					CronLog::Debug("$sDebugTaskClass: $sMessage");
+				}
+				$oEnd = new DateTime();
+				$sNextRunDate = $oTask->Get('next_run_date');
+				CronLog::Debug(sprintf("< Ending <<<<< %-'<49s", $sDebugTaskClass.' ')." Next: $sNextRunDate");
+				if (time() > $iTimeLimit) {
 					break 2;
 				}
-				CheckMaintenanceMode($oP);
+				CheckMaintenanceMode();
+				if ($iMaxCronProcess > 1) {
+					// Reindex tasks every time
+					break;
+				}
 			}
 
 			// Tasks to run later
-			if ($bVerbose)
+			if (count($aTasks) == 0) {
-			{
-				$oP->p('--');
 				$oSearch = new DBObjectSearch('BackgroundTask');
 				$oSearch->AddCondition('next_run_date', $sNow, '>');
 				$oSearch->AddCondition('status', 'active');
 				$oTasks = new DBObjectSet($oSearch, ['next_run_date' => true]);
-				while ($oTask = $oTasks->Fetch())
+				while ($oTask = $oTasks->Fetch()) {
-				{
+					if (!in_array($oTask->Get('class_name'), $aRunTasks)) {
-					if (!in_array($oTask->Get('class_name'), $aRunTasks))
+						$sDebugTaskClass = CronLog::GetDebugClassName($oTask->Get('class_name'));
-					{
+						CronLog::Trace(sprintf("-- Skipping task: %-'-40s", $sDebugTaskClass.' ')." until: ".$oTask->Get('next_run_date'));
-						$oP->p(sprintf("-- Skipping task: %-'-40s", $oTask->Get('class_name').' ')." until: ".$oTask->Get('next_run_date'));
 					}
 				}
 			}
 		}
-
+		if (count($aTasks) == 0) {
-		if ($bVerbose && $bWorkDone)
+			CronLog::Trace("sleeping...");
-		{
+			sleep($iCronSleep);
-			$oP->p("Sleeping...\n");
 		}
-		sleep($iCronSleep);
-	}
-	if ($bVerbose)
-	{
-		$oP->p('');
-		DisplayStatus($oP, ['next_run_date' => true]);
-		$oP->p("Reached normal execution time limit (exceeded by ".(time() - $iTimeLimit)."s)");
 	}
+	CronLog::Trace("Reached normal execution time limit (exceeded by ".(time() - $iTimeLimit)."s)");
 }
 
-/**
+function CheckMaintenanceMode()
- * @param WebPage $oP
+{
- */
-function CheckMaintenanceMode(Page $oP) {
 // Verify files instead of reloading the full config each time
 	if (file_exists(MAINTENANCE_MODE_FILE) || file_exists(READONLY_MODE_FILE)) {
-		$oP->p("Maintenance detected, exiting");
+		CronLog::Info("Maintenance detected, exiting");
 		exit(EXIT_CODE_ERROR);
 	}
 }
@@ -360,15 +324,14 @@ function CheckMaintenanceMode(Page $oP) {
  * @throws \MySQLException
  * @throws \OQLException
  */
-function DisplayStatus($oP, $aTaskOrderBy = [])
+function DisplayStatus($oP = null, $aTaskOrderBy = [])
 {
 	$oSearch = new DBObjectSearch('BackgroundTask');
 	$oTasks = new DBObjectSet($oSearch, $aTaskOrderBy);
 	$oP->p('+---------------------------+---------+---------------------+---------------------+--------+-----------+');
 	$oP->p('| Task Class                | Status  | Last Run            | Next Run            | Nb Run | Avg. Dur. |');
 	$oP->p('+---------------------------+---------+---------------------+---------------------+--------+-----------+');
-	while ($oTask = $oTasks->Fetch())
+	while ($oTask = $oTasks->Fetch()) {
-	{
 		$sTaskName = $oTask->Get('class_name');
 		$sStatus = $oTask->Get('status');
 		$sLastRunDate = $oTask->Get('latest_run_date');
@@ -382,8 +345,6 @@ function DisplayStatus($oP, $aTaskOrderBy = [])
 }
 
 /**
- * @param $oP
- * @param $bVerbose
  * @param $bDebug
  *
  * @throws \ArchivedObjectException
@@ -395,28 +356,25 @@ function DisplayStatus($oP, $aTaskOrderBy = [])
  * @throws \OQLException
  * @throws \ReflectionException
  */
-function ReSyncProcesses($oP, $bVerbose, $bDebug)
+function ReSyncProcesses($bDebug)
 {
 	// Enumerate classes implementing BackgroundProcess
 	//
 	$oSearch = new DBObjectSearch('BackgroundTask');
 	$oTasks = new DBObjectSet($oSearch);
-	$aTasks = array();
+	$aTasks = [];
-	while ($oTask = $oTasks->Fetch())
+	while ($oTask = $oTasks->Fetch()) {
-	{
 		$aTasks[$oTask->Get('class_name')] = $oTask;
 	}
 	$oNow = new DateTime();
 
-	$aProcesses = array();
+	$aProcesses = [];
-	foreach (InterfaceDiscovery::GetInstance()->FindItopClasses(iProcess::class) as $sTaskClass)
+	foreach (InterfaceDiscovery::GetInstance()->FindItopClasses(iProcess::class) as $sTaskClass) {
-	{
 		$oProcess = new $sTaskClass;
 		$aProcesses[$sTaskClass] = $oProcess;
 
 		// Create missing entry if needed
-		if (!array_key_exists($sTaskClass, $aTasks))
+		if (!array_key_exists($sTaskClass, $aTasks)) {
-		{
 			// New entry, let's create a new BackgroundTask record, and plan the first execution
 			$oTask = new BackgroundTask();
 			$oTask->SetDebug($bDebug);
@@ -426,41 +384,31 @@ function ReSyncProcesses($oP, $bVerbose, $bDebug)
 			$oTask->Set('max_run_duration', 0);
 			$oTask->Set('average_run_duration', 0);
 			$oRefClass = new ReflectionClass($sTaskClass);
-			if ($oRefClass->implementsInterface('iScheduledProcess'))
+			if ($oRefClass->implementsInterface('iScheduledProcess')) {
-			{
 				$oNextOcc = $oProcess->GetNextOccurrence();
 				$oTask->Set('next_run_date', $oNextOcc->format('Y-m-d H:i:s'));
-			}
+			} else {
-			else
-			{
 				// Background processes do start asap, i.e. "now"
 				$oTask->Set('next_run_date', $oNow->format('Y-m-d H:i:s'));
 			}
-			if ($bVerbose)
+			$sDebugTaskClass = CronLog::GetDebugClassName($sTaskClass);
-			{
+			CronLog::Trace('Creating record for: '.$sDebugTaskClass);
-				$oP->p('Creating record for: '.$sTaskClass);
+			CronLog::Trace('First execution planned at: '.$oTask->Get('next_run_date'));
-				$oP->p('First execution planned at: '.$oTask->Get('next_run_date'));
-			}
 			$oTask->DBInsert();
-		}
+		} else {
-		else
-		{
 			/** @var \BackgroundTask $oTask */
 			$oTask = $aTasks[$sTaskClass];
-			if ($oTask->Get('next_run_date') == '3000-01-01 00:00:00')
+			if ($oTask->Get('next_run_date') == '3000-01-01 00:00:00') {
-			{
 				// check for rescheduled tasks
 				$oRefClass = new ReflectionClass($sTaskClass);
-				if ($oRefClass->implementsInterface('iScheduledProcess'))
+				if ($oRefClass->implementsInterface('iScheduledProcess')) {
-				{
 					$oNextOcc = $oProcess->GetNextOccurrence();
 					$oTask->Set('next_run_date', $oNextOcc->format('Y-m-d H:i:s'));
 					$oTask->DBUpdate();
 				}
 			}
 			// Reactivate task if necessary
-			if ($oTask->Get('status') == 'removed')
+			if ($oTask->Get('status') == 'removed') {
-			{
 				$oTask->Set('status', 'active');
 				$oTask->DBUpdate();
 			}
@@ -470,26 +418,20 @@ function ReSyncProcesses($oP, $bVerbose, $bDebug)
 	}
 
 	// Remove all the tasks not having a valid class
-	foreach ($aTasks as $oTask)
+	foreach ($aTasks as $oTask) {
-	{
 		$sTaskClass = $oTask->Get('class_name');
-		if (!class_exists($sTaskClass))
+		if (!class_exists($sTaskClass)) {
-		{
 			$oTask->Set('status', 'removed');
 			$oTask->DBUpdate();
 		}
 	}
 
-	if ($bVerbose)
+	$aDisplayProcesses = [];
-	{
+	foreach ($aProcesses as $oExecInstance) {
-		$aDisplayProcesses = array();
+		$aDisplayProcesses[] = get_class($oExecInstance);
-		foreach ($aProcesses as $oExecInstance)
-		{
-			$aDisplayProcesses[] = get_class($oExecInstance);
-		}
-		$sDisplayProcesses = implode(', ', $aDisplayProcesses);
-		$oP->p("Background processes: ".$sDisplayProcesses);
 	}
+	$sDisplayProcesses = implode(', ', $aDisplayProcesses);
+	CronLog::Trace("Background processes: ".$sDisplayProcesses);
 }
 
 ////////////////////////////////////////////////////////////////////////////////
@@ -500,118 +442,91 @@ function ReSyncProcesses($oP, $bVerbose, $bDebug)
 set_time_limit(0); // Some background actions may really take long to finish (like backup)
 
 $bIsModeCLI = utils::IsModeCLI();
-if ($bIsModeCLI)
+if ($bIsModeCLI) {
-{
 	$oP = new CLIPage("iTop - cron");
 
 	SetupUtils::CheckPhpAndExtensionsForCli($oP, EXIT_CODE_FATAL);
-}
+} else {
-else
-{
 	$oP = new WebPage("iTop - cron");
 }
 
-try
+try {
-{
 	utils::UseParamFile();
 
-	$bVerbose = utils::ReadParam('verbose', false, true /* Allow CLI */);
+	// Allow verbosity on output from 0 => none, 1 => debug, 2 => trace
-	$bDebug = utils::ReadParam('debug', false, true /* Allow CLI */);
+	// (writing debug messages to the cron.log file is configured with log_level_min config parameter)
+	$iVerbose = utils::ReadParam('verbose', 0, true /* Allow CLI */);
+	CronLog::SetDebug($oP, $iVerbose);
 
-	if ($bIsModeCLI)
+	if ($bIsModeCLI) {
-	{
 		// Next steps:
 		//   specific arguments: 'csv file'
 		//
 		$sAuthUser = ReadMandatoryParam($oP, 'auth_user', 'raw_data');
 		$sAuthPwd = ReadMandatoryParam($oP, 'auth_pwd', 'raw_data');
-		if (UserRights::CheckCredentials($sAuthUser, $sAuthPwd))
+		if (UserRights::CheckCredentials($sAuthUser, $sAuthPwd)) {
-		{
 			UserRights::Login($sAuthUser); // Login & set the user's language
-		}
+		} else {
-		else
-		{
 			$oP->p("Access wrong credentials ('$sAuthUser')");
 			$oP->output();
 			exit(EXIT_CODE_ERROR);
 		}
-	}
+	} else {
-	else
-	{
 		require_once(APPROOT.'/application/loginwebpage.class.inc.php');
 		LoginWebPage::DoLogin(); // Check user rights and prompt if needed
 	}
 
-	if (!UserRights::IsAdministrator())
+	if (!UserRights::IsAdministrator()) {
-	{
 		$oP->p("Access restricted to administrators");
 		$oP->Output();
 		exit(EXIT_CODE_ERROR);
 	}
 
 
-	if (utils::ReadParam('status_only', false, true /* Allow CLI */))
+	if (utils::ReadParam('status_only', false, true /* Allow CLI */)) {
-	{
 		// Display status and exit
 		DisplayStatus($oP);
 		exit(0);
 	}
 
 	require_once(APPROOT.'core/mutex.class.inc.php');
-	$oP->p("Starting: ".time().' ('.date('Y-m-d H:i:s').')');
 }
-catch (Exception $e)
+catch (Exception $e) {
-{
 	$oP->p("Error: ".$e->GetMessage());
 	$oP->output();
 	exit(EXIT_CODE_FATAL);
 }
 
-try
+CronLog::Enable(APPROOT.'/log/error.log');
-{
+try {
-	$oMutex = new iTopMutex('cron');
+	if (!MetaModel::DBHasAccess(ACCESS_ADMIN_WRITE)) {
-	if (!MetaModel::DBHasAccess(ACCESS_ADMIN_WRITE))
+		CronLog::Debug("A maintenance is ongoing");
-	{
+	} else {
-		$oP->p("A maintenance is ongoing");
+		// Limit the number of cron process to run in parallel
-	}
+		$iMaxCronProcess = max(MetaModel::GetConfig()->Get('cron.max_processes'), 1);
-	else
+		$bCanRun = false;
-	{
+		$iProcessNumber = 0;
-		if ($oMutex->TryLock())
+		for ($i = 0; $i < $iMaxCronProcess; $i++) {
-		{
+			$oMutex = new iTopMutex("cron#$i");
-			CronExec($oP, $bVerbose, $bDebug);
+			if ($oMutex->TryLock()) {
+				$iProcessNumber = $i + 1;
+				$bCanRun = true;
+				break;
+			}
 		}
-		else
+		if ($bCanRun) {
-		{
+			CronLog::$iProcessNumber = $iProcessNumber;
-			// Exit silently
+			CronLog::Debug('Starting: '.time().' ('.date('Y-m-d H:i:s').')');
-			$oP->p("Already running...");
+			CronExec($iVerbose > 0);
+		} else {
+			CronLog::$iProcessNumber = $iMaxCronProcess + 1;
+			CronLog::Trace("The limit of $iMaxCronProcess cron process running in parallel is already reached");
 		}
 	}
 }
-catch (Exception $e)
+catch (Exception $e) {
-{
+	CronLog::Error("ERROR: '".$e->getMessage()."'", CronLog::CHANNEL_DEFAULT, ['stack' => $e->getTraceAsString()]);
-	$oP->p("ERROR: '".$e->getMessage()."'");
-	if ($bDebug)
-	{
-		// Might contain verb parameters such a password...
-		$oP->p($e->getTraceAsString());
-	}
-}
-finally
-{
-	try
-	{
-		$oMutex->Unlock();
-	}
-	catch (Exception $e)
-	{
-		$oP->p("ERROR: '".$e->getMessage()."'");
-		if ($bDebug)
-		{
-			// Might contain verb parameters such a password...
-			$oP->p($e->getTraceAsString());
-		}
-	}
 }
 
-$oP->p("Exiting: ".time().' ('.date('Y-m-d H:i:s').')');
+CronLog::Debug("Exiting: ".time().' ('.date('Y-m-d H:i:s').')');
 $oP->Output();