From e2af84ba5bcb6c6d99b730364c99dd6a2fbda91e Mon Sep 17 00:00:00 2001 From: Ingo Schommer Date: Wed, 10 Jun 2020 11:41:30 +1200 Subject: [PATCH] FIX Use logger consistently in QueuedJobService Job->addMessage() only adds the message to the job, but not the actual task output. Which means it's harder to diagnose issues. The logger already has a QueuedJobHander which also calls Job->addMessage(), *and* can do other things like output to php://stderr --- src/Services/QueuedJobService.php | 35 ++++++++++++++----------------- 1 file changed, 16 insertions(+), 19 deletions(-) diff --git a/src/Services/QueuedJobService.php b/src/Services/QueuedJobService.php index 4bdecdca..c5b8b5b7 100644 --- a/src/Services/QueuedJobService.php +++ b/src/Services/QueuedJobService.php @@ -849,9 +849,13 @@ public function runJob($jobId) ); break; } + + // Add job-specific logger handling. Modifies the job singleton by reference + $this->addJobHandlersToLogger($logger, $job, $jobDescriptor); + if ($jobDescriptor->JobStatus != QueuedJob::STATUS_RUN) { // we've been paused by something, so we'll just exit - $job->addMessage(_t( + $logger->warning(_t( __CLASS__ . '.JOB_PAUSED', 'Job paused at {time}', ['time' => DBDatetime::now()->Rfc2822()] @@ -860,9 +864,6 @@ public function runJob($jobId) } if (!$broken) { - // Add job-specific logger handling. Modifies the job singleton by reference - $this->addJobHandlersToLogger($logger, $job, $jobDescriptor); - // Collect output where jobs aren't using the logger singleton ob_start(function ($buffer, $phase) use ($job, $jobDescriptor) { $job->addMessage($buffer); @@ -891,26 +892,22 @@ public function runJob($jobId) if ($stallCount > static::config()->get('stall_threshold')) { $broken = true; - $job->addMessage( - _t( - __CLASS__ . '.JOB_STALLED', - 'Job stalled after {attempts} attempts - please check', - ['attempts' => $stallCount] - ) - ); + $logger->error(_t( + __CLASS__ . '.JOB_STALLED', + 'Job stalled after {attempts} attempts - please check', + ['attempts' => $stallCount] + )); $jobDescriptor->JobStatus = QueuedJob::STATUS_BROKEN; } // now we'll be good and check our memory usage. If it is too high, we'll set the job to // a 'Waiting' state, and let the next processing run pick up the job. if ($this->isMemoryTooHigh()) { - $job->addMessage( - _t( - __CLASS__ . '.MEMORY_RELEASE', - 'Job releasing memory and waiting ({used} used)', - ['used' => $this->humanReadable($this->getMemoryUsage())] - ) - ); + $logger->warning(_t( + __CLASS__ . '.MEMORY_RELEASE', + 'Job releasing memory and waiting ({used} used)', + ['used' => $this->humanReadable($this->getMemoryUsage())] + )); if ($jobDescriptor->JobStatus != QueuedJob::STATUS_BROKEN) { $jobDescriptor->JobStatus = QueuedJob::STATUS_WAIT; } @@ -919,7 +916,7 @@ public function runJob($jobId) // Also check if we are running too long if ($this->hasPassedTimeLimit()) { - $job->addMessage(_t( + $logger->warning(_t( __CLASS__ . '.TIME_LIMIT', 'Queue has passed time limit and will restart before continuing' ));