[performance] #5

robbdempsey · 2018-06-26T13:47:50Z

This PR makes a few changes

switch up how the app runs so doctor and flame have no issues.
adds a test related to the /flights
cleans up old and unused code/files

The test uses autocannon to request all flight data for a specific airport. This produces two queries. One to lookup the flight segments and the other the flights for those segments.

30 flight segments
174 flights

{ title: 'acmeair-flights',
  url: 'http://localhost:9080/rest/api/flights',
  socketPath: undefined,
  requests: 
   { average: 1981.77,
     mean: 1981.77,
     stddev: 1147.01,
     min: 84,
     max: 3007,
     total: 59442,
     sent: 59452 },
  latency: 
   { average: 4.54,
     mean: 4.54,
     stddev: 11.68,
     min: 0,
     max: 535.202768,
     p50: 3,
     p75: 4,
     p90: 5,
     p99: 64,
     p999: 114,
     p9999: 512,
     p99999: 535 },
  throughput: 
   { average: 2465792,
     mean: 2465792,
     stddev: 2925581.02,
     min: 557436,
     max: 9425066,
     total: 74525076 },
  errors: 0,
  timeouts: 0,
  duration: 30,
  start: 2018-06-26T13:25:14.298Z,
  finish: 2018-06-26T13:25:44.332Z,
  connections: 10,
  pipelining: 1,
  non2xx: 58299,
  '1xx': 0,
  '2xx': 1143,
  '3xx': 0,
  '4xx': 0,
  '5xx': 58299 }

Using the test for the flights against the API while clinic doctor is running produces graphs like below:

The current app on this PR doesn't approach the flight query the same as the original. The original was only looking up one flight segment, which then would produce one flight. The autocannon results against the older code looked like this:

{ title: 'acmeair-flights-old-code',
  url: 'http://localhost:9080/rest/api/flights/queryflights',
  socketPath: undefined,
  requests: 
   { average: 495.2,
     mean: 495.2,
     stddev: 141.3,
     min: 105,
     max: 662,
     total: 4952,
     sent: 4962 },
  latency: 
   { average: 19.69,
     mean: 19.69,
     stddev: 45.62,
     min: 3,
     max: 1026.932729,
     p50: 17,
     p75: 21,
     p90: 26,
     p99: 48,
     p999: 1022,
     p9999: 1026,
     p99999: 1026 },
  throughput: 
   { average: 389324.8,
     mean: 389324.8,
     stddev: 110145.28,
     min: 82635,
     max: 520994,
     total: 3897224 },
  errors: 0,
  timeouts: 0,
  duration: 10,
  start: 2018-06-21T18:48:15.477Z,
  finish: 2018-06-21T18:48:25.517Z,
  connections: 10,
  pipelining: 1,
  non2xx: 0,
  '1xx': 0,
  '2xx': 4952,
  '3xx': 0,
  '4xx': 0,
  '5xx': 0 }

The performance increase looks significant with these changes, but I'd like someone to take a look and make sure the results I'm generating are reality.

cc: @jasnell @mcollina

related: #3

autocannon tests that will run against the flights routes of the old and new code

switches up the way we run the app. clinic flame was having issues with fastify-cli not providing enough context. doctor and flame both work with this version

mcollina

Very good work! I've left a couple of notes.
It's impressive how better this is.

mcollina · 2018-06-26T14:10:07Z

test/perf-flights.js

+  connections: 10,
+  pipelining: 1,
+  duration: 30
+}, console.log)


V8 optimizes code as it runs, so it's better to run the test twice, and only print the second result. The results should improve.

Also, you should add https://github.com/mcollina/autocannon#autocannontrackinstance-opts so that it prints a nice progress bar (and output) as it runs.

mcollina · 2018-06-26T14:10:44Z

test/perf-all-flights.js

@@ -0,0 +1,19 @@
+'use strict'


I would move these under a benchmarks/ folder.

mcollina · 2018-06-26T14:12:43Z

Did you run Doctor on old-acmeair?

AndreasMadsen · 2018-06-26T14:15:21Z

Your standard deviation is crazy high so I doubt it is statistically significant. But mathematically it is impossible to say without knowing how many observations the mean and stddev. were sampled from. And as far as I can tell, that information is not provided by the autocannon output.

