Fix a bunch of HTTP measurement and handling issues #1047

na-- · 2019-06-10T16:23:15Z

This should fix #1041, fix #1044, fix #925, and also fix a potential minor data race in the httpext.Tracer! Hopefully, without introducing new bugs or performance regressions...

While investigating this, I realized that we should up the priority of fixing the HTTP digest authentication: #800

This should fix #1041, #1044, #925, and a potential minor data race! Hopefully, without introducing new bugs or preformance regressions...

na-- · 2019-06-10T17:31:46Z

Benchmarks comparing this branch and master with the same test script from #794 (comment):

This PR:

    data_received..............: 14 GB  232 MB/s
    data_sent..................: 26 MB  428 kB/s
    http_req_blocked...........: avg=250.72µs min=1.6µs   med=2.8µs    max=782.86ms p(90)=4.08µs   p(95)=5.74µs  
    http_req_connecting........: avg=26.95µs  min=0s      med=0s       max=37.43ms  p(90)=0s       p(95)=0s      
    http_req_duration..........: avg=39.39ms  min=84.72µs med=19.08ms  max=506.28ms p(90)=104.04ms p(95)=137.57ms
    http_req_receiving.........: avg=703.28µs min=12.12µs med=45.1µs   max=366.25ms p(90)=320.65µs p(95)=1.35ms  
    http_req_sending...........: avg=38.14µs  min=4.89µs  med=8.94µs   max=39.07ms  p(90)=20.32µs  p(95)=83.25µs 
    http_req_tls_handshaking...: avg=0s       min=0s      med=0s       max=0s       p(90)=0s       p(95)=0s      
    http_req_waiting...........: avg=38.65ms  min=42.43µs med=18.36ms  max=481.31ms p(90)=102.76ms p(95)=135.94ms
    http_reqs..................: 260000 4247.107964/s
    iteration_duration.........: avg=305.41ms min=16.31ms med=290.03ms max=1.16s    p(90)=473.71ms p(95)=531.21ms
    iterations.................: 10000  163.350306/s
    vus........................: 50     min=50 max=50
    vus_max....................: 50     min=50 max=50

57.29user 14.28system 1:03.54elapsed 112%CPU (0avgtext+0avgdata 865536maxresident)k
0inputs+0outputs (0major+222838minor)pagefaults 0swaps
/usr/bin/time k6 run test_case.js  57.30s user 14.29s system 112% cpu 1:03.55 total

master:

    data_received..............: 14 GB  220 MB/s
    data_sent..................: 26 MB  406 kB/s
    http_req_blocked...........: avg=337.5µs  min=1.61µs  med=2.81µs   max=717.91ms p(90)=4.1µs    p(95)=5.85µs  
    http_req_connecting........: avg=34.59µs  min=0s      med=0s       max=83.22ms  p(90)=0s       p(95)=0s      
    http_req_duration..........: avg=41.08ms  min=54.52µs med=18.91ms  max=597.72ms p(90)=109.88ms p(95)=147.07ms
    http_req_receiving.........: avg=41.94µs  min=5.2µs   med=14.38µs  max=42.37ms  p(90)=56.36µs  p(95)=94.92µs 
    http_req_sending...........: avg=41.91µs  min=4.98µs  med=8.96µs   max=51.18ms  p(90)=20.83µs  p(95)=83.65µs 
    http_req_tls_handshaking...: avg=0s       min=0s      med=0s       max=0s       p(90)=0s       p(95)=0s      
    http_req_waiting...........: avg=41ms     min=36.45µs med=18.82ms  max=597.69ms p(90)=109.79ms p(95)=146.97ms
    http_reqs..................: 260000 4026.740937/s
    iteration_duration.........: avg=322.15ms min=13.26ms med=305.36ms max=1.04s    p(90)=508.75ms p(95)=579.46ms
    iterations.................: 10000  154.874651/s
    vus........................: 50     min=50 max=50
    vus_max....................: 50     min=50 max=50

