process.hrtime gives incorrect results
mrft opened this issue ยท 4 comments
- FakeTimers version : ^11.0.0
- Environment : node 16.20.0 (but also 14 or 18 or 20), using ts-node 10.9.1
- Example URL :
- Other libraries you are using: /
IMPORTANT: my tests only started failing after I was playing with tsconfig.json settings in order to produce an EcmaScript Module instead of a CommonsJS module.
In order to get that working
- I added type: "module" to package.json
- I altered tsconfig.json
{
"compilerOptions": {
- "lib": ["es2018", "DOM"],
- "target": "es2018",
+ "lib": ["ES2020", "DOM"],
+ "target": "ES2020",
// "noImplicitAny": true,
"strictNullChecks": true,
"outDir": "./dist",
"rootDir": "./src",
- "module": "CommonJS",
+ "module": "ES2020",
"sourceMap": true,
"declaration": true,
- "esModuleInterop": true
+ "esModuleInterop": true,
+ "moduleResolution": "node"
// "strict": true,
// "isolatedModules": true,
},
"ts-node": {
"compilerOptions": {
- "module": "CommonJS"
+ "module": "ES2020",
}
},
- I changed the test script from
mocha --require ts-node/register
tomocha --require ts-node/esm
- and I added a .mocharc.json file containing
{
"node-option": [
"experimental-specifier-resolution=node",
"loader=ts-node/esm"
]
}
What did you expect to happen?
calling hrtime() after advancing the clock should return the start time + the number of milliseconds that the clock has advanced,
What actually happens
it always returns 0, while the version that uses Date.now() works as expected.
How to reproduce
Configure the project to be ESM by creating a similar configuration as shown above, and then run this test.
import FakeTimers from "@sinonjs/fake-timers";
import { assert } from "chai";
describe("@sinonjs/fake-timers", () => {
it("should behave as expected when using process.hrtime", async () => {
const clock = FakeTimers.install();
try {
const start = process.hrtime()[0];
const start2 = Date.now();
// await awaitPromiseWithFakeTimers(clock, sleep(50));
clock.tick(50);
const stop = process.hrtime()[0];
const stop2 = Date.now();
assert.equal(stop2 - start2, 50, "Date.now() gives incorrect results");
assert.equal(stop - start, 50, "process.hrtime gives incorrect results");
} finally {
clock.uninstall();
}
});
});
(The actual code that worked for me (different tests where I was using fake-timers) can be found here: https://github.com/mrft/itr8 (npm install && npm run test)
The changes to tsconfig that made it start failing have not been committed yet)
Thanks for reporting this and good details in the report!
The reproduction case seemed a bit elaborate and also was not so easily runnable, but seeing that this was essentially about CJS vs ESM it seemed fair to just run the code directly using those modes in Node, as there was no typescript specifics here. We also do not support Typescript (which does not mean you should not use it, just that TS specifics is not for us to debug as they often just obscure the real underlying issues with non-standard ES extensions such as decorators).
I just copied your code into repro.test.mjs
and added the dependencies and as expected the tests failed. So โ
.
Then I copied the test file to repro.test.js
and changed the imports to require
calls. Tests still failed. So โ on there being a difference.
I have found an issue with how you use process.hrtime()
(details about that below), but I don't see any difference between running tests in either mode.
So I cannot verify your issue about ESM being different than CJS. Unless you are able to come up with some reproduction case (TS or ES, does not matter), I will probably remove the TS specifics detail for clarity for latecomers.
Repro:
package.json
{
"name": "foo2",
"version": "1.0.0",
"description": "",
"main": "index.js",
"scripts": {
"test": "mocha ./repro.test.mjs"
},
"keywords": [],
"author": "",
"license": "ISC",
"dependencies": {
"@sinonjs/fake-timers": "^11.0.0",
"chai": "^4.3.7",
"mocha": "^10.2.0"
},
"devDependencies": {
"@types/mocha": "^10.0.1",
"@types/node": "^20.3.1"
}
}
Copy your own code into repro.test.mjs
and run npm test
.
About using process.hrtime()
wrong
The docs for process.hrtime()
states:
returns the current high-resolution real time in a [seconds, nanoseconds] tuple Array, where nanoseconds is the remaining part of the real time that can't be represented in second precision.
I understood something was off when console.log-ing the start and end process.hrtime results (with the full array), as it clearly adds 50 ms. This is what you get if you capture the full array and print both start and end:
[ 0, 0 ] [ 0, 50000000 ]
That's 0 seconds and 0.05 seconds in process.hrtime, but you are only comparing the seconds, not the nanoseconds. So changing your test to account for hrtime counting in nanosecons (1 ms = 1 million nanosecs) and comparing the right component of the array (๐) you get your test to pass with this diff:
< const start = process.hrtime()[0];
---
> const start = process.hrtime();
12c12
< const stop = process.hrtime()[0];
---
> const stop = process.hrtime();
15c15,19
< assert.equal(stop - start, 50, "process.hrtime gives incorrect results");
---
> assert.equal(
> stop[1] - start[1],
> 50 * 1e6,
> "process.hrtime gives incorrect results"
> );
P.S. You might want to be aware that process.hrtime() has been marked as a legacy API for the last 5 years (Node v10) and that you should prefer to use process.hrtime.bigint()
these days. It has a simple API, as it returns a scalar return value which would have avoided this bug altogether ๐
P.P.S. If you somehow manage to reproduce the ESM vs CJS inconsistency, please shout out so that we can take a look. We need to have two bits of code: the one that passes and the one that fails.
@fatso83 Thanks a lot for investigating.
The [0] in the provided test case was just an example I did here trying to stick to the essence.
I still don't understand why my tests would suddenly start failing after changing the tsconfig settings, but I realised that if I used fake-timers in my tests, I could just as well use Date.now() instead, and only use process.hrtime.bigint() for some performance tests (which will not use fake-timers).
So I have found an easy workaround by now, but I did want to let you know in case it was some hidden issue in this library.
@mrft No worries, glad if I could remove some sources of confusion. If you still experience this and manage to find some way of consistently reproducing this, please create a minimally reproducible test case and I will check it out asap. Until then, I will just assume this was some other temporary weirdness causing issues ๐
P.S. You should be able to use process.hrtime.bigint()
with fake-timers. We mock that as well.