From 76d05dfbd6b64f4bcf87670458edd14fd13fd48a Mon Sep 17 00:00:00 2001 From: Brent Deverman Date: Sat, 17 Oct 2026 20:10:53 +0800 Subject: [PATCH] Make benchmark timeout diagnostics passive (#222) --- .../BenchmarkListTasksCommand.swift | 20 ++--- .../BenchmarkProjectCountsCommand.swift | 8 +- Sources/FocusRelayCLI/BenchmarkSupport.swift | 76 ++++++------------- .../BenchmarkTaskCountsCommand.swift | 8 +- .../FocusRelayCLITests.swift | 37 +++++++++ scripts/benchmark-suite.sh | 6 +- 6 files changed, 72 insertions(+), 83 deletions(-) diff --git a/Sources/FocusRelayCLI/BenchmarkListTasksCommand.swift b/Sources/FocusRelayCLI/BenchmarkListTasksCommand.swift index 77fa106..ceecf08 100644 --- a/Sources/FocusRelayCLI/BenchmarkListTasksCommand.swift +++ b/Sources/FocusRelayCLI/BenchmarkListTasksCommand.swift @@ -21,7 +21,7 @@ struct BenchmarkListTasks: AsyncParsableCommand { var intervalMS: Int = 1500 @Option(name: .customLong("cooldown-ms"), help: "Cooldown delay after failed/timeout calls in milliseconds.") - var cooldownMS: Int = 3000 + var cooldownMS: Int = 13_000 @Option(name: .customLong("completed-after"), help: "Fixed ISO8601 anchor for completed-date scenario.") var completedAfter: String = "2020-01-01T00:00:00Z" @@ -52,7 +52,7 @@ struct BenchmarkListTasks: AsyncParsableCommand { if warmupCalls > 0 { for index in 0.. 0 { - try? await Task.sleep(nanoseconds: UInt64(cooldownMS) * 1_000_000) - } if timeout { - let diagnostic = await captureBenchmarkTimeoutDiagnostic( + let diagnostic = captureBenchmarkTimeoutDiagnostic( scenario: scenario.name, phase: phase, callIndex: callIndex, @@ -217,6 +207,10 @@ private func listTaskBenchCall( ) try? appendBenchmarkJSONLine(diagnostic, to: timeoutDiagnosticsURL) } + try await enforceBenchmarkInterval(started: started, intervalMS: intervalMS) + if cooldownMS > 0 { + try? await Task.sleep(nanoseconds: UInt64(cooldownMS) * 1_000_000) + } let event = ListTaskEvent( timestamp: benchmarkISO8601Now(), phase: phase, diff --git a/Sources/FocusRelayCLI/BenchmarkProjectCountsCommand.swift b/Sources/FocusRelayCLI/BenchmarkProjectCountsCommand.swift index 8754e56..220f151 100644 --- a/Sources/FocusRelayCLI/BenchmarkProjectCountsCommand.swift +++ b/Sources/FocusRelayCLI/BenchmarkProjectCountsCommand.swift @@ -21,7 +21,7 @@ struct BenchmarkProjectCounts: AsyncParsableCommand { var intervalMS: Int = 1200 @Option(name: .customLong("cooldown-ms"), help: "Cooldown delay after failed/timeout calls in milliseconds.") - var cooldownMS: Int = 5000 + var cooldownMS: Int = 13_000 @Option(name: .customLong("memory-interval-seconds"), help: "RSS sample interval in seconds.") var memoryIntervalSeconds: Int = 30 @@ -78,9 +78,6 @@ struct BenchmarkProjectCounts: AsyncParsableCommand { try await service.getProjectCounts(filter: scenario.filter) } try appendBenchmarkJSONLine(event, to: rawURL) - if event.timeout { - await runBenchmarkTimeoutRecoveryGate() - } } } @@ -112,9 +109,6 @@ struct BenchmarkProjectCounts: AsyncParsableCommand { overall: &overallStats, scenarios: &scenarioStats ) - if event.timeout { - await runBenchmarkTimeoutRecoveryGate() - } } let summary = renderCountBenchmarkSummary( diff --git a/Sources/FocusRelayCLI/BenchmarkSupport.swift b/Sources/FocusRelayCLI/BenchmarkSupport.swift index 39826ae..ac07f73 100644 --- a/Sources/FocusRelayCLI/BenchmarkSupport.swift +++ b/Sources/FocusRelayCLI/BenchmarkSupport.swift @@ -56,11 +56,6 @@ struct BenchmarkTimeoutProcessSnapshot: Codable { let rssKB: Int? } -struct BenchmarkTimeoutBridgeHealthSnapshot: Codable { - let ok: Bool - let detail: String -} - struct BenchmarkTimeoutDiagnostic: Codable { let timestamp: String let transport: String @@ -73,7 +68,6 @@ struct BenchmarkTimeoutDiagnostic: Codable { let queue: BenchmarkTimeoutQueueSnapshot? let omniFocus: BenchmarkTimeoutProcessSnapshot let focusrelay: BenchmarkTimeoutProcessSnapshot - let bridgeHealth: BenchmarkTimeoutBridgeHealthSnapshot? } func validateBenchmarkArguments( @@ -130,12 +124,8 @@ func runCountBenchmarkCall( } catch { let latencyMs = Date().timeIntervalSince(started) * 1000 let timeout = isBenchmarkTimeout(error) - try await enforceBenchmarkInterval(started: started, intervalMS: intervalMS) - if cooldownMS > 0 { - try? await Task.sleep(nanoseconds: UInt64(cooldownMS) * 1_000_000) - } if timeout { - let diagnostic = await captureBenchmarkTimeoutDiagnostic( + let diagnostic = captureBenchmarkTimeoutDiagnostic( scenario: scenario, phase: phase, callIndex: callIndex, @@ -144,6 +134,10 @@ func runCountBenchmarkCall( ) try? appendBenchmarkJSONLine(diagnostic, to: timeoutDiagnosticsURL) } + try await enforceBenchmarkInterval(started: started, intervalMS: intervalMS) + if cooldownMS > 0 { + try? await Task.sleep(nanoseconds: UInt64(cooldownMS) * 1_000_000) + } return CountBenchmarkEvent( timestamp: benchmarkISO8601Now(), phase: phase, @@ -240,15 +234,6 @@ func startBenchmarkMemorySampling(memoryURL: URL, intervalSeconds: Int) -> Task< } } -func runBenchmarkTimeoutRecoveryGate() async { - let environment = ProcessInfo.processInfo.environment - let recoveryMS = max(0, environment["FOCUS_RELAY_TIMEOUT_RECOVERY_MS"].flatMap(Int.init) ?? 10_000) - if recoveryMS > 0 { - try? await Task.sleep(nanoseconds: UInt64(recoveryMS) * 1_000_000) - } - _ = try? await OmniFocusBridgeService().healthCheck() -} - func enforceBenchmarkInterval(started: Date, intervalMS: Int) async throws { guard intervalMS > 0 else { return } let elapsed = Date().timeIntervalSince(started) @@ -379,11 +364,12 @@ func captureBenchmarkTimeoutDiagnostic( callIndex: Int, latencyMs: Double, errorMessage: String -) async -> BenchmarkTimeoutDiagnostic { +) -> BenchmarkTimeoutDiagnostic { + let timestamp = benchmarkISO8601Now() let requestID = extractBenchmarkRequestID(from: errorMessage) guard let baseURL = try? IPCEnvironment.defaultBaseURL() else { return BenchmarkTimeoutDiagnostic( - timestamp: benchmarkISO8601Now(), + timestamp: timestamp, transport: benchmarkTransport, scenario: scenario, phase: phase, @@ -397,33 +383,29 @@ func captureBenchmarkTimeoutDiagnostic( process: "focusrelay", pid: ProcessInfo.processInfo.processIdentifier, rssKB: nil - ), - bridgeHealth: BenchmarkTimeoutBridgeHealthSnapshot( - ok: false, - detail: "OmniFocus 4 container not found; IPC diagnostics unavailable" ) ) } let requestsURL = baseURL.appendingPathComponent("requests", isDirectory: true) let locksURL = baseURL.appendingPathComponent("locks", isDirectory: true) let responsesURL = baseURL.appendingPathComponent("responses", isDirectory: true) + let queue = BenchmarkTimeoutQueueSnapshot( + basePath: baseURL.path, + requestsCount: benchmarkDirectoryEntryCount(requestsURL), + locksCount: benchmarkDirectoryEntryCount(locksURL), + responsesCount: benchmarkDirectoryEntryCount(responsesURL), + requestExists: requestID.map { FileManager.default.fileExists(atPath: requestsURL.appendingPathComponent("\($0).json").path) }, + lockExists: requestID.map { FileManager.default.fileExists(atPath: locksURL.appendingPathComponent("\($0).lock").path) }, + responseExists: requestID.map { FileManager.default.fileExists(atPath: responsesURL.appendingPathComponent("\($0).json").path) }, + sampleRequests: benchmarkDirectoryEntrySamples(requestsURL), + sampleLocks: benchmarkDirectoryEntrySamples(locksURL), + sampleResponses: benchmarkDirectoryEntrySamples(responsesURL) + ) let omniPID = currentOmniFocusPID() let benchmarkPID = ProcessInfo.processInfo.processIdentifier - let bridgeHealth: BenchmarkTimeoutBridgeHealthSnapshot - if let result = try? await OmniFocusBridgeService().healthCheck() { - bridgeHealth = BenchmarkTimeoutBridgeHealthSnapshot( - ok: result.ok, - detail: "plugin=\(result.plugin ?? "unknown") version=\(result.version ?? "unknown")" - ) - } else { - bridgeHealth = BenchmarkTimeoutBridgeHealthSnapshot( - ok: false, - detail: "bridge-health-check failed after timeout" - ) - } return BenchmarkTimeoutDiagnostic( - timestamp: benchmarkISO8601Now(), + timestamp: timestamp, transport: benchmarkTransport, scenario: scenario, phase: phase, @@ -431,18 +413,7 @@ func captureBenchmarkTimeoutDiagnostic( latencyMs: latencyMs, error: errorMessage, requestId: requestID, - queue: BenchmarkTimeoutQueueSnapshot( - basePath: baseURL.path, - requestsCount: benchmarkDirectoryEntryCount(requestsURL), - locksCount: benchmarkDirectoryEntryCount(locksURL), - responsesCount: benchmarkDirectoryEntryCount(responsesURL), - requestExists: requestID.map { FileManager.default.fileExists(atPath: requestsURL.appendingPathComponent("\($0).json").path) }, - lockExists: requestID.map { FileManager.default.fileExists(atPath: locksURL.appendingPathComponent("\($0).lock").path) }, - responseExists: requestID.map { FileManager.default.fileExists(atPath: responsesURL.appendingPathComponent("\($0).json").path) }, - sampleRequests: benchmarkDirectoryEntrySamples(requestsURL), - sampleLocks: benchmarkDirectoryEntrySamples(locksURL), - sampleResponses: benchmarkDirectoryEntrySamples(responsesURL) - ), + queue: queue, omniFocus: BenchmarkTimeoutProcessSnapshot( process: "OmniFocus", pid: omniPID, @@ -452,8 +423,7 @@ func captureBenchmarkTimeoutDiagnostic( process: "focusrelay", pid: benchmarkPID, rssKB: benchmarkRSSKilobytes(pid: benchmarkPID) - ), - bridgeHealth: bridgeHealth + ) ) } diff --git a/Sources/FocusRelayCLI/BenchmarkTaskCountsCommand.swift b/Sources/FocusRelayCLI/BenchmarkTaskCountsCommand.swift index ef7e72e..aa1208a 100644 --- a/Sources/FocusRelayCLI/BenchmarkTaskCountsCommand.swift +++ b/Sources/FocusRelayCLI/BenchmarkTaskCountsCommand.swift @@ -21,7 +21,7 @@ struct BenchmarkTaskCounts: AsyncParsableCommand { var intervalMS: Int = 1200 @Option(name: .customLong("cooldown-ms"), help: "Cooldown delay after failed/timeout calls in milliseconds.") - var cooldownMS: Int = 5000 + var cooldownMS: Int = 13_000 @Option(name: .customLong("memory-interval-seconds"), help: "RSS sample interval in seconds.") var memoryIntervalSeconds: Int = 30 @@ -78,9 +78,6 @@ struct BenchmarkTaskCounts: AsyncParsableCommand { try await service.getTaskCounts(filter: scenario.filter) } try appendBenchmarkJSONLine(event, to: rawURL) - if event.timeout { - await runBenchmarkTimeoutRecoveryGate() - } } } @@ -112,9 +109,6 @@ struct BenchmarkTaskCounts: AsyncParsableCommand { overall: &overallStats, scenarios: &scenarioStats ) - if event.timeout { - await runBenchmarkTimeoutRecoveryGate() - } } let summary = renderCountBenchmarkSummary( diff --git a/Tests/FocusRelayCLITests/FocusRelayCLITests.swift b/Tests/FocusRelayCLITests/FocusRelayCLITests.swift index f9e9eae..2a49082 100644 --- a/Tests/FocusRelayCLITests/FocusRelayCLITests.swift +++ b/Tests/FocusRelayCLITests/FocusRelayCLITests.swift @@ -528,6 +528,43 @@ func countBenchmarkArtifactKeepsHistoricalKeys() throws { #expect(object["transport"] as? String == "plugin") } +@Test +func timeoutDiagnosticArtifactContainsPassiveQueueAndProcessStateOnly() throws { + let diagnostic = BenchmarkTimeoutDiagnostic( + timestamp: "2026-08-18T00:00:00.000Z", + transport: benchmarkTransport, + scenario: "default", + phase: "measured", + callIndex: 7, + latencyMs: 45_000, + error: "requestId=ABC-123 timed out", + requestId: "ABC-123", + queue: BenchmarkTimeoutQueueSnapshot( + basePath: "/tmp/focusrelay", + requestsCount: 1, + locksCount: 1, + responsesCount: 0, + requestExists: true, + lockExists: true, + responseExists: false, + sampleRequests: ["ABC-123.json"], + sampleLocks: ["ABC-123.lock"], + sampleResponses: [] + ), + omniFocus: BenchmarkTimeoutProcessSnapshot(process: "OmniFocus", pid: 42, rssKB: 1_024), + focusrelay: BenchmarkTimeoutProcessSnapshot(process: "focusrelay", pid: 43, rssKB: 512) + ) + let object = try #require(JSONSerialization.jsonObject(with: JSONEncoder().encode(diagnostic)) as? [String: Any]) + let queue = try #require(object["queue"] as? [String: Any]) + + #expect(queue["requestExists"] as? Bool == true) + #expect(queue["lockExists"] as? Bool == true) + #expect(queue["responseExists"] as? Bool == false) + #expect(object["omniFocus"] != nil) + #expect(object["focusrelay"] != nil) + #expect(object["bridgeHealth"] == nil) +} + @Test func listBenchmarkArtifactKeepsHistoricalKeys() throws { let event = ListTaskEvent( diff --git a/scripts/benchmark-suite.sh b/scripts/benchmark-suite.sh index 6a2772c..8673a5c 100755 --- a/scripts/benchmark-suite.sh +++ b/scripts/benchmark-suite.sh @@ -64,21 +64,21 @@ case "$PROFILE" in : "${TOTAL_HOURS:=0.5}" : "${WARMUP_CALLS:=10}" : "${INTERVAL_MS:=2000}" - : "${COOLDOWN_MS:=3000}" + : "${COOLDOWN_MS:=13000}" : "${MEMORY_INTERVAL_SECONDS:=60}" ;; release) : "${TOTAL_HOURS:=1.5}" : "${WARMUP_CALLS:=10}" : "${INTERVAL_MS:=5000}" - : "${COOLDOWN_MS:=5000}" + : "${COOLDOWN_MS:=15000}" : "${MEMORY_INTERVAL_SECONDS:=60}" ;; stress) : "${TOTAL_HOURS:=3}" : "${WARMUP_CALLS:=20}" : "${INTERVAL_MS:=1500}" - : "${COOLDOWN_MS:=3000}" + : "${COOLDOWN_MS:=13000}" : "${MEMORY_INTERVAL_SECONDS:=30}" ;; *)