How to cleanly switch to real time and back again to fake time while testing with Sinon?
Given the following UUT.js
, UUT.test.js
and timerUtils.js
, I want to shift from fake time to real time, for example to advance the promise resolution, and then continue test execution in the fake time.
Having promises that are produced in the stubs and resolved in the test, each promise of the promises list is resolved in the fake time, then the clock is ticked at the end of the for loop, but the code pointer does not jump back from the stub to the next line in the UUT, in which Invoked ...
log message is shown, unless either of the following happens:
Questions:
timerUtils
?enableFurtherWait
to run without blocking the promise?// UUT.js
const enableFurtherWait = false;
const callCount = 3;
async function subFunction(index) {
await new Promise((resolve) => setTimeout(resolve, 1000)); // to be stubbed anyway
}
async function mainFunction() {
for (let i = 1; i <= callCount; i++) {
// await subFunction(i); // this won't work!
console.log(`UUT: Invoking subfunction ${i} at ${new Date().toISOString()}`);
await UUT.subFunction(i);
console.log(`UUT: Invoked subfunction ${i} at ${new Date().toISOString()}`);
}
if (enableFurtherWait) {
console.log(`UUT: Waiting a couple of seconds after subfunctions at ${new Date().toISOString()}`);
await new Promise((resolve) => { console.log("Promise started"); setTimeout(resolve, 2000);}); // Wait for 2 seconds
}
console.log(`UUT: mainFunction completed at ${new Date().toISOString()}`);
}
export const UUT = {
mainFunction,
subFunction
};
// UUT.test.js
import { timerUtils } from './timerUtils.js';
import { UUT } from './UUT.js';
import sinon from 'sinon';
import { expect } from 'chai';
const promiseResolvers = [];
const useGlobalClock = true;
let clock;
// should always match with UUT.js, always the last call would show the Invoked log in real time
const callCount = 3;
describe('Main Function Test', function() {
beforeEach(function() {
if (useGlobalClock) {
clock = sinon.useFakeTimers();
} else {
timerUtils.useFakeTimer();
}
sinon.stub(UUT, 'subFunction').callsFake((index) => {
console.log(`Stub: subFunction ${index} called, ${new Date().toISOString()}`);
return new Promise((resolve) => {
promiseResolvers.push(resolve);
});
});
});
afterEach(function() {
if (useGlobalClock) {
clock.restore();
} else {
timerUtils.restoreRealTimer();
}
promiseResolvers.length = 0;
UUT.subFunction.restore();
});
it('should complete mainFunction with controlled promise resolution', async function() {
const mainFunctionPromise = UUT.mainFunction();
for (let i = 1; i <= callCount; i++) {
if (useGlobalClock) {
clock.restore()
} else {
timerUtils.pauseFakeTimer();
}
console.log(`Test: Restored the real time clock`);
await new Promise(resolve => setTimeout(resolve, 50));
console.log(`Test: Use fake timers again`)
if (useGlobalClock) {
clock = sinon.useFakeTimers();
} else {
timerUtils.resumeFakeTimer();
}
let rCount = promiseResolvers.length;
expect(rCount, `Expected ${i} resolvers but received ${rCount}`).to.equal(i);
console.log(`Test: Resolving subfunction ${i}`);
if (typeof promiseResolvers[i - 1] === 'function') {
// Resolve the i-th subfunction's promise
promiseResolvers[i - 1]();
console.log(`Test: Resolved subfunction ${i}`)
} else {
throw new Error(`Test: Resolver for subfunction ${i} is not a function`);
}
console.log(`Test: Advancing fake timer for subfunction ${i}`);
if (useGlobalClock) {
clock.tick(1000)
} else {
timerUtils.currentClock.tick(1000);
}
}
console.log(`Test: rCount is ${promiseResolvers.length}`)
console.log('Test: All subfunctions resolved, advancing time for the final wait');
if (useGlobalClock) {
clock.tick(2100)
} else {
timerUtils.currentClock.tick(2100);
}
console.log('Test: awaiting mainFunction promise');
await mainFunctionPromise;
console.log('Test: mainFunction should be completed now');
expect(UUT.subFunction.callCount).to.equal(callCount);
});
});
// timerUtils.js
import sinon from 'sinon';
export const timerUtils = {
currentClock: null,
elapsedFakeTime: 0,
useFakeTimer: function() {
console.log('Starting fake timer');
this.currentClock = sinon.useFakeTimers();
this.elapsedFakeTime = 0;
},
pauseFakeTimer: function() {
if (this.currentClock) {
this.elapsedFakeTime = this.currentClock.now;
console.log('Pausing fake timer at:', this.elapsedFakeTime);
this.currentClock.restore();
}
},
resumeFakeTimer: function() {
console.log('Resuming fake timer from:', this.elapsedFakeTime);
this.currentClock = sinon.useFakeTimers({ now: this.elapsedFakeTime });
},
restoreRealTimer: function() {
if (this.currentClock) {
console.log('Restoring real timer');
this.currentClock.restore();
this.currentClock = null;
}
}
};
// output
Main Function Test
UUT: Invoking subfunction 1 at 1970-01-01T00:00:00.000Z
Stub: subFunction 1 called, 1970-01-01T00:00:00.000Z
Test: Restored the real time clock
Test: Use fake timers again
Test: Resolving subfunction 1
Test: Resolved subfunction 1
Test: Advancing fake timer for subfunction 1
Test: Restored the real time clock
UUT: Invoked subfunction 1 at 2023-12-31T15:36:44.323Z
UUT: Invoking subfunction 2 at 2023-12-31T15:36:44.323Z
Stub: subFunction 2 called, 2023-12-31T15:36:44.323Z
Test: Use fake timers again
Test: Resolving subfunction 2
Test: Resolved subfunction 2
Test: Advancing fake timer for subfunction 2
Test: Restored the real time clock
UUT: Invoked subfunction 2 at 2023-12-31T15:36:44.376Z
UUT: Invoking subfunction 3 at 2023-12-31T15:36:44.376Z
Stub: subFunction 3 called, 2023-12-31T15:36:44.377Z
Test: Use fake timers again
Test: Resolving subfunction 3
Test: Resolved subfunction 3
Test: Advancing fake timer for subfunction 3
Test: rCount is 3
Test: All subfunctions resolved, advancing time for the final wait
Test: awaiting mainFunction promise
UUT: Invoked subfunction 3 at 1970-01-01T00:00:05.000Z
UUT: mainFunction completed at 1970-01-01T00:00:05.000Z
Test: mainFunction should be completed now
✔ should complete mainFunction with controlled promise resolution (162ms)
timerUtils
clock (resulted in the test using the real time). But the results were not always consistent. And thus the flag for useGlobalClock
await Promise.resolve()
which would allow resolving promises in fake time, but I would like to know if moving from and to real time is possible or not, plus of course the insights behind the current behaviour.As mentioned in this comment, the tickAsync
would allow promise resolution before executing the timers.
With await
ing the tickAsync
we could now switch to the real time in the stub and run any blocking code there before switching back to the fake time
For further insights, This gist includes an updated implementation