AndreasMadsen · 2018-06-26T14:16:20Z

Also, am I correct in understanding the only difference is adding the under-pressure plugin and the poolSize option?

robbdempsey · 2018-06-26T14:17:32Z

@mcollina I have not run doctor on the old one. Do you think its worth running?

@AndreasMadsen the PR adds that plugin and the autocannon scripts currently located under /test

moving autocannon scripts to benchmarks

mcollina · 2018-06-26T14:36:07Z

Your standard deviation is crazy high so I doubt it is statistically significant. But mathematically it is impossible to say without knowing how many observations the mean and stddev. were sampled from. And as far as I can tell, that information is not provided by the autocannon output.

The approach that autocannon takes is that it samples once per second the number of requests that happened within that second (https://github.com/mcollina/autocannon/blob/master/lib/run.js#L119-L122). So, it's 30 samples. Would you mind to open an issue in https://github.com/mcollina/autocannon on how to better record this? I think this area can definitely be improved.

Having a minum of 87 req/s vs a max of 3000 req/s tells that there is something weird happening somewhere. My bet is something database-related.

All of this being said, the amount of total requests completed successfully is 59452 vs 4962, which is staggering.

robbdempsey · 2018-06-27T11:26:11Z

results from the old code with doctor

Running 30s test @ http://localhost:9080/rest/api/flights/queryflights
10 connections

Stat         Avg    Stdev   Max     
Latency (ms) 20.21  27.21   1029.41 
Req/Sec      482.9  85.85   615     
Bytes/Sec    380 kB 66.7 kB 484 kB  

14k requests in 30s, 11.4 MB read
null { title: 'acmeair-flights-old-code',
  url: 'http://localhost:9080/rest/api/flights/queryflights',
  socketPath: undefined,
  requests: 
   { average: 482.9,
     mean: 482.9,
     stddev: 85.85,
     min: 183,
     max: 615,
     total: 14487,
     sent: 14497 },
  latency: 
   { average: 20.21,
     mean: 20.21,
     stddev: 27.21,
     min: 4,
     max: 1029.417518,
     p50: 18,
     p75: 22,
     p90: 27,
     p99: 41,
     p999: 85,
     p9999: 1026,
     p99999: 1029 },
  throughput: 
   { average: 380381.87,
     mean: 380381.87,
     stddev: 66667.43,
     min: 144021,
     max: 484005,
     total: 11401269 },
  errors: 0,
  timeouts: 0,
  duration: 30,
  start: 2018-06-27T11:20:21.592Z,
  finish: 2018-06-27T11:20:51.627Z,
  connections: 10,
  pipelining: 1,
  non2xx: 0,
  '1xx': 0,
  '2xx': 14487,
  '3xx': 0,
  '4xx': 0,
  '5xx': 0 }

robbdempsey · 2018-06-27T11:46:24Z

steps

npm start
run autocannon twice

results

these are the results from the second run on autocannon.

Running 30s test @ http://localhost:9080/rest/api/flights
10 connections

Stat         Avg     Stdev   Max   
Latency (ms) 59.56   15.94   154.9 
Req/Sec      166.4   15.58   197   
Bytes/Sec    16.1 MB 1.51 MB 19 MB 

5k requests in 30s, 481 MB read
null { title: 'acmeair-flights',
  url: 'http://localhost:9080/rest/api/flights',
  socketPath: undefined,
  requests: 
   { average: 166.4,
     mean: 166.4,
     stddev: 15.58,
     min: 135,
     max: 197,
     total: 4992,
     sent: 5002 },
  latency: 
   { average: 59.56,
     mean: 59.56,
     stddev: 15.94,
     min: 21,
     max: 154.908149,
     p50: 57,
     p75: 69,
     p90: 80,
     p99: 108,
     p999: 141,
     p9999: 154,
     p99999: 154 },
  throughput: 
   { average: 16086903.47,
     mean: 16086903.47,
     stddev: 1512706.92,
     min: 13013865,
     max: 18990603,
     total: 481223808 },
  errors: 0,
  timeouts: 0,
  duration: 30,
  start: 2018-06-27T11:43:13.392Z,
  finish: 2018-06-27T11:43:43.420Z,
  connections: 10,
  pipelining: 1,
  non2xx: 0,
  '1xx': 0,
  '2xx': 4992,
  '3xx': 0,
  '4xx': 0,
  '5xx': 0 }

old acmeair

Running 30s test @ http://localhost:9080/rest/api/flights/queryflights
10 connections

Stat         Avg    Stdev   Max    
Latency (ms) 16.18  7.95    212.33 
Req/Sec      599.37 46.6    677    
Bytes/Sec    472 kB 38.1 kB 533 kB 

18k requests in 30s, 14.2 MB read
null { title: 'acmeair-flights-old-code',
  url: 'http://localhost:9080/rest/api/flights/queryflights',
  socketPath: undefined,
  requests: 
   { average: 599.37,
     mean: 599.37,
     stddev: 46.6,
     min: 488,
     max: 677,
     total: 17981,
     sent: 17991 },
  latency: 
   { average: 16.18,
     mean: 16.18,
     stddev: 7.95,
     min: 3,
     max: 212.334212,
     p50: 15,
     p75: 19,
     p90: 24,
     p99: 38,
     p999: 61,
     p9999: 207,
     p99999: 212 },
  throughput: 
   { average: 471586.14,
     mean: 471586.14,
     stddev: 38054.37,
     min: 384056,
     max: 532799,
     total: 14151047 },
  errors: 0,
  timeouts: 0,
  duration: 30,
  start: 2018-06-27T11:40:16.140Z,
  finish: 2018-06-27T11:40:46.166Z,
  connections: 10,
  pipelining: 1,
  non2xx: 0,
  '1xx': 0,
  '2xx': 17981,
  '3xx': 0,
  '4xx': 0,
  '5xx': 0 }

robbdempsey added 9 commits June 21, 2018 17:09

[perf] adds autocannon and clinic to dev dependencies

4e27a0b

[WIP] old v new

6c26e2f

autocannon tests that will run against the flights routes of the old and new code

[mongodb] add poolSize to connection

f9ce996

[app]

f060bc0

switches up the way we run the app. clinic flame was having issues with fastify-cli not providing enough context. doctor and flame both work with this version

[clean-up] old autocannon results

e9f2d7e

[package] update dependencies and add scripts

1ed2f13

[test] 10 connections, 30s duration

7b45f42

[clean-up] unused files

3c4ebe4

[happy-lint]

d8e195e

mcollina approved these changes Jun 26, 2018

View reviewed changes

robbdempsey added 2 commits June 26, 2018 09:21

[benchmarks]

1071d40

moving autocannon scripts to benchmarks

[benchmarks] adds autocannon.track

964fb86

robbdempsey merged commit 5428237 into master Jun 27, 2018

robbdempsey deleted the perf branch June 27, 2018 11:53

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[performance] #5

[performance] #5

robbdempsey commented Jun 26, 2018 •

edited

Loading

mcollina left a comment

mcollina Jun 26, 2018

mcollina Jun 26, 2018

mcollina commented Jun 26, 2018

AndreasMadsen commented Jun 26, 2018

AndreasMadsen commented Jun 26, 2018 •

edited

Loading

robbdempsey commented Jun 26, 2018

mcollina commented Jun 26, 2018 •

edited

Loading

robbdempsey commented Jun 27, 2018

robbdempsey commented Jun 27, 2018

[performance] #5

[performance] #5

Conversation

robbdempsey commented Jun 26, 2018 • edited Loading

mcollina left a comment

Choose a reason for hiding this comment

mcollina Jun 26, 2018

Choose a reason for hiding this comment

mcollina Jun 26, 2018

Choose a reason for hiding this comment

mcollina commented Jun 26, 2018

AndreasMadsen commented Jun 26, 2018

AndreasMadsen commented Jun 26, 2018 • edited Loading

robbdempsey commented Jun 26, 2018

mcollina commented Jun 26, 2018 • edited Loading

robbdempsey commented Jun 27, 2018

robbdempsey commented Jun 27, 2018

steps

results

old acmeair

robbdempsey commented Jun 26, 2018 •

edited

Loading

AndreasMadsen commented Jun 26, 2018 •

edited

Loading

mcollina commented Jun 26, 2018 •

edited

Loading