diff --git a/src/Core/Worker.php b/src/Core/Worker.php index bfe70c39c..29d825050 100644 --- a/src/Core/Worker.php +++ b/src/Core/Worker.php @@ -356,14 +356,12 @@ class Worker { $a = \get_app(); - $mypid = getmypid(); - $argc = count($argv); $logger = $a->getLogger(); $workerLogger = new WorkerLogger($logger, $funcname); - $workerLogger ->info("Process start.", ['process' => $mypid, 'priority' => $queue["priority"], 'id' => $queue["id"]]); + $workerLogger ->info("Process start.", ['priority' => $queue["priority"], 'id' => $queue["id"]]); $stamp = (float)microtime(true); @@ -376,6 +374,7 @@ class Worker // Reset global data to avoid interferences unset($_SESSION); + // Set the workerLogger as new default logger Logger::init($workerLogger); if ($method_call) { call_user_func_array(sprintf('Friendica\Worker\%s::execute', $funcname), $argv); @@ -401,7 +400,7 @@ class Worker $rest = number_format(max(0, $up_duration - (self::$db_duration + self::$lock_duration)), 4); $exec = number_format($duration, 4); - Logger::info('Performance:', ['total' => $dbtotal, 'count' => $dbcount, 'stat' => $dbstat, 'write' => $dbwrite, 'block' => $dblock, 'rest' => $rest, 'exec' => $exec]); + $workerLogger->info('Performance log.', ['total' => $dbtotal, 'count' => $dbcount, 'stat' => $dbstat, 'write' => $dbwrite, 'block' => $dblock, 'rest' => $rest, 'exec' => $exec]); self::$up_start = microtime(true); self::$db_duration = 0; @@ -411,23 +410,23 @@ class Worker self::$lock_duration = 0; if ($duration > 3600) { - Logger::log("Prio ".$queue["priority"].": ".$queue["parameter"]." - longer than 1 hour (".round($duration/60, 3).")", Logger::DEBUG); + $workerLogger->info('Longer than 1 hour.', ['priority' => $queue["priority"], 'id' => $queue["id"], 'duration' => round($duration/60, 3)]); } elseif ($duration > 600) { - Logger::log("Prio ".$queue["priority"].": ".$queue["parameter"]." - longer than 10 minutes (".round($duration/60, 3).")", Logger::DEBUG); + $workerLogger->info('Longer than 10 minutes.', ['priority' => $queue["priority"], 'id' => $queue["id"], 'duration' => round($duration/60, 3)]); } elseif ($duration > 300) { - Logger::log("Prio ".$queue["priority"].": ".$queue["parameter"]." - longer than 5 minutes (".round($duration/60, 3).")", Logger::DEBUG); + $workerLogger->info('Longer than 5 minutes.', ['priority' => $queue["priority"], 'id' => $queue["id"], 'duration' => round($duration/60, 3)]); } elseif ($duration > 120) { - Logger::log("Prio ".$queue["priority"].": ".$queue["parameter"]." - longer than 2 minutes (".round($duration/60, 3).")", Logger::DEBUG); + $workerLogger->info('Longer than 2 minutes.', ['priority' => $queue["priority"], 'id' => $queue["id"], 'duration' => round($duration/60, 3)]); } - Logger::log("Process ".$mypid." - Prio ".$queue["priority"]." - ID ".$queue["id"].": ".$funcname." - done in ".number_format($duration, 4)." seconds."); + $workerLogger->info('Process done. ', ['priority' => $queue["priority"], 'id' => $queue["id"], 'duration' => number_format($duration, 4)]); $a->getProfiler()->saveLog($a->getLogger(), "ID " . $queue["id"] . ": " . $funcname); $cooldown = Config::get("system", "worker_cooldown", 0); if ($cooldown > 0) { - Logger::log("Process ".$mypid." - Prio ".$queue["priority"]." - ID ".$queue["id"].": ".$funcname." - in cooldown for ".$cooldown." seconds"); + $workerLogger->info('Cooldown.', ['priority' => $queue["priority"], 'id' => $queue["id"], 'cooldown' => $cooldown]); sleep($cooldown); } }