Enhanced logging, stopping worker after cron lifetime

This commit is contained in:
Michael 2019-02-27 06:36:19 +00:00
parent 7810227040
commit 40573120b9

View file

@ -28,6 +28,7 @@ class Worker
private static $db_duration_stat = 0; private static $db_duration_stat = 0;
private static $lock_duration = 0; private static $lock_duration = 0;
private static $last_update; private static $last_update;
private static $mode = 0;
/** /**
* @brief Processes the tasks that are in the workerqueue table * @brief Processes the tasks that are in the workerqueue table
@ -91,6 +92,7 @@ class Worker
} }
$starttime = time(); $starttime = time();
self::$mode = 1;
// We fetch the next queue entry that is about to be executed // We fetch the next queue entry that is about to be executed
while ($r = self::workerProcess()) { while ($r = self::workerProcess()) {
@ -108,9 +110,18 @@ class Worker
if (!self::getWaitingJobForPID() && Lock::acquire('worker_process', 0)) { if (!self::getWaitingJobForPID() && Lock::acquire('worker_process', 0)) {
self::findWorkerProcesses(); self::findWorkerProcesses();
Lock::release('worker_process'); Lock::release('worker_process');
self::$mode = 3;
} }
} }
self::$mode = 4;
// Quit the worker once every cron interval
if (time() > ($starttime + Config::get('system', 'cron_interval'))) {
Logger::log('Process lifetime reached, quitting.', Logger::DEBUG);
return;
}
// To avoid the quitting of multiple workers only one worker at a time will execute the check // To avoid the quitting of multiple workers only one worker at a time will execute the check
if (Lock::acquire('worker', 0)) { if (Lock::acquire('worker', 0)) {
// Count active workers and compare them with a maximum value that depends on the load // Count active workers and compare them with a maximum value that depends on the load
@ -128,12 +139,6 @@ class Worker
} }
Lock::release('worker'); Lock::release('worker');
} }
// Quit the worker once every 5 minutes
if (time() > ($starttime + 300)) {
Logger::log('Process lifetime reached, quitting.', Logger::DEBUG);
return;
}
} }
// Cleaning up. Possibly not needed, but it doesn't harm anything. // Cleaning up. Possibly not needed, but it doesn't harm anything.
@ -411,15 +416,16 @@ class Worker
* The execution time is the productive time. * The execution time is the productive time.
* By changing parameters like the maximum number of workers we can check the effectivness. * By changing parameters like the maximum number of workers we can check the effectivness.
*/ */
$dbtotal = number_format(self::$db_duration - (self::$db_duration_count + self::$db_duration_write + self::$db_duration_stat), 4); $dbtotal = round(self::$db_duration, 2);
$dbcount = number_format(self::$db_duration_count, 4); $dbread = round(self::$db_duration - (self::$db_duration_count + self::$db_duration_write + self::$db_duration_stat), 2);
$dbstat = number_format(self::$db_duration_stat, 4); $dbcount = round(self::$db_duration_count, 2);
$dbwrite = number_format(self::$db_duration_write, 4); $dbstat = round(self::$db_duration_stat, 2);
$dblock = number_format(self::$lock_duration, 4); $dbwrite = round(self::$db_duration_write, 2);
$rest = number_format(max(0, $up_duration - (self::$db_duration + self::$lock_duration)), 4); $dblock = round(self::$lock_duration, 2);
$exec = number_format($duration, 4); $rest = round(max(0, $up_duration - (self::$db_duration + self::$lock_duration)), 2);
$exec = round($duration, 2);
Logger::info('Performance:', ['total' => $dbtotal, 'count' => $dbcount, 'stat' => $dbstat, 'write' => $dbwrite, 'block' => $dblock, 'rest' => $rest, 'exec' => $exec]); Logger::info('Performance:', ['mode' => self::$mode, 'count' => $dbcount, 'stat' => $dbstat, 'write' => $dbwrite, 'lock' => $dblock, 'total' => $dbtotal, 'rest' => $rest, 'exec' => $exec]);
self::$up_start = microtime(true); self::$up_start = microtime(true);
self::$db_duration = 0; self::$db_duration = 0;
@ -427,6 +433,7 @@ class Worker
self::$db_duration_stat = 0; self::$db_duration_stat = 0;
self::$db_duration_write = 0; self::$db_duration_write = 0;
self::$lock_duration = 0; self::$lock_duration = 0;
self::$mode = 2;
if ($duration > 3600) { if ($duration > 3600) {
Logger::log("Prio ".$queue["priority"].": ".$queue["parameter"]." - longer than 1 hour (".round($duration/60, 3).")", Logger::DEBUG); Logger::log("Prio ".$queue["priority"].": ".$queue["parameter"]." - longer than 1 hour (".round($duration/60, 3).")", Logger::DEBUG);