Compare commits

...

11 Commits

Author SHA1 Message Date
Eric Espie
9ca2bd184f 🔊 better debug level 2026-03-27 14:20:39 +01:00
Eric Espie
7fe08b4d3a 🔊 better debug level 2026-03-27 14:20:39 +01:00
Eric Espie
69ece01f1b 🎨 reformat code 2026-03-27 14:20:39 +01:00
Eric Espie
9bcaf1cd8b N°4692 - Enable parallelization of multiple CRON jobs 2026-03-27 14:20:39 +01:00
Eric Espié
b9aa6e6649 Update sources/Service/Cron/CronLog.php
Co-authored-by: Molkobain <lajarige.guillaume@free.fr>
2026-03-27 14:20:39 +01:00
Eric Espie
2844064474 Cron parallelization * better logs 2026-03-27 14:20:39 +01:00
Eric Espie
7d79706824 Cron parallelization
* refactor logs
2026-03-27 14:20:39 +01:00
Eric Espie
fe675738f4 Cron parallelization
* refactor counts
2026-03-27 14:20:39 +01:00
Eric Espié
6735bb8721 Cron parallelization - change configuration param
Co-authored-by: Molkobain <lajarige.guillaume@free.fr>
2026-03-27 14:20:39 +01:00
Eric Espie
605512e0e4 Cron parallelization
* Setup wait for multiple cron processes
 * Avoid waiting while tasks must be run
2026-03-27 14:20:39 +01:00
Eric Espie
66383ddaac Cron parallelization
# Conflicts:
#	webservices/cron.php
2026-03-27 14:20:39 +01:00
5 changed files with 276 additions and 175 deletions

View File

