Performance degradation from 3.1.2 to 4.2.0

[jspitzig-cribl]

We are attempting to upgrade from redis 3.1.2 to 4.2.0, but in our testing, we observed a throughput degradation with the upgraded version. As I was investigating, I found the benchmarks in this project, but it appears that the tests favor 4.x, as they take advantage of automatic pipelining, while the v3 tests were not executing as a pipeline. When I corrected for this, I was able to reproduce the performance reduction. I also created a separate project to run a number of performance tests, which suffered similar results.

Forked branch containing the changes to the node-redis benchmarks:
https://github.com/jspitzig-cribl/node-redis/tree/benchmark-pipelining

Performance test project:
https://github.com/jspitzig-cribl/redis-perf-comparison

Perhaps there is a mistake or misunderstanding in my tests. If this is the case, please let me know.

Environment:

• Node.js Version: v14.18.3
• Redis Server Version: 6.2.5
• Node Redis Version: 4.2.0
• Platform: Ubuntu 22.04, MacOS 12.3.1

[leibale]

Have you tried running the PING test (which only executes the PING command)?
Also, ioredis does support auto-pipelining, you just need to enable it (https://github.com/luin/ioredis#autopipelining).

[jspitzig-cribl]

Running the ping test does seem to produce better results with v4:

[v3.js]:                                        [v4.js]:
┌─────────────────────┬───────────────────┐     ┌─────────────────────┬───────────────────┐
│       (index)       │      Values       │     │       (index)       │      Values       │
├─────────────────────┼───────────────────┤     ├─────────────────────┼───────────────────┤
│      timestamp      │   1658402507954   │     │      timestamp      │   1658402507954   │
│ operationsPerSecond │ 94255.65010499005 │     │ operationsPerSecond │ 201313.8381659342 │
│         p0          │       80064       │     │         p0          │      370944       │
│         p50         │      1023487      │     │         p50         │      531967       │
│         p95         │      1567743      │     │         p95         │      586751       │
│         p99         │      2027519      │     │         p99         │      864767       │
│        p100         │      2947071      │     │        p100         │      2439167      │
└─────────────────────┴───────────────────┘     └─────────────────────┴───────────────────┘

In my tests, I wasn't seeing this, though it is run sequentially:

[[redis 3.1.2]]:
┌─────────────────────┬─────────┬─────────┬─────────┬─────────┬─────────┬─────────┐
│       (index)       │    0    │    1    │    2    │    3    │    4    │   avg   │
├─────────────────────┼─────────┼─────────┼─────────┼─────────┼─────────┼─────────┤
│ operationsPerSecond │  8892   │  9388   │  8462   │  9260   │  8959   │  8992   │
│         p0          │  62208  │  64640  │  63424  │  62272  │  62784  │  63066  │
│         p50         │  94655  │  89151  │  89599  │  89407  │  90495  │  90661  │
│         p95         │ 138367  │ 131455  │ 168447  │ 124607  │ 140799  │ 140735  │
│         p99         │ 208511  │ 364031  │ 379135  │ 302591  │ 360703  │ 322994  │
│        p100         │ 2146303 │ 5074943 │ 3733503 │ 3577855 │ 4354047 │ 3777330 │
└─────────────────────┴─────────┴─────────┴─────────┴─────────┴─────────┴─────────┘
[[redis 4.2.0]]:
┌─────────────────────┬─────────┬─────────┬─────────┬─────────┬─────────┬─────────┐
│       (index)       │    0    │    1    │    2    │    3    │    4    │   avg   │
├─────────────────────┼─────────┼─────────┼─────────┼─────────┼─────────┼─────────┤
│ operationsPerSecond │  8027   │  8258   │  8230   │  8012   │  9064   │  8318   │
│         p0          │  74560  │  70656  │  71872  │  74752  │  70016  │  72371  │
│         p50         │ 100607  │  99455  │  98879  │ 109183  │  97727  │ 101170  │
│         p95         │ 165503  │ 155007  │ 159231  │ 138495  │ 128831  │ 149413  │
│         p99         │ 366591  │ 334079  │ 304383  │ 436223  │ 152063  │ 318668  │
│        p100         │ 3950591 │ 3913727 │ 3512319 │ 3979263 │ 2034687 │ 3478117 │
└─────────────────────┴─────────┴─────────┴─────────┴─────────┴─────────┴─────────┘

[leibale]

Results with enableAutoPipelining: true for ioredis

[ioredis.js]:
┌─────────────────────┬───────────────────┐
│       (index)       │      Values       │
├─────────────────────┼───────────────────┤
│      timestamp      │   1659038123697   │
│ operationsPerSecond │ 233179.8912102249 │
│         p0          │      210176       │
│         p50         │      343039       │
│         p95         │      458239       │
│         p99         │      3407871      │
│        p100         │      5570559      │
└─────────────────────┴───────────────────┘
[v3.js]:
┌─────────────────────┬───────────────────┐
│       (index)       │      Values       │
├─────────────────────┼───────────────────┤
│      timestamp      │   1659038123697   │
│ operationsPerSecond │ 178306.0887653474 │
│         p0          │       50208       │
│         p50         │      526847       │
│         p95         │      741375       │
│         p99         │      1015807      │
│        p100         │     11878399      │
└─────────────────────┴───────────────────┘
[v4.js]:
┌─────────────────────┬───────────────────┐
│       (index)       │      Values       │
├─────────────────────┼───────────────────┤
│      timestamp      │   1659038123697   │
│ operationsPerSecond │ 309448.7526183445 │
│         p0          │      180352       │
│         p50         │      303871       │
│         p95         │      402431       │
│         p99         │      704511       │
│        p100         │      1606655      │
└─────────────────────┴───────────────────┘