From c7469a91014483b0b96460d43ee0a1ecb409824c Mon Sep 17 00:00:00 2001 From: Iskren Alexandrov Date: Wed, 16 Sep 2026 19:43:31 +0300 Subject: [PATCH] fix(rescore): pace a backgrounded pass under iOS's CPU limit instead of deferring it MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit #1538 read the killed background passes as work that could not finish inside a wake, and deferred any pass whose last completed run took over 20 s to a processing task. The on-device crash reports say otherwise: 26 `cpu_resource_fatal` kills on one iPhone in five nights ("48 seconds cpu time over 52 seconds ... exceeding limit of 80% cpu over 60 seconds"), each about 52 s into a pass. A cold pass is ~144 s of near-continuous CPU on that install (`re-score: done — scored 21 night(s) in 144311 ms`, `dayCache reused=0/21`), so every attempt in the background was killed, including the processing task it was deferred to. The deferral only moved the kill, and the night's scores reached the phone when the app was next opened. A backgrounded pass now rests after each night, in both loops, for as long as the night took (capped at 30 s), holding it near 50% CPU. Suspension between rests does not kill it; it resumes on the next wake, so a pass longer than any single wake completes. With that, how long a pass takes stops being a reason to defer an offload, and the measurement rule is gone: - a real update (an offload) runs in the background, paced; - a pass owed from a KILLED attempt still defers, as before; - a pass running in this process is not a killed one: its own started-mark reads as owed, and deferring on it recorded a newer debt the running pass could not settle (#1681), so every later offload deferred. The trigger now reaches the engine, which re-arms one follow-up pass; - the backstop tick no longer runs in the background at all, since a paced pass costs minutes and every real update runs its own; - a processing task that finds a pass already running leaves it to settle its own debt. The measured duration is still banked and logged. --- Strand/App/AppModel.swift | 7 +- Strand/Data/IntelligenceEngine.swift | 4 + Strand/Data/RescoreBackgroundPolicy.swift | 79 +++++------ .../System/RescoreBackgroundScheduler.swift | 19 ++- .../RescoreBackgroundPolicyTests.swift | 131 ++++++++---------- .../RescoreBackgroundSchedulerTests.swift | 36 +++-- 6 files changed, 142 insertions(+), 134 deletions(-) diff --git a/Strand/App/AppModel.swift b/Strand/App/AppModel.swift index 572c4185b7..15d1abe676 100644 --- a/Strand/App/AppModel.swift +++ b/Strand/App/AppModel.swift @@ -670,7 +670,9 @@ final class AppModel: ObservableObject { /// so that it cannot mark unscored data as scored — so gating on the fingerprint here would be asking /// a question whose answer is already known to be "yes, there is work". func runDeferredRescoreIfOwed() async { - guard RescoreBackgroundScheduler.isRescoreOwed else { return } + // A pass already running here holds the owed mark itself and settles it when it finishes; forcing + // another would only queue a second full pass behind it. + guard RescoreBackgroundScheduler.isRescoreOwed, !intelligence.computing else { return } // #2238: force only when the debt is UNPROVEN — an interrupted pass, whose watermark was // deliberately never advanced. A pass that COMPLETED and was merely outvoted by a token recorded // mid-pass did advance it, so asking the fingerprint is a real question with a real answer, and a @@ -715,7 +717,8 @@ final class AppModel: ObservableObject { // the #1538 report while never producing a score. Decide first whether this pass can finish here, // and hand it to a background-processing task when it cannot. A no-op on macOS, and on iOS a // foreground pass is never deferred. - await RescoreBackgroundScheduler.run(log: { [live] line in live.append(log: line) }) { + await RescoreBackgroundScheduler.run(passInProgress: intelligence.computing, + log: { [live] line in live.append(log: line) }) { await intelligence.analyzeRecent(skipIfUnchanged: true) } await refreshV5Signals() diff --git a/Strand/Data/IntelligenceEngine.swift b/Strand/Data/IntelligenceEngine.swift index 616fd4e51c..650516760d 100644 --- a/Strand/Data/IntelligenceEngine.swift +++ b/Strand/Data/IntelligenceEngine.swift @@ -1062,7 +1062,9 @@ final class IntelligenceEngine: ObservableObject { try? await store.rrIntervals(deviceId: o, from: f, to: t, limit: StreamReadCap.rr, unlabelledAliasOfWhoop5: activeWhoop5RR && o == Repository.whoopSource) } + var paceMark = DispatchTime.now().uptimeNanoseconds for offset in 0.. 0 { await RescoreBackgroundScheduler.paceIfBackgrounded(since: &paceMark) } let dayStart = nowLocalMidnight - offset * 86_400 let day = AnalyticsEngine.dayString(dayStart, offsetSec: tzOffset) // Read a generous window around the night that ends on `day`; the stager finds the span. @@ -2052,7 +2054,9 @@ final class IntelligenceEngine: ObservableObject { nowLocalMidnight: nowLocalMidnight, now: now, offsetSec: tzOffset, maxDays: maxDays, strictCanonicalAlias: strictCanonicalAlias) var appliedLegacySnapshots: [String: LegacyScoreSnapshot] = [:] + var paceMark = DispatchTime.now().uptimeNanoseconds for night in scoredNights { + await RescoreBackgroundScheduler.paceIfBackgrounded(since: &paceMark) // #299: scope the edits to THIS day before folding. A userEdited row / hand-logged nap belongs // to exactly ONE day — the day its night ENDS on, matching the daily's end-day bucket. `endTs` // is stable under a bedtime edit (only the onset/`startTsAdjusted` moves), so end-day is the diff --git a/Strand/Data/RescoreBackgroundPolicy.swift b/Strand/Data/RescoreBackgroundPolicy.swift index e8488f49e7..fbda6a5164 100644 --- a/Strand/Data/RescoreBackgroundPolicy.swift +++ b/Strand/Data/RescoreBackgroundPolicy.swift @@ -7,7 +7,7 @@ import Foundation /// backgrounded — it stays alive as a `bluetooth-central` to receive the offload in the first place. But /// `analyzeRecent` is all-or-nothing: pass 1 writes nothing, every store write happens after both loops, /// and the watermark advances only at the very end so an interrupted run can never mark unscored data as -/// scored. On a heavy install the pass measured **474,778 ms** — nearly eight minutes. iOS suspends the +/// scored. On a heavy install the pass measured **474,778 ms** — nearly eight minutes. iOS ends the /// process long before that, so the work is lost in full. /// /// The lost work is not the worst of it. Because the watermark never advanced, the NEXT trigger still saw @@ -17,7 +17,9 @@ import Foundation /// guarantees it will be attempted again. The score appeared 1 h 57 m after the data was complete, and only /// because the app happened to stay foregrounded for eight unbroken minutes. /// -/// So this decides, before spending anything: is this a pass that can plausibly finish here? +/// What ends those passes is the background CPU limit, not suspension (see `backgroundRestPerWorkSecond`): +/// a suspended pass resumes on the next wake, a killed one does not. A backgrounded pass therefore paces +/// itself under that limit, and this decides only whether one should start here at all. /// /// Deliberately NOT a fix for how long the pass takes. A cold process still re-scores every night in the /// window, because the per-day reuse cache is in-memory and starts empty (`IntelligenceEngine.dayScanCache`). @@ -35,65 +37,56 @@ enum RescoreBackgroundPolicy { case deferToBackgroundTask(reason: String) } - /// What a background execution assertion is worth relying on, in seconds. + /// How long a backgrounded pass rests per second of work it just did. /// - /// `beginBackgroundTask` buys roughly 30 s on current iOS, and that figure is a courtesy rather than a - /// contract — it shrinks under memory pressure and in Low Power Mode. 20 s leaves headroom for the - /// assertion to be granted late and for the pass's own store writes to land, since being killed - /// mid-write is the one outcome worth spending real caution to avoid. - static let backgroundBudgetSeconds: Double = 20 + /// What actually killed the background passes was CPU, not time: iOS terminates a background process + /// that holds more than 80% CPU over 60 s (`cpu_resource_fatal`). A cold pass is roughly 144 s of + /// near-continuous CPU on a large install, so every overnight attempt was killed about 52 s in — 26 kills + /// on one phone in five nights, each leaving the debt for the next attempt to be killed on. Resting as + /// long as it worked holds the pass near 50%. A suspension between rests is harmless: the pass is not + /// killed by it, it resumes on the next wake, so a pass longer than any single wake still completes. + static let backgroundRestPerWorkSecond: Double = 1.0 - /// The longest measurement that can describe a pass's own cost, in seconds. - /// - /// The heaviest install on record (#1538) took about eight minutes. A figure far past that is not a - /// slow pass but a suspended one: the timing used a wall clock until the uptime clock replaced it, so - /// an install still carries whatever an overnight suspension banked (19 003 s on one phone). Read as - /// a cost, that value deferred every background re-score after it — and only a completed pass ever - /// overwrites it, which is the very thing it prevented. - static let maxPlausiblePassSeconds: Double = 30 * 60 + /// The longest single rest. Work measured on the uptime clock can include a suspension the process + /// spent mid-unit; resting for all of it would stall a pass that has already been idle. + static let maxBackgroundRestSeconds: Double = 30 + + /// Seconds to rest after `workSeconds` of re-score work. Zero in the foreground, where no CPU limit + /// applies and the user is waiting on the result. A non-finite or non-positive measurement rests zero. + static func restSeconds(afterWorkSeconds workSeconds: Double, isBackground: Bool) -> Double { + guard isBackground, workSeconds.isFinite, workSeconds > 0 else { return 0 } + return min(workSeconds * backgroundRestPerWorkSecond, maxBackgroundRestSeconds) + } /// - Parameters: /// - isBackground: whether the app is currently backgrounded. A foregrounded app is never deferred: /// the user is looking at the screen, there is no suspension deadline, and the existing behaviour /// is correct. + /// - isRealUpdate: the trigger carries new data that must be scored (an offload), as opposed to the + /// steady-state backstop tick. A backgrounded backstop does not run: a paced pass costs minutes, + /// the tick cannot tell live HR from a real change, and every real update already runs its own. /// - rescoreAlreadyOwed: a re-score is outstanding — either a pass marked itself started and never /// marked itself finished (it was killed; the mark survives process death, which is the point, /// because the killed process gets no chance to record anything) or an earlier trigger already - /// deferred one. Both mean the same operationally: the work is spoken for, and starting it here - /// would duplicate a pass that something better placed is going to run. This is the - /// self-correcting part — the FIRST background attempt on an install we know nothing about is - /// allowed to run, and from then on the work escalates instead of being re-killed on every - /// offload. - /// - lastCompletedPassSeconds: how long the last pass that ran to completion took, or nil if none - /// has. Measured rather than assumed — the cost varies by more than an order of magnitude with - /// history size, and a fixed guess would either defer installs that finish comfortably or wave - /// through ones that never could. - /// - budgetSeconds: see `backgroundBudgetSeconds`; a parameter so the tests can state the boundary - /// rather than inherit it. + /// deferred one. The work is spoken for by the processing task this escalated to. + /// - passInProgress: a pass is running in THIS process. Its own started-mark is what reads as owed, so + /// it is not evidence of a killed pass; the engine re-arms one follow-up pass for a trigger that + /// lands mid-run. Deferring instead recorded a newer debt, the running pass then finished without + /// settling it (#1681), and every offload after that deferred on it. static func decide(isBackground: Bool, + isRealUpdate: Bool = true, rescoreAlreadyOwed: Bool, - lastCompletedPassSeconds: Double?, - budgetSeconds: Double = backgroundBudgetSeconds, - maxPlausibleSeconds: Double = maxPlausiblePassSeconds) -> Decision { + passInProgress: Bool = false) -> Decision { guard isBackground else { return .run } - if rescoreAlreadyOwed { + guard isRealUpdate else { return .deferToBackgroundTask( - reason: "a re-score is already outstanding from an earlier trigger") + reason: "the backstop tick does not re-score while backgrounded; offloads run their own") } - // Only a FINITE, positive, PLAUSIBLE measurement can justify deferring. A nil (nothing has ever - // completed), a zero, a NaN/infinity from a corrupted default, or a figure past - // `maxPlausibleSeconds` all mean "unknown", and unknown must fall through to running: refusing to - // score on the strength of a value we cannot read would be a far worse failure than one wasted pass. - if budgetSeconds > 0, - let measured = lastCompletedPassSeconds, - measured.isFinite, measured > 0, - measured <= maxPlausibleSeconds, - measured > budgetSeconds { + if rescoreAlreadyOwed, !passInProgress { return .deferToBackgroundTask( - reason: "last completed pass took \(Int(measured.rounded()))s, over the " - + "\(Int(budgetSeconds.rounded()))s a background wake can be relied on for") + reason: "a re-score is already outstanding from an earlier trigger") } return .run diff --git a/Strand/System/RescoreBackgroundScheduler.swift b/Strand/System/RescoreBackgroundScheduler.swift index a3ccecf1c4..731536e21f 100644 --- a/Strand/System/RescoreBackgroundScheduler.swift +++ b/Strand/System/RescoreBackgroundScheduler.swift @@ -164,14 +164,18 @@ enum RescoreBackgroundScheduler { /// would conjure a forced full pass for a processing task to run when very likely nothing changed, /// which is the churn #1146 exists to avoid. A debt an earlier real pass already recorded is /// untouched either way. + /// - Parameter passInProgress: a pass is already running in this process; see + /// `RescoreBackgroundPolicy.decide`. static func run(isBackground: Bool? = nil, owesOnDefer: Bool = true, + passInProgress: Bool = false, log: @escaping (String) -> Void, work: () async -> Void) async { let decision = RescoreBackgroundPolicy.decide( isBackground: isBackground ?? isBackgrounded, + isRealUpdate: owesOnDefer, rescoreAlreadyOwed: isRescoreOwed, - lastCompletedPassSeconds: lastCompletedPassSeconds) + passInProgress: passInProgress) switch decision { case .deferToBackgroundTask(let reason): @@ -193,6 +197,17 @@ enum RescoreBackgroundScheduler { } } + /// Rest after a unit of re-score work when backgrounded, so the pass stays under iOS's background CPU + /// limit instead of being killed by it (`RescoreBackgroundPolicy.backgroundRestPerWorkSecond`). `mark` is + /// the uptime the unit started at, in nanoseconds; it is reset to the end of the rest for the next unit. + nonisolated static func paceIfBackgrounded(since mark: inout UInt64) async { + let workSeconds = Double(DispatchTime.now().uptimeNanoseconds &- mark) / 1_000_000_000 + let background = await MainActor.run { isBackgrounded } + let rest = RescoreBackgroundPolicy.restSeconds(afterWorkSeconds: workSeconds, isBackground: background) + if rest > 0 { try? await Task.sleep(nanoseconds: UInt64(rest * 1_000_000_000)) } + mark = DispatchTime.now().uptimeNanoseconds + } + /// Hold an execution assertion for the duration of `work` so a SHORT pass is not suspended halfway. /// A long one still outlives the grant; the assertion's expiry handler is where that becomes visible /// in the log and where the work is escalated, rather than the process simply vanishing. @@ -206,7 +221,7 @@ enum RescoreBackgroundScheduler { // the owed mark is still set (only a completed pass clears it) and that is what the next // decision reads. MainActor.assumeIsolated { - log("re-score: background time expired before the pass finished — escalating (#1538)") + log("re-score: background time expired mid-pass — it resumes on the next wake (#1538)") schedule() assertion.end() } diff --git a/StrandTests/RescoreBackgroundPolicyTests.swift b/StrandTests/RescoreBackgroundPolicyTests.swift index 9acd49f5f2..e666f9a810 100644 --- a/StrandTests/RescoreBackgroundPolicyTests.swift +++ b/StrandTests/RescoreBackgroundPolicyTests.swift @@ -1,23 +1,24 @@ import XCTest @testable import Strand -/// #1538: what a backgrounded re-score is allowed to attempt. +/// #1538: what a backgrounded re-score is allowed to attempt, and how it paces itself. /// /// The rules exist because getting them wrong is expensive in both directions. Too eager and the phone -/// pays for a full eight-minute pass on every offload that it will never be allowed to finish — the -/// livelock in the report. Too shy and a night goes unscored while the app waits for a background task -/// that may not arrive for hours. Neither failure is visible from inside a single run, so they are pinned -/// here rather than discovered on someone's wrist. +/// pays for passes it is killed partway through — the livelock in the report, which on-device crash +/// reports showed to be iOS's background CPU limit (`cpu_resource_fatal`, 80% over 60 s). Too shy and a +/// night goes unscored while the app waits for a background task that may not arrive for hours. Neither +/// failure is visible from inside a single run, so they are pinned here rather than discovered on +/// someone's wrist. final class RescoreBackgroundPolicyTests: XCTestCase { private func decide(background: Bool = true, + realUpdate: Bool = true, unfinished: Bool = false, - lastSeconds: Double? = nil, - budget: Double = 20) -> RescoreBackgroundPolicy.Decision { + running: Bool = false) -> RescoreBackgroundPolicy.Decision { RescoreBackgroundPolicy.decide(isBackground: background, + isRealUpdate: realUpdate, rescoreAlreadyOwed: unfinished, - lastCompletedPassSeconds: lastSeconds, - budgetSeconds: budget) + passInProgress: running) } private func isDeferred(_ d: RescoreBackgroundPolicy.Decision) -> Bool { @@ -32,94 +33,74 @@ final class RescoreBackgroundPolicyTests: XCTestCase { func testAForegroundPassAlwaysRuns() { XCTAssertEqual(decide(background: false), .run) XCTAssertEqual(decide(background: false, unfinished: true), .run) - XCTAssertEqual(decide(background: false, lastSeconds: 9_999), .run) + XCTAssertEqual(decide(background: false, realUpdate: false), .run) } - // MARK: - The livelock - - /// The core fix. An earlier pass marked itself started and never finished, which survives process - /// death — so the phone has already proved once that it cannot complete this work in the background. - /// Attempting it again is what burned nearly eight minutes per offload in #1538 while producing - /// nothing. - func testAnInterruptedPriorAttemptDefersInsteadOfRetrying() { - XCTAssertTrue(isDeferred(decide(unfinished: true))) - } + // MARK: - A real update runs, paced - /// ...and it defers even when the last COMPLETED pass looks fast, because "unfinished" is evidence - /// about this install right now, whereas the measurement may predate the history that made it slow. - func testAnInterruptedAttemptOutranksAFastMeasurement() { - XCTAssertTrue(isDeferred(decide(unfinished: true, lastSeconds: 2))) + /// An offload in the background runs now. It paces itself under the CPU limit and resumes across + /// wakes, so how long it takes is no longer a reason to hand it to a processing task that iOS may not + /// grant until the afternoon — which is when last night's scores used to appear. + func testABackgroundOffloadRuns() { + XCTAssertEqual(decide(), .run) } - // MARK: - The measurement + // MARK: - The livelock - /// A pass measured well inside the budget is exactly what SHOULD run in the background — that is the - /// case this whole mechanism must not break. - func testAPassThatFitsTheBudgetRuns() { - XCTAssertEqual(decide(lastSeconds: 5), .run) + /// An earlier pass marked itself started and never finished, and nothing is running now: that pass + /// was killed. Attempting it again on every offload is what burned the phone in #1538. + func testAnInterruptedPriorAttemptDefersInsteadOfRetrying() { + XCTAssertTrue(isDeferred(decide(unfinished: true))) } - /// The reporter's install: 474.778 s against a 20 s budget. - func testTheReportedPassDefers() { - XCTAssertTrue(isDeferred(decide(lastSeconds: 474.778))) + /// A pass running in THIS process reads as owed through its own started-mark. That is not a killed + /// pass, and deferring on it recorded a newer debt the running pass could then never settle (#1681), + /// so every later offload deferred too. The engine re-arms a follow-up pass for a mid-run trigger. + func testARunningPassIsNotMistakenForAKilledOne() { + XCTAssertEqual(decide(unfinished: true, running: true), .run) } - /// The boundary is stated rather than inherited: equal to the budget still runs, over it defers. - func testTheBudgetBoundary() { - XCTAssertEqual(decide(lastSeconds: 20, budget: 20), .run) - XCTAssertTrue(isDeferred(decide(lastSeconds: 20.001, budget: 20))) - } + // MARK: - The backstop - /// The reason is carried into the strap log, so it has to name the numbers that drove the decision. - /// #1538 was three nights of chasing BLE because the log recorded that scoring had not happened - /// without ever recording why. - func testTheDeferralReasonNamesTheMeasurementAndTheBudget() { - guard case .deferToBackgroundTask(let reason) = decide(lastSeconds: 475, budget: 20) else { - return XCTFail("expected a deferral") + /// The steady-state tick cannot tell live HR from a real change, and a paced pass costs minutes, so a + /// backgrounded tick does not run. Real updates run their own. + func testABackgroundedBackstopDoesNotRun() { + guard case .deferToBackgroundTask(let reason) = decide(realUpdate: false) else { + return XCTFail("expected the backstop to be skipped") } - XCTAssertTrue(reason.contains("475"), reason) - XCTAssertTrue(reason.contains("20"), reason) + XCTAssertTrue(reason.contains("backstop"), reason) } - // MARK: - Unknown is not "too slow" + // MARK: - Pacing - /// Nothing has ever completed on this install, so there is no measurement to defer on. Running is the - /// only way to acquire one, and a first attempt costs at most one pass. - func testAnInstallWithNoMeasurementRuns() { - XCTAssertEqual(decide(lastSeconds: nil), .run) + /// Resting as long as it worked holds a backgrounded pass near 50% CPU, under the 80% iOS kills at. + func testABackgroundedPassRestsAsLongAsItWorked() { + XCTAssertEqual(RescoreBackgroundPolicy.restSeconds(afterWorkSeconds: 6, isBackground: true), 6) } - /// A corrupted or absent default must never be read as "slow". Refusing to score on the strength of - /// a value that cannot be interpreted is a far worse failure than one wasted pass. - func testUnreadableMeasurementsRunRatherThanDefer() { - XCTAssertEqual(decide(lastSeconds: 0), .run) - XCTAssertEqual(decide(lastSeconds: -1), .run) - XCTAssertEqual(decide(lastSeconds: .nan), .run) - XCTAssertEqual(decide(lastSeconds: .infinity), .run) + /// No CPU limit applies in the foreground, and the user is waiting on the result. + func testTheForegroundNeverRests() { + XCTAssertEqual(RescoreBackgroundPolicy.restSeconds(afterWorkSeconds: 6, isBackground: false), 0) } - /// A measurement no pass could cost is a suspension, not a slow pass. The wall-clock timing banked - /// 19 003 s on a phone that slept through an overnight pass, and every background re-score after it - /// deferred. Past the ceiling it is unknown, and unknown runs. - func testAnImplausibleMeasurementIsReadAsUnknown() { - XCTAssertEqual(decide(lastSeconds: 19_003.76), .run) - XCTAssertEqual(decide(lastSeconds: RescoreBackgroundPolicy.maxPlausiblePassSeconds + 1), .run) - XCTAssertTrue(isDeferred(decide(lastSeconds: RescoreBackgroundPolicy.maxPlausiblePassSeconds))) - XCTAssertTrue(isDeferred(decide(unfinished: true, lastSeconds: 19_003.76)), - "an unfinished pass still defers on its own") + /// Work measured on the uptime clock can include a suspension; resting for all of it would stall a + /// pass that has already been idle. + func testARestIsCapped() { + XCTAssertEqual(RescoreBackgroundPolicy.restSeconds(afterWorkSeconds: 3_600, isBackground: true), + RescoreBackgroundPolicy.maxBackgroundRestSeconds) } - /// A nonsensical budget disables the measurement rule rather than deferring everything — the same - /// principle, applied to the other input. - func testANonPositiveBudgetDoesNotDeferEverything() { - XCTAssertEqual(decide(lastSeconds: 9_999, budget: 0), .run) - XCTAssertEqual(decide(lastSeconds: 9_999, budget: -5), .run) + /// An unreadable measurement rests zero rather than stalling the pass on a value that means nothing. + func testAnUnreadableMeasurementDoesNotRest() { + XCTAssertEqual(RescoreBackgroundPolicy.restSeconds(afterWorkSeconds: 0, isBackground: true), 0) + XCTAssertEqual(RescoreBackgroundPolicy.restSeconds(afterWorkSeconds: -1, isBackground: true), 0) + XCTAssertEqual(RescoreBackgroundPolicy.restSeconds(afterWorkSeconds: .nan, isBackground: true), 0) + XCTAssertEqual(RescoreBackgroundPolicy.restSeconds(afterWorkSeconds: .infinity, isBackground: true), 0) } - /// The shipped budget is the one the app actually uses; pin it so a change is deliberate. - func testTheDefaultBudgetIsTheShippedOne() { - XCTAssertEqual(RescoreBackgroundPolicy.backgroundBudgetSeconds, 20) - XCTAssertTrue(isDeferred(RescoreBackgroundPolicy.decide( - isBackground: true, rescoreAlreadyOwed: false, lastCompletedPassSeconds: 21))) + /// The shipped constants are the ones the app uses; pin them so a change is deliberate. + func testTheShippedPacingConstants() { + XCTAssertEqual(RescoreBackgroundPolicy.backgroundRestPerWorkSecond, 1.0) + XCTAssertEqual(RescoreBackgroundPolicy.maxBackgroundRestSeconds, 30) } } diff --git a/StrandTests/RescoreBackgroundSchedulerTests.swift b/StrandTests/RescoreBackgroundSchedulerTests.swift index b5f2930eb6..9218597bd9 100644 --- a/StrandTests/RescoreBackgroundSchedulerTests.swift +++ b/StrandTests/RescoreBackgroundSchedulerTests.swift @@ -76,9 +76,8 @@ final class RescoreBackgroundSchedulerTests: XCTestCase { /// The bug this file exists for: deferring has to record the debt, or the background task it defers /// to has nothing to find. func testDeferringMarksTheWorkOwedAndDoesNotRunIt() async { - // A measured pass far over the background budget, so the policy defers. - RescoreBackgroundScheduler.markRescoreCompleted(seconds: 474.778, owedToken: nil) // fixture: bank a duration, settle nothing - XCTAssertFalse(RescoreBackgroundScheduler.isRescoreOwed) + // An earlier pass was killed: its mark is set and nothing runs now, so the policy defers. + let killedToken = RescoreBackgroundScheduler.markRescoreOwed() var ran = false var logged: [String] = [] @@ -89,9 +88,11 @@ final class RescoreBackgroundSchedulerTests: XCTestCase { XCTAssertFalse(ran, "the pass must not be started in a context that cannot finish it") XCTAssertTrue(RescoreBackgroundScheduler.isRescoreOwed, "the deferred work must be recorded, or the background task does nothing") + XCTAssertNotEqual(RescoreBackgroundScheduler.currentOwedToken, killedToken, + "the deferral records its own debt for the processing task to settle") XCTAssertEqual(logged.count, 1) XCTAssertTrue(logged[0].contains("deferred"), logged[0]) - XCTAssertTrue(logged[0].contains("475"), logged[0]) + XCTAssertTrue(logged[0].contains("outstanding"), logged[0]) } /// A foregrounded pass runs, whatever the measurement says. This is the case the mechanism must not @@ -109,9 +110,9 @@ final class RescoreBackgroundSchedulerTests: XCTestCase { XCTAssertTrue(logged.isEmpty, "a pass that simply runs should not narrate itself") } - /// A background pass with no measurement yet is allowed to run — that is how the measurement is - /// acquired, and a first attempt costs at most one pass. + /// A background offload with nothing outstanding runs now, paced, however long the last pass took. func testAnUnmeasuredBackgroundPassRuns() async { + RescoreBackgroundScheduler.markRescoreCompleted(seconds: 474.778, owedToken: nil) // fixture: bank a duration, settle nothing var ran = false await RescoreBackgroundScheduler.run(isBackground: true, log: { _ in }) { ran = true } XCTAssertTrue(ran) @@ -128,6 +129,17 @@ final class RescoreBackgroundSchedulerTests: XCTestCase { XCTAssertFalse(ran) } + /// ...unless the owed mark is the running pass's own. The trigger then reaches the engine, which + /// re-arms one follow-up pass, and records no newer debt for the running pass to fail to settle. + func testATriggerDuringARunningPassReachesTheEngine() async { + let runningToken = RescoreBackgroundScheduler.markRescoreOwed() + + var ran = false + await RescoreBackgroundScheduler.run(isBackground: true, passInProgress: true, log: { _ in }) { ran = true } + XCTAssertTrue(ran) + XCTAssertEqual(RescoreBackgroundScheduler.currentOwedToken, runningToken) + } + // MARK: - The backstop tick owes nothing /// The steady-state tick is a backstop: every real update forces its own pass, so a tick that cannot @@ -160,19 +172,19 @@ final class RescoreBackgroundSchedulerTests: XCTestCase { XCTAssertTrue(RescoreBackgroundScheduler.isRescoreOwed) } - /// A backstop still RUNS in the foreground, and in a background that can afford it — the flag changes - /// only what a deferral records, never whether the pass happens. - func testABackstopStillRunsWhenItCan() async { + /// A backstop still RUNS in the foreground. In the background it does not, however fast the last pass + /// was: a paced pass costs minutes, and every real update runs its own. + func testABackstopRunsOnlyInTheForeground() async { var foreground = false await RescoreBackgroundScheduler.run(isBackground: false, owesOnDefer: false, log: { _ in }) { foreground = true } XCTAssertTrue(foreground) - var affordable = false + var background = false RescoreBackgroundScheduler.markRescoreCompleted(seconds: 3, owedToken: nil) // fixture: bank a duration, settle nothing await RescoreBackgroundScheduler.run(isBackground: true, owesOnDefer: false, - log: { _ in }) { affordable = true } - XCTAssertTrue(affordable) + log: { _ in }) { background = true } + XCTAssertFalse(background) } // MARK: - #1681: whose debt is it?