envoyproxy / envoyproxy/nighthawk

Issues around max QPS

Open
#576 3 comments 2 reactions 0 assignees View on GitHub
Dominant language
C++
Stars
414
Forks
95
Avg merge
2d 9h
Merged PRs (30d)
11

Description

I would like to send requests at the maximum RPS possible. Many other tools (hey: default, fortio: `-qps 0`) support this mode.

In nighthawk, `--rps` must be between `"value must be inside range [" '\x01' ", " '\U000f4240' "]` (yay for horrible error messages from envoy, this is 1-1million though).

If I request 1M rps, I get an actual of 10k RPS. If I request 50k RPS, I am able to get 50k RPS. This indicates nighthawk is getting throttled unnecessarily, while the server can handle more load.

1M request logs

```
$ nighthawk --rps 1000000 --concurrency 1 --duration 10 --connections 64 --prefetch-connections --max-active-requests 1000 http://127.0.0.1:8080
[12:25:26.352783][854812][I] Starting 1 threads / event loops. Time limit: 10 seconds.
[12:25:26.352823][854812][I] Global targets: 64 connections and 1000000 calls per second.
[12:25:26.353462][854812][W] Unable to use runtime singleton for feature envoy.http.headermap.lazy_map_min_size
[12:25:36.902843][854818][I] Stopping after 10000 ms. Initiated: 103381 / Completed: 103380. (Completion rate was 10337.99689860093 per second.)
Nighthawk - A layer 7 protocol benchmarking tool.

benchmark_http_client.latency_2xx (103317 samples)
min: 0s 000ms 034us | mean: 0s 000ms 087us | max: 0s 005ms 736us | pstdev: 0s 000ms 041us

Percentile Count Value
0.5 51659 0s 000ms 084us
0.75 77488 0s 000ms 093us
0.8 82654 0s 000ms 096us
0.9 92988 0s 000ms 104us
0.95 98152 0s 000ms 115us
0.990625 102349 0s 000ms 163us
0.99902344 103217 0s 000ms 594us

Queueing and connection setup latency (103318 samples)
min: 0s 000ms 001us | mean: 0s 000ms 003us | max: 0s 025ms 735us | pstdev: 0s 000ms 080us

Percentile Count Value
0.5 51675 0s 000ms 003us
0.75 77510 0s 000ms 004us
0.8 82656 0s 000ms 004us
0.9 92997 0s 000ms 005us
0.95 98156 0s 000ms 005us
0.990625 102350 0s 000ms 011us
0.99902344 103218 0s 000ms 016us

Request start to response end (103317 samples)
min: 0s 000ms 034us | mean: 0s 000ms 087us | max: 0s 005ms 735us | pstdev: 0s 000ms 041us

Percentile Count Value
0.5 51669 0s 000ms 083us
0.75 77491 0s 000ms 093us
0.8 82659 0s 000ms 096us
0.9 92987 0s 000ms 104us
0.95 98153 0s 000ms 115us
0.990625 102349 0s 000ms 162us
0.99902344 103217 0s 000ms 593us

Response body size in bytes (103317 samples)
min: 0 | mean: 0.0 | max: 0 | pstdev: 0.0

Response header size in bytes (103317 samples)
min: 58 | mean: 58.0 | max: 58 | pstdev: 0.0

Blocking. Results are skewed when significant numbers are reported here. (103318 samples)
min: 0s 000ms 018us | mean: 0s 000ms 096us | max: 0s 005ms 778us | pstdev: 0s 000ms 042us

Percentile Count Value
0.5 51659 0s 000ms 092us
0.75 77490 0s 000ms 104us
0.8 82656 0s 000ms 107us
0.9 92989 0s 000ms 116us
0.95 98154 0s 000ms 129us
0.990625 102350 0s 000ms 180us
0.99902344 103218 0s 000ms 607us

Initiation to completion (103380 samples)
min: 0s 000ms 037us | mean: 0s 000ms 108us | max: 0s 026ms 479us | pstdev: 0s 000ms 635us

Percentile Count Value
0.5 51694 0s 000ms 089us
0.75 77539 0s 000ms 099us
0.8 82712 0s 000ms 103us
0.9 93042 0s 000ms 112us
0.95 98211 0s 000ms 124us
0.990625 102411 0s 000ms 176us
0.99902344 103280 0s 000ms 773us

Counter Value Per second
benchmark.http_2xx 103317 10331.70
benchmark.pool_overflow 63 6.30
cluster_manager.cluster_added 1 0.10
default.total_match_count 1 0.10
membership_change 1 0.10
runtime.load_success 1 0.10
runtime.override_dir_not_exists 1 0.10
upstream_cx_http1_total 64 6.40
upstream_cx_rx_bytes_total 7748775 774877.27
upstream_cx_total 64 6.40
upstream_cx_tx_bytes_total 6095762 609576.02
upstream_rq_pending_overflow 63 6.30
upstream_rq_pending_total 1 0.10
upstream_rq_total 103318 10331.80
```

50k request logs

