Python Benchmark Tools

Scenarios

In src/proto/grpc/testing/control.proto, it defines the fields of a scenario. In tools/run_tests/performance/scenario_config.py, the script generates actual scenario content that usually in json format, or piped to another script.

All Python related benchmark scenarios are:

  • netperf
  • python_generic_sync_streaming_ping_pong
  • python_protobuf_sync_streaming_ping_pong
  • python_protobuf_async_unary_ping_pong
  • python_protobuf_sync_unary_ping_pong
  • python_protobuf_sync_unary_qps_unconstrained
  • python_protobuf_sync_streaming_qps_unconstrained
  • python_protobuf_sync_unary_ping_pong_1MB

Here we picked a small but representative subset, and reduce their benchmark duration from 30 seconds to 10 seconds:

  • python_protobuf_async_unary_ping_pong
  • python_protobuf_sync_streaming_ping_pong

Why keep the scenario file if it can be generated?

Well... The tools/run_tests/performance/scenario_config.py is 1274 lines long. The intention of building these benchmark tools is reducing the complexity of existing infrastructure code. So, instead of calling layers of abstraction to generate the scenario file, keeping a valid static copy is preferable.

Also, if the use case for this tool grows beyond simple static scenarios, we can incorporate automatic generation and selection of scenarios into the tool.

How to run it?

bazel test --test_output=streamed src/python/grpcio_tests/tests/qps:basic_benchmark_test

What does the output look like?

