search

kontena / kontena-websocket-client

Ruby websocket client library
Other
2 stars 11 forks source link

Benchmarking #13

Closed SpComb closed 7 years ago

SpComb commented 7 years ago

Preliminary results show a ~100% performance improvement from using the native websocket_mask extension: ~3000/s -> ~6000/s before overload

Results (non-dropping mode)

The benchmarks fail with write timeouts once the client saturates. This is caused by the read thread deadlocking on the blocked socket write with the driver mutex held: #14

With websocket-driver from websocket-driver-kontena (pure-ruby websocket/mask)

TIME     RATE/s     COUNT: send @  MESSAGES/s (  UTIL%   MISS%) read @  MESSAGES/s (  DROP%) =        BYTES/s ~  LATENCY
 5.00s      1/s         5: send @      1.00/s (  0.18%   0.00%) read @      1.00/s (  0.00%) =       1.003K/s ~ 0.002466s
 5.00s     10/s        50: send @     10.00/s (  2.06%   0.00%) read @     10.00/s (  0.00%) =      10.027K/s ~ 0.002729s
 5.00s    100/s       500: send @    100.00/s ( 19.82%   0.00%) read @     99.97/s (  0.00%) =     100.268K/s ~ 0.002686s
 5.00s   1000/s      5000: send @    999.97/s ( 35.95%   0.00%) read @    999.90/s (  0.00%) =       1.003M/s ~ 0.000776s
 5.00s   2500/s     12500: send @   2499.95/s ( 70.05%   0.00%) read @   2499.87/s (  0.00%) =       2.507M/s ~ 0.002333s
 5.00s   3000/s     15000: send @   2999.90/s ( 84.71%   0.00%) read @   2961.51/s (  0.00%) =       2.970M/s ~ 0.458441s
 5.00s   3500/s     17500: send @   3499.63/s ( 88.13%   0.00%) read @   3342.98/s (  0.00%) =       3.353M/s ~ 1.224913s
/home/kontena/kontena/kontena-websocket-client/lib/kontena/websocket/client/connection.rb:25:in `wait_socket_writable!': write timeout after 5.0s (Kontena::Websocket::TimeoutError)

With websocket-driver from websocket-driver (native websocket_mask extension)

TIME     RATE/s     COUNT: send @  MESSAGES/s (  UTIL%   MISS%) read @  MESSAGES/s (  DROP%) =        BYTES/s ~  LATENCY
 5.00s      1/s         5: send @      1.00/s (  0.11%   0.00%) read @      1.00/s (  0.00%) =       1.003K/s ~ 0.001730s
 5.00s     10/s        50: send @     10.00/s (  1.41%   0.00%) read @     10.00/s (  0.00%) =      10.027K/s ~ 0.002177s
 5.00s    100/s       500: send @    100.00/s ( 11.69%   0.00%) read @     99.98/s (  0.00%) =     100.284K/s ~ 0.001840s
 5.00s   1000/s      5000: send @    999.97/s ( 32.65%   0.00%) read @    999.92/s (  0.00%) =       1.003M/s ~ 0.000576s
 5.00s   2500/s     12500: send @   2499.97/s ( 37.79%   0.00%) read @   2499.87/s (  0.00%) =       2.507M/s ~ 0.000411s
 5.00s   5000/s     25000: send @   4999.87/s ( 73.90%   0.00%) read @   4936.86/s (  0.00%) =       4.952M/s ~ 0.303535s
 5.00s   5500/s     27498: send @   5499.58/s ( 74.16%   0.00%) read @   5376.22/s (  0.00%) =       5.392M/s ~ 0.413898s
 5.00s   6000/s     30000: send @   5999.56/s ( 78.46%   0.00%) read @   5571.35/s (  0.00%) =       5.588M/s ~ 1.175362s
/home/kontena/kontena/kontena-websocket-client/lib/kontena/websocket/client/connection.rb:25:in `wait_socket_writable!': write timeout after 5.0s (Kontena::Websocket::TimeoutError)

Results (drop mode)

Running the websocket-echo-server in -drop mode, where the server drops messages if it reads them faster than the client reads the echo responses. This shows that the client write thread is starving the read thread, as the write rate keeps increasing, but the read rate declines and messages start getting dropped.

With websocket-driver from websocket-driver-kontena (pure-ruby websocket/mask)

