diff --git a/core/Service/CronService.php b/core/Service/CronService.php index 807658bf1d49e..ee4b0e3902be8 100644 --- a/core/Service/CronService.php +++ b/core/Service/CronService.php @@ -18,6 +18,7 @@ use OC\Session\Memory; use OC\User\Session; use OCP\App\IAppManager; +use OCP\BackgroundJob\IJob; use OCP\BackgroundJob\IJobList; use OCP\Files\ISetupManager; use OCP\IAppConfig; @@ -29,6 +30,8 @@ use Psr\Log\LoggerInterface; class CronService { + private ?IJob $currentJob = null; + /** * @var ?callable $verboseCallback */ private $verboseCallback = null; @@ -151,6 +154,21 @@ private function runCli(string $appMode, ?array $jobClasses): void { } } + // Try to log and unlock job in case of failure (eg. Allowed memory size exhausted) + register_shutdown_function(function () { + $error = error_get_last(); + if ($error === null) { + return; + } + + $message = 'Uncatched error when running job ' . $this->currentJob->getId() . ': ' . $error['message']; + $this->logger->error($message); + $this->verboseOutput($message); + if ($this->currentJob instanceof IJob) { + $this->jobList->unlockJob($this->currentJob); + } + }); + // We only ask for jobs for 14 minutes, because after 5 minutes the next // system cron task should spawn and we want to have at most three // cron jobs running in parallel. @@ -159,6 +177,7 @@ private function runCli(string $appMode, ?array $jobClasses): void { $executedJobs = []; while ($job = $this->jobList->getNext($onlyTimeSensitive, $jobClasses)) { + $this->currentJob = $job; if (isset($executedJobs[$job->getId()])) { $this->jobList->unlockJob($job); break; @@ -167,20 +186,19 @@ private function runCli(string $appMode, ?array $jobClasses): void { $jobDetails = get_class($job) . ' (id: ' . $job->getId() . ', arguments: ' . json_encode($job->getArgument()) . ')'; $this->logger->debug('CLI cron call has selected job ' . $jobDetails, ['app' => 'cron']); - $timeBefore = time(); - $memoryBefore = memory_get_usage(); - $memoryPeakBefore = memory_get_peak_usage(); - $this->verboseOutput('Starting job ' . $jobDetails); + $startTime = microtime(true); + $referenceMemory = memory_get_usage(); + memory_reset_peak_usage(); + $job->start($this->jobList); - $timeAfter = time(); - $memoryAfter = memory_get_usage(); - $memoryPeakAfter = memory_get_peak_usage(); + $memoryIncrease = memory_get_usage() - $referenceMemory; + $timeSpent = microtime(true) - $startTime; + $jobMemoryPeak = memory_get_peak_usage() - $referenceMemory; $cronInterval = 5 * 60; - $timeSpent = $timeAfter - $timeBefore; if ($timeSpent > $cronInterval) { $logLevel = match (true) { $timeSpent > $cronInterval * 128 => ILogger::FATAL, @@ -196,13 +214,13 @@ private function runCli(string $appMode, ?array $jobClasses): void { ); } - if ($memoryAfter - $memoryBefore > 50_000_000) { - $message = 'Used memory grew by more than 50 MB when executing job ' . $jobDetails . ': ' . Util::humanFileSize($memoryAfter) . ' (before: ' . Util::humanFileSize($memoryBefore) . ')'; + if ($memoryIncrease > 50 * 1024 * 1024) { + $message = 'Memory leak detected after executing job ' . $jobDetails . '. Memory usage grew by ' . Util::humanFileSize($memoryIncrease) . '.'; $this->logger->warning($message, ['app' => 'cron']); $this->verboseOutput($message); } - if ($memoryPeakAfter > 300_000_000 && $memoryPeakBefore <= 300_000_000) { - $message = 'Cron job used more than 300 MB of ram after executing job ' . $jobDetails . ': ' . Util::humanFileSize($memoryPeakAfter) . ' (before: ' . Util::humanFileSize($memoryPeakBefore) . ')'; + if ($jobMemoryPeak > 300 * 1024 * 1024) { + $message = 'Cron job used more than 300 MiB of RAM after executing job ' . $jobDetails . ': ' . Util::humanFileSize($jobMemoryPeak) . ')'; $this->logger->warning($message, ['app' => 'cron']); $this->verboseOutput($message); } @@ -211,16 +229,19 @@ private function runCli(string $appMode, ?array $jobClasses): void { $this->setupManager->tearDown(); $this->tempManager->clean(); - $this->verboseOutput('Job ' . $jobDetails . ' done in ' . ($timeAfter - $timeBefore) . ' seconds'); + $this->verboseOutput('Job ' . $jobDetails . ' done in ' . number_format($timeSpent, 2) . ' seconds'); $this->jobList->setLastJob($job); $executedJobs[$job->getId()] = true; unset($job); - if ($timeAfter > $endTime) { + if (time() > $endTime) { break; } } + + // Makes sure last error isn't catched by shutdown function + error_clear_last(); } private function runWeb(string $appMode): void {