58.94user 14.59system 1:07.19elapsed 109%CPU (0avgtext+0avgdata 844524maxresident)k
0inputs+0outputs (0major+217122minor)pagefaults 0swaps
/usr/bin/time k6 run test_case.js  58.95s user 14.60s system 109% cpu 1:07.20 total

The slightly better results for the code of this PR are probably a fluke, since I'm not doing anything that could speed the process up. Quite the opposite, these fixes add 2 mutex operations for each HTTP request... But it probably means that there aren't any huge performance regressions with the new code.

codecov · 2019-06-11T05:31:10Z

Codecov Report

Merging #1047 into master will increase coverage by 0.17%.
The diff coverage is 90.2%.

@@            Coverage Diff             @@
##           master    #1047      +/-   ##
==========================================
+ Coverage   72.64%   72.81%   +0.17%     
==========================================
  Files         133      133              
  Lines        9848     9882      +34     
==========================================
+ Hits         7154     7196      +42     
+ Misses       2276     2270       -6     
+ Partials      418      416       -2

Impacted Files	Coverage Δ
lib/testutils/httpmultibin.go	`95.45% <100%> (+0.16%)`	⬆️
lib/netext/httpext/tracer.go	`98.26% <100%> (+0.04%)`	⬆️
lib/netext/httpext/request.go	`88.49% <84.5%> (+0.15%)`	⬆️
lib/netext/httpext/transport.go	`96.05% <95.31%> (+6.39%)`	⬆️
js/runner.go	`85.54% <0%> (+0.8%)`	⬆️
js/bundle.go	`83.33% <0%> (+1.24%)`	⬆️
lib/netext/httpext/response.go	`76.92% <0%> (+5.12%)`	⬆️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update b8ea29d...cf000d7. Read the comment docs.

codecov · 2019-06-11T05:31:10Z

Codecov Report

Merging #1047 into master will increase coverage by 0.11%.
The diff coverage is 89.2%.

@@            Coverage Diff             @@
##           master    #1047      +/-   ##
==========================================
+ Coverage   72.67%   72.79%   +0.11%     
==========================================
  Files         133      133              
  Lines        9846     9878      +32     
==========================================
+ Hits         7156     7191      +35     
+ Misses       2274     2271       -3     
  Partials      416      416

Impacted Files	Coverage Δ
lib/netext/httpext/tracer.go	`98.26% <100%> (+0.04%)`	⬆️
lib/netext/httpext/request.go	`88.04% <82.85%> (-0.29%)`	⬇️
lib/netext/httpext/transport.go	`96.05% <95.31%> (+6.39%)`	⬆️
lib/netext/httpext/response.go	`76.92% <0%> (+5.12%)`	⬆️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 607b63c...2bf26be. Read the comment docs.

lib/netext/httpext/request.go

mstoykov

Seems pretty good. I don't see any reason why this should be buggy (apart from some magical transport reuse that we are not aware in the stdlib).
Can you add the benchmark as well, as a benchmark :) possibly hitting the local httpbin .

lib/netext/httpext/request.go

lib/netext/httpext/transport.go

na-- · 2019-06-11T08:04:35Z

Can you add the benchmark as well, as a benchmark :) possibly hitting the local httpbin .

It's going to be a bit tricky to do, but I'll see if I can't work it in. The Go benchmarking logic should hopefully somewhat compensate for the lack of the multiple VUs and no k6 scheduling, though I'm not sure about the buffer pools. It think that benchmark will probably return more reliable results, but they won't be as realistic as the ones from the full end-to-end test.

js/modules/k6/http/request_test.go

lib/netext/httpext/request.go

mstoykov

LGTM. Can you put the benchcmp results from before to now in the commit message when you merge? Maybe in the PR as well

na-- · 2019-06-13T10:27:04Z