RUNNING SCENARIO: python_protobuf_async_unary_ping_pong
I0123 00:26:04.746195000 140736237159296 driver.cc:288]                Starting server on localhost:10086 (worker #0)
D0123 00:26:04.747190000 140736237159296 ev_posix.cc:170]              Using polling engine: poll
D0123 00:26:04.747264000 140736237159296 dns_resolver_ares.cc:488]     Using ares dns resolver
I0123 00:26:04.748445000 140736237159296 subchannel.cc:869]            Connect failed: {"created":"@1548203164.748403000","description":"Failed to connect to remote host: Connection refused","errno":61,"file":"src/core/lib/iomgr/tcp_client_posix.cc","file_line":207,"os_error":"Connection refused","syscall":"connect","target_address":"ipv6:[::1]:10086"}
I0123 00:26:04.748585000 140736237159296 subchannel.cc:869]            Connect failed: {"created":"@1548203164.748564000","description":"Failed to connect to remote host: Connection refused","errno":61,"file":"src/core/lib/iomgr/tcp_client_posix.cc","file_line":207,"os_error":"Connection refused","syscall":"connect","target_address":"ipv4:127.0.0.1:10086"}
I0123 00:26:04.748596000 140736237159296 subchannel.cc:751]            Subchannel 0x7fca43c19360: Retry in 999 milliseconds
I0123 00:26:05.751251000 123145571299328 subchannel.cc:710]            Failed to connect to channel, retrying
I0123 00:26:05.752209000 140736237159296 subchannel.cc:832]            New connected subchannel at 0x7fca45000060 for subchannel 0x7fca43c19360
I0123 00:26:05.772291000 140736237159296 driver.cc:349]                Starting client on localhost:10087 (worker #1)
D0123 00:26:05.772384000 140736237159296 driver.cc:373]                Client 0 gets 1 channels
I0123 00:26:05.773286000 140736237159296 subchannel.cc:832]            New connected subchannel at 0x7fca45004a80 for subchannel 0x7fca451034b0
I0123 00:26:05.789797000 140736237159296 driver.cc:394]                Initiating
I0123 00:26:05.790858000 140736237159296 driver.cc:415]                Warming up
I0123 00:26:07.791078000 140736237159296 driver.cc:421]                Starting
I0123 00:26:07.791860000 140736237159296 driver.cc:448]                Running
I0123 00:26:17.790915000 140736237159296 driver.cc:462]                Finishing clients
I0123 00:26:17.791821000 140736237159296 driver.cc:476]                Received final status from client 0
I0123 00:26:17.792148000 140736237159296 driver.cc:508]                Finishing servers
I0123 00:26:17.792493000 140736237159296 driver.cc:522]                Received final status from server 0
I0123 00:26:17.795786000 140736237159296 report.cc:82]                 QPS: 2066.6
I0123 00:26:17.795799000 140736237159296 report.cc:122]                QPS: 2066.6 (258.3/server core)
I0123 00:26:17.795805000 140736237159296 report.cc:127]                Latencies (50/90/95/99/99.9%-ile): 467.9/504.8/539.0/653.3/890.4 us
I0123 00:26:17.795811000 140736237159296 report.cc:137]                Server system time: 100.00%
I0123 00:26:17.795815000 140736237159296 report.cc:139]                Server user time:   100.00%
I0123 00:26:17.795818000 140736237159296 report.cc:141]                Client system time: 100.00%
I0123 00:26:17.795821000 140736237159296 report.cc:143]                Client user time:   100.00%
I0123 00:26:17.795825000 140736237159296 report.cc:148]                Server CPU usage: 0.00%
I0123 00:26:17.795828000 140736237159296 report.cc:153]                Client Polls per Request: 0.00
I0123 00:26:17.795831000 140736237159296 report.cc:155]                Server Polls per Request: 0.00
I0123 00:26:17.795834000 140736237159296 report.cc:160]                Server Queries/CPU-sec: 1033.19
I0123 00:26:17.795837000 140736237159296 report.cc:162]                Client Queries/CPU-sec: 1033.32
RUNNING SCENARIO: python_protobuf_sync_streaming_ping_pong
I0123 00:26:17.795888000 140736237159296 driver.cc:288]                Starting server on localhost:10086 (worker #0)
D0123 00:26:17.795964000 140736237159296 ev_posix.cc:170]              Using polling engine: poll
D0123 00:26:17.795978000 140736237159296 dns_resolver_ares.cc:488]     Using ares dns resolver
I0123 00:26:17.796613000 140736237159296 subchannel.cc:832]            New connected subchannel at 0x7fca43c15820 for subchannel 0x7fca43d12140
I0123 00:26:17.810911000 140736237159296 driver.cc:349]                Starting client on localhost:10087 (worker #1)
D0123 00:26:17.811037000 140736237159296 driver.cc:373]                Client 0 gets 1 channels
I0123 00:26:17.811892000 140736237159296 subchannel.cc:832]            New connected subchannel at 0x7fca43d18f40 for subchannel 0x7fca43d16b80
I0123 00:26:17.818902000 140736237159296 driver.cc:394]                Initiating
I0123 00:26:17.820776000 140736237159296 driver.cc:415]                Warming up
I0123 00:26:19.824685000 140736237159296 driver.cc:421]                Starting
I0123 00:26:19.825970000 140736237159296 driver.cc:448]                Running
I0123 00:26:29.821866000 140736237159296 driver.cc:462]                Finishing clients
I0123 00:26:29.823259000 140736237159296 driver.cc:476]                Received final status from client 0
I0123 00:26:29.827195000 140736237159296 driver.cc:508]                Finishing servers
I0123 00:26:29.827599000 140736237159296 driver.cc:522]                Received final status from server 0
I0123 00:26:29.828739000 140736237159296 report.cc:82]                 QPS: 619.5
I0123 00:26:29.828752000 140736237159296 report.cc:122]                QPS: 619.5 (77.4/server core)
I0123 00:26:29.828760000 140736237159296 report.cc:127]                Latencies (50/90/95/99/99.9%-ile): 1589.8/1854.3/1920.4/2015.8/2204.8 us
I0123 00:26:29.828765000 140736237159296 report.cc:137]                Server system time: 100.00%
I0123 00:26:29.828769000 140736237159296 report.cc:139]                Server user time:   100.00%
I0123 00:26:29.828772000 140736237159296 report.cc:141]                Client system time: 100.00%
I0123 00:26:29.828776000 140736237159296 report.cc:143]                Client user time:   100.00%
I0123 00:26:29.828780000 140736237159296 report.cc:148]                Server CPU usage: 0.00%
I0123 00:26:29.828784000 140736237159296 report.cc:153]                Client Polls per Request: 0.00
I0123 00:26:29.828788000 140736237159296 report.cc:155]                Server Polls per Request: 0.00
I0123 00:26:29.828792000 140736237159296 report.cc:160]                Server Queries/CPU-sec: 309.58
I0123 00:26:29.828795000 140736237159296 report.cc:162]                Client Queries/CPU-sec: 309.75

Future Works (TODOs)

  1. Generate a target for each scenario.
  2. Simplify the main entrance of our benchmark related code, or make it depends on Bazel.