diff --git a/Sources/CodexBarCore/BarTelemetry.swift b/Sources/CodexBarCore/BarTelemetry.swift index 4fc3f9f..7e3cb47 100644 --- a/Sources/CodexBarCore/BarTelemetry.swift +++ b/Sources/CodexBarCore/BarTelemetry.swift @@ -71,7 +71,7 @@ enum BarEvents { /// Events for every Limit that appeared, reset, or disappeared since `previous`. /// `previous == nil` means nothing has been seen since tracking started, so every Limit appears. - static func limitEvents(previous: [String: ObservedLimit]?, current: [BarLimit]) -> [OTLPTelemetryEncoder.Event] { + static func limitEvents(previous: [String: ObservedLimit]?, current: [BarLimit], now: Date) -> [OTLPTelemetryEncoder.Event] { let previous = previous ?? [:] var events: [OTLPTelemetryEncoder.Event] = [] for limit in current { @@ -79,7 +79,7 @@ enum BarEvents { events.append(.init(name: "bar.limit.appeared", attributes: limit.attributes)) continue } - if didReset(from: before, to: limit) { + if didReset(from: before, to: limit, now: now) { var attributes = limit.attributes + [.init("limit.utilization.last", before.utilization)] if let next = limit.resetsAt { attributes.append(.init("limit.resets_at.next", Int(next))) } events.append(.init(name: "bar.limit.reset", attributes: attributes)) @@ -94,14 +94,44 @@ enum BarEvents { return events } - /// A rolled-over window ends roughly a whole window later than the old one did. Half a - /// window is far beyond the few seconds Codex's reset time drifts between reads. - static func didReset(from before: ObservedLimit, to limit: BarLimit) -> Bool { - if let old = before.resetsAt, let new = limit.resetsAt { - let threshold = limit.windowMinutes.map { Double($0) * 30 } ?? 3_600 - return new - old >= threshold + /// More than Codex's reset time drifts between reads, and more than a Window that hasn't + /// started yet creeps forward per poll (its reset time is always a full Window from now). + static let resetJumpTolerance: TimeInterval = 3_600 + + /// A Window that runs to its end comes back ending roughly a whole Window later, so a + /// jump of half a Window is a reset. Codex also resets a Window early, days before its + /// end, and then the reset time only moves by what was left. Any jump past the drift + /// tolerance counts as well when usage dropped or a full fresh Window now lies ahead. + static func didReset(from before: ObservedLimit, to limit: BarLimit, now: Date) -> Bool { + guard let old = before.resetsAt, let new = limit.resetsAt else { + return usageDidReset(from: before.utilization, to: limit.utilization) + } + let jump = new - old + // A Window not started yet floats a full Window ahead of every poll, so after a long + // gap its reset time jumps as far as a real rollover. With no usage either side there + // is nothing to tell them apart, and an unused Window resetting loses nothing. + if before.utilization == 0 && limit.utilization == 0 { + return false + } + if let minutes = limit.windowMinutes, jump >= Double(minutes) * 30 { + return true + } + if limit.windowMinutes == nil, jump >= resetJumpTolerance { + return true + } + guard jump > resetJumpTolerance else { + return false + } + if usageDidReset(from: before.utilization, to: limit.utilization) { + return true + } + // A full Window ahead alone could still be a floating Window; usage going down is + // what tells a real reset apart. + guard let minutes = limit.windowMinutes, limit.utilization < before.utilization else { + return false } - return usageDidReset(from: before.utilization, to: limit.utilization) + let window = Double(minutes) * 60 + return abs(new - now.timeIntervalSince1970 - window) <= resetJumpTolerance } static func perkAttributes(id: String?, expiresAt: TimeInterval?, quantity: Int? = nil) -> [OTLPTelemetryEncoder.Attribute] { diff --git a/Sources/CodexBarCore/TelemetryRecorder.swift b/Sources/CodexBarCore/TelemetryRecorder.swift index 416c628..8e9df8b 100644 --- a/Sources/CodexBarCore/TelemetryRecorder.swift +++ b/Sources/CodexBarCore/TelemetryRecorder.swift @@ -5,6 +5,10 @@ struct TelemetryState: Codable, Sendable, Equatable { var scan: SessionScanState? /// `nil` until the first successful usage read since tracking started. var limits: [String: ObservedLimit]? + /// The account (or plan) `limits` were observed on. Limit IDs only name the bucket and + /// Window, so another account's Limits must not be diffed against these. Nil for state + /// saved before this was recorded, which then belongs to whichever account is current. + var limitsScope: String? var perks: ObservedPerks? /// `false` from a new baseline until `bar.tracking.started` is written. The baseline is /// kept meanwhile, so a failed write delays the event without losing tokens. @@ -87,10 +91,20 @@ public actor TelemetryRecorder { if progress != loadState() { try save(progress) } var limits = current.limits + var limitsScope = current.limitsScope if let result { let barLimits = BarLimit.limits(from: result) - events += BarEvents.limitEvents(previous: current.limits, current: barLimits) - limits = BarEvents.observed(barLimits) + let resultScope = result.accountId ?? planType + let switchedAccount = resultScope != nil && current.limitsScope != nil && resultScope != current.limitsScope + if switchedAccount { + // Another account's Windows aren't a continuation of these: start a new + // baseline instead of reading the difference as resets. + limits = BarEvents.observed(barLimits) + } else { + events += BarEvents.limitEvents(previous: current.limits, current: barLimits, now: date) + limits = BarEvents.observed(barLimits) + } + limitsScope = resultScope ?? current.limitsScope } let scope = result?.accountId ?? planType ?? dailyAccountScope @@ -116,6 +130,7 @@ public actor TelemetryRecorder { // means a failed write re-emits them on the next capture instead of losing them. var saved = loadState() saved.limits = limits + saved.limitsScope = limitsScope if saved.startAnnounced == false { saved.startAnnounced = true } try save(saved) for bucket in changedBuckets ?? [] { dailyBuckets[bucket.startDate] = bucket.tokens } diff --git a/Tests/CodexBarCoreTests/BarTelemetryTests.swift b/Tests/CodexBarCoreTests/BarTelemetryTests.swift index 69666eb..25891f4 100644 --- a/Tests/CodexBarCoreTests/BarTelemetryTests.swift +++ b/Tests/CodexBarCoreTests/BarTelemetryTests.swift @@ -96,6 +96,20 @@ final class BarTelemetryTests: XCTestCase { XCTAssertEqual(try eventNames([lines[1]]).filter { $0 == "bar.limit.appeared" }.count, 2) } + func testSwitchingAccountsStartsANewLimitBaselineInsteadOfLoggingAReset() async throws { + // Account b has less usage and a reset time two days later than account a's: compared + // against a's observation, that reads as an early reset, though nothing reset. + let sink = RecordingSink() + let start = Date(timeIntervalSince1970: 1_792_000_000) + let recorder = recorder(sink) + try await recorder.recordSample(result: try weekly(40, resetsAt: 1_792_000_000 + 3 * 86_400), planType: nil, observedAt: start, at: start) + let otherAccount = try result(#"{"accountId":"b","rateLimitsByLimitId":{"codex":{"secondary":{"usedPercent":0,"windowDurationMins":10080,"resetsAt":\#(1_792_000_000 + 7 * 86_400)}}}}"#) + try await recorder.recordSample(result: otherAccount, planType: nil, observedAt: start, at: start) + + let names = try eventNames(await sink.lines).filter { $0.hasPrefix("bar.limit.") } + XCTAssertEqual(names, ["bar.limit.appeared"]) + } + func testLimitResetAndDisappearanceEventsSurviveARelaunch() async throws { let sink = RecordingSink() let start = Date(timeIntervalSince1970: 1_799_000_000) diff --git a/Tests/CodexBarCoreTests/LimitResetDetectionTests.swift b/Tests/CodexBarCoreTests/LimitResetDetectionTests.swift new file mode 100644 index 0000000..21e0f9a --- /dev/null +++ b/Tests/CodexBarCoreTests/LimitResetDetectionTests.swift @@ -0,0 +1,104 @@ +import Foundation +import XCTest +@testable import CodexBarCore + +/// Window rollovers taken from real CodexBar telemetry: Codex reset the Weekly Window early, +/// days before its reset time, so the reset time jumped about two days, not a whole Window. +final class LimitResetDetectionTests: XCTestCase { + private func observed(_ utilization: Double, resetsAt: TimeInterval?) -> ObservedLimit { + ObservedLimit(name: "Weekly", windowMinutes: 10_080, utilization: utilization, resetsAt: resetsAt) + } + + private func limit(_ utilization: Double, resetsAt: TimeInterval?) -> BarLimit { + BarLimit(id: "codex:10080", name: "Weekly", windowMinutes: 10_080, utilization: utilization, resetsAt: resetsAt) + } + + private func at(_ seconds: TimeInterval) -> Date { Date(timeIntervalSince1970: seconds) } + + func testEarlyWeeklyResetsFromRealTelemetryCount() { + // (sample time, old reset time, old usage, new reset time, new usage) for 13, 15 and 18 Oct. + let rollovers: [(TimeInterval, TimeInterval, Double, TimeInterval, Double)] = [ + (1_791_867_609, 1_792_310_768, 6, 1_792_472_409, 0), + (1_792_044_791, 1_792_475_653, 5, 1_792_649_591, 0), + (1_792_269_763, 1_792_652_811, 6, 1_792_874_563, 0) + ] + for (time, oldReset, oldUsage, newReset, newUsage) in rollovers { + XCTAssertTrue( + BarEvents.didReset(from: observed(oldUsage, resetsAt: oldReset), to: limit(newUsage, resetsAt: newReset), now: at(time)), + "rollover at \(time)" + ) + } + } + + func testAnEarlyResetWithUsageAlreadyBackCountsWhenAFullWindowStarts() { + // Usage went from 6% to 1% (a request landed straight after the reset), too small a + // drop for the usage check on its own, but a full fresh Window lies ahead. + // The old Window had five days left, so the two-day jump stays under half a Window + // and only the full-Window check can catch it. + let now: TimeInterval = 1_792_000_000 + XCTAssertTrue(BarEvents.didReset( + from: observed(6, resetsAt: now + 5 * 86_400), + to: limit(1, resetsAt: now + 7 * 86_400), + now: at(now) + )) + } + + func testASmallUsageDipWithoutAFullWindowAheadIsNotAReset() { + // The same two-day jump and 6% to 1% dip, but the new reset time is only three days + // out, so no fresh Window started. + let now: TimeInterval = 1_792_000_000 + XCTAssertFalse(BarEvents.didReset( + from: observed(6, resetsAt: now + 1 * 86_400), + to: limit(1, resetsAt: now + 3 * 86_400), + now: at(now) + )) + } + + func testAWindowNotStartedYetSeenAcrossAPollGapIsNotAReset() { + // Two hours asleep: the not-yet-started Window's reset time moved two hours, past the + // tolerance, and still reads as a full Window ahead, but usage stayed at zero. + let now: TimeInterval = 1_792_000_000 + XCTAssertFalse(BarEvents.didReset( + from: observed(0, resetsAt: now - 7_200 + 604_800), + to: limit(0, resetsAt: now + 604_800), + now: at(now) + )) + } + + func testAFewMinutesOfDriftIsNotAReset() { + let now: TimeInterval = 1_792_000_000 + XCTAssertFalse(BarEvents.didReset(from: observed(6, resetsAt: now + 86_400), to: limit(6, resetsAt: now + 86_400 + 300), now: at(now))) + } + + func testAWindowThatHasNotStartedIsNotAResetEachPoll() { + // Before the first request in a Window, Codex reports the reset a full Window from now, + // so it creeps forward with every poll while usage stays at zero. + let now: TimeInterval = 1_792_000_000 + XCTAssertFalse(BarEvents.didReset( + from: observed(0, resetsAt: now - 600 + 604_800), + to: limit(0, resetsAt: now + 604_800), + now: at(now) + )) + } + + func testAnUnusedWindowNotStartedYetAcrossALongGapIsNotAReset() { + // Four days without a poll: the floating reset time jumped more than half a Window, + // but usage stayed at zero, so nothing reset. + let now: TimeInterval = 1_792_000_000 + XCTAssertFalse(BarEvents.didReset( + from: observed(0, resetsAt: now - 4 * 86_400 + 604_800), + to: limit(0, resetsAt: now + 604_800), + now: at(now) + )) + } + + func testAUsageDropWithoutTheResetTimeMovingIsNotAReset() { + let now: TimeInterval = 1_792_000_000 + XCTAssertFalse(BarEvents.didReset(from: observed(40, resetsAt: now + 86_400), to: limit(0, resetsAt: now + 86_400), now: at(now))) + } + + func testAWindowRunningToItsEndStillCounts() { + let now: TimeInterval = 1_800_000_000 + XCTAssertTrue(BarEvents.didReset(from: observed(81, resetsAt: 1_800_000_004), to: limit(2, resetsAt: 1_800_604_800), now: at(now))) + } +} diff --git a/docs/telemetry.md b/docs/telemetry.md index 88ef359..9e47132 100644 --- a/docs/telemetry.md +++ b/docs/telemetry.md @@ -28,7 +28,15 @@ Every window in every bucket that `account/rateLimits/read` reports becomes a Li - `limit.name` is the name the menu shows (`Weekly`, `Session (5h)`). Buckets other than the default `codex` one get the bucket's name added, as in `Weekly ยท Gpt Spark`. - Don't count on a five-hour window. Some plans report only the weekly one. -`bar.limit.reset` fires when a Limit's reset time moves forward by at least half a window. When Codex gives no reset time, it fires when usage drops sharply instead (the same rule the celebrations use). +`bar.limit.reset` fires when a Limit's Window rolls over: + +- **A Window that ran to its end:** the reset time moves forward by at least half a Window. +- **An early reset:** Codex can reset a Window days before its reset time, and then the reset time only moves by what was left. A move of more than an hour also counts when usage drops sharply (the same rule the celebrations use), or when usage goes down and the new reset time is a full Window away. +- **Never when usage is 0% both before and after.** A Window nobody has used yet floats a full Window ahead of each read, so after a long gap it can look like a rollover. +- **When Codex gives no Window length:** any move of the reset time by an hour or more counts. +- **When Codex gives no reset time:** it fires when usage drops sharply. + +Switching Codex accounts starts a new baseline instead of firing, because another account's Window isn't a continuation of the last one. The baseline belongs to the account ID, or to the plan when Codex reports no account ID, so a plan change then starts a new baseline too. ### Tokens