Switching between fake and real time using sinon.js

Question

Summary

How to cleanly switch to real time and back again to fake time while testing with Sinon?

---

Details

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:

• An await of a stub promise that times out in at least 1 ms (which happens at the beginning of the for loop, allowing each resolver to move on based on the previous one), in which case the date in the UUT is set to the real time again.
• An await of a UUT promise (which happens in the n-th subfunction call which continues when we finish the loop and await the mainFunction's promise), in which case the date in the UUT is set to the fake time.

Questions:

• Is there a better way to change to and back from real time?
• How to ensure that the Test is always set back to the fake time, while using the timerUtils?
• Bonus, how to get enableFurtherWait to run without blocking the promise?

Code

// 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)

Notes

• Sometimes I noticed that there was a difference when using the global clock directly (resulted in the test using the fake time) versus using the normal timerUtils clock (resulted in the test using the real time). But the results were not always consistent. And thus the flag for useGlobalClock
• I know of the possibility of using 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.
• The code is a demo that showcases the issue, the original codebase is much larger.

Answer 1

As mentioned in this comment, the tickAsync would allow promise resolution before executing the timers.

With awaiting 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