mirror of
https://github.com/block/buzz.git
synced 2026-11-06 09:21:45 +00:00
test(mobile): report host hop latency when a push snapshot callback times out
Follow-up to 885804282 from its review. That commit added a class-level
`BuzzTestHostSettleBarrier` that measured a user-initiated-queue-then-main
hop in `setUp` and let the class start once three consecutive hops were
fast. Re-reading both 2026-11-01 CI logs showed the barrier would have
opened immediately in both failing runs: in job 124905175903 the one-hop
test `testAllowedNotificationRestoreNeedsNoAppGroupStore` passed in
0.070 s at the start of the class, and in job 124910378184 the gate would
have opened in the 1-2 s lull after its 1.287 s hop. Both stalls began
mid-class and recurred mid-test, which a one-instant gate cannot cover,
and a sustained-hop version would be a CI-only wait. The barrier, its
doc comment with the measurement figures, and its "settled/gave up" print
are removed. The per-element QoS assertion from 885804282 and everything
from f0bf2c0c8 stay.
In its place, a `waitForCallback` helper in `BuzzPushSnapshotEnrichmentTests`
wraps the three callback waits in the two affected tests. It waits with
`XCTWaiter` for the unchanged 10 s `callbackTimeout` and returns at once on
success, costing nothing on a passing run. Only when the wait does not
complete does it time one fresh user-initiated-queue-then-main-queue hop,
the path every bridge reply follows, bounded at 2 s, and fail with the
expectation's description plus the measured hop ("a fresh queue->main hop
took 705.3 ms", "took 0.4 ms", or "did not finish within 2 s"). That lets a
starved host be told apart from a callback that never fired the next time
this appears in CI. The original assertions still run after the helper, so
the nil-versus-reason evidence is unchanged.
If this recurs, the remaining levers are the test host (RunnerTests boot
the full Flutter app as TEST_HOST, which is what saturated the 3-vCPU
runner) or the 10 s `callbackTimeout`.
Verification (Xcode 27.2, iOS 26.2 simulator runtime, 16-core host):
- Forced timeout, with temporary variants not committed: making the
bridge's retry deletion never call back produced "'retry failure stays
allowed' not fulfilled within 10 s; a fresh queue->main hop took 0.4 ms"
followed by the existing nil-versus-reason assertion failure; adding a
0.7 s sleep inside the hop produced "took 705.3 ms".
- Class in isolation with the final code: 10/10 green, 0.1-0.5 s each.
- Full RunnerTests bundle with CI's `-parallel-testing-enabled NO`: 2/2
green (101 tests, 24-29 s).
- The commit touches only this test file; the pinned Dart formatter was
first on PATH so the pre-commit hook reformatted nothing else. No
swiftformat or swiftlint configuration in the repo; `git diff --check`
is clean.
Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Signed-off-by: Matt Toohey <contact@matttoohey.com>
This commit is contained in:
@@ -242,61 +242,36 @@ final class BuzzCommunicationNotificationTests: XCTestCase {
|
||||
}
|
||||
}
|
||||
|
||||
/// RunnerTests load the full Flutter app as their host. On CI's 3-vCPU runners
|
||||
/// its launch saturated the machine for about 40 s (both 2026-11-01 failures):
|
||||
/// a trivial queue-to-main hop took 1.3 s, then over 10 s, while a synchronous
|
||||
/// main-thread test slowed from 0.013 s to 2.65 s, and the bridge's replies
|
||||
/// missed their 10 s waits. This barrier measures that same hop, at the QoS
|
||||
/// the bridge uses, and lets the class begin only once three consecutive hops
|
||||
/// are fast again. On an idle host it costs a few milliseconds. The cap keeps a
|
||||
/// host that never settles from hanging the run; its tests then fail with the
|
||||
/// real symptom, and the printed line says the barrier gave up.
|
||||
enum BuzzTestHostSettleBarrier {
|
||||
/// A hop this slow leaves too little margin under the class's 10 s waits.
|
||||
static let slowHop: TimeInterval = 0.5
|
||||
static let consecutiveFastHops = 3
|
||||
static let cap: TimeInterval = 60
|
||||
|
||||
/// Waits once per process; later calls return immediately.
|
||||
static func waitUntilSettled() {
|
||||
_ = settled
|
||||
}
|
||||
|
||||
private static let settled: Void = {
|
||||
let queue = DispatchQueue(label: "xyz.block.buzz.test-host-settle", qos: .userInitiated)
|
||||
let started = Date()
|
||||
let deadline = started.addingTimeInterval(cap)
|
||||
var fastHops = 0
|
||||
var slowHops = 0
|
||||
while fastHops < consecutiveFastHops, Date() < deadline {
|
||||
let hopStarted = Date()
|
||||
let hop = XCTestExpectation(description: "queue to main hop")
|
||||
queue.async { DispatchQueue.main.async { hop.fulfill() } }
|
||||
_ = XCTWaiter().wait(for: [hop], timeout: max(deadline.timeIntervalSinceNow, 0))
|
||||
if Date().timeIntervalSince(hopStarted) < slowHop {
|
||||
fastHops += 1
|
||||
} else {
|
||||
fastHops = 0
|
||||
slowHops += 1
|
||||
}
|
||||
}
|
||||
let outcome = fastHops < consecutiveFastHops ? "gave up" : "settled"
|
||||
print(
|
||||
"BuzzTestHostSettleBarrier \(outcome) after \(Date().timeIntervalSince(started)) s"
|
||||
+ " (\(slowHops) slow hops)"
|
||||
)
|
||||
}()
|
||||
}
|
||||
|
||||
/// Callbacks only record what they receive and assertions run after the wait,
|
||||
/// so a callback that lands after its test returned cannot fail a later test.
|
||||
/// The timeout is a cap; a passing test returns as soon as its callback runs.
|
||||
final class BuzzPushSnapshotEnrichmentTests: XCTestCase {
|
||||
private let callbackTimeout: TimeInterval = 10
|
||||
|
||||
override class func setUp() {
|
||||
super.setUp()
|
||||
BuzzTestHostSettleBarrier.waitUntilSettled()
|
||||
/// Waits for a bridge callback. On timeout the failure also reports how long
|
||||
/// one fresh user-initiated-queue-then-main-queue hop takes right then (the
|
||||
/// path every bridge reply follows), so a starved test host ("hop took 7.2 s")
|
||||
/// reads differently from a callback that never fired ("hop took 12 ms").
|
||||
/// Both 2026-11-01 CI failures were the former: the RunnerTests host is the
|
||||
/// full Flutter app, and its launch saturated the 3-vCPU runner mid-class.
|
||||
/// A passing wait returns as soon as the callback runs and measures nothing.
|
||||
private func waitForCallback(
|
||||
_ expectation: XCTestExpectation, file: StaticString = #filePath, line: UInt = #line
|
||||
) {
|
||||
guard XCTWaiter().wait(for: [expectation], timeout: callbackTimeout) != .completed else { return }
|
||||
let hop = XCTestExpectation(description: "queue to main hop")
|
||||
let started = Date()
|
||||
DispatchQueue(label: "xyz.block.buzz.test-hop", qos: .userInitiated).async {
|
||||
DispatchQueue.main.async { hop.fulfill() }
|
||||
}
|
||||
let hopResult = XCTWaiter().wait(for: [hop], timeout: 2)
|
||||
let elapsed = String(format: "%.1f ms", Date().timeIntervalSince(started) * 1000)
|
||||
let hopReport = hopResult == .completed ? "took \(elapsed)" : "did not finish within 2 s"
|
||||
XCTFail(
|
||||
"'\(expectation.expectationDescription)' not fulfilled within \(Int(callbackTimeout)) s;"
|
||||
+ " a fresh queue->main hop \(hopReport)",
|
||||
file: file, line: line
|
||||
)
|
||||
}
|
||||
|
||||
func testAgeSignalRequestDoesNotDependOnNotificationStorage() {
|
||||
@@ -406,7 +381,7 @@ final class BuzzPushSnapshotEnrichmentTests: XCTestCase {
|
||||
purgeResult = value
|
||||
restricted.fulfill()
|
||||
})
|
||||
wait(for: [restricted], timeout: callbackTimeout)
|
||||
waitForCallback(restricted)
|
||||
XCTAssertEqual((purgeResult as? FlutterError)?.code, "age_restriction_purge_failed")
|
||||
XCTAssertTrue(BuzzAgeRestrictionSession.isRestricted(containerURL: directory))
|
||||
XCTAssertEqual(try Data(contentsOf: snapshotURL), original)
|
||||
@@ -419,7 +394,7 @@ final class BuzzPushSnapshotEnrichmentTests: XCTestCase {
|
||||
restoreResult = value
|
||||
restored.fulfill()
|
||||
})
|
||||
wait(for: [restored], timeout: callbackTimeout)
|
||||
waitForCallback(restored)
|
||||
XCTAssertNil(restoreResult)
|
||||
XCTAssertFalse(BuzzAgeRestrictionSession.isRestricted(containerURL: directory))
|
||||
XCTAssertEqual(deletionCalls, 2)
|
||||
@@ -459,7 +434,7 @@ final class BuzzPushSnapshotEnrichmentTests: XCTestCase {
|
||||
received = value
|
||||
completed.fulfill()
|
||||
})
|
||||
wait(for: [completed], timeout: callbackTimeout)
|
||||
waitForCallback(completed)
|
||||
XCTAssertEqual((received as? FlutterError)?.code, "interaction_cleanup_retry_failed")
|
||||
XCTAssertFalse(BuzzAgeRestrictionSession.isRestricted(containerURL: directory))
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user