Skip to content

Commit 1d64565

Browse files
JohnMcLearclaude
andcommitted
test(SessionStore): drive expiry timers with a fake clock
The SessionStore spec scheduled sessions to expire a few hundred ms in the future and then slept on the real clock. Under CPU load the DB round trips between "set" and the cleanup/cancel step could take longer than the expiry window, so the store's own expiry timer fired mid-setup and purged the record (e.g. "shutdown cancels timeouts" and "destroy cancels the timeout" failing with the record missing). Reproduced 4/20 runs with the CPU oversubscribed. Give SessionStore a `_timers` seam (defaults to globalThis) for the Date/setTimeout/clearTimeout used by its expiration timers, and have the spec install a sinon fake clock on it. The DB keeps real timers, so time only moves when a test advances it, and the spec awaits the DB reads started by any timer that fired. The "timer must not fire" tests now also assert the timer callback never ran, and the expiry tests check the record survives until the exact expiry instant. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01V4cYEvi9Y4BTPntnkV9tzh
1 parent a185a9d commit 1d64565

2 files changed

Lines changed: 91 additions & 53 deletions

File tree

‎src/node/db/SessionStore.ts‎

Lines changed: 12 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -48,6 +48,10 @@ class SessionStore extends expressSession.Store {
4848
this._expirations = new Map();
4949
this._cleanupTimer = null;
5050
this._cleanupRunning = false;
51+
// Source of `Date`, `setTimeout` and `clearTimeout` for the session expiration timers. Only
52+
// replaced by tests, which swap in a fake clock so expiry can be checked without depending on
53+
// wall-clock timing.
54+
this._timers = globalThis;
5155
}
5256

