TechEmpower / FrameworkBenchmarks

Source for the TechEmpower Framework Benchmarks project
https://www.techempower.com/benchmarks/
Other
7.64k stars 1.94k forks source link

Add the test running in out.txt and terminal #3295

Open joanhey opened 6 years ago

joanhey commented 6 years ago

In out.txt

To know when and where the problems begin. And the time of dstat, to not look the stats blindly.

Expected Behavior

--------------------------------------------------------------------------------
Started plaintext  concurrency 256
2018/02/06 19:10:00 | 1517943552.195 Dstat time
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
Started plaintext  concurrency 512
2018/02/06 19:10:20 | 1517943552.195 Dstat time
--------------------------------------------------------------------------------
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
--------------------------------------------------------------------------------
Started plaintext  concurrency 1024
2018/02/06 19:10:30 | 1517943552.195 Dstat time
--------------------------------------------------------------------------------
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
--------------------------------------------------------------------------------
  Stopping framework-x
--------------------------------------------------------------------------------

Actual Behavior

Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
Server php: 2018/02/06 19:10:00 [alert] 32170#0: 1024 worker_connections are not enough
--------------------------------------------------------------------------------
  Stopping framework-x
--------------------------------------------------------------------------------

In terminal

tfb --m benchmark When benchmarking locally, if your are looking htop, Dstats, ... you don't know what is doing the benchmark. Only when finish a test, show the json results, without any information about which test. Also the json don't show the req/s, easier to check with different durations than the total requests. Perhaps will be better to show the wrk results.

Expected Behavior

--------------------------------------------------------------------------------
Started plaintext  concurrency 256
--------------------------------------------------------------------------------
Running 15s test @ http://TFB-server:8080/plaintext
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   790.68ms  755.27ms   7.67s    95.61%
    Req/Sec   152.19    205.04     0.91k    89.45%
  Latency Distribution
     50%  596.39ms
     75%  756.29ms
     90%    1.19s 
     99%    4.99s 
  3923 requests in 15.07s, 2.55MB read
  Socket errors: connect 0, read 0, write 0, timeout 44
Requests/sec:    260.27
Transfer/sec:    173.29KB
STARTTIME 1518551389
ENDTIME 1518551404
--------------------------------------------------------------------------------
Started plaintext  concurrency 512
--------------------------------------------------------------------------------
Running 15s test @ http://TFB-server:8080/plaintext
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   790.68ms  755.27ms   7.67s    95.61%
    Req/Sec   152.19    205.04     0.91k    89.45%
  Latency Distribution
     50%  596.39ms
     75%  756.29ms
     90%    1.19s 
     99%    4.99s 
  3923 requests in 15.07s, 2.55MB read
  Socket errors: connect 0, read 0, write 0, timeout 44
Requests/sec:    260.27
Transfer/sec:    173.29KB
STARTTIME 1518551389
ENDTIME 1518551404
--------------------------------------------------------------------------------
Started db concurrency 256
--------------------------------------------------------------------------------
...

Actual Behavior


INFO:root:Benchmarking
Benchmark results:
{'results': [{'endTime': 1518787736,
              'latencyAvg': '15.27ms',
              'latencyMax': '64.67ms',
              'latencyStdev': '6.51ms',
              'startTime': 1518787676,
              'totalRequests': 31734},
             {'endTime': 1518787798,
              'latencyAvg': '30.44ms',
              'latencyMax': '168.01ms',
              'latencyStdev': '12.70ms',
              'startTime': 1518787738,
              'totalRequests': 31931},
             {'endTime': 1518787860,
              'latencyAvg': '61.38ms',
              'latencyMax': '216.13ms',
              'latencyStdev': '24.09ms',
              'startTime': 1518787800,
              'totalRequests': 31466},
             {'endTime': 1518787922,
              'latencyAvg': '126.88ms',
              'latencyMax': '661.41ms',
              'latencyStdev': '35.82ms',
              'startTime': 1518787862,
              'totalRequests': 30334},
             {'endTime': 1518787984,
              'latencyAvg': '272.43ms',
              'latencyMax': '3.88s',
              'latencyStdev': '222.05ms',
              'startTime': 1518787924,
              'totalRequests': 30516},
             {'connect': 0,
              'endTime': 1518788046,
              'latencyAvg': '568.44ms',
              'latencyMax': '7.92s',
              'latencyStdev': '506.73ms',
              'read': 0,
              'startTime': 1518787986,
              'timeout': 37,
              'totalRequests': 28512,
              'write': 0}]}
