From 3450a0463389274a5a24800c5b7a34f75c3304d7 Mon Sep 17 00:00:00 2001 From: Fanboynz Date: Wed, 9 Sep 2026 21:48:41 +1200 Subject: [PATCH] diag(steps): count and time the per-day probe queries With the steps-calibration fold reused rather than recomputed, a warm pass still reported ~3.3 s in the steps phase with stepsMotion reused=60/60 beside it. The fold was provably not the cost and nothing said what was: the phase is bracketed as one number and sits outside the #1538 day-loop tally, so the sixty per-day probe queries, the one appleDaily read and the in-memory calibration fit were indistinguishable from each other. Count and time the two probes that have exactly ONE call site each, so the numbers attribute themselves with no bookkeeping at the call site and no way to drift: hasHrInWindow, the day-owner resolver's per-candidate presence probe, and gravityFingerprint, the steps loop's per-day motion witness. Emitted as one line beside the existing reused=N/M line, which together answer the question a batching change would otherwise be built on a guess: a warm pass that folded nothing and still spent its time here means the round trips are the cost, and one that did not means they are not. Calls are printed beside the milliseconds because they answer different questions. The time says whether this is where the pass went; the count says whether the loop issued the number of round trips it was believed to, one per day. A right count with a large time is a slow query, a wrong count is a different bug, and one line should not be able to hide either. Counted one level down, in the store rather than at the call site, for a mechanical reason on each platform. analyzeRecentOnCpu sits 210 bytes under the JaCoCo ratchet and the steps loop is inside it, so a stopwatch there costs more than the margin and the ratchet's own note says to extract rather than raise; the Swift resolver is nonisolated static and has nowhere to accumulate. Both platforms reset and emit in the unbudgeted wrapper, so the budgeted method is untouched and its test still passes. Both sides count MONOTONIC nanoseconds and accumulate them as integers, dividing once when the line is rendered. A Date() difference would have been wrong in the one direction the clamp does not cover, since a forward clock correction mid-probe adds itself to that probe's time and inflates the total the decision reads. Summing per-call Double seconds would have been wrong differently: sixty calls of 20 ms accumulate to 1.2000000000000006 rather than 1.2, against a twin that spends no roundings at all, and the difference reaches the rendered millisecond whenever the true total sits near a half-millisecond boundary. Instrumentation only. Nothing reads the counters but the log line, and a single-strap install renders ownerHr=0/0ms because #970 skips that probe entirely, which is a finding rather than a gap. --- .../StrandAnalytics/StoreProbeTally.swift | 49 ++++++++++ .../StoreProbeTallyTests.swift | 46 +++++++++ .../WhoopStore/Sources/WhoopStore/Reads.swift | 14 ++- .../Sources/WhoopStore/StoreProbeCounts.swift | 63 +++++++++++++ .../Sources/WhoopStore/WhoopStore.swift | 4 + .../StoreProbeCountsTests.swift | 44 +++++++++ Strand/Data/IntelligenceEngine.swift | 11 +++ .../com/noop/analytics/IntelligenceEngine.kt | 7 ++ .../com/noop/analytics/StoreProbeTally.kt | 93 +++++++++++++++++++ .../java/com/noop/data/WhoopRepository.kt | 20 +++- .../com/noop/analytics/StoreProbeTallyTest.kt | 91 ++++++++++++++++++ 11 files changed, 436 insertions(+), 6 deletions(-) create mode 100644 Packages/StrandAnalytics/Sources/StrandAnalytics/StoreProbeTally.swift create mode 100644 Packages/StrandAnalytics/Tests/StrandAnalyticsTests/StoreProbeTallyTests.swift create mode 100644 Packages/WhoopStore/Sources/WhoopStore/StoreProbeCounts.swift create mode 100644 Packages/WhoopStore/Tests/WhoopStoreTests/StoreProbeCountsTests.swift create mode 100644 android/app/src/main/java/com/noop/analytics/StoreProbeTally.kt create mode 100644 android/app/src/test/java/com/noop/analytics/StoreProbeTallyTest.kt diff --git a/Packages/StrandAnalytics/Sources/StrandAnalytics/StoreProbeTally.swift b/Packages/StrandAnalytics/Sources/StrandAnalytics/StoreProbeTally.swift new file mode 100644 index 0000000000..d307b3cf3d --- /dev/null +++ b/Packages/StrandAnalytics/Sources/StrandAnalytics/StoreProbeTally.swift @@ -0,0 +1,49 @@ +import Foundation + +/// How much of an `analyzeRecent` pass goes into its per-day PROBE queries, as calls and milliseconds. +/// +/// The blind spot this closes: with the steps-calibration fold now reused rather than recomputed, a warm +/// pass still reported ~3.3 s in the steps phase with `stepsMotion reused=60/60` beside it, so the fold was +/// provably not the cost and nothing said what was. The phase is bracketed as one number and sits outside +/// the `#1538` day-loop tally, so the remaining candidates — the sixty per-day probe queries, the one +/// `appleDaily` read, and the in-memory calibration fit — were indistinguishable from each other. +/// +/// Two probes are worth counting because each has exactly ONE call site, so the counts attribute themselves +/// with no bookkeeping at the call site and no way to drift: +/// - `ownerHr`: `hasHrInWindow`, the day-owner resolver's per-candidate presence probe. Runs in BOTH the +/// scoring loop and the sixty-day steps loop, and is skipped entirely on a default single-strap install +/// (#970), so a two-strap library is the only one that pays it. +/// - `gravityFp`: `gravityFingerprint`, the steps loop's per-day motion witness. Steps-only. +/// +/// Read with the `stepsMotion reused=N/M` line, this is decisive rather than suggestive: a warm pass that +/// folded nothing and still spent its time here means the round trips ARE the cost and batching them into a +/// grouped query is worth building; one that does not means the cost is the `appleDaily` read or the fit, +/// and batching would have bought nothing. Measured, not guessed — the same reason the day-loop split and +/// the day-cache duration are measured rather than reasoned about. +/// +/// Instrumentation only: nothing reads these counts but the log line. +public enum StoreProbeTally { + /// Render ordered `(name, calls, seconds)` probes as one line. + /// + /// `calls` is printed beside the time because the two answer different questions: the time says whether + /// this is where the pass went, and the count says whether the loop issued the number of round trips it + /// was believed to (sixty per steps pass, one per day). A count that is right with a time that is large + /// is a slow query; a count that is wrong is a different bug entirely, and one line should not be able + /// to hide either. Byte-identical to the Kotlin `StoreProbeTally.logLine`. + public static func logLine(_ probes: [(name: String, calls: Int, seconds: Double)]) -> String { + let parts = probes.map { "\($0.name)=\($0.calls)/\(millis($0.seconds))ms" } + let total = probes.reduce(0.0) { $0 + $1.seconds } + return "analyzeRecent storeProbes total=\(millis(total))ms " + + (parts.isEmpty ? "(no probes)" : parts.joined(separator: " ")) + } + + /// Seconds to whole milliseconds, floored at zero. The clamp is the parity contract, not defensive + /// habit: a negative or non-finite input is where Swift's round-half-away-from-zero and Kotlin's + /// round-half-up disagree, at exactly -0.5 ms, and both sides render into one shared strap log. The + /// callers here cannot produce one (they count monotonic nanoseconds), which makes this a guarantee + /// about the renderer rather than a repair of its inputs. + private static func millis(_ seconds: Double) -> Int { + guard seconds.isFinite, seconds > 0 else { return 0 } + return Int((seconds * 1000).rounded()) + } +} diff --git a/Packages/StrandAnalytics/Tests/StrandAnalyticsTests/StoreProbeTallyTests.swift b/Packages/StrandAnalytics/Tests/StrandAnalyticsTests/StoreProbeTallyTests.swift new file mode 100644 index 0000000000..5f28f5de42 --- /dev/null +++ b/Packages/StrandAnalytics/Tests/StrandAnalyticsTests/StoreProbeTallyTests.swift @@ -0,0 +1,46 @@ +import XCTest +@testable import StrandAnalytics + +/// The per-day probe readout. Mirrored by the Kotlin `StoreProbeTallyTest`, which pins the SAME literals: +/// the line is read off one shared strap log, so a one-sided change to the format would make two platforms' +/// logs incomparable exactly when they are being compared. +final class StoreProbeTallyTests: XCTestCase { + + /// A warm two-strap pass: the scoring loop's 21 owner probes plus the steps loop's 60, and one gravity + /// witness per steps day. This is the shape the line exists to make readable. + func testRendersCallsAndMillisInOrder() { + let line = StoreProbeTally.logLine([ + (name: "ownerHr", calls: 81, seconds: 1.24), + (name: "gravityFp", calls: 60, seconds: 1.89), + ]) + XCTAssertEqual(line, "analyzeRecent storeProbes total=3130ms ownerHr=81/1240ms gravityFp=60/1890ms") + } + + /// A default SINGLE-strap install skips the owner probe entirely (#970), so zero calls must render as + /// zero rather than being omitted: "not measured" and "measured, and it was free" are different + /// findings, and only one of them means the batching idea is pointless for that user. + func testZeroCallsStillRender() { + let line = StoreProbeTally.logLine([ + (name: "ownerHr", calls: 0, seconds: 0), + (name: "gravityFp", calls: 60, seconds: 1.89), + ]) + XCTAssertEqual(line, "analyzeRecent storeProbes total=1890ms ownerHr=0/0ms gravityFp=60/1890ms") + } + + func testNoProbesSaysSoRatherThanRenderingAnEmptyTail() { + XCTAssertEqual(StoreProbeTally.logLine([]), "analyzeRecent storeProbes total=0ms (no probes)") + } + + /// The renderer clamps, and that is a contract about the RENDERER rather than a claim about the probes: + /// both sides now count monotonic nanoseconds, so neither can hand it a negative. It is pinned anyway + /// because a negative or non-finite seconds value is the one input where Swift's round-half-away-from- + /// zero and Kotlin's round-half-up disagree, at exactly -0.5 ms, and the two platforms render into one + /// shared strap log. A probe cannot take less than no time, so nothing true is lost by flooring it. + func testNegativeAndNonFiniteSecondsClampToZeroOnBothSides() { + let line = StoreProbeTally.logLine([ + (name: "ownerHr", calls: 3, seconds: -0.0005), + (name: "gravityFp", calls: 1, seconds: .nan), + ]) + XCTAssertEqual(line, "analyzeRecent storeProbes total=0ms ownerHr=3/0ms gravityFp=1/0ms") + } +} diff --git a/Packages/WhoopStore/Sources/WhoopStore/Reads.swift b/Packages/WhoopStore/Sources/WhoopStore/Reads.swift index 6d6844488c..ad4d21e3bf 100644 --- a/Packages/WhoopStore/Sources/WhoopStore/Reads.swift +++ b/Packages/WhoopStore/Sources/WhoopStore/Reads.swift @@ -1,3 +1,4 @@ +import Dispatch import Foundation import GRDB import WhoopProtocol @@ -112,7 +113,13 @@ extension WhoopStore { /// "hrSample non-empty OR ppgHrSample non-empty". OR short-circuits, so the common case is one probe. /// Twin of Kotlin's `WhoopDao.hasHrInWindow`. public func hasHrInWindow(deviceId: String, from: Int, to: Int) async throws -> Bool { - try syncRead { db in + // Counted HERE rather than at the call site, mirroring the Kotlin repository: the resolver this + // serves is `nonisolated static`, so it has nowhere to accumulate, and the steps loop that drives + // most of these runs inside a detached task. One call site each makes the count unambiguous. + // See `StoreProbeTally` (StrandAnalytics). Instrumentation only. + let probeStarted = DispatchTime.now().uptimeNanoseconds + defer { probeCounts.ownerHr.record(nanos: DispatchTime.now().uptimeNanoseconds &- probeStarted) } + return try syncRead { db in try Bool.fetchOne(db, sql: """ SELECT EXISTS(SELECT 1 FROM hrSample WHERE deviceId = ? AND ts >= ? AND ts <= ?) OR EXISTS(SELECT 1 FROM ppgHrSample WHERE deviceId = ? AND ts >= ? AND ts <= ?) @@ -129,7 +136,10 @@ extension WhoopStore { /// stream moves and at no other time. Same COUNT/COALESCE(MAX) shape and the same `(deviceId, ts)` /// index as `hrFingerprint(deviceId:from:to:)` above, and never a row fetch. public func gravityFingerprint(deviceId: String, from: Int, to: Int) async throws -> (count: Int, maxTs: Int) { - try syncRead { db in + // Counted for the same reason as `hasHrInWindow` above; see `StoreProbeTally`. + let probeStarted = DispatchTime.now().uptimeNanoseconds + defer { probeCounts.gravityFp.record(nanos: DispatchTime.now().uptimeNanoseconds &- probeStarted) } + return try syncRead { db in guard let row = try Row.fetchOne(db, sql: """ SELECT COUNT(*) AS c, COALESCE(MAX(ts), 0) AS m FROM gravitySample WHERE deviceId = ? AND ts >= ? AND ts <= ? diff --git a/Packages/WhoopStore/Sources/WhoopStore/StoreProbeCounts.swift b/Packages/WhoopStore/Sources/WhoopStore/StoreProbeCounts.swift new file mode 100644 index 0000000000..eb87cddb48 --- /dev/null +++ b/Packages/WhoopStore/Sources/WhoopStore/StoreProbeCounts.swift @@ -0,0 +1,63 @@ +import Dispatch +import Foundation + +/// Per-pass call/time counters for the two per-day PROBE reads, rendered by +/// `StrandAnalytics.StoreProbeTally`. Twin of the Kotlin `StoreProbeTally` counters. +/// +/// Lives on the store because that is where each probe has exactly ONE call site, which is what makes the +/// counts attribute themselves: `hasHrInWindow` is only ever the day-owner resolver's presence probe and +/// `gravityFingerprint` only ever the steps loop's per-day motion witness. Counting at the call sites +/// instead would mean threading an accumulator through a `nonisolated static` resolver and a detached task, +/// and on Android through a method with no ratchet margin to spend. +/// +/// Actor-isolated by living on `WhoopStore`, so no lock and no `Sendable` gymnastics. Instrumentation only: +/// nothing reads these but the diagnostic line. +public struct StoreProbeCounts: Sendable, Equatable { + /// One probe's calls and accumulated time. + public struct Probe: Sendable, Equatable { + public private(set) var calls = 0 + + /// Accumulated INTEGER nanoseconds, divided to seconds once when read rather than per call. + /// + /// The Kotlin twin sums `System.nanoTime()` deltas into an `AtomicLong` and divides once at render. + /// Converting each call to `Double` seconds instead would spend sixty to eighty roundings where the + /// twin spends none, and the two would then disagree in the last bits — which survives into the + /// rendered line whenever the true total sits near a half-millisecond boundary, the exact boundary + /// `StoreProbeTallyTests` pins. Integer accumulation makes the two provably the same arithmetic. + public private(set) var nanos: UInt64 = 0 + + /// Accumulated seconds, for the renderer. One division, matching the twin. + public var seconds: Double { Double(nanos) / 1_000_000_000 } + + /// Add one call of `nanos` monotonic nanoseconds. + /// + /// Nanoseconds from a MONOTONIC source, not a `Date()` difference, and that is the whole point of + /// the type. These counters exist to decide whether the per-day round trips are worth batching, so + /// a number that a clock correction can move is worse than no number: `Date()` steps in BOTH + /// directions, and while a backwards step is clamped away, a forward NTP jump mid-probe would + /// silently add itself to that probe's time and inflate the very total the decision reads. The + /// Kotlin twin counts `System.nanoTime()` for the same reason, so the two measure the same thing. + mutating func record(nanos elapsed: UInt64) { + calls += 1 + nanos &+= elapsed + } + } + + /// `hasHrInWindow` — the day-owner resolver's per-candidate presence probe, in BOTH the scoring loop + /// and the sixty-day steps loop. Skipped entirely on a default single-strap install (#970). + public var ownerHr = Probe() + /// `gravityFingerprint` — the steps loop's per-day motion witness. Steps-only. + public var gravityFp = Probe() + + public init() {} +} + +public extension WhoopStore { + /// Read the counters and zero them, so a line describes ONE pass and never accumulates across the + /// back-to-back passes an offload storm is made of. + func takeProbeCounts() -> StoreProbeCounts { + let counts = probeCounts + probeCounts = StoreProbeCounts() + return counts + } +} diff --git a/Packages/WhoopStore/Sources/WhoopStore/WhoopStore.swift b/Packages/WhoopStore/Sources/WhoopStore/WhoopStore.swift index f75e185afa..2d6edbc4dc 100644 --- a/Packages/WhoopStore/Sources/WhoopStore/WhoopStore.swift +++ b/Packages/WhoopStore/Sources/WhoopStore/WhoopStore.swift @@ -59,6 +59,10 @@ private actor StoreOpenGate { /// data or the query results. public actor WhoopStore { + /// Per-pass call/time counters for the two per-day PROBE reads, drained by `takeProbeCounts()`. + /// Instrumentation only — nothing reads them but a diagnostic line. See `StoreProbeCounts`. + var probeCounts = StoreProbeCounts() + /// PPG waveform rows banked since its retention sweep last ran, PER DEVICE, for the same reason as /// `v18AuxRowsSincePrune` below: the sweep is per device, so a shared counter would let one strap /// spend another's budget. Separate counter from the v18 aux one because the two caps differ and a diff --git a/Packages/WhoopStore/Tests/WhoopStoreTests/StoreProbeCountsTests.swift b/Packages/WhoopStore/Tests/WhoopStoreTests/StoreProbeCountsTests.swift new file mode 100644 index 0000000000..309931351d --- /dev/null +++ b/Packages/WhoopStore/Tests/WhoopStoreTests/StoreProbeCountsTests.swift @@ -0,0 +1,44 @@ +import XCTest +@testable import WhoopStore + +/// The per-day probe counters' ARITHMETIC, pinned against the Kotlin twin's. +/// +/// The twin sums `System.nanoTime()` deltas into an `AtomicLong` and divides once at render. This side has +/// to do the same thing, not merely a similar thing: dividing each call to `Double` seconds and summing +/// those would spend sixty to eighty roundings where the twin spends none, and the difference survives into +/// the rendered millisecond whenever the true total sits near a half-millisecond boundary. Both platforms +/// render into ONE shared strap log, so a divergence there is read as two devices behaving differently. +final class StoreProbeCountsTests: XCTestCase { + + /// Sixty calls of exactly 20 ms. Integer accumulation makes this exactly 1.2 s, so it renders 1200ms; + /// per-call `Double` division would land a hair either side. The literal matches the Kotlin + /// `StoreProbeTallyTest.recordAccumulatesIntegerNanosLikeTheSwiftTwin`. + func testAccumulatesIntegerNanosRatherThanSummingDoubles() { + var probe = StoreProbeCounts.Probe() + for _ in 0..<60 { probe.record(nanos: 20_000_000) } + XCTAssertEqual(probe.calls, 60) + XCTAssertEqual(probe.nanos, 1_200_000_000) + XCTAssertEqual(probe.seconds, 1.2, accuracy: 0) + } + + /// A probe that was never called contributes nothing and says so, which is what makes `ownerHr=0/0ms` + /// on a single-strap install (#970) a finding rather than a missing measurement. + func testUncalledProbeIsZeroNotAbsent() { + let probe = StoreProbeCounts.Probe() + XCTAssertEqual(probe.calls, 0) + XCTAssertEqual(probe.seconds, 0) + } + + /// `takeProbeCounts()` DRAINS. A line has to describe one pass, and the passes this runs under are the + /// back-to-back ones an offload storm is made of, so a read that left the counters standing would make + /// every pass after the first report its predecessors' work as its own. + func testTakeDrainsSoAPassCannotInheritTheLastOne() async throws { + let store = try await WhoopStore.inMemory() + _ = try? await store.hasHrInWindow(deviceId: "d", from: 0, to: 1) + let first = await store.takeProbeCounts() + XCTAssertEqual(first.ownerHr.calls, 1) + let second = await store.takeProbeCounts() + XCTAssertEqual(second.ownerHr.calls, 0) + XCTAssertEqual(second.ownerHr.seconds, 0) + } +} diff --git a/Strand/Data/IntelligenceEngine.swift b/Strand/Data/IntelligenceEngine.swift index 987f8cb0a2..fae79fea3e 100644 --- a/Strand/Data/IntelligenceEngine.swift +++ b/Strand/Data/IntelligenceEngine.swift @@ -854,6 +854,10 @@ final class IntelligenceEngine: ObservableObject { let effortMethodGlobal = PuffinExperiment.effortMethod let dayCycleMode = DayCycleMode.persisted(UserDefaults.standard.string(forKey: DayCycleMode.storageKey)) + // Zero the per-day probe counters so the line emitted after the steps phase describes THIS pass + // and never accumulates across the back-to-back passes an offload storm is made of. Must precede + // the day loop below, which is the scoring half of the owner probes. See `StoreProbeTally`. + _ = await store.takeProbeCounts() // ── #1005 BATTERY: per-day reuse cache setup (see `dayScanCache`) ──────────────────────────── // The stager toggles are read per-day inside the loop below, but they are global (same value every // day); read them ONCE here too so the config signature can fold them without reaching into the @@ -2477,6 +2481,13 @@ final class IntelligenceEngine: ObservableObject { UserDefaults.standard.set(stepsMotionPayload, forKey: Self.stepsMotionCacheDefaultsKey) } diagnosticSink?(stepsMotionLogLine, nil) + // What the pass spent on its per-day probe queries, beside the `stepsMotion reused=N/M` line above. + // Together they say whether a warm pass that folded nothing still went into the round trips. + let probeCounts = await store.takeProbeCounts() + diagnosticSink?(StoreProbeTally.logLine([ + (name: "ownerHr", calls: probeCounts.ownerHr.calls, seconds: probeCounts.ownerHr.seconds), + (name: "gravityFp", calls: probeCounts.gravityFp.calls, seconds: probeCounts.gravityFp.seconds), + ]), nil) // #1816: persist whether the strap has banked ANY motion in the calibration scan window, so the // Today tile can distinguish "Need N more phone-step days" (motion exists, phone half missing) // from "No motion synced yet" (the motion half is the blocker, and no number of phone-step days diff --git a/android/app/src/main/java/com/noop/analytics/IntelligenceEngine.kt b/android/app/src/main/java/com/noop/analytics/IntelligenceEngine.kt index bb74f55aeb..8ddff15f71 100644 --- a/android/app/src/main/java/com/noop/analytics/IntelligenceEngine.kt +++ b/android/app/src/main/java/com/noop/analytics/IntelligenceEngine.kt @@ -493,6 +493,10 @@ object IntelligenceEngine { // relaunch is a repeat the process boundary hid. Nothing pass-global feeds the fold, so a // payload written by a previous launch is as good as one written by the previous pass; see // [StepsMotionCache]. Inside the lock because it writes the gate-guarded cache. + // Zero the per-day probe counters so the line below describes THIS pass and never accumulates + // across the back-to-back passes an offload storm is made of. Reset and emit both live in this + // wrapper, never in `analyzeRecentOnCpu`, whose ratchet margin has no room for either. + StoreProbeTally.reset() if (!stepsMotionCacheLoaded && stepsMotionCacheGet != null) { stepsMotionCacheLoaded = true val raw = stepsMotionCacheGet() @@ -529,6 +533,9 @@ object IntelligenceEngine { stepsMotionCacheSet(payload) } } + // What the pass spent on its per-day probe queries, beside the `stepsMotion reused=N/M` line. + // Together they say whether a warm pass that folded nothing still went into the round trips. + diag(StoreProbeTally.line()) result } diag("re-score: done — scored ${scored.size} night(s) in ${(System.nanoTime() - reScoreStart) / 1_000_000} ms (#1005)") diff --git a/android/app/src/main/java/com/noop/analytics/StoreProbeTally.kt b/android/app/src/main/java/com/noop/analytics/StoreProbeTally.kt new file mode 100644 index 0000000000..23fe1290ff --- /dev/null +++ b/android/app/src/main/java/com/noop/analytics/StoreProbeTally.kt @@ -0,0 +1,93 @@ +package com.noop.analytics + +import java.util.concurrent.atomic.AtomicLong +import kotlin.math.roundToLong + +/** + * How much of an `analyzeRecent` pass goes into its per-day PROBE queries, as calls and milliseconds. + * Kotlin twin of the Swift `StoreProbeTally`. + * + * The blind spot this closes: with the steps-calibration fold now reused rather than recomputed, a warm + * pass still reported ~3.3 s in the steps phase with `stepsMotion reused=60/60` beside it, so the fold was + * provably not the cost and nothing said what was. The phase is bracketed as one number and sits outside + * the #1538 day-loop tally, so the remaining candidates — the sixty per-day probe queries, the one + * `appleDaily` read, and the in-memory calibration fit — were indistinguishable from each other. + * + * Two probes are worth counting because each has exactly ONE call site, so the counts attribute themselves + * with no bookkeeping at the call site and no way to drift: + * - `ownerHr`: [com.noop.data.WhoopRepository.hasHrInWindow], the day-owner resolver's per-candidate + * presence probe. Runs in BOTH the scoring loop and the sixty-day steps loop, and is skipped entirely on + * a default single-strap install (#970), so a two-strap library is the only one that pays it. + * - `gravityFp`: [com.noop.data.WhoopRepository.gravityFingerprintWindow], the steps loop's per-day motion + * witness. Steps-only. + * + * Read with the `stepsMotion reused=N/M` line, this is decisive rather than suggestive: a warm pass that + * folded nothing and still spent its time here means the round trips ARE the cost and batching them into a + * grouped query is worth building; one that does not means the cost is the `appleDaily` read or the fit, + * and batching would have bought nothing. Measured, not guessed. + * + * Counted in the repository rather than at the call site for a mechanical reason: `analyzeRecentOnCpu` sits + * 210 bytes under the JaCoCo method-size ratchet [IntelligenceEngineJacocoBudgetTest] holds, and the steps + * loop is inside it. Timing there would cost more than the margin, and the ratchet's own note says to + * extract rather than raise it. Counting one level down costs the budgeted method nothing at all, and the + * reset and the emit both live in the unbudgeted `analyzeRecent` wrapper. + * + * Instrumentation only: nothing reads these counts but the log line. + */ +object StoreProbeTally { + private val ownerHrCalls = AtomicLong() + private val ownerHrNanos = AtomicLong() + private val gravityFpCalls = AtomicLong() + private val gravityFpNanos = AtomicLong() + + /** Record one day-owner HR presence probe. Called from the repository, off the pass's hot method. */ + fun recordOwnerHr(nanos: Long) { + ownerHrCalls.incrementAndGet() + ownerHrNanos.addAndGet(nanos) + } + + /** Record one per-day gravity witness read. */ + fun recordGravityFp(nanos: Long) { + gravityFpCalls.incrementAndGet() + gravityFpNanos.addAndGet(nanos) + } + + /** Zero the counters at the start of a pass, so a line describes ONE pass and never accumulates across + * the back-to-back passes an offload storm is made of. */ + fun reset() { + ownerHrCalls.set(0); ownerHrNanos.set(0) + gravityFpCalls.set(0); gravityFpNanos.set(0) + } + + /** This pass's line, in the shared format. */ + fun line(): String = logLine( + listOf( + Triple("ownerHr", ownerHrCalls.get(), ownerHrNanos.get() / 1_000_000_000.0), + Triple("gravityFp", gravityFpCalls.get(), gravityFpNanos.get() / 1_000_000_000.0), + ) + ) + + /** + * Render ordered `(name, calls, seconds)` probes as one line. + * + * [calls] is printed beside the time because the two answer different questions: the time says whether + * this is where the pass went, and the count says whether the loop issued the number of round trips it + * was believed to (sixty per steps pass, one per day). A count that is right with a time that is large + * is a slow query; a count that is wrong is a different bug entirely, and one line should not be able + * to hide either. Byte-identical to the Swift `StoreProbeTally.logLine`. + */ + fun logLine(probes: List>): String { + val parts = probes.map { "${it.first}=${it.second}/${millis(it.third)}ms" } + val total = probes.sumOf { it.third } + return "analyzeRecent storeProbes total=${millis(total)}ms " + + if (parts.isEmpty()) "(no probes)" else parts.joinToString(" ") + } + + /** Seconds to whole milliseconds, floored at zero. The clamp is the parity contract, not defensive + * habit: a negative or non-finite input is where Swift's round-half-away-from-zero and Kotlin's + * round-half-up disagree, at exactly -0.5 ms, and both sides render into one shared strap log. The + * callers here cannot produce one (they count monotonic nanoseconds), which makes this a guarantee + * about the renderer rather than a repair of its inputs. */ + private fun millis(seconds: Double): Long = + if (!seconds.isFinite() || seconds <= 0.0) 0L else (seconds * 1000).roundToLong() +} diff --git a/android/app/src/main/java/com/noop/data/WhoopRepository.kt b/android/app/src/main/java/com/noop/data/WhoopRepository.kt index 23b04162bd..45ba7dde51 100644 --- a/android/app/src/main/java/com/noop/data/WhoopRepository.kt +++ b/android/app/src/main/java/com/noop/data/WhoopRepository.kt @@ -705,14 +705,26 @@ class WhoopRepository( /** Whether [deviceId] has ANY heart-rate row in the window, as a scalar EXISTS rather than a fetched * row. The day-owner resolver's per-candidate-per-day probe; see [WhoopDao.hasHrInWindow]. */ - suspend fun hasHrInWindow(deviceId: String, from: Long, to: Long): Boolean = - dao.hasHrInWindow(deviceId, from, to) + suspend fun hasHrInWindow(deviceId: String, from: Long, to: Long): Boolean { + // Timed HERE rather than at the call site: the steps loop that drives most of these sits inside + // `analyzeRecentOnCpu`, which has 210 bytes of JaCoCo ratchet margin and no room for a stopwatch. + // See StoreProbeTally. Instrumentation only. + val started = System.nanoTime() + val present = dao.hasHrInWindow(deviceId, from, to) + com.noop.analytics.StoreProbeTally.recordOwnerHr(System.nanoTime() - started) + return present + } /** Per-day (device + window) gravity fingerprint as (count, newestTs) for the steps-calibration * motion cache. Narrower than [dayStreamFingerprint] on purpose: dayMotionIntensity folds gravity * alone, so a new HR row must not invalidate it. Mirrors Swift WhoopStore.gravityFingerprint. */ - suspend fun gravityFingerprintWindow(deviceId: String, from: Long, to: Long): Pair = - dao.gravityWitnessInWindow(deviceId, from, to).let { it.c to it.m } + suspend fun gravityFingerprintWindow(deviceId: String, from: Long, to: Long): Pair { + // Timed here for the same budget reason as [hasHrInWindow]; see StoreProbeTally. + val started = System.nanoTime() + val witness = dao.gravityWitnessInWindow(deviceId, from, to) + com.noop.analytics.StoreProbeTally.recordGravityFp(System.nanoTime() - started) + return witness.c to witness.m + } /** #29 — the same per-day (device + window) witness for every OTHER stream analyzeDay scores: PPG-derived * HR, R-R, respiration, SpO2, gravity, steps, skin temp and events. [hrFingerprintWindow] cannot see a diff --git a/android/app/src/test/java/com/noop/analytics/StoreProbeTallyTest.kt b/android/app/src/test/java/com/noop/analytics/StoreProbeTallyTest.kt new file mode 100644 index 0000000000..fcdfc3966f --- /dev/null +++ b/android/app/src/test/java/com/noop/analytics/StoreProbeTallyTest.kt @@ -0,0 +1,91 @@ +package com.noop.analytics + +import org.junit.Assert.assertEquals +import org.junit.Test + +/** + * The per-day probe readout. Twin of the Swift `StoreProbeTallyTests`, pinned against the SAME literals: + * the line is read off one shared strap log, so a one-sided change to the format would make two platforms' + * logs incomparable exactly when they are being compared. + */ +class StoreProbeTallyTest { + + /** + * A warm two-strap pass: the scoring loop's 21 owner probes plus the steps loop's 60, and one gravity + * witness per steps day. This is the shape the line exists to make readable. + */ + @Test + fun rendersCallsAndMillisInOrder() { + val line = StoreProbeTally.logLine( + listOf(Triple("ownerHr", 81L, 1.24), Triple("gravityFp", 60L, 1.89)), + ) + assertEquals("analyzeRecent storeProbes total=3130ms ownerHr=81/1240ms gravityFp=60/1890ms", line) + } + + /** + * A default SINGLE-strap install skips the owner probe entirely (#970), so zero calls must render as + * zero rather than being omitted: "not measured" and "measured, and it was free" are different + * findings, and only one of them means the batching idea is pointless for that user. + */ + @Test + fun zeroCallsStillRender() { + val line = StoreProbeTally.logLine( + listOf(Triple("ownerHr", 0L, 0.0), Triple("gravityFp", 60L, 1.89)), + ) + assertEquals("analyzeRecent storeProbes total=1890ms ownerHr=0/0ms gravityFp=60/1890ms", line) + } + + @Test + fun noProbesSaysSoRatherThanRenderingAnEmptyTail() { + assertEquals("analyzeRecent storeProbes total=0ms (no probes)", StoreProbeTally.logLine(emptyList())) + } + + /** + * The renderer clamps, and that is a contract about the RENDERER rather than a claim about the probes: + * both sides now count monotonic nanoseconds, so neither can hand it a negative. It is pinned anyway + * because a negative or non-finite seconds value is the one input where Swift's round-half-away-from- + * zero and Kotlin's round-half-up disagree, at exactly -0.5 ms, and the two platforms render into one + * shared strap log. A probe cannot take less than no time, so nothing true is lost by flooring it. + */ + @Test + fun negativeAndNonFiniteSecondsClampToZeroOnBothSides() { + val line = StoreProbeTally.logLine( + listOf(Triple("ownerHr", 3L, -0.0005), Triple("gravityFp", 1L, Double.NaN)), + ) + assertEquals("analyzeRecent storeProbes total=0ms ownerHr=3/0ms gravityFp=1/0ms", line) + } + + /** + * Sixty calls of exactly 20 ms. The counters accumulate INTEGER nanos and divide once, so this is + * exactly 1.2 s and renders 1200ms. Converting each call to seconds and summing those would spend + * sixty roundings and land a hair either side. The Swift twin + * `StoreProbeCountsTests.testAccumulatesIntegerNanosRatherThanSummingDoubles` pins the same literal, + * because both platforms render into ONE shared strap log and a divergence there reads as two devices + * behaving differently rather than as an arithmetic difference. + */ + @Test + fun recordAccumulatesIntegerNanosLikeTheSwiftTwin() { + StoreProbeTally.reset() + repeat(60) { StoreProbeTally.recordGravityFp(20_000_000L) } + assertEquals( + "analyzeRecent storeProbes total=1200ms ownerHr=0/0ms gravityFp=60/1200ms", + StoreProbeTally.line(), + ) + } + + /** + * [StoreProbeTally.reset] DRAINS. A line has to describe one pass, and the passes this runs under are + * the back-to-back ones an offload storm is made of, so counters left standing would make every pass + * after the first report its predecessors' work as its own. + */ + @Test + fun resetDrainsSoAPassCannotInheritTheLastOne() { + StoreProbeTally.reset() + StoreProbeTally.recordOwnerHr(5_000_000L) + StoreProbeTally.reset() + assertEquals( + "analyzeRecent storeProbes total=0ms ownerHr=0/0ms gravityFp=0/0ms", + StoreProbeTally.line(), + ) + } +}