5357
/**
@@ -73,7 +77,7 @@ class SessionStore extends expressSession.Store {
7377
}
7478

7579
shutdown() {
76-
for (const {timeout} of this._expirations.values()) clearTimeout(timeout);
80+
for (const {timeout} of this._expirations.values()) this._timers.clearTimeout(timeout);
7781
if (this._cleanupTimer) {
7882
clearTimeout(this._cleanupTimer);
7983
this._cleanupTimer = null;
@@ -157,14 +161,14 @@ class SessionStore extends expressSession.Store {
157161

158162
async _updateExpirations(sid: string, sess: any, updateDbExp = true) {
159163
const exp = this._expirations.get(sid) || {};
160-
clearTimeout(exp.timeout);
164+
this._timers.clearTimeout(exp.timeout);
161165
// @ts-ignore
162166
const {cookie: {expires} = {}} = sess || {};
163167
if (expires) {
164168
const sessExp = new Date(expires).getTime();
165169
if (updateDbExp) exp.db = sessExp;
166170
exp.real = Math.max(exp.real || 0, exp.db || 0, sessExp);
167-
const now = Date.now();
171+
const now = this._timers.Date.now();
168172
if (exp.real <= now) return await this._destroy(sid);
169173
// If reading from the database, update the expiration with the latest value from touch() so
170174
// that touch() appears to write to the database every time even though it doesn't.
@@ -173,11 +177,12 @@ class SessionStore extends expressSession.Store {
173177
// the in-memory expiry first — touch() may have extended it without rescheduling the timeout
174178
// (e.g., if touch's clearTimeout raced with the timer on a slow system). If the session was
175179
// extended, reschedule instead of reading from the DB which may return stale cached data.
176-
exp.timeout = setTimeout(() => {
180+
exp.timeout = this._timers.setTimeout(() => {
177181
const currentExp = this._expirations.get(sid);
178-
if (currentExp && currentExp.real > Date.now()) {
182+
if (currentExp && currentExp.real > this._timers.Date.now()) {
179183
// Expiry was extended (e.g., by touch). Reschedule.
180-
currentExp.timeout = setTimeout(() => this._get(sid), currentExp.real - Date.now());
184+
currentExp.timeout = this._timers.setTimeout(
185+
() => this._get(sid), currentExp.real - this._timers.Date.now());
181186
return;
182187
}
183188
// Use this._get(), not this._destroy(), to query the DB for the latest expiration in case
@@ -210,7 +215,7 @@ class SessionStore extends expressSession.Store {
210215

211216
async _destroy(sid:string) {
212217
logger.debug(`DESTROY ${sid}`);
213-
clearTimeout((this._expirations.get(sid) || {}).timeout);
218+
this._timers.clearTimeout((this._expirations.get(sid) || {}).timeout);
214219
this._expirations.delete(sid);
215220
await DB.remove(`sessionstorage:${sid}`);
216221
}

‎src/tests/backend/specs/SessionStore.ts‎

Lines changed: 79 additions & 46 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ import {strict as assert} from 'assert';
55
const common = require('../common');
66
const db = require('../../../node/db/DB');
77
import util from 'util';
8+
import sinon from 'sinon';
89

910
type Session = {
1011
set: (sid: string|null,sess:any, sess2:any) => void;
@@ -15,36 +16,55 @@ type Session = {
1516
startCleanup: () => void;
1617
_cleanup: () => Promise<void>;
1718
_cleanupTimer: any;
19+
_timers: any;
20+
_get: (sid: string) => Promise<any>;
1821
}
1922

2023
describe(__filename, function () {
2124
let ss: Session|null;
2225
let sid: string|null;
26+
// Fake clock driving the store's expiration timers and its notion of "now". The DB keeps using
27+
// real timers, so awaiting DB calls never moves the store's clock: expiry is only reached when a
28+
// test explicitly advances time, no matter how slow the machine is.
29+
let clock: sinon.SinonFakeTimers|null = null;
30+
// Records the DB reads kicked off by the store's expiration timers (the timer callbacks call
31+
// `this._get()`; the public callback API does not go through the instance property).
32+
let timerGets: sinon.SinonSpy;
2333

2434
const set = async (sess: string|null) => await util.promisify(ss!.set).call(ss, sid, sess);
2535
const get = async () => await util.promisify(ss!.get).call(ss, sid);
2636
const destroy = async () => await util.promisify(ss!.destroy).call(ss, sid);
2737
const touch = async (sess: Session) => await util.promisify(ss!.touch).call(ss, sid, sess);
2838

29-
// Poll until `cond` is true. Used in place of fixed sleeps for "the cleanup timer should have
30-
// fired by now" assertions — passes immediately when cleanup completes so tests stay fast,
31-
// but tolerates slow CI runners where the event loop may be delayed by hundreds of ms.
32-
const eventually = async (cond: () => Promise<boolean>, maxMs = 2000, intervalMs = 25) => {
33-
const deadline = Date.now() + maxMs;
34-
// First check is immediate so the helper doesn't add a fixed delay.
35-
while (true) {
36-
if (await cond()) return;
37-
if (Date.now() >= deadline) throw new Error(`condition not met within ${maxMs}ms`);
38-
await new Promise((r) => setTimeout(r, intervalMs));
39-
}
39+
const now = () => clock!.now;
40+
41+
// Replaces `ss` with a new store whose timers run on a fresh fake clock.
42+
const newStore = (refresh?: number) => {
43+
if (ss != null) ss.shutdown();
44+
if (clock != null) clock.uninstall();
45+
ss = new SessionStore(refresh);
46+
const timers = {Date, setTimeout, clearTimeout};
47+
// `global` is supported by sinon (it fakes the given object instead of globalThis) but is
48+
// missing from @types/sinon, hence the cast.
49+
clock = sinon.useFakeTimers(
50+
{global: timers, now: Date.now(), toFake: ['Date', 'setTimeout', 'clearTimeout']} as any);
51+
ss!._timers = timers;
52+
timerGets = sinon.spy(ss!, '_get');
53+
};
54+
55+
// Advances the store's clock, firing any due expiration timers, and waits for the DB work those
56+
// timers started to finish.
57+
const advance = async (ms: number) => {
58+
clock!.tick(ms);
59+
await Promise.all(timerGets.returnValues);
4060
};
4161

4262
before(async function () {
4363
await common.init();
4464
});
4565

4666
beforeEach(async function () {
47-
ss = new SessionStore();
67+
newStore();
4868
sid = common.randomString();
4969
});
5070

@@ -53,6 +73,8 @@ describe(__filename, function () {
5373
if (sid != null) await destroy();
5474
ss.shutdown();
5575
}
76+
if (clock != null) clock.uninstall();
77+
clock = null;
5678
sid = null;
5779
ss = null;
5880
});
@@ -70,11 +92,14 @@ describe(__filename, function () {
7092
});
7193

7294
it('set of session that expires', async function () {
73-
const sess:any = {foo: 'bar', cookie: {expires: new Date(Date.now() + 300)}};
95+
const sess:any = {foo: 'bar', cookie: {expires: new Date(now() + 300)}};
7496
await set(sess);
7597
assert.equal(JSON.stringify(await db.get(`sessionstorage:${sid}`)), JSON.stringify(sess));
7698
// Writing should start a timeout that purges the record once expiry passes.
77-
await eventually(async () => await db.get(`sessionstorage:${sid}`) == null);
99+
await advance(299);
100+
assert.equal(JSON.stringify(await db.get(`sessionstorage:${sid}`)), JSON.stringify(sess));
101+
await advance(1);
102+
assert(await db.get(`sessionstorage:${sid}`) == null);
78103
});
79104

80105
it('set of already expired session', async function () {
@@ -87,17 +112,19 @@ describe(__filename, function () {
87112
it('switch from non-expiring to expiring', async function () {
88113
const sess:any = {foo: 'bar'};
89114
await set(sess);
90-
const sess2:any = {foo: 'bar', cookie: {expires: new Date(Date.now() + 300)}};
115+
const sess2:any = {foo: 'bar', cookie: {expires: new Date(now() + 300)}};
91116
await set(sess2);
92-
await eventually(async () => await db.get(`sessionstorage:${sid}`) == null);
117+
await advance(300);
118+
assert(await db.get(`sessionstorage:${sid}`) == null);
93119
});
94120

95121
it('switch from expiring to non-expiring', async function () {
96-
const sess:any = {foo: 'bar', cookie: {expires: new Date(Date.now() + 300)}};
122+
const sess:any = {foo: 'bar', cookie: {expires: new Date(now() + 300)}};
97123
await set(sess);
98124
const sess2:any = {foo: 'bar'};
99125
await set(sess2);
100-
await new Promise((resolve) => setTimeout(resolve, 330));
126+
await advance(330);
127+
assert(timerGets.notCalled);
101128
assert.equal(JSON.stringify(await db.get(`sessionstorage:${sid}`)), JSON.stringify(sess2));
102129
});
103130
});
@@ -120,11 +147,12 @@ describe(__filename, function () {
120147
});
121148

122149
it('get of record from previous run (not yet expired)', async function () {
123-
const sess = {foo: 'bar', cookie: {expires: new Date(Date.now() + 300)}};
150+
const sess = {foo: 'bar', cookie: {expires: new Date(now() + 300)}};
124151
await db.set(`sessionstorage:${sid}`, sess);
125152
assert.equal(JSON.stringify(await get()), JSON.stringify(sess));
126153
// Reading should start a timeout that purges the record once expiry passes.
127-
await eventually(async () => await db.get(`sessionstorage:${sid}`) == null);
154+
await advance(300);
155+
assert(await db.get(`sessionstorage:${sid}`) == null);
128156
});
129157

130158
it('get of record from previous run (already expired)', async function () {
@@ -135,47 +163,47 @@ describe(__filename, function () {
135163
});
136164

137165
it('external expiration update is picked up', async function () {
138-
const sess:any = {foo: 'bar', cookie: {expires: new Date(Date.now() + 300)}};
166+
const sess:any = {foo: 'bar', cookie: {expires: new Date(now() + 300)}};
139167
await set(sess);
140168
assert.equal(JSON.stringify(await get()), JSON.stringify(sess));
141-
const sess2 = {...sess, cookie: {expires: new Date(Date.now() + 600)}};
169+
const sess2 = {...sess, cookie: {expires: new Date(now() + 600)}};
142170
await db.set(`sessionstorage:${sid}`, sess2);
143171
assert.equal(JSON.stringify(await get()), JSON.stringify(sess2));
144-
await new Promise((resolve) => setTimeout(resolve, 330));
172+
await advance(330);
145173
// The original timeout should not have fired.
174+
assert(timerGets.notCalled);
146175
assert.equal(JSON.stringify(await get()), JSON.stringify(sess2));
147176
});
148177
});
149178

150179
describe('shutdown', function () {
151180
it('shutdown cancels timeouts', async function () {
152-
// expires=500 / wait=700 keeps comfortable headroom on slow CI: setup
153-
// (set+get+shutdown) must finish before the timer would fire (500ms is plenty), and the
154-
// 700ms wait is past the original expiry so a cancelled timer would have fired by then.
155-
const sess:any = {foo: 'bar', cookie: {expires: new Date(Date.now() + 500)}};
181+
const sess:any = {foo: 'bar', cookie: {expires: new Date(now() + 300)}};
156182
await set(sess);
157183
assert.equal(JSON.stringify(await get()), JSON.stringify(sess));
158184
ss!.shutdown();
159-
await new Promise((resolve) => setTimeout(resolve, 700));
185+
await advance(330);
186+
assert(timerGets.notCalled);
160187
// The record should not have been automatically purged.
161188
assert.equal(JSON.stringify(await db.get(`sessionstorage:${sid}`)), JSON.stringify(sess));
162189
});
163190
});
164191

165192
describe('destroy', function () {
166193
it('destroy deletes the database record', async function () {
167-
const sess:any = {cookie: {expires: new Date(Date.now() + 300)}};
194+
const sess:any = {cookie: {expires: new Date(now() + 300)}};
168195
await set(sess);
169196
await destroy();
170197
assert(await db.get(`sessionstorage:${sid}`) == null);
171198
});
172199

173200
it('destroy cancels the timeout', async function () {
174-
const sess:any = {cookie: {expires: new Date(Date.now() + 300)}};
201+
const sess:any = {cookie: {expires: new Date(now() + 300)}};
175202
await set(sess);
176203
await destroy();
177204
await db.set(`sessionstorage:${sid}`, sess);
178-
await new Promise((resolve) => setTimeout(resolve, 330));
205+
await advance(330);
206+
assert(timerGets.notCalled);
179207
assert.equal(JSON.stringify(await db.get(`sessionstorage:${sid}`)), JSON.stringify(sess));
180208
});
181209

@@ -186,13 +214,13 @@ describe(__filename, function () {
186214

187215
describe('touch without refresh', function () {
188216
it('touch before set is equivalent to set if session expires', async function () {
189-
const sess:any = {cookie: {expires: new Date(Date.now() + 1000)}};
217+
const sess:any = {cookie: {expires: new Date(now() + 1000)}};
190218
await touch(sess);
191219
assert.equal(JSON.stringify(await get()), JSON.stringify(sess));
192220
});
193221

194222
it('touch updates observed expiration but not database', async function () {
195-
const start = Date.now();
223+
const start = now();
196224
const sess:any = {cookie: {expires: new Date(start + 200)}};
197225
await set(sess);
198226
const sess2:any = {cookie: {expires: new Date(start + 12000)}};
@@ -204,52 +232,57 @@ describe(__filename, function () {
204232

205233
describe('touch with refresh', function () {
206234
beforeEach(async function () {
207-
ss = new SessionStore(200);
235+
newStore(200);
208236
});
209237

210238
it('touch before set is equivalent to set if session expires', async function () {
211-
const sess:any = {cookie: {expires: new Date(Date.now() + 1000)}};
239+
const sess:any = {cookie: {expires: new Date(now() + 1000)}};
212240
await touch(sess);
213241
assert.equal(JSON.stringify(await get()), JSON.stringify(sess));
214242
});
215243

216244
it('touch before eligible for refresh updates expiration but not DB', async function () {
217-
const now = Date.now();
218-
const sess:any = {foo: 'bar', cookie: {expires: new Date(now + 1000)}};
245+
const start = now();
246+
const sess:any = {foo: 'bar', cookie: {expires: new Date(start + 1000)}};
219247
await set(sess);
220-
const sess2:any = {foo: 'bar', cookie: {expires: new Date(now + 1001)}};
248+
const sess2:any = {foo: 'bar', cookie: {expires: new Date(start + 1001)}};
221249
await touch(sess2);
222250
assert.equal(JSON.stringify(await db.get(`sessionstorage:${sid}`)), JSON.stringify(sess));
223251
assert.equal(JSON.stringify(await get()), JSON.stringify(sess2));
224252
});
225253

226254
it('touch before eligible for refresh updates timeout', async function () {
227-
const start = Date.now();
255+
const start = now();
228256
const sess:any = {foo: 'bar', cookie: {expires: new Date(start + 200)}};
229257
await set(sess);
230-
await new Promise((resolve) => setTimeout(resolve, 100));
258+
await advance(100);
231259
const sess2:any = {foo: 'bar', cookie: {expires: new Date(start + 399)}};
232260
await touch(sess2);
233-
await new Promise((resolve) => setTimeout(resolve, 110));
261+
await advance(110);
262+
// Past the original expiry, but the touch moved the timeout out.
263+
assert(timerGets.notCalled);
234264
assert.equal(JSON.stringify(await db.get(`sessionstorage:${sid}`)), JSON.stringify(sess));
235265
assert.equal(JSON.stringify(await get()), JSON.stringify(sess2));
266+
// The rescheduled timeout purges the record once the touched expiry passes.
267+
await advance(189);
268+
assert(await db.get(`sessionstorage:${sid}`) == null);
236269
});
237270

238271
it('touch after eligible for refresh updates db', async function () {
239-
const start = Date.now();
272+
const start = now();
240273
const sess:any = {foo: 'bar', cookie: {expires: new Date(start + 2000)}};
241274
await set(sess);
242-
await new Promise((resolve) => setTimeout(resolve, 100));
275+
await advance(100);
243276
const sess2:any = {foo: 'bar', cookie: {expires: new Date(start + 4000)}};
244277
await touch(sess2);
245-
await new Promise((resolve) => setTimeout(resolve, 110));
278+
await advance(110);
246279
assert.equal(JSON.stringify(await db.get(`sessionstorage:${sid}`)), JSON.stringify(sess2));
247280
assert.equal(JSON.stringify(await get()), JSON.stringify(sess2));
248281
});
249282

250283
it('refresh=0 updates db every time', async function () {
251-
ss = new SessionStore(0);
252-
const sess:any = {foo: 'bar', cookie: {expires: new Date(Date.now() + 1000)}};
284+
newStore(0);
285+
const sess:any = {foo: 'bar', cookie: {expires: new Date(now() + 1000)}};
253286
await set(sess);
254287
await db.remove(`sessionstorage:${sid}`);
255288
await touch(sess); // No change in expiration time.

0 commit comments

Comments
 (0)