Fix to avoid idle connections from blocking worker threads #20

uatuko · 2024-01-12T10:05:53Z

Because of workers running the event loop using UV_RUN_ONCE, worker threads can get blocked waiting on idle connections.

grpcxx/lib/grpcxx/worker.cpp

Line 17 in d81fe86

if (uv_run(&_loop, UV_RUN_ONCE) != 0) {

This change let libuv run the event loop using UV_RUN_DEFAULT and use async handles to indicate when there are new incoming worker requests.

Benchmarks

	1a	1b	2a	2b	3a	3b
Multi-threaded, hardware concurrency (`a37d0ad`)	31k	136k	80k	309k	68k	319k
Multi-threaded, 2 workers (`a37d0ad`)	32k	135k	89k	311k	89k	301k

Benchmark details

Benchmarks were run on a MacBook Pro 2021 (M1 Max, 32GB), macOS 14.2.1 (23C71).

⚠️ The device and macOS is different to the one used for benchmarks in #2.

[2024-01-12] Multi-threaded (hardware concurrency)

[2024-01-12] Multi-threaded, hardware concurrency (`a37d0ad`)

1a.

❯ h2load --clients=1 --requests=100000 --header='Content-Type: application/grpc' --data=examples/helloworld/testdata/hello.grpc-lpm.data http://localhost:7000/helloworld.v1.Greeter/Hello
starting benchmark...
spawning thread #0: 1 total client(s). 100000 total requests
Application protocol: h2c
progress: 10% done
progress: 20% done
progress: 30% done
progress: 40% done
progress: 50% done
progress: 60% done
progress: 70% done
progress: 80% done
progress: 90% done
progress: 100% done

finished in 3.24s, 30872.24 req/s, 1.80MB/s
requests: 100000 total, 100000 started, 100000 done, 100000 succeeded, 0 failed, 0 errored, 0 timeout
status codes: 100000 2xx, 0 3xx, 0 4xx, 0 5xx
traffic: 5.82MB (6100749) total, 195.32KB (200012) headers (space savings 94.74%), 2.96MB (3100000) data
                     min         max         mean         sd        +/- sd
time for request:       20us      1.00ms        30us         8us    94.18%
time for connect:      711us       711us       711us         0us   100.00%
time to 1st byte:     1.70ms      1.70ms      1.70ms         0us   100.00%
req/s           :   30872.31    30872.31    30872.31        0.00   100.00%

1b.

❯ h2load --clients=1 --requests=100000 --max-concurrent-streams=10 --header='Content-Type: application/grpc' --data=examples/helloworld/testdata/hello.grpc-lpm.data http://localhost:7000/helloworld.v1.Greeter/Hello
starting benchmark...
spawning thread #0: 1 total client(s). 100000 total requests
Application protocol: h2c
progress: 10% done
progress: 20% done
progress: 30% done
progress: 40% done
progress: 50% done
progress: 60% done
progress: 70% done
progress: 80% done
progress: 90% done
progress: 100% done

finished in 735.86ms, 135894.68 req/s, 7.91MB/s
requests: 100000 total, 100000 started, 100000 done, 100000 succeeded, 0 failed, 0 errored, 0 timeout
status codes: 100000 2xx, 0 3xx, 0 4xx, 0 5xx
traffic: 5.82MB (6100749) total, 195.32KB (200012) headers (space savings 94.74%), 2.96MB (3100000) data
                     min         max         mean         sd        +/- sd
time for request:       26us      1.00ms        67us        26us    89.54%
time for connect:      396us       396us       396us         0us   100.00%
time to 1st byte:      836us       836us       836us         0us   100.00%
req/s           :  135895.54   135895.54   135895.54        0.00   100.00%

2a.

❯ h2load --clients=10 --requests=100000 --header='Content-Type: application/grpc' --data=examples/helloworld/testdata/hello.grpc-lpm.data http://localhost:7000/helloworld.v1.Greeter/Hello
starting benchmark...
spawning thread #0: 10 total client(s). 100000 total requests
Application protocol: h2c
progress: 10% done
progress: 20% done
progress: 30% done
progress: 40% done
progress: 50% done
progress: 60% done
progress: 70% done
progress: 80% done
progress: 90% done
progress: 100% done

finished in 1.25s, 79823.49 req/s, 4.64MB/s
requests: 100000 total, 100000 started, 100000 done, 100000 succeeded, 0 failed, 0 errored, 0 timeout
status codes: 100000 2xx, 0 3xx, 0 4xx, 0 5xx
traffic: 5.82MB (6101120) total, 195.43KB (200120) headers (space savings 94.73%), 2.96MB (3100000) data
                     min         max         mean         sd        +/- sd
time for request:       22us      1.49ms       100us        44us    89.62%
time for connect:      380us       767us       545us       153us    70.00%
time to 1st byte:     1.80ms      2.09ms      1.91ms       128us    70.00%
req/s           :    7984.11     8020.25     7995.68       10.28    70.00%

2b.

❯ h2load --clients=10 --requests=100000 --max-concurrent-streams=10 --header='Content-Type: application/grpc' --data=examples/helloworld/testdata/hello.grpc-lpm.data http://localhost:7000/helloworld.v1.Greeter/Hello
starting benchmark...
spawning thread #0: 10 total client(s). 100000 total requests
Application protocol: h2c
progress: 10% done
progress: 20% done
progress: 30% done
progress: 40% done
progress: 50% done
progress: 60% done
progress: 70% done
progress: 80% done
progress: 90% done
progress: 100% done

finished in 323.54ms, 309081.75 req/s, 17.98MB/s
requests: 100000 total, 100000 started, 100000 done, 100000 succeeded, 0 failed, 0 errored, 0 timeout
status codes: 100000 2xx, 0 3xx, 0 4xx, 0 5xx
traffic: 5.82MB (6101120) total, 195.43KB (200120) headers (space savings 94.73%), 2.96MB (3100000) data
                     min         max         mean         sd        +/- sd
time for request:       15us      7.50ms       222us       200us    99.23%
time for connect:      405us       616us       496us        78us    60.00%
time to 1st byte:     1.12ms      8.01ms      5.22ms      2.85ms    80.00%
req/s           :   30922.88    31623.76    31068.12      210.12    90.00%

3a.

❯ h2load --clients=100 --requests=100000 --header='Content-Type: application/grpc' --data=examples/helloworld/testdata/hello.grpc-lpm.data http://localhost:7000/helloworld.v1.Greeter/Hello
starting benchmark...
spawning thread #0: 100 total client(s). 100000 total requests
Application protocol: h2c
progress: 10% done
progress: 20% done
progress: 30% done
progress: 40% done
progress: 50% done
progress: 60% done
progress: 70% done
progress: 80% done
progress: 90% done
progress: 100% done

finished in 1.48s, 67675.85 req/s, 3.94MB/s
requests: 100000 total, 100000 started, 100000 done, 100000 succeeded, 0 failed, 0 errored, 0 timeout
status codes: 100000 2xx, 0 3xx, 0 4xx, 0 5xx
traffic: 5.82MB (6104700) total, 196.48KB (201200) headers (space savings 94.71%), 2.96MB (3100000) data
                     min         max         mean         sd        +/- sd
time for request:       31us     15.34ms       986us      1.00ms    96.46%
time for connect:     3.19ms      6.11ms      5.10ms       704us    68.00%
time to 1st byte:     7.61ms     20.00ms     13.60ms      3.75ms    50.00%
req/s           :     676.99      735.20      688.70       12.85    86.00%

3b.

❯ h2load --clients=100 --requests=100000 --max-concurrent-streams=10 --header='Content-Type: application/grpc' --data=examples/helloworld/testdata/hello.grpc-lpm.data http://localhost:7000/helloworld.v1.Greeter/Hello
starting benchmark...
spawning thread #0: 100 total client(s). 100000 total requests
Application protocol: h2c
progress: 10% done
progress: 20% done
progress: 30% done
progress: 40% done
progress: 50% done
progress: 60% done
progress: 70% done
progress: 80% done
progress: 90% done
progress: 100% done

finished in 313.54ms, 318935.52 req/s, 18.57MB/s
requests: 100000 total, 100000 started, 100000 done, 100000 succeeded, 0 failed, 0 errored, 0 timeout
status codes: 100000 2xx, 0 3xx, 0 4xx, 0 5xx
traffic: 5.82MB (6104700) total, 196.48KB (201200) headers (space savings 94.71%), 2.96MB (3100000) data
                     min         max         mean         sd        +/- sd
time for request:       96us     18.07ms      1.90ms      1.25ms    94.55%
time for connect:     2.42ms      4.34ms      3.48ms       481us    70.00%
time to 1st byte:     7.15ms     21.18ms     16.11ms      3.41ms    74.00%
req/s           :    3193.03     3309.22     3223.15       24.82    83.00%

[2024-01-12] Multi-threaded (2 workers)

[2024-01-12] Multi-threaded, 2 workers (`a37d0ad`)

💡 Worker count was set by passing in the number of workers to grpcxx::server{}.

grpcxx/examples/helloworld/main.cpp

Line 38 in a37d0ad

grpcxx::server server;

1a.

❯ h2load --clients=1 --requests=100000 --header='Content-Type: application/grpc' --data=examples/helloworld/testdata/hello.grpc-lpm.data http://localhost:7000/helloworld.v1.Greeter/Hello
starting benchmark...
spawning thread #0: 1 total client(s). 100000 total requests
Application protocol: h2c
progress: 10% done
progress: 20% done
progress: 30% done
progress: 40% done
progress: 50% done
progress: 60% done
progress: 70% done
progress: 80% done
progress: 90% done
progress: 100% done

finished in 3.12s, 32077.53 req/s, 1.87MB/s
requests: 100000 total, 100000 started, 100000 done, 100000 succeeded, 0 failed, 0 errored, 0 timeout
status codes: 100000 2xx, 0 3xx, 0 4xx, 0 5xx
traffic: 5.82MB (6100749) total, 195.32KB (200012) headers (space savings 94.74%), 2.96MB (3100000) data
                     min         max         mean         sd        +/- sd
time for request:       21us       674us        29us         6us    95.31%
time for connect:      404us       404us       404us         0us   100.00%
time to 1st byte:     1.09ms      1.09ms      1.09ms         0us   100.00%
req/s           :   32077.58    32077.58    32077.58        0.00   100.00%

1b.

❯ h2load --clients=1 --requests=100000 --max-concurrent-streams=10 --header='Content-Type: application/grpc' --data=examples/helloworld/testdata/hello.grpc-lpm.data http://localhost:7000/helloworld.v1.Greeter/Hello
starting benchmark...
spawning thread #0: 1 total client(s). 100000 total requests
Application protocol: h2c
progress: 10% done
progress: 20% done
progress: 30% done
progress: 40% done
progress: 50% done
progress: 60% done
progress: 70% done
progress: 80% done
progress: 90% done
progress: 100% done

finished in 738.27ms, 135451.07 req/s, 7.88MB/s
requests: 100000 total, 100000 started, 100000 done, 100000 succeeded, 0 failed, 0 errored, 0 timeout
status codes: 100000 2xx, 0 3xx, 0 4xx, 0 5xx
traffic: 5.82MB (6100749) total, 195.32KB (200012) headers (space savings 94.74%), 2.96MB (3100000) data
                     min         max         mean         sd        +/- sd
time for request:       25us       967us        67us        28us    92.37%
time for connect:      400us       400us       400us         0us   100.00%
time to 1st byte:      951us       951us       951us         0us   100.00%
req/s           :  135451.88   135451.88   135451.88        0.00   100.00%

2a.

❯ h2load --clients=10 --requests=100000 --header='Content-Type: application/grpc' --data=examples/helloworld/testdata/hello.grpc-lpm.data http://localhost:7000/helloworld.v1.Greeter/Hello
starting benchmark...
spawning thread #0: 10 total client(s). 100000 total requests
Application protocol: h2c
progress: 10% done
progress: 20% done
progress: 30% done
progress: 40% done
progress: 50% done
progress: 60% done
progress: 70% done
progress: 80% done
progress: 90% done
progress: 100% done

finished in 1.13s, 88804.58 req/s, 5.17MB/s
requests: 100000 total, 100000 started, 100000 done, 100000 succeeded, 0 failed, 0 errored, 0 timeout
status codes: 100000 2xx, 0 3xx, 0 4xx, 0 5xx
traffic: 5.82MB (6101120) total, 195.43KB (200120) headers (space savings 94.73%), 2.96MB (3100000) data
                     min         max         mean         sd        +/- sd
time for request:       21us      4.56ms        89us        54us    97.00%
time for connect:      711us      1.08ms       879us       145us    60.00%
time to 1st byte:     1.70ms      2.58ms      2.12ms       316us    60.00%
req/s           :    8882.84     8905.57     8893.74        7.15    60.00%

2b.

❯ h2load --clients=10 --requests=100000 --max-concurrent-streams=10 --header='Content-Type: application/grpc' --data=examples/helloworld/testdata/hello.grpc-lpm.data http://localhost:7000/helloworld.v1.Greeter/Hello
starting benchmark...
spawning thread #0: 10 total client(s). 100000 total requests
Application protocol: h2c
progress: 10% done
progress: 20% done
progress: 30% done
progress: 40% done
progress: 50% done
progress: 60% done
progress: 70% done
progress: 80% done
progress: 90% done
progress: 100% done

finished in 321.04ms, 311487.67 req/s, 18.12MB/s
requests: 100000 total, 100000 started, 100000 done, 100000 succeeded, 0 failed, 0 errored, 0 timeout
status codes: 100000 2xx, 0 3xx, 0 4xx, 0 5xx
traffic: 5.82MB (6101120) total, 195.43KB (200120) headers (space savings 94.73%), 2.96MB (3100000) data
                     min         max         mean         sd        +/- sd
time for request:       22us      8.22ms       281us       276us    98.23%
time for connect:      424us       713us       549us       109us    70.00%
time to 1st byte:     1.22ms      3.34ms      1.98ms       773us    80.00%
req/s           :   31202.62    35978.75    33143.34     1746.76    70.00%

3a.

❯ h2load --clients=100 --requests=100000 --header='Content-Type: application/grpc' --data=examples/helloworld/testdata/hello.grpc-lpm.data http://localhost:7000/helloworld.v1.Greeter/Hello
starting benchmark...
spawning thread #0: 100 total client(s). 100000 total requests
Application protocol: h2c
progress: 10% done
progress: 20% done
progress: 30% done
progress: 40% done
progress: 50% done
progress: 60% done
progress: 70% done
progress: 80% done
progress: 90% done
progress: 100% done

finished in 1.13s, 88589.50 req/s, 5.16MB/s
requests: 100000 total, 100000 started, 100000 done, 100000 succeeded, 0 failed, 0 errored, 0 timeout
status codes: 100000 2xx, 0 3xx, 0 4xx, 0 5xx
traffic: 5.82MB (6104700) total, 196.48KB (201200) headers (space savings 94.71%), 2.96MB (3100000) data
                     min         max         mean         sd        +/- sd
time for request:       53us      8.63ms       685us       303us    90.00%
time for connect:     2.01ms      5.72ms      4.68ms      1.07ms    79.00%
time to 1st byte:     9.84ms     12.29ms     11.44ms       602us    69.00%
req/s           :     886.49      889.14      887.75        0.60    69.00%

3b.

❯ h2load --clients=100 --requests=100000 --max-concurrent-streams=10 --header='Content-Type: application/grpc' --data=examples/helloworld/testdata/hello.grpc-lpm.data http://localhost:7000/helloworld.v1.Greeter/Hello
starting benchmark...
spawning thread #0: 100 total client(s). 100000 total requests
Application protocol: h2c
progress: 10% done
progress: 20% done
progress: 30% done
progress: 40% done
progress: 50% done
progress: 60% done
progress: 70% done
progress: 80% done
progress: 90% done
progress: 100% done

finished in 332.69ms, 300578.31 req/s, 17.50MB/s
requests: 100000 total, 100000 started, 100000 done, 100000 succeeded, 0 failed, 0 errored, 0 timeout
status codes: 100000 2xx, 0 3xx, 0 4xx, 0 5xx
traffic: 5.82MB (6104700) total, 196.48KB (201200) headers (space savings 94.71%), 2.96MB (3100000) data
                     min         max         mean         sd        +/- sd
time for request:       37us     19.33ms      3.15ms      1.46ms    96.60%
time for connect:     2.34ms      3.74ms      3.23ms       380us    61.00%
time to 1st byte:     6.14ms     22.34ms     18.51ms      5.55ms    78.00%
req/s           :    3006.70     3155.54     3080.28       38.38    61.00%

(grpcxx) fix to avoid idle connections blocking workers

a37d0ad

uatuko marked this pull request as ready for review January 12, 2024 10:50

(grpcxx) tidy-up

2df4cb6

uatuko merged commit b815efe into main Jan 12, 2024
5 checks passed

uatuko deleted the bugfix/idle-connections branch January 12, 2024 16:48

uatuko mentioned this pull request Jan 14, 2024

Rust benchmarks #21

Closed

uatuko mentioned this pull request Feb 2, 2024

v0.2.0 benchmark results #25

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix to avoid idle connections from blocking worker threads #20

Fix to avoid idle connections from blocking worker threads #20

uatuko commented Jan 12, 2024 •

edited

Loading

Fix to avoid idle connections from blocking worker threads #20

Fix to avoid idle connections from blocking worker threads #20

Conversation

uatuko commented Jan 12, 2024 • edited Loading

Benchmarks

Benchmark details

[2024-01-12] Multi-threaded, hardware concurrency (a37d0ad)

1a.

1b.

2a.

2b.

3a.

3b.

[2024-01-12] Multi-threaded, 2 workers (a37d0ad)

1a.

1b.

2a.

2b.

3a.

3b.

uatuko commented Jan 12, 2024 •

edited

Loading

[2024-01-12] Multi-threaded, hardware concurrency (`a37d0ad`)

[2024-01-12] Multi-threaded, 2 workers (`a37d0ad`)