fix: a batch the user themselves cancelled is not called a lapse
Picking "Alap" revokes the consent, and a batch still in flight is then answered by the server with the same 409 a real expiry gets. The 409 arm only checked that the consent session had not changed, not that this tab was still streaming — so the user's own log gained a "diagnostics level lapsed" line for a level they had just turned off themselves, plus a pointless `me` refetch. The same guard also stops a lapse this tab has already announced being announced a second time. Measured in Chrome by holding the POST at the network layer, switching to Alap and only then answering 409: the line appears without the guard and not with it. Three tests that named the session counter never reached it — they settled the refusal while the stream was already stopped, where `unsubscribe` does the work, so the counter could be deleted from both arms with the suite green. The refusal now settles after the re-raise, which is the ordering it exists for. Same for the queue trim on the 429 path: the old test unshifted a batch into an empty queue, so the trim was a no-op and only the subscribe path was ever measured.
This commit is contained in:
@@ -190,6 +190,87 @@ describe("diagnostics level", () => {
|
||||
expect(later).toContain("diagnostics level raised");
|
||||
});
|
||||
|
||||
it("a batch refused after a re-raise is still not sent: it was taken under the old consent", async () => {
|
||||
// The test above settles the refusal while the stream is STOPPED, so `unsubscribe` is what
|
||||
// blocks the requeue there. Here it settles after the new consent is already streaming — the
|
||||
// ordering only the `session` counter can catch, and the one that would leak events across a
|
||||
// withdrawal if it did not.
|
||||
const d = await fresh();
|
||||
let refuse: (err: unknown) => void = () => {};
|
||||
answer = () => new Promise((_, reject) => (refuse = reject));
|
||||
d.applyDiagnostics(raised("DEBUG"), () => {});
|
||||
d.log.debug("ui.click", "under the first consent");
|
||||
await vi.advanceTimersByTimeAsync(5_000); // in flight
|
||||
d.applyDiagnostics({ level: "INFO", until: null, retention_days: 7 }, () => {});
|
||||
answer = () => Promise.resolve({ ok: true, stored: 0 });
|
||||
d.applyDiagnostics(raised("TRACE"), () => {});
|
||||
refuse(new d.HttpError(429, "slow down")); // only now does the old consent's batch come back
|
||||
await vi.advanceTimersByTimeAsync(60_000);
|
||||
const later = sent
|
||||
.slice(1)
|
||||
.flat()
|
||||
.map((e) => (e as { msg: string }).msg);
|
||||
expect(later).not.toContain("under the first consent");
|
||||
expect(later).toContain("diagnostics level raised");
|
||||
});
|
||||
|
||||
it("a 409 for a batch taken under the old consent does not lapse the new one", async () => {
|
||||
const d = await fresh();
|
||||
const lapsed = vi.fn();
|
||||
let refuse: (err: unknown) => void = () => {};
|
||||
answer = () => new Promise((_, reject) => (refuse = reject));
|
||||
d.applyDiagnostics(raised("DEBUG"), lapsed);
|
||||
d.log.debug("ui.click", "under the first consent");
|
||||
await vi.advanceTimersByTimeAsync(5_000); // in flight
|
||||
d.applyDiagnostics({ level: "INFO", until: null, retention_days: 7 }, lapsed);
|
||||
answer = () => Promise.resolve({ ok: true, stored: 0 });
|
||||
d.applyDiagnostics(raised("TRACE"), lapsed);
|
||||
refuse(new d.HttpError(409, "off"));
|
||||
await vi.advanceTimersByTimeAsync(60_000);
|
||||
expect(lapsed).not.toHaveBeenCalled();
|
||||
expect(d.enabled("TRACE")).toBe(true);
|
||||
});
|
||||
|
||||
it("a 409 answering a batch the user themselves cancelled is not called a lapse", async () => {
|
||||
// "Alap" is the user revoking their own consent; the server answers the still-flying batch with
|
||||
// the same 409 a real expiry gets. Their own log must not tell them the consent ran out.
|
||||
const d = await fresh();
|
||||
const lapsed = vi.fn();
|
||||
let refuse: (err: unknown) => void = () => {};
|
||||
answer = () => new Promise((_, reject) => (refuse = reject));
|
||||
d.applyDiagnostics(raised("DEBUG"), lapsed);
|
||||
d.log.debug("ui.click", "under the consent");
|
||||
await vi.advanceTimersByTimeAsync(5_000); // in flight
|
||||
d.applyDiagnostics({ level: "INFO", until: null, retention_days: 7 }, lapsed);
|
||||
refuse(new d.HttpError(409, "off"));
|
||||
await vi.advanceTimersByTimeAsync(0);
|
||||
expect(lapsed).not.toHaveBeenCalled();
|
||||
expect(d.events().map((e) => e.msg)).not.toContain("diagnostics level lapsed");
|
||||
});
|
||||
|
||||
it("a refused batch that comes back to a full queue is what goes, not the events since", async () => {
|
||||
// The cap test above fills the queue AFTER the refusal landed, so the trim it measures is the
|
||||
// one on the subscribe path. This one has the queue already at the cap when the batch comes
|
||||
// back — the only state where the trim in the 429 handler decides anything.
|
||||
const d = await fresh();
|
||||
let refuse: (err: unknown) => void = () => {};
|
||||
answer = () => new Promise((_, reject) => (refuse = reject));
|
||||
d.applyDiagnostics(raised("DEBUG"), () => {});
|
||||
for (let i = 0; i < 99; i++) d.log.debug("ui.click", `old ${i}`);
|
||||
await vi.advanceTimersByTimeAsync(0); // the 100 oldest are in flight, the queue is empty
|
||||
for (let i = 0; i < 1_000; i++) d.log.debug("ui.click", `new ${i}`);
|
||||
answer = () => Promise.resolve({ ok: true, stored: 0 });
|
||||
refuse(new d.HttpError(429, "slow down")); // 1_000 + 100 back = 1_100, over the cap
|
||||
await vi.advanceTimersByTimeAsync(60_000);
|
||||
const msgs = sent
|
||||
.slice(1)
|
||||
.flat()
|
||||
.map((e) => (e as { msg: string }).msg);
|
||||
expect(msgs).toHaveLength(1_000);
|
||||
expect(msgs).not.toContain("old 0");
|
||||
expect([msgs[0], msgs[msgs.length - 1]]).toEqual(["new 0", "new 999"]);
|
||||
});
|
||||
|
||||
it("a closing tab sends what is still waiting with a keepalive request", async () => {
|
||||
const d = await fresh();
|
||||
d.applyDiagnostics(raised("DEBUG"), () => {});
|
||||
|
||||
@@ -128,8 +128,17 @@ async function flush(): Promise<void> {
|
||||
queue.unshift(...batch);
|
||||
keepNewest();
|
||||
}
|
||||
} else if (err instanceof HttpError && err.status === 409 && takenIn === session) {
|
||||
lapse(); // the server has it off: withdrawn in another tab, or lapsed by its clock
|
||||
} else if (
|
||||
err instanceof HttpError &&
|
||||
err.status === 409 &&
|
||||
takenIn === session &&
|
||||
unsubscribe
|
||||
) {
|
||||
// The server has it off: withdrawn in another tab, or lapsed by its clock. `unsubscribe`
|
||||
// means THIS tab does not already know — without it, the 409 answering a batch that was in
|
||||
// flight when the user picked Alap writes "lapsed" into their own log for a level they
|
||||
// revoked, and a lapse this tab has already announced gets announced a second time.
|
||||
lapse();
|
||||
}
|
||||
} finally {
|
||||
inFlight = false;
|
||||
|
||||
Reference in New Issue
Block a user