🔊 better debug level

This commit is contained in:
Eric Espie
2025-03-28 10:04:58 +01:00
parent 69ece01f1b
commit 7fe08b4d3a
2 changed files with 32 additions and 26 deletions

View File

@@ -14,9 +14,9 @@ use Page;
*/ */
class CronLog extends LogAPI class CronLog extends LogAPI
{ {
public static $iProcessNumber = 0; public static int $iProcessNumber = 0;
private static $bDebug = false; private static int $iDebugLevel = 0;
private static $oP = null; private static ?Page $oP = null;
const CHANNEL_DEFAULT = 'Cron'; const CHANNEL_DEFAULT = 'Cron';
/** /**
@@ -36,15 +36,23 @@ class CronLog extends LogAPI
public static function Debug($sMessage, $sChannel = null, $aContext = []): void public static function Debug($sMessage, $sChannel = null, $aContext = []): void
{ {
if (self::$bDebug && self::$oP) { if (self::$iDebugLevel > 0 && self::$oP) {
self::$oP->p('cron'.str_pad(static::$iProcessNumber, 3).$sMessage); self::$oP->p('cron'.str_pad(static::$iProcessNumber, 3).$sMessage);
} }
parent::Debug($sMessage, $sChannel, $aContext); parent::Debug($sMessage, $sChannel, $aContext);
} }
public static function SetDebug(Page $oP, $bDebug): void public static function Trace($sMessage, $sChannel = null, $aContext = []): void
{
if (self::$iDebugLevel > 2 && 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::$oP = $oP;
self::$bDebug = $bDebug; self::$iDebugLevel = $iDebugLevel;
} }
} }

View File

@@ -67,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");
} }
@@ -189,9 +189,9 @@ function CronExec($bDebug )
$iTotalAvailableTime = $iMaxDuration * $iMaxCronProcess; $iTotalAvailableTime = $iMaxDuration * $iMaxCronProcess;
$iTimeSlot = (int)($iTotalAvailableTime / max($iCount, 1)); $iTimeSlot = (int)($iTotalAvailableTime / max($iCount, 1));
CronLog::Debug("Planned duration = $iMaxDuration seconds"); CronLog::Trace("Planned duration = $iMaxDuration seconds");
CronLog::Debug("Planned duration per task = $iTimeSlot seconds"); CronLog::Trace("Planned duration per task = $iTimeSlot seconds");
CronLog::Debug("Loop pause = $iCronSleep seconds"); CronLog::Trace("Loop pause = $iCronSleep seconds");
ReSyncProcesses($bDebug); ReSyncProcesses($bDebug);
@@ -222,9 +222,9 @@ function CronExec($bDebug )
$aDebugMessages[] = 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); $sCount = count($aDebugMessages);
CronLog::Debug("$sCount Tasks planned to run now ($sNow):"); CronLog::Trace("$sCount Tasks planned to run now ($sNow):");
foreach ($aDebugMessages as $sDebugMessage) { foreach ($aDebugMessages as $sDebugMessage) {
CronLog::Debug($sDebugMessage); CronLog::Trace($sDebugMessage);
} }
$aRunTasks = []; $aRunTasks = [];
while (count($aTasks) > 0) { while (count($aTasks) > 0) {
@@ -286,17 +286,17 @@ function CronExec($bDebug )
$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)) {
CronLog::Debug(sprintf("-- Skipping task: %-'-40s", $oTask->Get('class_name').' ')." until: ".$oTask->Get('next_run_date')); CronLog::Trace(sprintf("-- Skipping task: %-'-40s", $oTask->Get('class_name').' ')." until: ".$oTask->Get('next_run_date'));
} }
} }
} }
} }
if (count($aTasks) == 0) { if (count($aTasks) == 0) {
CronLog::Debug("sleeping..."); CronLog::Trace("sleeping...");
sleep($iCronSleep); sleep($iCronSleep);
} }
} }
CronLog::Debug("Reached normal execution time limit (exceeded by ".(time() - $iTimeLimit)."s)"); CronLog::Trace("Reached normal execution time limit (exceeded by ".(time() - $iTimeLimit)."s)");
} }
function CheckMaintenanceMode() function CheckMaintenanceMode()
@@ -392,8 +392,8 @@ function ReSyncProcesses($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'));
} }
CronLog::Debug('Creating record for: '.$sTaskClass); CronLog::Trace('Creating record for: '.$sTaskClass);
CronLog::Debug('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 */
@@ -431,7 +431,7 @@ function ReSyncProcesses($bDebug)
$aDisplayProcesses[] = get_class($oExecInstance); $aDisplayProcesses[] = get_class($oExecInstance);
} }
$sDisplayProcesses = implode(', ', $aDisplayProcesses); $sDisplayProcesses = implode(', ', $aDisplayProcesses);
CronLog::Debug("Background processes: ".$sDisplayProcesses); CronLog::Trace("Background processes: ".$sDisplayProcesses);
} }
//////////////////////////////////////////////////////////////////////////////// ////////////////////////////////////////////////////////////////////////////////
@@ -454,12 +454,10 @@ if ($bIsModeCLI) {
try { try {
utils::UseParamFile(); utils::UseParamFile();
// Allow verbosity on output (writing debug messages to the cron.log file is configured with log_level_min config parameter) // Allow verbosity on output from 0 => none, 1 => debug, 2 => trace
$bVerbose = utils::ReadParam('verbose', false, true /* Allow CLI */); // (writing debug messages to the cron.log file is configured with log_level_min config parameter)
CronLog::SetDebug($oP, $bVerbose); $iVerbose = utils::ReadParam('verbose', 0, true /* Allow CLI */);
CronLog::SetDebug($oP, $iVerbose);
// Used to launch the BackgroundTask in debug mode
$bDebug = utils::ReadParam('debug', false, true /* Allow CLI */);
if ($bIsModeCLI) { if ($bIsModeCLI) {
// Next steps: // Next steps:
@@ -518,10 +516,10 @@ try {
if ($bCanRun) { if ($bCanRun) {
CronLog::$iProcessNumber = $iProcessNumber; CronLog::$iProcessNumber = $iProcessNumber;
CronLog::Info('Starting: '.time().' ('.date('Y-m-d H:i:s').')'); CronLog::Info('Starting: '.time().' ('.date('Y-m-d H:i:s').')');
CronExec($bDebug); CronExec($iVerbose > 0);
} else { } else {
CronLog::$iProcessNumber = $iMaxCronProcess + 1; CronLog::$iProcessNumber = $iMaxCronProcess + 1;
CronLog::Debug("The limit of $iMaxCronProcess cron process running in parallel is already reached"); CronLog::Trace("The limit of $iMaxCronProcess cron process running in parallel is already reached");
} }
} }
} }