```
[12:26:36.753033][855204][I] Starting 1 threads / event loops. Time limit: 10 seconds.
[12:26:36.753072][855204][I] Global targets: 64 connections and 50000 calls per second.
[12:26:36.753695][855204][W] Unable to use runtime singleton for feature envoy.http.headermap.lazy_map_min_size
[12:26:47.303113][855210][I] Stopping after 10000 ms. Initiated: 499999 / Completed: 499996. (Completion rate was 49999.475001312494 per second.)
Nighthawk - A layer 7 protocol benchmarking tool.

benchmark_http_client.latency_2xx (499965 samples)
min: 0s 000ms 026us | mean: 0s 000ms 169us | max: 0s 007ms 123us | pstdev: 0s 000ms 180us

Percentile Count Value
0.5 249986 0s 000ms 086us
0.75 374976 0s 000ms 230us
0.8 399980 0s 000ms 282us
0.9 449975 0s 000ms 410us
0.95 474967 0s 000ms 495us
0.990625 495278 0s 000ms 759us
0.99902344 499477 0s 001ms 405us

Queueing and connection setup latency (499968 samples)
min: 0s 000ms 000us | mean: 0s 000ms 001us | max: 0s 016ms 741us | pstdev: 0s 000ms 023us

Percentile Count Value
0.5 250156 0s 000ms 001us
0.75 375423 0s 000ms 002us
0.8 400613 0s 000ms 002us
0.9 450102 0s 000ms 002us
0.95 474994 0s 000ms 002us
0.990625 495281 0s 000ms 003us
0.99902344 499480 0s 000ms 008us

Request start to response end (499965 samples)
min: 0s 000ms 026us | mean: 0s 000ms 169us | max: 0s 007ms 122us | pstdev: 0s 000ms 180us

Percentile Count Value
0.5 249992 0s 000ms 086us
0.75 374976 0s 000ms 230us
0.8 399975 0s 000ms 281us
0.9 449973 0s 000ms 410us
0.95 474968 0s 000ms 495us
0.990625 495278 0s 000ms 759us
0.99902344 499477 0s 001ms 405us

Response body size in bytes (499965 samples)
min: 0 | mean: 0.0 | max: 0 | pstdev: 0.0

Response header size in bytes (499965 samples)
min: 58 | mean: 5unneccesarily8.0 | max: 58 | pstdev: 0.0

Blocking. Results are skewed when significant numbers are reported here. (4370 samples)
min: 0s 000ms 014us | mean: 0s 000ms 264us | max: 0s 005ms 615us | pstdev: 0s 000ms 152us

Percentile Count Value
0.5 2185 0s 000ms 253us
0.75 3278 0s 000ms 350us
0.8 3496 0s 000ms 357us
0.9 3933 0s 000ms 373us
0.95 4152 0s 000ms 386us
0.990625 4330 0s 000ms 472us
0.99902344 4366 0s 001ms 388us

Initiation to completion (499996 samples)
min: 0s 000ms 029us | mean: 0s 000ms 178us | max: 0s 017ms 698us | pstdev: 0s 000ms 187us

Percentile Count Value
0.5 250004 0s 000ms 091us
0.75 374999 0s 000ms 243us
0.8 400002 0s 000ms 298us
0.9 450000 0s 000ms 435us
0.95 474998 0s 000ms 518us
0.990625 495309 0s 000ms 771us
0.99902344 499508 0s 001ms 424us

Counter Value Per second
benchmark.http_2xx 499965 49996.37
benchmark.pool_overflow 31 3.10
cluster_manager.cluster_added 1 0.10
default.total_match_count 1 0.10
membership_change 1 0.10
runtime.load_success 1 0.10
runtime.override_dir_not_exists 1 0.10
upstream_cx_http1_total 64 6.40
upstream_cx_rx_bytes_total 37497375 3749727.91
upstream_cx_total 64 6.40
upstream_cx_tx_bytes_total 29498112 2949803.65
upstream_rq_pending_overflow 31 3.10
upstream_rq_pending_total 2 0.20
upstream_rq_total 499968 49996.67

[12:26:47.424905][855204][I] Done.
```

Both of these are from `nighthawk --rps ... --concurrency 1 --duration 10 --connections 64 --prefetch-connections`, against `fortio server` on the same machine.

Based on this, the main thing I am seeing is pool_overflow=63 for the 1M requests, but pool_overflow=31 for 50k request.

I was a bit surprised the 50k QPS showed `pool_overflow=31`, despite everything seeming fine.

It would be great if some combination of these were addressed:
* Add an option to request "max RPS"
* Degrade gracefully when requested RPS > server/client max RPS.
* I would expect the invariant that, barring test variance, as request RPS increases, actual RPS either increases or maintains constant. Today, at some breaking point, it actual QPS starts decreasing
* If this is expected due to some `pool_overflow`, add some documentation on what settings can be tuned to ensure we do not overflow. I didn't see much here, but perhaps I missed something.

Results of varying QPS settings:
```
DEST TOOL QPS CONS DUR SUCCESS THROUGHPUT P50 P90 P99
http://127.0.0.1:8080 nighthawk 10000 64 10 99968 9996.89qps 0.08ms 0.12ms 0.34ms
http://127.0.0.1:8080 nighthawk 50000 64 10 499966 49996.70qps 0.09ms 0.42ms 0.77ms
http://127.0.0.1:8080 nighthawk 75000 64 10 687395 68740.33qps 0.30ms 0.41ms 1.03ms
http://127.0.0.1:8080 nighthawk 100000 64 10 690584 69058.48qps 0.30ms 0.42ms 1.03ms
http://127.0.0.1:8080 nighthawk 200000 64 10 688416 68843.29qps 0.30ms 0.42ms 1.03ms
http://127.0.0.1:8080 nighthawk 500000 64 10 694161 69417.19qps 0.30ms 0.40ms 1.02ms
http://127.0.0.1:8080 nighthawk 750000 64 10 103356 10335.69qps 0.08ms 0.10ms 0.16ms
http://127.0.0.1:8080 nighthawk 1000000 64 10 103350 10335.09qps 0.08ms 0.10ms 0.16ms
```

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.