@@ -585,14 +585,6 @@ class Config
'source_of_value' => '', 'source_of_value' => '',
'show_in_conf_sample' => true, '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' => [ 'cron_sleep' => [
'type' => 'integer', 'type' => 'integer',
'description' => 'Duration (seconds) before cron.php checks again if something must be done', 'description' => 'Duration (seconds) before cron.php checks again if something must be done',
@@ -601,6 +593,14 @@ class Config
'source_of_value' => '', 'source_of_value' => '',
'show_in_conf_sample' => false, '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' => [ 'async_task_retries' => [
'type' => 'array', 'type' => 'array',
'description' => 'Automatic retries of asynchronous tasks in case of failure (per class)', 'description' => 'Automatic retries of asynchronous tasks in case of failure (per class)',

View File

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

View File

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

View File

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

View File

@@ -19,10 +19,14 @@
*/ */
use Combodo\iTop\Application\WebPage\CLIPage; use Combodo\iTop\Application\WebPage\CLIPage;
use Combodo\iTop\Application\WebPage\Page;
use Combodo\iTop\Application\WebPage\WebPage; use Combodo\iTop\Application\WebPage\WebPage;
use Combodo\iTop\Service\Cron\CronLog;
use Combodo\iTop\Service\InterfaceDiscovery\InterfaceDiscovery; use Combodo\iTop\Service\InterfaceDiscovery\InterfaceDiscovery;
if (!defined('__DIR__')) {
define('__DIR__', dirname(__FILE__));
}
require_once(__DIR__.'/../approot.inc.php'); require_once(__DIR__.'/../approot.inc.php');
const EXIT_CODE_ERROR = -1; const EXIT_CODE_ERROR = -1;
@@ -63,7 +67,7 @@ function UsageAndExit($oP)
if ($bModeCLI) { if ($bModeCLI) {
$oP->p("USAGE:\n"); $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->p("Optional parameters: verbose, param_file, status_only\n");
} }
@@ -91,7 +95,6 @@ function RunTask(BackgroundTask $oTask, $iTimeLimit)
$oProcess = new $TaskClass(); $oProcess = new $TaskClass();
$oRefClass = new ReflectionClass(get_class($oProcess)); $oRefClass = new ReflectionClass(get_class($oProcess));
$oDateStarted = new DateTime(); $oDateStarted = new DateTime();
$oDatePlanned = new DateTime($oTask->Get('next_run_date'));
$fStart = microtime(true); $fStart = microtime(true);
$oCtx = new ContextTag('CRON:Task:'.$TaskClass); $oCtx = new ContextTag('CRON:Task:'.$TaskClass);
@@ -99,25 +102,34 @@ function RunTask(BackgroundTask $oTask, $iTimeLimit)
$oExceptionToThrow = null; $oExceptionToThrow = null;
try { try {
// Record (when starting) that this task was started, just in case it crashes during the execution // 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')); $oTask->Set('latest_run_date', $oDateStarted->format('Y-m-d H:i:s'));
// Record the current user running the cron // Record the current user running the cron
$oTask->Set('system_user', utils::GetCurrentUserName()); $oTask->Set('system_user', utils::GetCurrentUserName());
$oTask->Set('running', 1); $oTask->Set('running', 1);
// Compute the next run date
if ($oRefClass->implementsInterface('iScheduledProcess')) {
// Schedules process do repeat at specific moments
$oPlannedStart = $oProcess->GetNextOccurrence();
} else {
// Background processes do repeat periodically
$oDatePlanned = new DateTime($oTask->Get('next_run_date'));
$oPlannedStart = clone $oDatePlanned;
// Let's schedule from the previous planned date of execution to avoid shift
$oPlannedStart->modify('+'.$oProcess->GetPeriodicity().' seconds');
$oNow = new DateTime();
while ($oPlannedStart->format('U') <= $oNow->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'));
$oTask->DBUpdate(); $oTask->DBUpdate();
// Time in seconds allowed to the task
$iCurrTimeLimit = $iTimeLimit; $sMessage = $oProcess->Process($iTimeLimit);
// Compute allowed time
if ($oRefClass->implementsInterface('iScheduledProcess') === false) {
// Periodic task, allow only X times ($iMaxTaskExecutionTime) its periodicity (GetPeriodicity())
$iMaxTaskExecutionTime = MetaModel::GetConfig()->Get('cron_task_max_execution_time');
$iTaskLimit = time() + $oProcess->GetPeriodicity() * $iMaxTaskExecutionTime;
// If our proposed time limit is less than cron limit, and cron_task_max_execution_time is > 0
if ($iTaskLimit < $iTimeLimit && $iMaxTaskExecutionTime > 0) {
$iCurrTimeLimit = $iTaskLimit;
}
}
$sMessage = $oProcess->Process($iCurrTimeLimit);
$oTask->Set('running', 0);
} catch (MySQLHasGoneAwayException $e) { } catch (MySQLHasGoneAwayException $e) {
throw $e; throw $e;
} catch (ProcessFatalException $e) { } catch (ProcessFatalException $e) {
@@ -129,34 +141,12 @@ function RunTask(BackgroundTask $oTask, $iTimeLimit)
$sMessage = 'Processing failed with message: '.$e->getMessage(); $sMessage = 'Processing failed with message: '.$e->getMessage();
} }
} }
finally {
$oTask->Set('running', 0);
$fDuration = microtime(true) - $fStart; $fDuration = microtime(true) - $fStart;
if ($oTask->Get('total_exec_count') == 0) {
// First execution
$oTask->Set('first_run_date', $oDateStarted->format('Y-m-d H:i:s'));
}
$oTask->ComputeDurations($fDuration); // does increment the counter and compute statistics $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'));
$oTask->DBUpdate(); $oTask->DBUpdate();
}
if ($oExceptionToThrow) { if ($oExceptionToThrow) {
throw $oExceptionToThrow; throw $oExceptionToThrow;
@@ -168,8 +158,6 @@ function RunTask(BackgroundTask $oTask, $iTimeLimit)
} }
/** /**
* @param CLIPage|WebPage $oP
* @param boolean $bVerbose
* *
* @param bool $bDebug * @param bool $bDebug
* *
@@ -184,22 +172,31 @@ function RunTask(BackgroundTask $oTask, $iTimeLimit)
* @throws \OQLException * @throws \OQLException
* @throws \ReflectionException * @throws \ReflectionException
*/ */
function CronExec($oP, $bVerbose, $bDebug = false) function CronExec($bDebug )
{ {
$iStarted = time(); $iStarted = time();
$iMaxDuration = MetaModel::GetConfig()->Get('cron_max_execution_time'); $iMaxDuration = MetaModel::GetConfig()->Get('cron_max_execution_time');
$iTimeLimit = $iStarted + $iMaxDuration; $iTimeLimit = $iStarted + $iMaxDuration;
$iCronSleep = MetaModel::GetConfig()->Get('cron_sleep'); $iCronSleep = MetaModel::GetConfig()->Get('cron_sleep');
$iMaxCronProcess = max(MetaModel::GetConfig()->Get('cron.max_processes'), 1);
if ($bVerbose) { // Allow a time slot for every task
$oP->p("Planned duration = $iMaxDuration seconds"); // knowing that there are $iMaxCronProcess running in parallel for the amount of tasks
$oP->p("Loop pause = $iCronSleep seconds"); $oSearch = new DBObjectSearch('BackgroundTask');
} $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");
ReSyncProcesses($bDebug);
while (time() < $iTimeLimit) { while (time() < $iTimeLimit) {
CheckMaintenanceMode($oP); CheckMaintenanceMode();
$oNow = new DateTime(); $oNow = new DateTime();
$sNow = $oNow->format('Y-m-d H:i:s'); $sNow = $oNow->format('Y-m-d H:i:s');
@@ -207,103 +204,108 @@ function CronExec($oP, $bVerbose, $bDebug = false)
$oSearch->AddCondition('next_run_date', $sNow, '<='); $oSearch->AddCondition('next_run_date', $sNow, '<=');
$oSearch->AddCondition('status', 'active'); $oSearch->AddCondition('status', 'active');
$oTasks = new DBObjectSet($oSearch, ['next_run_date' => true]); $oTasks = new DBObjectSet($oSearch, ['next_run_date' => true]);
$bWorkDone = false;
if ($oTasks->CountExceeds(0)) {
$bWorkDone = true;
$aTasks = []; $aTasks = [];
if ($bVerbose) { if ($oTasks->CountExceeds(0)) {
$sCount = $oTasks->Count(); $aDebugMessages = [];
$oP->p("$sCount Tasks planned to run now ($sNow):");
$oP->p('+---------------------------+---------+---------------------+---------------------+');
$oP->p('| Task Class | Status | Last Run | Next Run |');
$oP->p('+---------------------------+---------+---------------------+---------------------+');
}
while ($oTask = $oTasks->Fetch()) { while ($oTask = $oTasks->Fetch()) {
$aTasks[$oTask->Get('class_name')] = $oTask;
if ($bVerbose) {
$sTaskName = $oTask->Get('class_name'); $sTaskName = $oTask->Get('class_name');
$oTaskMutex = new iTopMutex("cron_$sTaskName");
if ($oTaskMutex->IsLocked()) {
// Already running, ignore
continue;
}
$aTasks[] = $oTask;
$sStatus = $oTask->Get('status'); $sStatus = $oTask->Get('status');
$sLastRunDate = $oTask->Get('latest_run_date'); $sLastRunDate = $oTask->Get('latest_run_date');
$sNextRunDate = $oTask->Get('next_run_date'); $sNextRunDate = $oTask->Get('next_run_date');
$oP->p(sprintf('| %1$-25.25s | %2$-7s | %3$-19s | %4$-19s |', $sTaskName, $sStatus, $sLastRunDate, $sNextRunDate)); $aDebugMessages[] = sprintf('Task Class: %1$-25.25s Status: %2$-7s Last Run: %3$-19s Next Run: %4$-19s', $sTaskName, $sStatus, $sLastRunDate, $sNextRunDate);
} }
} $sCount = count($aDebugMessages);
if ($bVerbose) { CronLog::Trace("$sCount Tasks planned to run now ($sNow):");
$oP->p('+---------------------------+---------+---------------------+---------------------+'); foreach ($aDebugMessages as $sDebugMessage) {
CronLog::Trace($sDebugMessage);
} }
$aRunTasks = []; $aRunTasks = [];
foreach ($aTasks as $oTask) { while (count($aTasks) > 0) {
$oTask = array_shift($aTasks);
$sTaskClass = $oTask->Get('class_name'); $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; $aRunTasks[] = $sTaskClass;
// N°3219 for each process will use a specific CMDBChange object with a specific track info // 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)"); CMDBObject::SetCurrentChangeFromParams("Background task ($sTaskClass)");
// Run the task and record its next run time // Run the task and record its next run time
if ($bVerbose) { $sDebugTaskClass = CronLog::GetDebugClassName($sTaskClass);
$oNow = new DateTime(); $oNow = new DateTime();
$oP->p(">> === ".$oNow->format('Y-m-d H:i:s').sprintf(" Starting:%-'=49s", ' '.$sTaskClass.' ')); CronLog::Debug(sprintf("> Starting >>> %-'>49s", $sDebugTaskClass.' '));
}
try { try {
$sMessage = RunTask($aTasks[$sTaskClass], $iTimeLimit); // The limit of time for this task corresponds to the time slot allowed for every task
} catch (MySQLHasGoneAwayException $e) { // but limited to the cron job time limit
$oP->p("ERROR : 'MySQL has gone away' thrown when processing $sTaskClass (error_code=".$e->getCode().")"); $sMessage = RunTask($oTask, min($iTimeLimit, time() + $iTimeSlot));
exit(EXIT_CODE_FATAL); }
} catch (ProcessFatalException $e) { catch (MySQLHasGoneAwayException $e) {
$oP->p("ERROR : an exception was thrown when processing '$sTaskClass' (".$e->getInfoLog().")"); CronLog::Error("ERROR : 'MySQL has gone away' thrown when processing $sDebugTaskClass (error_code=".$e->getCode().")", CronLog::CHANNEL_DEFAULT, ['stack' => $e->getTraceAsString()]);
IssueLog::Error("Cron.php error : an exception was thrown when processing '$sTaskClass' (".$e->getInfoLog().')'); exit(EXIT_CODE_FATAL);
}
catch (ProcessFatalException $e) {
CronLog::Error("ERROR : an exception was thrown when processing '$sDebugTaskClass' (".$e->getInfoLog().")", CronLog::CHANNEL_DEFAULT, ['stack' => $e->getTraceAsString()]);
}
finally {
$oTaskMutex->Unlock();
} }
if ($bVerbose) {
if (!empty($sMessage)) { if (!empty($sMessage)) {
$oP->p("$sTaskClass: $sMessage"); CronLog::Debug("$sDebugTaskClass: $sMessage");
} }
$oEnd = new DateTime(); $oEnd = new DateTime();
$sNextRunDate = $oTask->Get('next_run_date'); $sNextRunDate = $oTask->Get('next_run_date');
$oP->p("<< === ".$oEnd->format('Y-m-d H:i:s').sprintf(" End of: %-'=42s", ' '.$sTaskClass.' ')." Next: $sNextRunDate"); CronLog::Debug(sprintf("< Ending <<<<< %-'<49s", $sDebugTaskClass.' ')." Next: $sNextRunDate");
}
if (time() > $iTimeLimit) { if (time() > $iTimeLimit) {
break 2; break 2;
} }
CheckMaintenanceMode($oP); CheckMaintenanceMode();
if ($iMaxCronProcess > 1) {
// Reindex tasks every time
break;
}
} }
// Tasks to run later // Tasks to run later
if ($bVerbose) { if (count($aTasks) == 0) {
$oP->p('--');
$oSearch = new DBObjectSearch('BackgroundTask'); $oSearch = new DBObjectSearch('BackgroundTask');
$oSearch->AddCondition('next_run_date', $sNow, '>'); $oSearch->AddCondition('next_run_date', $sNow, '>');
$oSearch->AddCondition('status', 'active'); $oSearch->AddCondition('status', 'active');
$oTasks = new DBObjectSet($oSearch, ['next_run_date' => true]); $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)) {
$oP->p(sprintf("-- Skipping task: %-'-40s", $oTask->Get('class_name').' ')." until: ".$oTask->Get('next_run_date')); $sDebugTaskClass = CronLog::GetDebugClassName($oTask->Get('class_name'));
CronLog::Trace(sprintf("-- Skipping task: %-'-40s", $sDebugTaskClass.' ')." until: ".$oTask->Get('next_run_date'));
} }
} }
} }
} }
if (count($aTasks) == 0) {
if ($bVerbose && $bWorkDone) { CronLog::Trace("sleeping...");
$oP->p("Sleeping...\n");
}
sleep($iCronSleep); 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 // Verify files instead of reloading the full config each time
if (file_exists(MAINTENANCE_MODE_FILE) || file_exists(READONLY_MODE_FILE)) { 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); exit(EXIT_CODE_ERROR);
} }
} }
@@ -318,7 +320,7 @@ function CheckMaintenanceMode(Page $oP)
* @throws \MySQLException * @throws \MySQLException
* @throws \OQLException * @throws \OQLException
*/ */
function DisplayStatus($oP, $aTaskOrderBy = []) function DisplayStatus($oP = null, $aTaskOrderBy = [])
{ {
$oSearch = new DBObjectSearch('BackgroundTask'); $oSearch = new DBObjectSearch('BackgroundTask');
$oTasks = new DBObjectSet($oSearch, $aTaskOrderBy); $oTasks = new DBObjectSet($oSearch, $aTaskOrderBy);
@@ -346,8 +348,6 @@ function DisplayStatus($oP, $aTaskOrderBy = [])
} }
/** /**
* @param $oP
* @param $bVerbose
* @param $bDebug * @param $bDebug
* *
* @throws \ArchivedObjectException * @throws \ArchivedObjectException
@@ -359,7 +359,7 @@ function DisplayStatus($oP, $aTaskOrderBy = [])
* @throws \OQLException * @throws \OQLException
* @throws \ReflectionException * @throws \ReflectionException
*/ */
function ReSyncProcesses($oP, $bVerbose, $bDebug) function ReSyncProcesses($bDebug)
{ {
// Enumerate classes implementing BackgroundProcess // Enumerate classes implementing BackgroundProcess
// //
@@ -394,10 +394,9 @@ function ReSyncProcesses($oP, $bVerbose, $bDebug)
// Background processes do start asap, i.e. "now" // Background processes do start asap, i.e. "now"
$oTask->Set('next_run_date', $oNow->format('Y-m-d H:i:s')); $oTask->Set('next_run_date', $oNow->format('Y-m-d H:i:s'));
} }
if ($bVerbose) { $sDebugTaskClass = CronLog::GetDebugClassName($sTaskClass);
$oP->p('Creating record for: '.$sTaskClass); CronLog::Trace('Creating record for: '.$sDebugTaskClass);
$oP->p('First execution planned at: '.$oTask->Get('next_run_date')); CronLog::Trace('First execution planned at: '.$oTask->Get('next_run_date'));
}
$oTask->DBInsert(); $oTask->DBInsert();
} else { } else {
/** @var \BackgroundTask $oTask */ /** @var \BackgroundTask $oTask */
@@ -430,14 +429,12 @@ function ReSyncProcesses($oP, $bVerbose, $bDebug)
} }
} }
if ($bVerbose) {
$aDisplayProcesses = []; $aDisplayProcesses = [];
foreach ($aProcesses as $oExecInstance) { foreach ($aProcesses as $oExecInstance) {
$aDisplayProcesses[] = get_class($oExecInstance); $aDisplayProcesses[] = get_class($oExecInstance);
} }
$sDisplayProcesses = implode(', ', $aDisplayProcesses); $sDisplayProcesses = implode(', ', $aDisplayProcesses);
$oP->p("Background processes: ".$sDisplayProcesses); CronLog::Trace("Background processes: ".$sDisplayProcesses);
}
} }
//////////////////////////////////////////////////////////////////////////////// ////////////////////////////////////////////////////////////////////////////////
@@ -457,8 +454,13 @@ try {
$oP = new WebPage("iTop - cron"); $oP = new WebPage("iTop - cron");
} }
$bVerbose = utils::ReadParam('verbose', false, true /* Allow CLI */); try {
$bDebug = utils::ReadParam('debug', false, true /* Allow CLI */); utils::UseParamFile();
// Allow verbosity on output from 0 => none, 1 => debug, 2 => trace
// (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: // Next steps:
@@ -491,31 +493,41 @@ try {
} }
require_once(APPROOT.'core/mutex.class.inc.php'); 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->p("Error: ".$e->GetMessage());
$oP->output(); $oP->output();
exit(EXIT_CODE_FATAL); exit(EXIT_CODE_FATAL);
} }
CronLog::Enable(APPROOT.'/log/error.log');
try { try {
$oMutex = new iTopMutex('cron');
if (!MetaModel::DBHasAccess(ACCESS_ADMIN_WRITE)) { if (!MetaModel::DBHasAccess(ACCESS_ADMIN_WRITE)) {
$oP->p("A maintenance is ongoing"); CronLog::Debug("A maintenance is ongoing");
} else { } else {
// Limit the number of cron process to run in parallel
$iMaxCronProcess = max(MetaModel::GetConfig()->Get('cron.max_processes'), 1);
$bCanRun = false;
$iProcessNumber = 0;
for ($i = 0; $i < $iMaxCronProcess; $i++) {
$oMutex = new iTopMutex("cron#$i");
if ($oMutex->TryLock()) { if ($oMutex->TryLock()) {
CronExec($oP, $bVerbose, $bDebug); $iProcessNumber = $i + 1;
$bCanRun = true;
break;
}
}
if ($bCanRun) {
CronLog::$iProcessNumber = $iProcessNumber;
CronLog::Debug('Starting: '.time().' ('.date('Y-m-d H:i:s').')');
CronExec($iVerbose > 0);
} else { } else {
// Exit silently CronLog::$iProcessNumber = $iMaxCronProcess + 1;
$oP->p("Already running..."); CronLog::Trace("The limit of $iMaxCronProcess cron process running in parallel is already reached");
} }
} }
} catch (Exception $e) {
$oP->p("ERROR: '".$e->getMessage()."'");
if ($bDebug) {
// Might contain verb parameters such a password...
$oP->p($e->getTraceAsString());
} }
catch (Exception $e) {
CronLog::Error("ERROR: '".$e->getMessage()."'", CronLog::CHANNEL_DEFAULT, ['stack' => $e->getTraceAsString()]);
} finally { } finally {
try { try {
$oMutex->Unlock(); $oMutex->Unlock();
@@ -528,5 +540,5 @@ try {
} }
} }
$oP->p("Exiting: ".time().' ('.date('Y-m-d H:i:s').')'); CronLog::Debug("Exiting: ".time().' ('.date('Y-m-d H:i:s').')');
$oP->Output(); $oP->Output();