diff --git a/Sources/Container-Compose/CommandOutcome.swift b/Sources/Container-Compose/CommandOutcome.swift new file mode 100644 index 0000000..ba0ee41 --- /dev/null +++ b/Sources/Container-Compose/CommandOutcome.swift @@ -0,0 +1,59 @@ +//===----------------------------------------------------------------------===// +// Copyright © 2025 Morris Richman and the Container-Compose project authors. All rights reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// https://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +//===----------------------------------------------------------------------===// + +import Foundation + +/// How a child process ended. +/// +/// The exit status alone cannot answer "did this command succeed", because a +/// process that installs a signal handler and exits 0 when terminated reports +/// the same status as one that finished its work. A healthcheck probe that does +/// that would be recorded as healthy while it was in fact killed for overrunning +/// its timeout, so whether the timeout fired is carried alongside the status +/// rather than inferred from it. +public struct CommandOutcome: Sendable, Equatable { + /// The process's exit status, as reported by the kernel. + public let status: Int32 + /// Whether this command was terminated for exceeding its timeout. + public let timedOut: Bool + + public init(status: Int32, timedOut: Bool) { + self.status = status + self.timedOut = timedOut + } + + /// A command succeeded only if it exited cleanly *and* was left alone to do it. + public var succeeded: Bool { status == 0 && !timedOut } +} + +/// A one-way flag the timeout callback sets and the termination handler reads. +/// Both run on arbitrary dispatch queues, so the write has to be synchronised. +final class TimeoutFlag: @unchecked Sendable { + private let lock = NSLock() + private var value = false + + func set() { + lock.lock() + value = true + lock.unlock() + } + + var isSet: Bool { + lock.lock() + defer { lock.unlock() } + return value + } +} diff --git a/Sources/Container-Compose/Commands/ComposeUp.swift b/Sources/Container-Compose/Commands/ComposeUp.swift index d42efd7..038e6f3 100644 --- a/Sources/Container-Compose/Commands/ComposeUp.swift +++ b/Sources/Container-Compose/Commands/ComposeUp.swift @@ -1161,14 +1161,14 @@ public struct ComposeUp: AsyncParsableCommand, @unchecked Sendable { print("\nStarting service: \(serviceName)") print("Starting \(serviceName)") print("----------------------------------------\n") - let exitCode = try await streamCommand( + let outcome = try await streamCommand( "container", args: ["run"] + runCommandArgs, onStdout: handleOutput, onStderr: handleOutput ) - guard exitCode == 0 else { - throw ComposeError.containerRunFailed(serviceName, exitCode) + guard outcome.status == 0 else { + throw ComposeError.containerRunFailed(serviceName, outcome.status) } let detachedContainerName = containerName await ServiceExitCodeRegistry.shared.set(Task { @@ -1188,15 +1188,15 @@ public struct ComposeUp: AsyncParsableCommand, @unchecked Sendable { print("Starting \(serviceName)") print("----------------------------------------\n") do { - let exitCode = try await streamCommand( + let outcome = try await streamCommand( "container", args: ["run"] + runCommandArgs, onStdout: handleOutput, onStderr: handleOutput ) - await runHandle.complete(exitCode) - if exitCode != 0 { - fputs("Error: Service '\(serviceName)' exited with status \(exitCode).\n", stderr) + await runHandle.complete(outcome.status) + if outcome.status != 0 { + fputs("Error: Service '\(serviceName)' exited with status \(outcome.status).\n", stderr) } } catch { await runHandle.complete(-1) @@ -1253,28 +1253,68 @@ public struct ComposeUp: AsyncParsableCommand, @unchecked Sendable { let retries = max(healthcheck.retries ?? 3, 1) let interval = Healthcheck.parseDuration(healthcheck.interval, default: 30) let startPeriod = Healthcheck.parseDuration(healthcheck.start_period, default: 0) + let timeout = Healthcheck.parseDuration(healthcheck.timeout, default: 30) - if startPeriod > 0 { - try await Task.sleep(nanoseconds: UInt64(startPeriod * 1_000_000_000)) - } - - for attempt in 1...retries { - let exitCode = try await streamCommand( + @Sendable func probeSucceeded() async throws -> Bool { + try await streamCommand( "container", args: ["exec", containerName] + execArguments, + timeout: timeout, onStdout: { _ in }, onStderr: { _ in } - ) - if exitCode == 0 { - return + ).succeeded + } + + let healthy = try await Self.awaitHealthy( + retries: retries, + interval: interval, + startPeriod: startPeriod, + probe: probeSucceeded, + sleep: { try await Task.sleep(for: .seconds($0)) }) + if !healthy { + throw ComposeError.healthcheckFailed(serviceName) + } + } + + /// The Compose healthcheck waiting policy, with the probe and the clock + /// injected so the policy can be exercised without a daemon. + /// + /// `start_period` is a grace window, not a delay: probes run during it, the + /// first success ends the wait immediately, and failures inside it do not + /// consume the retry budget. Only once the window has elapsed does each + /// failure count against `retries`. + /// + /// The window is wall clock, so a slow probe consumes it exactly as it does in + /// production; `now` is injected only so a test can drive that clock instead + /// of waiting out the real one. + static func awaitHealthy( + retries: Int, + interval: TimeInterval, + startPeriod: TimeInterval, + probe: () async throws -> Bool, + sleep: (TimeInterval) async throws -> Void, + now: () -> TimeInterval = { Double(DispatchTime.now().uptimeNanoseconds) / 1_000_000_000 } + ) async throws -> Bool { + if startPeriod > 0 { + let deadline = now() + startPeriod + while now() < deadline { + if try await probe() { + return true + } + try await sleep(interval) } + } - if attempt < retries { - try await Task.sleep(nanoseconds: UInt64(interval * 1_000_000_000)) + for attempt in 1...max(retries, 1) { + if try await probe() { + return true + } + if attempt < max(retries, 1) { + try await sleep(interval) } } - throw ComposeError.healthcheckFailed(serviceName) + return false } private func pullImage(_ imageName: String, platform: String?) async throws { @@ -1481,10 +1521,12 @@ extension ComposeUp { func streamCommand( _ command: String, args: [String] = [], + timeout: TimeInterval? = nil, onStdout: @escaping (@Sendable (String) -> Void), onStderr: @escaping (@Sendable (String) -> Void) - ) async throws -> Int32 { - try await withCheckedThrowingContinuation { continuation in + ) async throws -> CommandOutcome { + let timedOut = TimeoutFlag() + return try await withCheckedThrowingContinuation { continuation in let process = Process() let stdoutPipe = Pipe() let stderrPipe = Pipe() @@ -1521,11 +1563,36 @@ extension ComposeUp { process.terminationHandler = { proc in stdoutHandle.readabilityHandler = nil stderrHandle.readabilityHandler = nil - continuation.resume(returning: proc.terminationStatus) + continuation.resume( + returning: CommandOutcome(status: proc.terminationStatus, timedOut: timedOut.isSet)) } do { try process.run() + if let timeout, timeout > 0 { + // Docker treats a check that overruns `timeout` as one failed + // attempt, not as a hang. Terminating the child makes the + // termination handler fire with a non-zero status, so the + // caller sees a normal failure. + DispatchQueue.global().asyncAfter(deadline: .now() + timeout) { [weak process] in + guard let process, process.isRunning else { return } + // Recorded before the signal: a probe that traps the + // signal and exits 0 would otherwise be indistinguishable + // from one that genuinely passed. + timedOut.set() + process.terminate() + // `container exec` ignores SIGTERM while the process it + // is proxying is stuck — measured: a probe that hangs + // survives `timeout 25` and only dies to SIGKILL (137). + // Without escalating, the termination handler never + // fires, the continuation never resumes, and `up` stalls + // forever instead of recording one failed attempt. + DispatchQueue.global().asyncAfter(deadline: .now() + 2) { [weak process] in + guard let process, process.isRunning else { return } + kill(process.processIdentifier, SIGKILL) + } + } + } } catch { continuation.resume(throwing: error) } diff --git a/Tests/Container-Compose-DynamicTests/HealthcheckProbeTimeoutTests.swift b/Tests/Container-Compose-DynamicTests/HealthcheckProbeTimeoutTests.swift new file mode 100644 index 0000000..a0e7a38 --- /dev/null +++ b/Tests/Container-Compose-DynamicTests/HealthcheckProbeTimeoutTests.swift @@ -0,0 +1,97 @@ +//===----------------------------------------------------------------------===// +// Copyright © 2025 Morris Richman and the Container-Compose project authors. All rights reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// https://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +//===----------------------------------------------------------------------===// + +import Testing +import Foundation +@testable import ContainerComposeCore + +/// The probe timeout against a real `container exec`. +/// +/// The static suite drives `streamCommand` with host `sleep`, which dies on +/// SIGTERM. `container exec` does not: while the process it proxies is stuck it +/// survives the signal, so a probe timeout that only calls `terminate()` never +/// returns and `up` stalls instead of recording one failed attempt. That +/// difference is invisible to any test using a host process, which is why this +/// one needs a container. +@Suite("Healthcheck Probe Timeout - Real container exec", .containerDependent, .serialized) +struct HealthcheckProbeTimeoutTests { + + private static let probeTimeout: TimeInterval = 2 + /// The exec sleeps far longer than the timeout, so returning at all means the + /// timeout ended it rather than the command finishing. + private static let execSleepSeconds = 300 + + @Test("a hung container exec is killed by the probe timeout") + func hungExecIsKilledByTimeout() async throws { + let name = "probe-timeout-\(UUID().uuidString.prefix(8).lowercased())" + let dir = URL.temporaryDirectory.appending(path: name) + try FileManager.default.createDirectory(at: dir, withIntermediateDirectories: true) + let yaml = """ + name: \(name) + services: + victim: + image: alpine:latest + command: ["sleep", "600"] + """ + try yaml.write(to: dir.appending(path: "docker-compose.yaml"), atomically: false, encoding: .utf8) + + var composeUp = try ComposeUp.parse(["-d", "--cwd", dir.path(percentEncoded: false)]) + try await composeUp.run() + + // Torn down on both paths and awaited. A `defer` cannot hold the async + // call, and spawning a detached Task from one leaves the container behind + // whenever the test finishes first -- measured. + func tearDown() async { + var down = try? ComposeDown.parse(["--cwd", dir.path(percentEncoded: false)]) + try? await down?.run() + // `down` stops the container but leaves it listed, so the suite would + // accumulate one stopped container per run. Removing it explicitly + // keeps repeated runs clean. + _ = try? await ComposeUp + .parse(["-d", "--cwd", dir.path(percentEncoded: false)]) + .streamCommand( + "container", + args: ["delete", "-f", "\(name)-victim"], + onStdout: { _ in }, + onStderr: { _ in }) + try? FileManager.default.removeItem(at: dir) + } + + let composeCommand = try ComposeUp.parse(["-d", "--cwd", dir.path(percentEncoded: false)]) + let start = ContinuousClock.now + let outcome: CommandOutcome + do { + outcome = try await composeCommand.streamCommand( + "container", + args: ["exec", "\(name)-victim", "sleep", "\(Self.execSleepSeconds)"], + timeout: Self.probeTimeout, + onStdout: { _ in }, + onStderr: { _ in } + ) + } catch { + await tearDown() + throw error + } + let elapsed = ContinuousClock.now - start + await tearDown() + + // Without the SIGKILL escalation this call does not return and the test + // times out rather than failing here. + #expect(elapsed < .seconds(Self.execSleepSeconds / 2)) + #expect(outcome.timedOut) + #expect(!outcome.succeeded) + } +} diff --git a/Tests/Container-Compose-StaticTests/HealthcheckTimeoutTests.swift b/Tests/Container-Compose-StaticTests/HealthcheckTimeoutTests.swift new file mode 100644 index 0000000..e65944b --- /dev/null +++ b/Tests/Container-Compose-StaticTests/HealthcheckTimeoutTests.swift @@ -0,0 +1,203 @@ +//===----------------------------------------------------------------------===// +// Copyright © 2025 Morris Richman and the Container-Compose project authors. All rights reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// https://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +//===----------------------------------------------------------------------===// + +import Testing +import Foundation +@testable import ContainerComposeCore + +@Suite("Healthcheck Timeout Tests") +struct HealthcheckTimeoutTests { + + /// `healthcheck.timeout` is only useful if an overrunning probe is actually + /// killed. Without the timeout the child below runs for its full 30s and + /// exits 0, so this test fails on both counts. + @Test("streamCommand terminates a child that overruns its timeout") + func streamCommandHonoursTimeout() async throws { + let composeUp = try ComposeUp.parse(["-d", "--cwd", NSTemporaryDirectory()]) + + let start = ContinuousClock.now + let outcome = try await composeUp.streamCommand( + "sleep", + args: ["30"], + timeout: 1, + onStdout: { _ in }, + onStderr: { _ in } + ) + let elapsed = ContinuousClock.now - start + + // Generous window: the point is "well under 30s", not millisecond accuracy. + #expect(elapsed < .seconds(15)) + #expect(outcome.status != 0) + #expect(outcome.timedOut) + #expect(!outcome.succeeded) + } + + /// A probe that finishes inside its timeout must be reported verbatim. + @Test("streamCommand leaves a fast child alone") + func streamCommandDoesNotKillFastChild() async throws { + let composeUp = try ComposeUp.parse(["-d", "--cwd", NSTemporaryDirectory()]) + + let outcome = try await composeUp.streamCommand( + "true", + args: [], + timeout: 10, + onStdout: { _ in }, + onStderr: { _ in } + ) + + #expect(outcome.status == 0) + #expect(!outcome.timedOut) + #expect(outcome.succeeded) + } + + /// The case the exit status cannot answer on its own: a probe that installs a + /// signal handler and exits 0 when terminated. It overran its timeout and was + /// killed, so it is not healthy — but `status == 0` says otherwise, which is + /// why the timeout is carried in the outcome rather than inferred. + @Test("a probe that traps the signal and exits 0 is not healthy") + func timedOutProbeExitingZeroIsNotHealthy() async throws { + let composeUp = try ComposeUp.parse(["-d", "--cwd", NSTemporaryDirectory()]) + + let outcome = try await composeUp.streamCommand( + "sh", + args: ["-c", "trap 'exit 0' TERM; sleep 30"], + timeout: 1, + onStdout: { _ in }, + onStderr: { _ in } + ) + + #expect(outcome.status == 0) // it really did exit cleanly + #expect(outcome.timedOut) // but only because we signalled it + #expect(!outcome.succeeded) // so the probe failed + } + + /// `timeout` has a Compose default of 30s; an omitted value must not be + /// read as "no timeout". + @Test("Omitted healthcheck timeout falls back to the Compose default") + func omittedTimeoutUsesDefault() throws { + let healthcheck = Healthcheck(test: ["CMD", "true"]) + #expect(Healthcheck.parseDuration(healthcheck.timeout, default: 30) == 30) + } +} + +/// The waiting policy `healthcheck` applies, exercised through `awaitHealthy`'s +/// injected probe and clock so no daemon is involved. +@Suite("Healthcheck Waiting Policy") +struct HealthcheckWaitingPolicyTests { + + /// Drives `awaitHealthy` with a scripted probe, a fake clock the sleeps + /// advance, and a record of what it was asked. Nothing here waits. + private final class Probe: @unchecked Sendable { + private let lock = NSLock() + private var results: [Bool] + private var _calls = 0 + private var _sleeps: [TimeInterval] = [] + private var _time: TimeInterval = 0 + + init(_ results: [Bool]) { self.results = results } + + func next() -> Bool { + lock.lock(); defer { lock.unlock() } + _calls += 1 + return results.isEmpty ? false : results.removeFirst() + } + + /// Sleeping is the only thing that moves the clock, which is what makes + /// the window deterministic without making it a count of iterations. + func recordSleep(_ seconds: TimeInterval) { + lock.lock(); defer { lock.unlock() } + _sleeps.append(seconds) + _time += seconds + } + + func now() -> TimeInterval { + lock.lock(); defer { lock.unlock() } + return _time + } + + var calls: Int { lock.lock(); defer { lock.unlock() }; return _calls } + var sleeps: [TimeInterval] { lock.lock(); defer { lock.unlock() }; return _sleeps } + } + + /// `start_period` is a grace window, not a delay: a probe that comes up + /// inside it ends the wait there and then. Without that, a service that is + /// ready in one second still waits out the whole window. + @Test("a probe that succeeds inside start_period returns immediately") + func earlySuccessDuringStartPeriod() async throws { + let probe = Probe([true]) + + let healthy = try await ComposeUp.awaitHealthy( + retries: 3, interval: 1, startPeriod: 30, + probe: { probe.next() }, + sleep: { probe.recordSleep($0) }, + now: { probe.now() }) + + #expect(healthy) + #expect(probe.calls == 1) + // Returned before sleeping even once, so it did not sit out the window. + #expect(probe.sleeps.isEmpty) + } + + /// Failures inside the window must not be charged against `retries`, so the + /// full retry budget is still available once the window closes. With a 3s + /// window at 1s intervals the probe fails 3 times inside it and must then + /// still be given all 3 retries — 6 calls, not 3. + @Test("failures inside start_period do not consume the retry budget") + func failuresDuringStartPeriodDoNotConsumeRetries() async throws { + let probe = Probe([]) // always fails + + let healthy = try await ComposeUp.awaitHealthy( + retries: 3, interval: 1, startPeriod: 3, + probe: { probe.next() }, + sleep: { probe.recordSleep($0) }, + now: { probe.now() }) + + #expect(!healthy) + #expect(probe.calls == 6) + } + + /// The retry budget itself, with no grace window in play. + @Test("without a start_period the probe is tried exactly retries times") + func retriesWithoutStartPeriod() async throws { + let probe = Probe([]) + + let healthy = try await ComposeUp.awaitHealthy( + retries: 2, interval: 1, startPeriod: 0, + probe: { probe.next() }, + sleep: { probe.recordSleep($0) }, + now: { probe.now() }) + + #expect(!healthy) + #expect(probe.calls == 2) + // One sleep between the two attempts, and none after the last. + #expect(probe.sleeps.count == 1) + } + + /// A probe that recovers after the window still passes on a later retry. + @Test("a success on the last retry is still healthy") + func successOnLastRetry() async throws { + let probe = Probe([false, false, true]) + + let healthy = try await ComposeUp.awaitHealthy( + retries: 3, interval: 1, startPeriod: 0, + probe: { probe.next() }, + sleep: { probe.recordSleep($0) }, + now: { probe.now() }) + + #expect(healthy) + #expect(probe.calls == 3) + } +}