Benchmark results:
{'results': [{'connect': 0,
              'endTime': 1518788185,
              'latencyAvg': '576.81ms',
              'latencyMax': '7.90s',
              'latencyStdev': '509.39ms',
              'read': 0,
              'startTime': 1518788124,
              'timeout': 25,
              'totalRequests': 28309,
              'write': 0},
             {'endTime': 1518788247,
              'latencyAvg': '709.20ms',
              'latencyMax': '5.68s',
              'latencyStdev': '442.51ms',
              'startTime': 1518788187,
              'totalRequests': 22294},
             {'connect': 0,
              'endTime': 1518788309,
              'latencyAvg': '787.28ms',
              'latencyMax': '7.98s',
              'latencyStdev': '526.70ms',
              'read': 0,
              'startTime': 1518788249,
              'timeout': 34,
              'totalRequests': 19728,
              'write': 0},
             {'endTime': 1518788371,
              'latencyAvg': '923.36ms',
              'latencyMax': '7.69s',
              'latencyStdev': '621.00ms',
              'startTime': 1518788311,
              'totalRequests': 16870},
             {'connect': 0,
              'endTime': 1518788433,
              'latencyAvg': '891.47ms',
              'latencyMax': '7.80s',
              'latencyStdev': '510.11ms',
              'read': 0,
              'startTime': 1518788373,
              'timeout': 107,
              'totalRequests': 15715,
              'write': 0}]}
Benchmark results:
{'results': [{'endTime': 1518788571,
              'latencyAvg': '639.26ms',
              'latencyMax': '5.39s',
              'latencyStdev': '359.95ms',
              'startTime': 1518788511,
              'totalRequests': 24647},
             {'endTime': 1518788633,
              'latencyAvg': '926.89ms',
              'latencyMax': '4.59s',
              'latencyStdev': '479.44ms',
              'startTime': 1518788573,
              'totalRequests': 16831},
             {'endTime': 1518788695,
              'latencyAvg': '1.29s',
              'latencyMax': '5.07s',
              'latencyStdev': '739.68ms',
              'startTime': 1518788635,
              'totalRequests': 11952},
             {'connect': 0,
              'endTime': 1518788758,
              'latencyAvg': '1.80s',
              'latencyMax': '7.39s',
              'latencyStdev': '935.09ms',
              'read': 0,
              'startTime': 1518788697,
              'timeout': 1,
              'totalRequests': 8643,
              'write': 0},
             {'endTime': 1518788820,
              'latencyAvg': '2.18s',
              'latencyMax': '6.06s',
              'latencyStdev': '914.02ms',
              'startTime': 1518788760,
              'totalRequests': 6907}]}
Benchmark results:
{'results': [{'endTime': 1518788958,
              'latencyAvg': '15.77ms',
              'latencyMax': '69.99ms',
              'latencyStdev': '7.03ms',
              'startTime': 1518788898,
              'totalRequests': 30732},
             {'endTime': 1518789020,
              'latencyAvg': '31.14ms',
              'latencyMax': '144.31ms',
              'latencyStdev': '11.66ms',
              'startTime': 1518788960,
              'totalRequests': 31007},
             {'endTime': 1518789082,
              'latencyAvg': '62.52ms',
              'latencyMax': '189.79ms',
              'latencyStdev': '20.19ms',
              'startTime': 1518789022,
              'totalRequests': 30807},
             {'endTime': 1518789144,
              'latencyAvg': '127.20ms',
              'latencyMax': '752.99ms',
              'latencyStdev': '41.93ms',
              'startTime': 1518789084,
              'totalRequests': 30356},
             {'endTime': 1518789207,
              'latencyAvg': '300.75ms',
              'latencyMax': '3.27s',
              'latencyStdev': '270.02ms',
              'startTime': 1518789146,
              'totalRequests': 28642},
             {'endTime': 1518789269,
              'latencyAvg': '567.14ms',
              'latencyMax': '4.59s',
              'latencyStdev': '351.54ms',
              'startTime': 1518789209,
              'totalRequests': 27671}]}
framework-raw: setup.sh and framework processes have terminated
Server framework-raw: Framework processes have terminated
benchmark: 100% |#################################################################################################################| Rough Time: 00:32:14
================================================================================
  Parsing Results ...
================================================================================

WARNING:root:Framework http4k does not define a default test in benchmark_config.json
fatal: Not a git repository (or any of the parent directories): .git
WARNING:root:Framework http4k does not define a default test in benchmark_config.json
WARNING:root:Framework http4k does not define a default test in benchmark_config.json
================================================================================
  Verification Summary

| Test: framework-raw
|       query         : PASS
|       db            : PASS
|       update        : PASS
|       fortune       : PASS
================================================================================

Time to complete: 1938 seconds
Results are saved in /home/vagrant/FrameworkBenchmarks/results/20180216132227

Also fix Framework http4k

To not show in every bench this:

WARNING:root:Framework http4k does not define a default test in benchmark_config.json
fatal: Not a git repository (or any of the parent directories): .git
WARNING:root:Framework http4k does not define a default test in benchmark_config.json
WARNING:root:Framework http4k does not define a default test in benchmark_config.json

PD: What gui do you use to look at the stats of dstat?

michaelhixson commented 6 years ago

Thanks for fixing that http4k warning! (edit: oops, this is an issue not a PR)

Someone on our mailing list recommended this tool for viewing dstat data: https://lamada.eu/dstat-graph/#