Merge pull request #42391 from nextcloud/bugfix/noid/warn-on-excessiv…

…e-memory-consumption-in-background-jobs

feat(cron): Warn on excessive memory consumption in background jobs

cron.php

@@ -148,9 +148,24 @@
 				break;
 			}
 
-			$logger->debug('CLI cron call has selected job with ID ' . strval($job->getId()), ['app' => 'cron']);
+			$jobDetails = get_class($this) . ' (id: ' . $this->getId() . ', arguments: ' . json_encode($this->getArgument()) . ')';
+			$logger->debug('CLI cron call has selected job ' . $jobDetails, ['app' => 'cron']);
+
+			$memoryBefore = memory_get_usage();
+			$memoryPeakBefore = memory_get_peak_usage();
+
 			$job->execute($jobList, $logger);
 
+			$memoryAfter = memory_get_usage();
+			$memoryPeakAfter = memory_get_peak_usage();
+
+			if ($memoryAfter - $memoryBefore > 10_000_000) {
+				$logger->warning('Used memory grew by more than 10 MB when executing job ' . $jobDetails . ': ' . \OCP\Util::humanFileSize($memoryAfter). ' (before: ' . \OCP\Util::humanFileSize($memoryBefore) . ')', ['app' => 'cron']);
+			}
+			if ($memoryPeakAfter > 300_000_000) {
+				$logger->warning('Cron job used more than 300 MB of ram after executing job ' . $jobDetails . ': ' . \OCP\Util::humanFileSize($memoryPeakAfter) . ' (before: ' . \OCP\Util::humanFileSize($memoryPeakBefore) . ')', ['app' => 'cron']);
+			}
+
 			// clean up after unclean jobs
 			\OC_Util::tearDownFS();
 			$tempManager->clean();

lib/public/BackgroundJob/Job.php

@@ -76,16 +76,17 @@ public function start(IJobList $jobList): void {
 		$logger = $this->logger ?? \OCP\Server::get(LoggerInterface::class);
 
 		try {
+			$jobDetails = get_class($this) . ' (id: ' . $this->getId() . ', arguments: ' . json_encode($this->getArgument()) . ')';
 			$jobStartTime = $this->time->getTime();
-			$logger->debug('Run ' . get_class($this) . ' job with ID ' . $this->getId(), ['app' => 'cron']);
+			$logger->debug('Starting job ' . $jobDetails, ['app' => 'cron']);
 			$this->run($this->argument);
 			$timeTaken = $this->time->getTime() - $jobStartTime;
 
-			$logger->debug('Finished ' . get_class($this) . ' job with ID ' . $this->getId() . ' in ' . $timeTaken . ' seconds', ['app' => 'cron']);
+			$logger->debug('Finished job ' . $jobDetails . ' in ' . $timeTaken . ' seconds', ['app' => 'cron']);
 			$jobList->setExecutionTime($this, $timeTaken);
 		} catch (\Throwable $e) {
 			if ($logger) {
-				$logger->error('Error while running background job (class: ' . get_class($this) . ', arguments: ' . print_r($this->argument, true) . ')', [
+				$logger->error('Error while running background job ' . $jobDetails, [
 					'app' => 'core',
 					'exception' => $e,
 				]);