Not ideal, but... https://twitter.com/CodeWisdom/status/1136250570455605249

benchmark                                      old ns/op     new ns/op     delta
BenchmarkHandlingOfResponseBodies/text-4       88628185      90169724      +1.74%
BenchmarkHandlingOfResponseBodies/binary-4     88821807      90402150      +1.78%
BenchmarkHandlingOfResponseBodies/none-4       87605321      88749469      +1.31%

benchmark                                      old allocs     new allocs     delta
BenchmarkHandlingOfResponseBodies/text-4       255475         255597         +0.05%
BenchmarkHandlingOfResponseBodies/binary-4     256182         256332         +0.06%
BenchmarkHandlingOfResponseBodies/none-4       255493         255517         +0.01%

benchmark                                      old bytes     new bytes     delta
BenchmarkHandlingOfResponseBodies/text-4       21949431      21784999      -0.75%
BenchmarkHandlingOfResponseBodies/binary-4     20212931      21772523      +7.72%
BenchmarkHandlingOfResponseBodies/none-4       20217637      20123372      -0.47%

Fix a bunch of HTTP measurement and handling issues

2bf26be

This should fix #1041, #1044, #925, and a potential minor data race! Hopefully, without introducing new bugs or preformance regressions...

na-- requested a review from mstoykov June 10, 2019 16:23

mstoykov reviewed Jun 11, 2019

View reviewed changes

lib/netext/httpext/request.go Outdated Show resolved Hide resolved

na-- commented Jun 11, 2019

View reviewed changes

lib/netext/httpext/request.go Outdated Show resolved Hide resolved

mstoykov requested changes Jun 11, 2019

View reviewed changes

Fix the issues from the code review and add a benchmark

d41b6c4

golangcibot reviewed Jun 13, 2019

View reviewed changes

js/modules/k6/http/request_test.go Outdated Show resolved Hide resolved

golangcibot reviewed Jun 13, 2019

View reviewed changes

lib/netext/httpext/request.go Show resolved Hide resolved

lib/netext/httpext/request.go Outdated Show resolved Hide resolved

Fix minor CI and code issues

cf000d7

na-- force-pushed the fix-http-issues branch from 49c5e41 to cf000d7 Compare June 13, 2019 07:17

na-- requested a review from mstoykov June 13, 2019 07:18

mstoykov approved these changes Jun 13, 2019

View reviewed changes

na-- merged commit 2a2fe2c into master Jun 13, 2019

na-- deleted the fix-http-issues branch June 13, 2019 10:28

na-- mentioned this pull request Jun 13, 2019

Investigate core.js performance impacts on VU initialization and memory usage #1036

Closed

na-- mentioned this pull request Oct 18, 2019

Remove httpbin.org from tests #1207

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix a bunch of HTTP measurement and handling issues #1047

Fix a bunch of HTTP measurement and handling issues #1047

na-- commented Jun 10, 2019 •

edited

Loading

na-- commented Jun 10, 2019

codecov bot commented Jun 11, 2019 •

edited

Loading

codecov bot commented Jun 11, 2019

mstoykov left a comment

na-- commented Jun 11, 2019

mstoykov left a comment

na-- commented Jun 13, 2019

Fix a bunch of HTTP measurement and handling issues #1047

Fix a bunch of HTTP measurement and handling issues #1047

Conversation

na-- commented Jun 10, 2019 • edited Loading

na-- commented Jun 10, 2019

This PR:

codecov bot commented Jun 11, 2019 • edited Loading

Codecov Report

codecov bot commented Jun 11, 2019

Codecov Report

mstoykov left a comment

Choose a reason for hiding this comment

na-- commented Jun 11, 2019

mstoykov left a comment

Choose a reason for hiding this comment

na-- commented Jun 13, 2019

na-- commented Jun 10, 2019 •

edited

Loading

codecov bot commented Jun 11, 2019 •

edited

Loading