Cron parallelization * better logs

This commit is contained in:
Eric Espie
2022-11-18 23:41:13 +01:00
parent 7f080f6fbe
commit a0761a079b
4 changed files with 55 additions and 25 deletions

View File

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

View File

@@ -2038,8 +2038,10 @@ 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;
@@ -2047,7 +2049,6 @@ JS
// Limit the number of cron process to run in parallel
$iMaxCronProcess = $oConfig->Get('cron.max_processes');
$iCount = 1;
$iMaxDuration = $oConfig->Get('cron_max_execution_time');
$iTimeLimit = time() + $iMaxDuration;
do {
$bIsRunning = false;
@@ -2055,26 +2056,26 @@ JS
for ($i = 0; $i < $iMaxCronProcess; $i++) {
$sName = "cron#$i";
$oMutex = new iTopMutex(
$oMutex = new iTopMutex(
$sName.$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')
);
$oConfig->Get('db_host'),
$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)
{
throw new Exception("Cannot enter $sMode mode, consider stopping the cron temporarily");
}
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) {

View File

@@ -7,10 +7,13 @@
namespace Combodo\iTop\Service\Cron;
use LogAPI;
use Page;
class CronLog extends LogAPI
{
public static $iProcessNumber = 0;
private static $bDebug = false;
private static $oP = null;
const CHANNEL_DEFAULT = 'Cron';
/**
@@ -27,4 +30,18 @@ class CronLog extends LogAPI
$sMessage = 'cron'.str_pad(static::$iProcessNumber, 3).$sMessage;
parent::Log($sLevel, $sMessage, $sChannel, $aContext);
}
public static function Debug($sMessage, $sChannel = null, $aContext = array())
{
if (self::$bDebug && self::$oP) {
self::$oP->p('cron'.str_pad(static::$iProcessNumber, 3).$sMessage);
}
parent::Debug($sMessage, $sChannel, $aContext);
}
public static function SetDebug(Page $oP, $bDebug)
{
self::$oP = $oP;
self::$bDebug = $bDebug;
}
}

View File

@@ -208,10 +208,8 @@ function CronExec($bDebug)
$oTasks = new DBObjectSet($oSearch, ['next_run_date' => true]);
$aTasks = [];
if ($oTasks->CountExceeds(0))
{
$sCount = $oTasks->Count();
CronLog::Debug("$sCount Tasks planned to run now ($sNow):");
if ($oTasks->CountExceeds(0)) {
$aDebugMessages = [];
while ($oTask = $oTasks->Fetch())
{
$sTaskName = $oTask->Get('class_name');
@@ -224,7 +222,12 @@ function CronExec($bDebug)
$sStatus = $oTask->Get('status');
$sLastRunDate = $oTask->Get('latest_run_date');
$sNextRunDate = $oTask->Get('next_run_date');
CronLog::Debug(sprintf('Task Class: %1$-25.25s Status: %2$-7s Last Run: %3$-19s Next Run: %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);
CronLog::Debug("$sCount Tasks planned to run now ($sNow):");
foreach ($aDebugMessages as $sDebugMessage) {
CronLog::Debug($sDebugMessage);
}
$aRunTasks = [];
while ($aTasks != []) {
@@ -268,7 +271,7 @@ function CronExec($bDebug)
}
$oEnd = new DateTime();
$sNextRunDate = $oTask->Get('next_run_date');
CronLog::Debug("<< === ".$oEnd->format('Y-m-d H:i:s').sprintf(" End of: %-'=42s", ' '.$sTaskClass.' ')." Next: $sNextRunDate");
CronLog::Debug("<< === ".$oEnd->format('Y-m-d H:i:s').sprintf(" End of: %-'=49s", ' '.$sTaskClass.' ')." Next: $sNextRunDate");
if (time() > $iTimeLimit)
{
break 2;
@@ -297,6 +300,7 @@ function CronExec($bDebug)
}
}
if (count($aTasks) == 0) {
CronLog::Debug("sleeping...");
sleep($iCronSleep);
}
}
@@ -454,6 +458,11 @@ try
{
utils::UseParamFile();
// Allow verbosity on output (writing debug messages to the cron.log file is configured with log_level_min config parameter)
$bVerbose = utils::ReadParam('verbose', false, true /* Allow CLI */);
CronLog::SetDebug($oP, $bVerbose);
// Used to launch the BackgroundTask in debug mode
$bDebug = utils::ReadParam('debug', false, true /* Allow CLI */);
if ($bIsModeCLI)
@@ -530,7 +539,8 @@ try
CronLog::Info('Starting: '.time().' ('.date('Y-m-d H:i:s').')');
CronExec($bDebug);
} else {
CronLog::Debug("Already $iMaxCronProcess are running...");
CronLog::$iProcessNumber = $iMaxCronProcess + 1;
CronLog::Debug("The limit of $iMaxCronProcess cron process running in parallel is already reached");
}
}
}