diff --git a/.ai/lessons.md b/.ai/lessons.md index ec90c5ea28..a3027b4200 100644 --- a/.ai/lessons.md +++ b/.ai/lessons.md @@ -18,6 +18,7 @@ - `sshd` keeps the login shell of an open multiplexed SSH connection. Call `SshMultiplexingHelper::removeMuxFile()` before a live test of SSH or login-shell behavior. - Remote command batches run in `bash -se` (`sh -se` only when the host has no bash). A command that can fail without being an error (such as `cat` of an optional file) stops the batch unless it ends with `|| true`. `Process::fake()` cannot show this, so run such a command once in a real `bash -se` on the target host. - SSH retries replay the full command batch. Only exit code 255 is an SSH transport failure; other exit codes come from the remote command, so do not retry them. Keep batches safe to run twice (for example `docker rm -f || true` before `docker run --name `). +- When one job timeout covers several remote steps, give each step only the time that is left of the job budget, and keep a margin below the worker timeout. If each step gets the full timeout, the worker kills the job mid-step and no `catch`/`finally` cleanup runs (leftover containers, files, and `running` rows). - Do not put `pkill -f "playwright run-server"` in the same shell command as other work; the pattern matches that shell and kills it. Run it as its own command. - Redirect browser test output to a file (`> /tmp/x.log 2>&1`); piping it (`| tail`) hangs because the Playwright server keeps the pipe open. - Browser `click()`/`assertSee()` wait forever when nothing matches, so a bad selector hangs the run instead of failing it. `click('Text')` can match a hidden element first (use `button:visible:has-text("Text")`); `:text-is()` on an element with child elements and `assertSee()` text with double quotes never match. Prefer plain CSS selectors. `click()` also hung on a button far down the long `/analytics` page; click it with `$page->script("document.querySelector('...').click()")` there. diff --git a/app/Jobs/CleanupHelperContainersJob.php b/app/Jobs/CleanupHelperContainersJob.php index 2c44b57dde..9da13aed70 100644 --- a/app/Jobs/CleanupHelperContainersJob.php +++ b/app/Jobs/CleanupHelperContainersJob.php @@ -4,6 +4,7 @@ namespace App\Jobs; use App\Enums\ApplicationDeploymentStatus; use App\Models\ApplicationDeploymentQueue; +use App\Models\ScheduledDatabaseBackupExecution; use App\Models\Server; use Illuminate\Bus\Queueable; use Illuminate\Contracts\Queue\ShouldBeEncrypted; @@ -12,6 +13,7 @@ use Illuminate\Contracts\Queue\ShouldQueue; use Illuminate\Foundation\Bus\Dispatchable; use Illuminate\Queue\InteractsWithQueue; use Illuminate\Queue\SerializesModels; +use Illuminate\Support\Str; class CleanupHelperContainersJob implements ShouldBeEncrypted, ShouldBeUnique, ShouldQueue { @@ -38,9 +40,9 @@ class CleanupHelperContainersJob implements ShouldBeEncrypted, ShouldBeUnique, S } /** - * Removes helper containers of finished deployments. Backups, imports, and file browsers also run in - * helper containers, so a container is removed only when its name is the UUID of a deployment that - * is not queued or in progress. + * Removes helper containers of finished deployments and the S3 upload containers (`backup-of-`) + * of database backups that are not running. Imports and file browsers also run in helper containers, so + * other containers stay. */ public function handle(): void { @@ -62,12 +64,23 @@ class CleanupHelperContainersJob implements ShouldBeEncrypted, ShouldBeUnique, S ->pluck('deployment_uuid') ->all(); + $runningBackupUploadNames = ScheduledDatabaseBackupExecution::query() + ->whereIn('uuid', $helperContainers->pluck('Names')->map(fn (string $name): string => Str::after($name, 'backup-of-'))->all()) + ->where('status', 'running') + ->pluck('uuid') + ->map(fn (string $uuid): string => "backup-of-{$uuid}") + ->all(); + foreach ($helperContainers as $container) { - if (! in_array($container['Names'], $finishedDeploymentUuids, true)) { + $isFinishedDeployment = in_array($container['Names'], $finishedDeploymentUuids, true); + // A worker that is killed during the upload never removes its upload container. + $isOrphanedBackupUpload = str_starts_with($container['Names'], 'backup-of-') + && ! in_array($container['Names'], $runningBackupUploadNames, true); + if (! $isFinishedDeployment && ! $isOrphanedBackupUpload) { continue; } - \Log::info('CleanupHelperContainersJob - Removing orphaned deployment helper container', [ + \Log::info('CleanupHelperContainersJob - Removing orphaned helper container', [ 'container' => $container['Names'], 'id' => $container['ID'], ]); diff --git a/app/Jobs/DatabaseBackupJob.php b/app/Jobs/DatabaseBackupJob.php index 776a17f58e..1ebf176e1f 100644 --- a/app/Jobs/DatabaseBackupJob.php +++ b/app/Jobs/DatabaseBackupJob.php @@ -97,6 +97,11 @@ class DatabaseBackupJob implements ShouldBeEncrypted, ShouldQueue */ public ?string $executionUuidPrefix = null; + /** + * Unix time when the backup timeout of this run ends. Set when handle() starts. + */ + private ?int $deadline = null; + public function __construct(public ScheduledDatabaseBackup $backup, public ?string $occurrenceUuid = null) { $this->onQueue(crons_queue()); @@ -118,6 +123,7 @@ class DatabaseBackupJob implements ShouldBeEncrypted, ShouldQueue } $failed = false; + $this->deadline = Carbon::now()->getTimestamp() + (int) ($this->backup->timeout ?? 3600); try { $databasesToBackup = null; @@ -578,9 +584,37 @@ class DatabaseBackupJob implements ShouldBeEncrypted, ShouldQueue } } + /** + * Seconds left of the backup timeout. The timeout limits the complete run (every database, dump and + * upload), so a run that takes too long fails inside handle(), where the cleanup runs, and not when the + * worker kills the job. + */ private function commandTimeout(): int { - return (int) ($this->backup->timeout ?? 3600); + $timeout = (int) ($this->backup->timeout ?? 3600); + if ($this->deadline === null) { + return $timeout; + } + + $remaining = $this->deadline - Carbon::now()->getTimestamp(); + if ($remaining < 1) { + throw new \RuntimeException("The backup timeout of {$timeout} seconds has passed.", 124); + } + + return $remaining; + } + + /** + * Runs the commands that write the backup file. They run only once: an SSH retry replays the batch, and + * a dump that lost its SSH connection can still run in the database container, so a second dump would + * write into the same file. + * + * @param list $commands + */ + private function runBackupCommands(array $commands): void + { + $output = trim((string) instant_remote_process($this->writeBackupFileAsRoot($commands), $this->server, true, false, $this->commandTimeout(), disableMultiplexing: true, maxAttempts: 1)); + $this->backup_output = $output === '' ? null : $output; } private function backupFilenamePart(string $database): string @@ -652,11 +686,7 @@ class DatabaseBackupJob implements ShouldBeEncrypted, ShouldQueue } } } - $this->backup_output = instant_remote_process($this->writeBackupFileAsRoot($commands), $this->server, true, false, $this->commandTimeout(), disableMultiplexing: true); - $this->backup_output = trim($this->backup_output); - if ($this->backup_output === '') { - $this->backup_output = null; - } + $this->runBackupCommands($commands); } catch (Throwable $e) { $this->add_to_error_output($e->getMessage()); throw $e; @@ -711,11 +741,7 @@ class DatabaseBackupJob implements ShouldBeEncrypted, ShouldQueue } $commands[] = $backupCommand; - $this->backup_output = instant_remote_process($this->writeBackupFileAsRoot($commands), $this->server, true, false, $this->commandTimeout(), disableMultiplexing: true); - $this->backup_output = trim($this->backup_output); - if ($this->backup_output === '') { - $this->backup_output = null; - } + $this->runBackupCommands($commands); } catch (Throwable $e) { $this->add_to_error_output($e->getMessage()); throw $e; @@ -738,11 +764,7 @@ class DatabaseBackupJob implements ShouldBeEncrypted, ShouldQueue $escapedDatabase = escapeshellarg($database); $commands[] = "docker exec {$escapedContainerName} mysqldump -u root -p$escapedPassword $escapedDatabase > {$escapedBackupLocation}"; } - $this->backup_output = instant_remote_process($this->writeBackupFileAsRoot($commands), $this->server, true, false, $this->commandTimeout(), disableMultiplexing: true); - $this->backup_output = trim($this->backup_output); - if ($this->backup_output === '') { - $this->backup_output = null; - } + $this->runBackupCommands($commands); } catch (Throwable $e) { $this->add_to_error_output($e->getMessage()); throw $e; @@ -765,11 +787,7 @@ class DatabaseBackupJob implements ShouldBeEncrypted, ShouldQueue $escapedDatabase = escapeshellarg($database); $commands[] = "docker exec {$escapedContainerName} mariadb-dump -u root -p$escapedPassword $escapedDatabase > {$escapedBackupLocation}"; } - $this->backup_output = instant_remote_process($this->writeBackupFileAsRoot($commands), $this->server, true, false, $this->commandTimeout(), disableMultiplexing: true); - $this->backup_output = trim($this->backup_output); - if ($this->backup_output === '') { - $this->backup_output = null; - } + $this->runBackupCommands($commands); } catch (Throwable $e) { $this->add_to_error_output($e->getMessage()); throw $e; @@ -788,11 +806,7 @@ class DatabaseBackupJob implements ShouldBeEncrypted, ShouldQueue backupDirectory: $this->backup_dir, )]; - $this->backup_output = instant_remote_process($this->writeBackupFileAsRoot($commands), $this->server, true, false, $this->commandTimeout(), disableMultiplexing: true); - $this->backup_output = trim($this->backup_output); - if ($this->backup_output === '') { - $this->backup_output = null; - } + $this->runBackupCommands($commands); } catch (Throwable $e) { $this->add_to_error_output($e->getMessage()); throw $e; @@ -812,11 +826,7 @@ class DatabaseBackupJob implements ShouldBeEncrypted, ShouldQueue $script = 'f=$(mktemp) && sqlite3 -readonly '.escapeshellarg(StandaloneSqlite::DATA_DIRECTORY.'/'.$database).' \'.timeout 10000\' "VACUUM INTO \'$f\'" && cat "$f"; s=$?; rm -f "$f"; exit $s'; $dumpCommand = 'docker exec '.escapeshellarg($this->container_name).' sh -c '.escapeshellarg($script); $commands[] = $this->buildCompressedDumpCommand($dumpCommand, escapeshellarg($this->backup_location)); - $this->backup_output = instant_remote_process($this->writeBackupFileAsRoot($commands), $this->server, true, false, $this->commandTimeout(), disableMultiplexing: true); - $this->backup_output = trim($this->backup_output); - if ($this->backup_output === '') { - $this->backup_output = null; - } + $this->runBackupCommands($commands); } catch (Throwable $e) { $this->add_to_error_output($e->getMessage()); throw $e; @@ -830,6 +840,8 @@ class DatabaseBackupJob implements ShouldBeEncrypted, ShouldQueue private function exitCodeReason(int|string $exitCode): ?string { return match ($exitCode) { + 124 => 'The backup stopped with exit code 124: it did not finish within the backup timeout of '.((int) ($this->backup->timeout ?? 3600)).' seconds. ' + .'The timeout counts for the complete run: the dumps and S3 uploads of all databases. Increase the timeout in the backup settings.', 137 => 'The backup stopped with exit code 137: the dump process or the database container was killed (SIGKILL). ' .'This is usually the out-of-memory killer: the dump runs inside the database container and shares its memory limit. ' .'Check the memory limit of the database and the kernel log (dmesg) on the server.', diff --git a/resources/views/livewire/project/database/backup-edit/general.blade.php b/resources/views/livewire/project/database/backup-edit/general.blade.php index f5a0c1d738..0b70283102 100644 --- a/resources/views/livewire/project/database/backup-edit/general.blade.php +++ b/resources/views/livewire/project/database/backup-edit/general.blade.php @@ -101,7 +101,7 @@ helper="Uses the deployment server timezone, or the instance timezone when none is configured." required /> + helper="Maximum runtime in seconds of the complete backup run: the dumps and S3 uploads of all databases." required /> diff --git a/tests/Feature/BackupFailureExitCodeTest.php b/tests/Feature/BackupFailureExitCodeTest.php index d1e122dc16..450536fa4d 100644 --- a/tests/Feature/BackupFailureExitCodeTest.php +++ b/tests/Feature/BackupFailureExitCodeTest.php @@ -98,3 +98,45 @@ it('keeps the error of a dump that reports its own failure', function () { expect($this->backup->executions()->latest('id')->firstOrFail()->message) ->toBe('Failed: error connecting to db server: server returned error on SASL authentication step'); }); + +it('runs a dump only once when its SSH connection closes', function () { + config(['constants.ssh.max_retries' => 3]); + $dumps = 0; + Process::fake(function ($process) use (&$dumps) { + if (str_contains(remoteProcessScript($process), 'mongodump')) { + $dumps++; + + return Process::result(exitCode: 255); + } + + return Process::result(output: ''); + }); + + (new DatabaseBackupJob($this->backup))->handle(); + + expect($dumps)->toBe(1) + ->and($this->backup->executions()->sole()->status)->toBe('failed'); +}); + +it('fails the next database inside the job when the backup timeout of the run has passed', function () { + $this->backup->update(['databases_to_backup' => 'first|second', 'timeout' => 600]); + $dumpTimeouts = []; + Process::fake(function ($process) use (&$dumpTimeouts) { + $script = remoteProcessScript($process); + if (str_contains($script, 'mongodump')) { + preg_match('/^timeout (\d+) ssh /', $script, $match); + $dumpTimeouts[] = (int) $match[1]; + $this->travel(601)->seconds(); + } + + return Process::result(output: str_contains($script, 'du -b') ? '128' : ''); + }); + + (new DatabaseBackupJob($this->backup))->handle(); + + $executions = $this->backup->executions()->get()->sortBy('id')->values(); + expect($dumpTimeouts)->toBe([600]) + ->and($executions->pluck('status')->all())->toBe(['success', 'failed']) + ->and($executions[1]->message)->toStartWith('The backup stopped with exit code 124: it did not finish within the backup timeout of 600 seconds.') + ->and($executions[1]->finished_at)->not->toBeNull(); +}); diff --git a/tests/Feature/BackupTimeoutSecretRedactionTest.php b/tests/Feature/BackupTimeoutSecretRedactionTest.php index 29bf6fdefc..757e2b9f47 100644 --- a/tests/Feature/BackupTimeoutSecretRedactionTest.php +++ b/tests/Feature/BackupTimeoutSecretRedactionTest.php @@ -109,7 +109,9 @@ it('does not put database credentials into the backup execution or the failure n $execution = $backup->executions()->latest('id')->firstOrFail(); expect($execution->status)->toBe('failed') - ->and($execution->message)->toBe('The command on the server timed out after 600 seconds.'); + ->and($execution->message)->toStartWith('The backup stopped with exit code 124: it did not finish within the backup timeout of 600 seconds.') + ->and($execution->message)->toEndWith('The command on the server timed out after 600 seconds.') + ->and($execution->message)->not->toContain('TopSecretPass'); Notification::assertSentTo($team, BackupFailed::class, fn (BackupFailed $notification) => ! str_contains((string) $notification->output, 'TopSecretPass') && str_contains((string) $notification->output, 'timed out after 600 seconds')); }); diff --git a/tests/Feature/CleanupHelperContainersJobDedupTest.php b/tests/Feature/CleanupHelperContainersJobDedupTest.php index 7a6cbde9cc..29dc42fbbe 100644 --- a/tests/Feature/CleanupHelperContainersJobDedupTest.php +++ b/tests/Feature/CleanupHelperContainersJobDedupTest.php @@ -4,7 +4,10 @@ use App\Enums\ApplicationDeploymentStatus; use App\Jobs\CleanupHelperContainersJob; use App\Models\ApplicationDeploymentQueue; use App\Models\PrivateKey; +use App\Models\ScheduledDatabaseBackup; +use App\Models\ScheduledDatabaseBackupExecution; use App\Models\Server; +use App\Models\StandalonePostgresql; use App\Models\Team; use Illuminate\Foundation\Testing\RefreshDatabase; use Illuminate\Process\PendingProcess; @@ -31,7 +34,7 @@ it('queues one helper container cleanup per server', function () { Queue::assertPushed(CleanupHelperContainersJob::class, 2); }); -it('removes only helper containers of finished deployments', function () { +it('removes helper containers of finished deployments and upload containers of backups that are not running', function () { Storage::fake('ssh-keys'); Storage::fake('ssh-mux'); config(['constants.ssh.mux_enabled' => false]); @@ -40,13 +43,20 @@ it('removes only helper containers of finished deployments', function () { foreach (['finished-uuid' => ApplicationDeploymentStatus::FINISHED, 'failed-uuid' => ApplicationDeploymentStatus::FAILED, 'running-uuid' => ApplicationDeploymentStatus::IN_PROGRESS] as $uuid => $status) { ApplicationDeploymentQueue::create(['application_id' => '1', 'deployment_uuid' => $uuid, 'server_id' => $server->id, 'status' => $status->value]); } + $backup = ScheduledDatabaseBackup::create(['frequency' => '0 0 * * *', 'database_type' => StandalonePostgresql::class, 'database_id' => 1, 'team_id' => $this->team->id]); + foreach (['uploading' => 'running', 'killed' => 'failed', 'done' => 'success'] as $uuid => $status) { + ScheduledDatabaseBackupExecution::create(['uuid' => $uuid, 'scheduled_database_backup_id' => $backup->id, 'status' => $status, 'local_storage_deleted' => false]); + } $containers = collect([ 'finished-uuid' => 'aaa111', 'failed-uuid' => 'bbb222', 'running-uuid' => 'ccc333', 'volume-upload-abc' => 'ddd444', 'volume-backup-abc' => 'eee555', - 'backup-of-abc' => 'fff666', + 'backup-of-uploading' => 'fff666', + 'backup-of-killed' => 'ggg777', + 'backup-of-done' => 'hhh888', + 'backup-of-deleted' => 'iii999', ])->map(fn (string $id, string $name): array => ['ID' => $id, 'Names' => $name, 'Image' => 'ghcr.io/coollabsio/coolify-helper:1.0.13'])->values(); $removed = []; @@ -61,5 +71,5 @@ it('removes only helper containers of finished deployments', function () { (new CleanupHelperContainersJob($server))->handle(); - expect($removed)->toBe(['aaa111', 'bbb222']); + expect($removed)->toBe(['aaa111', 'bbb222', 'ggg777', 'hhh888', 'iii999']); });