TIME     RATE/s     COUNT: send @  MESSAGES/s (  UTIL%   MISS%) read @  MESSAGES/s (  DROP%) =        BYTES/s ~  LATENCY
 5.00s      1/s         5: send @      1.00/s (  0.16%   0.00%) read @      1.00/s (  0.00%) =       1.003K/s ~ 0.002145s
 5.00s     10/s        50: send @     10.00/s (  1.43%   0.00%) read @     10.00/s (  0.00%) =      10.028K/s ~ 0.002030s
 5.00s    100/s       500: send @    100.00/s ( 16.78%   0.00%) read @     99.99/s (  0.00%) =     100.287K/s ~ 0.002330s
 5.00s   1000/s      5000: send @    999.98/s ( 42.32%   0.00%) read @    999.92/s (  0.00%) =       1.003M/s ~ 0.001917s
 5.00s   2500/s     12500: send @   2500.00/s ( 73.15%   0.00%) read @   2499.86/s (  0.00%) =       2.507M/s ~ 0.003623s
 5.00s   3000/s     15000: send @   2999.87/s ( 85.34%   0.00%) read @   2936.82/s (  0.00%) =       2.946M/s ~ 0.895454s
 5.00s   3500/s     17500: send @   3499.85/s ( 89.54%   0.00%) read @   3312.76/s (  0.00%) =       3.323M/s ~ 1.453292s
 5.00s   4000/s     19378: send @   3875.44/s ( 97.06% 100.00%) read @   1594.71/s ( 56.70%) =       1.599M/s ~ 3.601528s
 5.00s   4500/s     19314: send @   3862.74/s ( 97.07% 100.00%) read @    873.74/s ( 76.75%) =     876.365K/s ~ 4.257373s
 5.00s   6000/s     18770: send @   3753.88/s ( 96.73% 100.00%) read @   1417.77/s ( 60.48%) =       1.422M/s ~ 3.658015s
 5.00s  10000/s     16794: send @   3358.74/s ( 96.07% 100.00%) read @    863.12/s ( 73.24%) =     865.708K/s ~ 4.279212s

With websocket-driver from websocket-driver (native websocket_mask extension)

TIME     RATE/s     COUNT: send @  MESSAGES/s (  UTIL%   MISS%) read @  MESSAGES/s (  DROP%) =        BYTES/s ~  LATENCY
 5.00s      1/s         5: send @      1.00/s (  0.13%   0.00%) read @      1.00/s (  0.00%) =       1.003K/s ~ 0.001995s
 5.00s     10/s        50: send @     10.00/s (  1.34%   0.00%) read @      9.99/s (  0.00%) =      10.024K/s ~ 0.002143s
 5.00s    100/s       500: send @    100.00/s ( 11.63%   0.00%) read @     99.97/s (  0.00%) =     100.265K/s ~ 0.001838s
 5.00s   1000/s      5000: send @    999.97/s ( 30.20%   0.00%) read @    999.87/s (  0.00%) =       1.003M/s ~ 0.000610s
 5.00s   2500/s     12500: send @   2499.97/s ( 37.82%   0.00%) read @   2499.87/s (  0.00%) =       2.507M/s ~ 0.000536s
 5.00s   5000/s     25000: send @   4999.90/s ( 73.16%   0.00%) read @   4963.86/s (  0.00%) =       4.979M/s ~ 0.196671s
 5.00s   5500/s     27500: send @   5499.88/s ( 73.21%   0.00%) read @   5372.98/s (  0.00%) =       5.389M/s ~ 0.465545s
 5.00s   6000/s     30000: send @   5999.92/s ( 79.53%   0.00%) read @   5070.66/s ( 10.81%) =       5.086M/s ~ 1.182131s
 5.00s   6500/s     32479: send @   6493.83/s ( 83.61%   0.00%) read @   3825.08/s ( 37.21%) =       3.837M/s ~ 1.568008s
 5.00s   7000/s     34989: send @   6997.72/s ( 88.34%   0.00%) read @   2580.66/s ( 61.72%) =       2.588M/s ~ 2.083625s
 5.00s   8000/s     38165: send @   7632.93/s ( 94.77% 100.00%) read @    884.60/s ( 88.10%) =     887.251K/s ~ 4.527284s
 5.00s  10000/s     38030: send @   7605.86/s ( 94.69% 100.00%) read @   1644.86/s ( 77.25%) =       1.650M/s ~ 2.646985s
SpComb commented 7 years ago

Worked around the #14 issue with write timeouts onr ead deadlocks by having the server drop messages instead. The benchmarks now show that the client write thread starves the read thread, as the write rate keeps increasing while the read rate plummets, and the drop ratio goes up.