Skip to content
Open
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
49 changes: 35 additions & 14 deletions core/Service/CronService.php
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -29,6 +30,8 @@
use Psr\Log\LoggerInterface;

class CronService {
private ?IJob $currentJob = null;

/** * @var ?callable $verboseCallback */
private $verboseCallback = null;

Expand Down Expand Up @@ -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.
Expand All @@ -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;
Expand All @@ -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,
Expand All @@ -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);
}
Expand All @@ -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 {
Expand Down
Loading