In v4.0.0 require('redis') is one order of magnitude slower than in v3.1.2

[Desno365]

Calling require('redis') in v4.0.0 is 10 times slower than calling it in v3.1.2.
Using v4.0.0 on our machine we measured an average time of ≈150ms, while in v3.1.2 is of ≈15ms.

This is affecting the cold start time for our functions considerably.

Is this normal? Is there any way for us to reduce the loading time?

How to reproduce:

In package.json

"dependencies": {
   "redis-new": "npm:[email protected]",
   "redis-old": "npm:[email protected]"
 },

In a js file:

console.time("old");
const redisOld = require("redis-old");
console.timeEnd("old");

console.time("new");
const redis = require("redis-new");
console.timeEnd("new");

Environment:

• Node.js Version: v14.18.1
• Redis Server Version: Redis 6.2.6 64 bit
• Platform: Mac OS 12.0.1

[gebbber]

I am getting a loading time of ~3.5 seconds in my app:

Before:

╒═════ 2021-12-27 18:07:00 (UTC-0000): (T₀ + 0s)
├380ms =-=-=-=-=-=-=-=-=-=-=-= Starting Server =-=-=-=-=-=-=-=-=-=-=-=
╒═════ 2021-12-27 18:07:01 (UTC-0000): (T₀ + 1.519:)
├899ms welcome: app enabled /api/welcome → http://app-welcome:3000 ✓

When I add import { createClient } from 'redis', but don't do anything with it yet:

╒═════ 2021-12-27 18:04:53 (UTC-0000): (T₀ + 0.001:)
├433ms =-=-=-=-=-=-=-=-=-=-=-= Starting Server =-=-=-=-=-=-=-=-=-=-=-=
╒═════ 2021-12-27 18:04:58 (UTC-0000): (T₀ + 5.541:)
├973ms welcome: app enabled /api/welcome → http://app-welcome:3000 ✓

(Next logged event went from T₀ + 1.519 seconds after server startup to T₀ + 5.541 seconds.)

I attempted to duplicate this in an empty app, which should reflect the original posted issue here, but noted that console.timeEnd reports milliseconds, not seconds. In my case if I misread the logging as 'seconds', it would appear to have been 150 milliseconds, but was actually only 0.15 milliseconds difference:

//test.js
console.time('loading');
import test from './load-redis.js'
console.timeEnd('loading');

//load-redis.js

//import { createClient } from "redis";
export default function test () {

}

With the import commented out, as above:

> node test.js
loading: 0.069ms

With the import reinstated:

> node test.js
loading: 0.221ms

(~150 microseconds difference, not milliseconds)

This isn't too bad, but the import is still blocking my app for 3.5 seconds, despite that I'm importing it and not doing anything with it.

[Desno365]

//test.js
console.time('loading');
import test from './load-redis.js'
console.timeEnd('loading');

For what I know require is synchronous while import is asynchronous, so you probably can't measure the import command like that

[leibale]

test.cjs:

console.time('v3');
const v3 = require('v3');
console.timeEnd('v3');

console.time('v4');
const v4 = require('v4');
console.timeEnd('v4');

// v3: 34.651ms
// v4: 110.697ms

test.mjs:

console.time('v3');
const v3 = await import('v3');
console.timeEnd('v3');

console.time('v4');
const v4 = await import('v4');
console.timeEnd('v4');

// v3: 50.647ms
// v4: 111.086ms

After bundling v4 (using webpack), it went down to about 40ms, but I don't think this should be added to the build/release process because:

1. For most users, the throughput of the client is what matters, not the startup time...
2. It'll "ruin" error stack traces.
3. Users that care about startup time will bundle some (or even all) the node_modules, not just node-redis.

[Desno365]

test.cjs:

console.time('v3');
const v3 = require('v3');
console.timeEnd('v3');

console.time('v4');
const v4 = require('v4');
console.timeEnd('v4');

// v3: 34.651ms
// v4: 110.697ms

Consider also that by running require('v3') just before require('v4') helps the v4 timing since some packages that are in common are already cached.
In my opinion this problem should be considered and not just ignored.

[leibale]

@Desno365

I've run the tests again, this time each test in a different process, here are the results:

• v3.cjs 34.51ms
• v3.mjs: 47.431ms
• v4.cjs: 119.96ms
• v4.mjs: 132.075ms
• v4-bundled.mjs: 45.306ms

[gebbber]

For what I know require is synchronous while import is asynchronous, so you probably can't measure the import command like that

Yeah there are a few things I'm confused on here. If it's asynchronous, why is it blocking my app for 3.5 seconds to import it, even when I'm not doing anything with it? I'm also confused about your using the require statement, because I thought 4.0 didn't have an interface for CJS require.

[gebbber]

I've determined that my issue was related to running this in a Docker container, with node_modules bound to my local drive for development purposes. It loads instantly when I copy things in while building the container. Sorry for any inconvenience!