Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

cls-rtracer uses synchronous API #21

Closed
tsondergaard opened this issue Dec 29, 2019 · 1 comment · Fixed by #22
Closed

cls-rtracer uses synchronous API #21

tsondergaard opened this issue Dec 29, 2019 · 1 comment · Fixed by #22
Labels
bug Something isn't working
Milestone

Comments

@tsondergaard
Copy link

Running node with --trace-sync-io for an application that uses cls-rtracer outputs warnings such as this one:

(node:31771) WARNING: Detected use of sync API
    at randomBytes (internal/crypto/random.js:54:31)
    at nodeRNG ([...]/node_modules/cls-rtracer/node_modules/uuid/lib/rng.js:7:17)
    at v4 ([...]/node_modules/cls-rtracer/node_modules/uuid/v4.js:13:52)
    at [...]/node_modules/cls-rtracer/index.js:30:30
    at handle ([...]/node_modules/express/lib/router/layer.js:95:5)
    at trim_prefix ([...]/node_modules/express/lib/router/index.js:317:13)
    at [...]/node_modules/express/lib/router/index.js:284:7
    at process_params ([...]/node_modules/express/lib/router/index.js:335:12)
    at next ([...]/node_modules/express/lib/router/index.js:275:10)

Using a synchronous API is undesirable even if the randomBytes() function is normally very fast. If for no other reason, just for the fact that it makes --trace-sync-io much less useful when cls-rtracer creates a lot of noise.

I would expect that a UUID V1 should be plenty good enough for cls-rtracer. uuid.v1() is 5 times faster than uuid.v4() and does not trigger the "WARNING: Detected use of sync API" when run with --trace-sync-io as demonstrated by this little experiment:

$ cat experiment.js 
const uuid = require("uuid");
const { performance } = require("perf_hooks");

const iterations = 5000000;

let t_begin = performance.now();
for (let i = 0; i < iterations; ++i) {
    uuid.v1();
}
console.log(`${iterations} uuid.v1(): ${(performance.now() - t_begin).toFixed(0)} ms`);

t_begin = performance.now();
for (let i = 0; i < iterations; ++i) {
    uuid.v4();
}
console.log(`${iterations} uuid.v4(): ${(performance.now() - t_begin).toFixed(0)} ms`);

$ node experiment.js 
5000000 uuid.v1(): 2941 ms
5000000 uuid.v4(): 14589 ms
@puzpuzpuz puzpuzpuz added the bug Something isn't working label Dec 30, 2019
@puzpuzpuz
Copy link
Owner

Many thanks for finding this issue @tsondergaard

I completely agree that there is not point in using UUID V4 for cls-rtracer, especially considering the sync call that happens in uuid/v4. Going to fix this defect and ship it in 1.4.0 today.

@puzpuzpuz puzpuzpuz added this to the 1.4.0 milestone Dec 30, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants