diff --git a/app/Actions/ImageScan/ScanImage.php b/app/Actions/ImageScan/ScanImage.php index 9d939f41bf..08ce3c37ab 100644 --- a/app/Actions/ImageScan/ScanImage.php +++ b/app/Actions/ImageScan/ScanImage.php @@ -50,11 +50,25 @@ class ScanImage { use AsAction; - public const LOCK_TTL = 2700; + /** + * The longest run of handle() under the lock: database status, update, and status again, inspect, pull, and + * inspect again, Grype on a stored SBOM that is gone, disk check, SBOM, packages, Grype, cleanup. The lock must + * not expire under a scan that still runs. + */ + public const LOCK_TTL = 2 * self::TIMEOUT_DEFAULT + self::TIMEOUT_DB_UPDATE + + 2 * self::TIMEOUT_DEFAULT + self::TIMEOUT_PULL + + self::TIMEOUT_GRYPE + self::TIMEOUT_DEFAULT + self::TIMEOUT_SBOM + 2 * self::TIMEOUT_GRYPE + + self::TIMEOUT_DEFAULT; - /** A deploy gate waits this long for the server lock (spec 5); background scans never wait. */ + /** + * One wait of a deploy gate for the server lock (spec 5); background scans never wait. The gate waits again while + * the lock is busy, see `DeploymentImageScan::gateLockWaitSeconds()`. + */ public const GATE_LOCK_WAIT_SECONDS = 120; + /** The deploy time that a gate keeps for its own scan (SBOM and Grype) after it waited for the lock. */ + public const GATE_SCAN_RESERVE_SECONDS = self::TIMEOUT_SBOM + self::TIMEOUT_GRYPE; + public const LAST_ERROR_TTL_DAYS = 7; /** ScannerCommands budgets plus 60 s. */ diff --git a/app/Jobs/ApplicationDeploymentJob.php b/app/Jobs/ApplicationDeploymentJob.php index abd72e3a2d..cb29a80bd8 100644 --- a/app/Jobs/ApplicationDeploymentJob.php +++ b/app/Jobs/ApplicationDeploymentJob.php @@ -128,6 +128,9 @@ class ApplicationDeploymentJob implements ShouldBeEncrypted, ShouldQueue public $timeout = 3600; + /** Unix time when the worker started handle(); the timeout counts from it. */ + private ?int $handleStartedAt = null; + public static int $batch_counter = 0; private ApplicationDeploymentQueue $application_deployment_queue; @@ -445,6 +448,8 @@ class ApplicationDeploymentJob implements ShouldBeEncrypted, ShouldQueue public function handle(): void { + $this->handleStartedAt = now()->getTimestamp(); + // Check if deployment was cancelled before we even started $this->application_deployment_queue->refresh(); if ($this->application_deployment_queue->status === ApplicationDeploymentStatus::CANCELLED_BY_USER->value) { @@ -3104,7 +3109,9 @@ class ApplicationDeploymentJob implements ShouldBeEncrypted, ShouldQueue 'server', 'mainServer', 'use_build_server', 'deployment_uuid', 'pull_request_id', 'commit', 'rollback', 'skip_build', 'is_this_additional_server', 'container_name', 'docker_compose', 'generated_docker_compose', 'docker_compose_custom_start_command', 'docker_compose_custom_build_command', 'workdir', - 'docker_compose_location', 'saved_outputs' => $this->{$property}, + 'docker_compose_location', 'saved_outputs', 'timeout' => $this->{$property}, + // Unix time when the worker started the job; null when handle() did not run. + 'started_at' => $this->handleStartedAt, // Not set before the build server is chosen or the image is named. 'build_server', 'production_image_name' => $this->{$property} ?? null, }, diff --git a/app/Services/ImageScan/DeploymentImageScan.php b/app/Services/ImageScan/DeploymentImageScan.php index ff49658306..fe4ca04e20 100644 --- a/app/Services/ImageScan/DeploymentImageScan.php +++ b/app/Services/ImageScan/DeploymentImageScan.php @@ -186,7 +186,10 @@ final class DeploymentImageScan } $reused = $image !== null ? $this->completedImageScan($image['id']) : null; try { - $scan = $reused ?? ScanImage::run($this->job('server'), $this->application, $imageRef, $this->deployment, lockWaitSeconds: ScanImage::GATE_LOCK_WAIT_SECONDS, baseImageRef: $this->baseImageRef, queueCandidateCheck: false); + $scan = $reused ?? $this->scanWhenLockFree($imageRef); + } catch (DeploymentException $e) { + // A cancel while the gate waits for the lock. + throw $e; } catch (Throwable $e) { // An unexpected error is a scan that could not run: "If the scan cannot run" decides, not the error. report($e); @@ -203,6 +206,48 @@ final class DeploymentImageScan } } + /** + * Scans the image for the gate. A busy server lock is not a scan error: another scan holds it, and background + * scans do not start while the gate waits. The gate waits in steps, checks for a cancel between them, and stops + * at `gateLockWaitSeconds()`; only then the busy lock follows "If the scan cannot run". + */ + private function scanWhenLockFree(string $imageRef): ImageScan + { + $server = $this->job('server'); + $deadline = now()->addSeconds($this->gateLockWaitSeconds()); + $waitLogged = false; + + while (true) { + $wait = (int) max(1, min(ScanImage::GATE_LOCK_WAIT_SECONDS, ceil(now()->diffInSeconds($deadline, false)))); + $lastTry = now()->addSeconds($wait)->gte($deadline); + $scan = ScanImage::run($server, $this->application, $imageRef, $this->deployment, lockWaitSeconds: $wait, baseImageRef: $this->baseImageRef, queueCandidateCheck: false, retryWhenBusy: ! $lastTry); + + if ($lastTry || ! ScanImage::lockWasBusy($scan)) { + return $scan; + } + + if (! $waitLogged) { + $waitLogged = true; + $minutes = (int) ceil(now()->diffInSeconds($deadline, false) / 60); + $this->deployment->addLogEntry("Another image scan is running on {$server->name}. Waiting up to {$minutes} more minutes for it to finish."); + } + ($this->checkForCancellation)(); + } + } + + /** + * How long the gate waits in total for the server lock: until the lock expires at the latest, and only while the + * deployment keeps time for its own scan before its timeout. At least one lock wait. + */ + private function gateLockWaitSeconds(): int + { + $startedAt = $this->job('started_at'); + $elapsed = $startedAt === null ? 0 : max(0, now()->getTimestamp() - (int) $startedAt); + $left = (int) $this->job('timeout') - $elapsed - ScanImage::GATE_SCAN_RESERVE_SECONDS; + + return max(ScanImage::GATE_LOCK_WAIT_SECONDS, min(ScanImage::LOCK_TTL, $left)); + } + /** * Gates every image of a Compose deployment before the running containers stop, and keeps Compose from pulling * a different image for a checked service. diff --git a/tests/Feature/ImageScan/DeploymentGateTest.php b/tests/Feature/ImageScan/DeploymentGateTest.php index 16615d9a1a..d57d43170f 100644 --- a/tests/Feature/ImageScan/DeploymentGateTest.php +++ b/tests/Feature/ImageScan/DeploymentGateTest.php @@ -34,6 +34,7 @@ use Illuminate\Support\Facades\Process; use Illuminate\Support\Facades\Queue; use Illuminate\Support\Facades\Storage; use Illuminate\Support\Once; +use Illuminate\Support\Sleep; use Symfony\Component\Yaml\Yaml; uses(RefreshDatabase::class); @@ -643,6 +644,68 @@ it('applies the scan error rule when the scan fails with an unexpected error', f 'block on error' => ['block', false], ]); +/** + * Lets ScanImage::run() take the server lock like the real action, and returns a clean scan or a busy lock. + */ +function deployGateScanWithServerLock(): void +{ + ScanImage::shouldRun()->andReturnUsing(function (Server $server, $resource, $ref, $deployment, int $lockWaitSeconds) { + $lock = ScanImage::serverLock($server); + if (! ScanImage::acquireServerLock($lock, $server, $lockWaitSeconds)) { + return (new ImageScan)->forceFill(['status' => ImageScanStatus::Failed, 'error_code' => ImageScanErrorCode::LockBusy, 'error_context' => ['server' => $server->name]]); + } + $lock->release(); + + return deployGateReturnedScan([]); + }); +} + +it('waits for a background scan that holds the server lock longer than one lock wait', function () { + deployGatePolicy(onScanError: 'block'); + deployGateScanWithServerLock(); + $background = ScanImage::serverLock($this->server); + expect($background->get())->toBeTrue(); + $releaseAt = now()->addSeconds(600); + Sleep::fake(syncWithCarbon: true); + Sleep::whenFakingSleep(function () use ($background, $releaseAt) { + if (now()->gte($releaseAt)) { + $background->release(); + } + }); + + expect(deployGateReachesStart(deployGateJob()))->toBeTrue() + ->and(test()->queue->fresh()->scan_gate_result)->toMatchArray(['blocked' => false, 'error' => null]) + ->and(deployGateLogs())->toContain('Another image scan is running on main-server.'); +}); + +it('stops waiting for the server lock before the deployment times out', function () { + deployGatePolicy(onScanError: 'block'); + deployGateScanWithServerLock(); + expect(ScanImage::serverLock($this->server)->get())->toBeTrue(); + $startedAt = now(); + Sleep::fake(syncWithCarbon: true); + $job = deployGateJob(); + + expect(deployGateBlocked($job)->getMessage())->toBe('Deploy blocked: '.ImageScanErrorCode::LockBusy->message(['server' => 'main-server'])) + ->and((int) $startedAt->diffInSeconds(now()))->toBeLessThanOrEqual($job->timeout - ScanImage::GATE_SCAN_RESERVE_SECONDS + 1); +}); + +it('stops waiting for the server lock when the deployment is cancelled', function () { + deployGatePolicy(onScanError: 'block'); + deployGateScanWithServerLock(); + expect(ScanImage::serverLock($this->server)->get())->toBeTrue(); + $cancelAt = now()->addSeconds(300); + Sleep::fake(syncWithCarbon: true); + Sleep::whenFakingSleep(function () use ($cancelAt) { + if (now()->gte($cancelAt)) { + test()->queue->update(['status' => ApplicationDeploymentStatus::CANCELLED_BY_USER->value]); + } + }); + + expect(deployGateBlocked(deployGateJob())->getCode())->toBe(69420) + ->and(test()->queue->fresh()->scan_gate_result)->toBeNull(); +}); + it('pulls a Docker image, pins its digest, and starts it without a compose pull', function () { deployGatePolicy(); ScanImage::shouldRun()->once()