http: optimize by corking outgoing requests by brendanashworth · Pull Request #7946 · nodejs/node

brendanashworth · 2016-08-02T08:57:14Z

Checklist

make -j4 test (UNIX), or vcbuild test nosign (Windows) passes
commit message follows commit guidelines

Affected core subsystem(s)

http

Description of change

This commit optimizes outgoing HTTP responses by corking the socket upon each write and then uncorking on the next tick. By doing this we get to remove a "shameful hack" that is years old while at the same time fixing #7914 and getting some performance improvements.

The second commit is just a cleanup commit that makes nothing do even less nothing.

benchmarks!

 improvement significant p.value
http/simple.js c=50 chunks=0 length=1024 type="buffer" 1.79 % 6.312062e-01
http/simple.js c=50 chunks=0 length=1024 type="bytes" -0.05 % 9.835961e-01
http/simple.js c=50 chunks=0 length=102400 type="buffer" 5.62 % 1.250185e-01
http/simple.js c=50 chunks=0 length=102400 type="bytes" 504.10 % *** 3.837119e-12
http/simple.js c=50 chunks=0 length=4 type="buffer" 6.68 % ** 9.582778e-03
http/simple.js c=50 chunks=0 length=4 type="bytes" -5.70 % * 3.114749e-02
http/simple.js c=50 chunks=1 length=1024 type="buffer" 2.64 % 4.060173e-01
http/simple.js c=50 chunks=1 length=1024 type="bytes" 7.69 % * 2.072578e-02
http/simple.js c=50 chunks=1 length=102400 type="buffer" 1.05 % 6.860244e-01
http/simple.js c=50 chunks=1 length=102400 type="bytes" 43.97 % *** 1.209619e-11
http/simple.js c=50 chunks=1 length=4 type="buffer" 2.05 % 4.243028e-01
http/simple.js c=50 chunks=1 length=4 type="bytes" 2.94 % 2.278701e-01
http/simple.js c=50 chunks=4 length=1024 type="buffer" 3.99 % 1.028562e-01
http/simple.js c=50 chunks=4 length=1024 type="bytes" 93.05 % *** 6.741354e-16
http/simple.js c=50 chunks=4 length=102400 type="buffer" -0.67 % 8.158624e-01
http/simple.js c=50 chunks=4 length=102400 type="bytes" 21.27 % *** 2.395868e-05
http/simple.js c=50 chunks=4 length=4 type="buffer" 1.20 % 7.638681e-01
http/simple.js c=50 chunks=4 length=4 type="bytes" 83.91 % *** 9.042857e-12
http/simple.js c=500 chunks=0 length=1024 type="buffer" 3.91 % 2.187250e-01
http/simple.js c=500 chunks=0 length=1024 type="bytes" -3.62 % 2.884252e-01
http/simple.js c=500 chunks=0 length=102400 type="buffer" 4.06 % 1.118611e-01
http/simple.js c=500 chunks=0 length=102400 type="bytes" 462.59 % *** 1.329366e-14
http/simple.js c=500 chunks=0 length=4 type="buffer" 3.36 % 1.562332e-01
http/simple.js c=500 chunks=0 length=4 type="bytes" -6.84 % * 2.868192e-02
http/simple.js c=500 chunks=1 length=1024 type="buffer" 1.44 % 6.530913e-01
http/simple.js c=500 chunks=1 length=1024 type="bytes" 7.24 % ** 1.642590e-03
http/simple.js c=500 chunks=1 length=102400 type="buffer" -1.07 % 7.202359e-01
http/simple.js c=500 chunks=1 length=102400 type="bytes" 38.69 % *** 1.560892e-07
http/simple.js c=500 chunks=1 length=4 type="buffer" 0.22 % 9.431102e-01
http/simple.js c=500 chunks=1 length=4 type="bytes" 2.24 % 2.752881e-01
http/simple.js c=500 chunks=4 length=1024 type="buffer" 4.81 % 1.307765e-01
http/simple.js c=500 chunks=4 length=1024 type="bytes" 86.55 % *** 9.028564e-15
http/simple.js c=500 chunks=4 length=102400 type="buffer" 0.91 % 7.931741e-01
http/simple.js c=500 chunks=4 length=102400 type="bytes" 11.95 % ** 1.007196e-03
http/simple.js c=500 chunks=4 length=4 type="buffer" 3.75 % 1.063908e-01
http/simple.js c=500 chunks=4 length=4 type="bytes" 77.90 % *** 2.854701e-10

CI: https://ci.nodejs.org/job/node-test-pull-request/3498/

addaleax · 2016-08-02T09:56:41Z

CI failed with some possibly related failures:

parallel/test-https-foafssl 1 and 2
parallel/test-http-conn-reset 1 and 2
and parallel/test-http-upgrade-client2

ronkorving · 2016-08-02T10:37:10Z

Makes you wonder if this block could benefit from being changed to multiple sends like we do with Buffers:

chunk=len.toString(16)+CRLF+chunk+CRLF;ret=this._send(chunk,encoding,callback);

brendanashworth · 2016-08-03T03:19:48Z

I do think those failures are related, so I'm going to do some looking into those. @ronkorving good idea — the string concatenation could be a problem. I might try that, thanks!

I'm having slight second thoughts about my approach to this. I think the idea of corking and uncorking on the next tick (like #2020) should be in streams rather than HTTP so I'm going to put together an alternative PR with that in mind. This sort of stuff should also be available to TLS and such.

jasnell · 2016-08-03T16:10:04Z

@nodejs/http @nodejs/streams

mcollina · 2016-08-04T07:11:56Z

Maybe this might benefit from some string concatenation optimizations, e.g. https://github.com/davidmarkclements/flatstr. cc @davidmarkclements.

@brendanashworth #2020 is unrelated to this case. I agree that uncork is not the perfect API, but the cost of changing it would be very high, and we might discuss that in another issue (feel free to open!)

mcollina · 2016-08-04T07:13:18Z

This is not correct. Multiple cork() call increase the corked counter: https://github.com/nodejs/node/blob/master/lib/_stream_writable.js#L226-L230.
This needs to be a for loop that calls uncork() until corked is 0.

AFAIK that would be a backwards-incompatible change. It would change behavior in something like this:
(req,res)=>{res.cork();res.write('should not write');res.destroy();}
Because Socket#destroy() stops all IO on the socket, it isn't supposed to flush the last message. With this commit, writing to the stream will only cork it once, and thus we only uncork once, to leave the dev's previous cork-intent there. Looping until we uncork fully would write the message which I don't believe happens right now (edge case, yes 😛 )

I'm lost. Why are you uncorking on destroy then?
Probably we shouldn't.

I'm uncorking on destroy because, without it, it broke a test — leaving it corked would be backwards-incompatible as well. Unfortunately this is part of a gray area. There isn't any guarantee that the message would be flushed regardless, as net.js may not be able to write it synchronously. If the message is buffered to be written asynchronously, and res.destroy() is called before that happens, the message will not be written at all. It's an odd gray area, but this is the best way to keep code breakage down.

which test was failing?
IMHO not transmitting the data when destroy() is hit is the correct behavior of destroy(). destroy is a dangerous operation anyway. @mafintosh what do you think?
Beware that, if the socket was corked twice, we need to call enough uncork() for this to take into effect.

IMHO not transmitting the data when destroy() is hit is the correct behavior of destroy().
Yes, that's how it behaves right now. .write()can however flush the data synchronously if the socket is ready, so this has undefined behavior:
res.write('this may or may not send');res.destroy();
The data may or may not be flushed. This has been around in node forever.
Beware that, if the socket was corked twice, we need to call enough uncork() for this to take into effect.
That's not what I'm doing here — we add only a single cork, so we uncork only once. If the user wants to cork the socket, write to it and destroy it, we shouldn't flush the message. That would be backwards-incompatible.
(edit): which test was failing?
test/parallel/test-http-abort-client.js fails without this change.

IMHO not transmitting the data when destroy() is hit is the correct behavior of destroy().
Yes, that's how it behaves right now. .write() can however flush the data synchronously if the socket is ready, so this has undefined behavior:
res.write('this may or may not send');res.destroy();
The behavior of destroy() is something we should define and clarify throughout core.
I'm ok with this particular change. Can you add a reference to the failing unit test in the comment? Otherwise it will be extremely hard to make the connection when looking at the code.
Beware that, if the socket was corked twice, we need to call enough uncork() for this to take into effect.
That's not what I'm doing here — we add only a single cork, so we uncork only once. If the user wants to cork the socket, write to it and destroy it, we shouldn't flush the message. That would be backwards-incompatible.
In this PR, every time write() is called, this.connection.cork() is called. It is entirely possible that _writableState.corked is greater that one.
res.write('a')res.write('b')res.destroy()// will not uncork

The behavior of destroy() is something we should define and clarify throughout core.
Not so much destroy(), it's just the socket.write()API is weird. It returns a boolean about whether or not it works like a sync or async function. It doesn't necessarily have to be fixed, it just has to be worked around because test/parallel/test-http-abort-client.js and userland doesn't always use it perfectly. I'll add a better comment.
It is entirely possible that _writableState.corked is greater that one.
Ah, I think you're right. I'll fix that.

it's just the socket.write() API is weird. It returns a boolean about whether or not it works like a sync or async function.
This is not true. socket.write() is consistent from the point of view of the stream. It returns true if the user can keep writing, and false otherwise. From an implementation perspective, it will return true for a while after "operations become asynchronous" (that's a simplification) because of the buffering.
Add a unit test for the "write-write-destroy" use case, similar to test/parallel/test-http-abort-client.js.

mcollina · 2016-08-04T07:20:45Z

Good work! I think it is a good contribution!

brendanashworth · 2016-08-04T08:29:29Z

@mcollina thanks for your review! I like your judgement on the streams api, I might open an issue once this PR is 👍

mcollina · 2016-08-04T10:04:54Z

I think this should be semver-major.
It's probably safe to be semver-minor, but I prefer to be safe than sorry, and we are cutting v7 soon anyway.

Any other opinion?

jasnell · 2016-08-04T19:12:22Z

I happily defer to your judgement on the semveriness of it. Marking semver-major to be safe.

addaleax · 2016-08-28T13:22:04Z

New CI: https://ci.nodejs.org/job/node-test-commit/4806/

mcollina · 2016-08-28T13:56:11Z

@addaleax we are still waiting for some nits to be fixed. However, I would love to see this lands on v7.

@brendanashworth how are you with this? Do you need any help?

brendanashworth · 2016-08-28T23:02:28Z

@mcollina doing good! It's not so much the nits that I need to spend time working on, but I need to investigate the test failures. I just haven't had the time to ask rvagg for access to one of the nodes yet — I'll try to get it working within the week.

ronkorving · 2016-08-29T07:21:07Z

@brendanashworth Any updates on the suggestion I made?

jbergstroem · 2016-10-06T00:21:17Z

Just checking in! Keen on progress updates.

mcollina · 2016-10-07T01:37:12Z

@brendanashworth I would love to see this landed. Would you like somebody else to continue your work? Have you have more time to work on this?

jbergstroem · 2016-10-07T02:08:49Z

I can facilitate access to any test host if need be.

Since CI results are long gone, I rebased (no conflicts) and started a new run: https://ci.nodejs.org/job/node-test-commit/5483/

brendanashworth · 2016-10-07T03:41:32Z

Sorry about the lack of updates — I'll be doing the rest of the work on this over the long weekend 😄 happy to see that there's interest in landing this!

indutny

LGTM if CI is green and benchmarks are good!

mcollina

Good work!

LGTM with some nits to be fixed regarding comments.

mcollina · 2016-10-11T06:44:54Z

can you remove "should" here? They are corked.

got it 👍

mcollina · 2016-10-11T06:46:37Z

can you rephrase this? Something like "avoid writing an empty buffer"

mcollina

Sorry for the confusion, not LGTM yet. There is the discussion around _writableState.corked to be finalized.

mcollina · 2016-10-11T07:01:48Z

CI: https://ci.nodejs.org/job/node-test-pull-request/4451/
CITGM: https://ci.nodejs.org/view/Node.js-citgm/job/citgm-smoker/409/

brendanashworth · 2016-10-11T08:27:20Z

@mcollina thank you for your very thorough review 😅 please take another look. @ronkorving thanks for your suggestion earlier — I've incorporated it into the latest changes.

Regarding the CI and other platforms — there were problems with test-http-client-upgrade2 on freebsd and folks which seem to have gone away on the latest run. I'm not sure whether that's because its flaky or because its fixed...

mcollina

Sorry to be picky, but connectionCorkNT is needed

mcollina · 2016-10-11T08:53:48Z

do not allocate a closure here, it will slow things down considerably. Use connectionCorkNT as it was done before.

This commit opts for a simpler way to batch writes to HTTP clients into fewer packets. Instead of the complicated snafu which was before, now OutgoingMessage#write automatically corks the socket and uncorks on the next tick, allowing streams to batch them efficiently. It also makes the code cleaner and removes an ugly-ish hack.

The first change in `_writeRaw`: This reduces drops an unnecessary if check (`outputLength`), because it is redone in `_flushOutput`. It also changes an if/else statement to an if statement, because the blocks were unrelated. The second change in `write`: This consolidates code in #write() that handled different string encodings and Buffers. There was no reason to handle the encodings differently, so after splitting them based on Buffer vs encoding, the code is consolidated. This might see a speedup. Shoutout to Ron Korving <ron@ronkorving.nl> for spotting this.

brendanashworth · 2016-12-14T15:29:25Z

PTAL @mcollina 😄

edit: CI: https://ci.nodejs.org/job/node-test-pull-request/5402/

mcollina

LGTM if CI is green and the perf results are still confirmed.

mscdex · 2017-01-07T16:02:10Z

I'm seeing regressions with strong significance when both chunks <= 1 and length <= 1024 for strings (mostly the 'bytes' type in the benchmark):

 improvement significant p.value
http/simple.js c=50 chunks=0 length=1024 type="buffer" benchmarker="wrk" 2.88 % *** 1.972424e-07
http/simple.js c=50 chunks=0 length=1024 type="bytes" benchmarker="wrk" -11.54 % *** 6.466690e-32
http/simple.js c=50 chunks=0 length=102400 type="buffer" benchmarker="wrk" 2.57 % *** 3.612979e-08
http/simple.js c=50 chunks=0 length=102400 type="bytes" benchmarker="wrk" 213.15 % *** 2.030384e-32
http/simple.js c=50 chunks=0 length=4 type="buffer" benchmarker="wrk" 3.66 % *** 7.068239e-10
http/simple.js c=50 chunks=0 length=4 type="bytes" benchmarker="wrk" -12.58 % *** 5.493742e-35
http/simple.js c=50 chunks=1 length=1024 type="buffer" benchmarker="wrk" -1.17 % ** 2.759235e-03
http/simple.js c=50 chunks=1 length=1024 type="bytes" benchmarker="wrk" 0.50 % 2.348991e-01
http/simple.js c=50 chunks=1 length=102400 type="buffer" benchmarker="wrk" -0.66 % 7.578784e-02
http/simple.js c=50 chunks=1 length=102400 type="bytes" benchmarker="wrk" 354.77 % *** 3.996312e-36
http/simple.js c=50 chunks=1 length=4 type="buffer" benchmarker="wrk" -1.36 % ** 2.483386e-03
http/simple.js c=50 chunks=1 length=4 type="bytes" benchmarker="wrk" -5.23 % *** 3.465286e-14
http/simple.js c=50 chunks=4 length=1024 type="buffer" benchmarker="wrk" 0.60 % 3.069889e-01
http/simple.js c=50 chunks=4 length=1024 type="bytes" benchmarker="wrk" 775.19 % *** 7.762663e-52
http/simple.js c=50 chunks=4 length=102400 type="buffer" benchmarker="wrk" 0.36 % 3.421042e-01
http/simple.js c=50 chunks=4 length=102400 type="bytes" benchmarker="wrk" 18.99 % *** 1.534301e-32
http/simple.js c=50 chunks=4 length=4 type="buffer" benchmarker="wrk" -0.11 % 7.803265e-01
http/simple.js c=50 chunks=4 length=4 type="bytes" benchmarker="wrk" 835.54 % *** 7.120948e-51
http/simple.js c=500 chunks=0 length=1024 type="buffer" benchmarker="wrk" 3.87 % *** 4.717166e-10
http/simple.js c=500 chunks=0 length=1024 type="bytes" benchmarker="wrk" -11.26 % *** 2.732567e-33
http/simple.js c=500 chunks=0 length=102400 type="buffer" benchmarker="wrk" 2.71 % *** 6.950788e-09
http/simple.js c=500 chunks=0 length=102400 type="bytes" benchmarker="wrk" 230.10 % *** 2.497100e-43
http/simple.js c=500 chunks=0 length=4 type="buffer" benchmarker="wrk" 2.87 % *** 1.664165e-07
http/simple.js c=500 chunks=0 length=4 type="bytes" benchmarker="wrk" -11.78 % *** 1.783927e-30
http/simple.js c=500 chunks=1 length=1024 type="buffer" benchmarker="wrk" -1.56 % *** 3.648309e-04
http/simple.js c=500 chunks=1 length=1024 type="bytes" benchmarker="wrk" 0.59 % 9.217040e-02
http/simple.js c=500 chunks=1 length=102400 type="buffer" benchmarker="wrk" -0.50 % 2.265089e-01
http/simple.js c=500 chunks=1 length=102400 type="bytes" benchmarker="wrk" 406.52 % *** 2.627477e-51
http/simple.js c=500 chunks=1 length=4 type="buffer" benchmarker="wrk" -1.64 % *** 1.109017e-04
http/simple.js c=500 chunks=1 length=4 type="bytes" benchmarker="wrk" -4.80 % *** 1.372847e-14
http/simple.js c=500 chunks=4 length=1024 type="buffer" benchmarker="wrk" 0.30 % 4.962431e-01
http/simple.js c=500 chunks=4 length=1024 type="bytes" benchmarker="wrk" 24.65 % *** 2.527061e-47
http/simple.js c=500 chunks=4 length=102400 type="buffer" benchmarker="wrk" 0.31 % 5.864431e-01
http/simple.js c=500 chunks=4 length=102400 type="bytes" benchmarker="wrk" 25.25 % *** 4.540902e-49
http/simple.js c=500 chunks=4 length=4 type="buffer" benchmarker="wrk" 0.17 % 6.059476e-01
http/simple.js c=500 chunks=4 length=4 type="bytes" benchmarker="wrk" 23.39 % *** 2.387182e-40

ronkorving · 2017-03-16T09:06:06Z

@brendanashworth Any chance you could look into those performance regressions?

mscdex · 2017-05-11T21:27:58Z

A rebase is needed.

jasnell · 2017-08-24T23:27:44Z

Ping. What do we want to do with this one?

nodejs-github-bot added the http Issues or PRs related to the http subsystem. label Aug 2, 2016

brendanashworth mentioned this pull request Aug 2, 2016
HTTP OutgoingMessage _send in two packets when a Buffer is written #7914
Closed

mscdex added the performance Issues and PRs related to the performance of Node.js. label Aug 2, 2016

mcollina reviewed Aug 4, 2016
View reviewed changes

jasnell added the semver-major PRs that contain breaking changes and should be released in the next major version. label Aug 4, 2016

Trott force-pushed the master branch from b0df363 to c5ce7f4Compare September 21, 2016 00:09

indutny approved these changes Oct 8, 2016
View reviewed changes

jbergstroem mentioned this pull request Oct 9, 2016
temporary access to @brendanashworth nodejs/build#511
Closed

brendanashworth force-pushed the http-fix-cork branch 2 times, most recently from 82dee6b to f3bba20Compare October 11, 2016 06:20

mcollina approved these changes Oct 11, 2016
View reviewed changes

mcollina requested changes Oct 11, 2016
View reviewed changes

brendanashworth force-pushed the http-fix-cork branch from f3bba20 to 1311f0eCompare October 11, 2016 08:21

mcollina requested changes Oct 11, 2016
View reviewed changes

brendanashworth force-pushed the http-fix-cork branch 2 times, most recently from c109972 to ec42085Compare October 17, 2016 03:04

rvagg force-pushed the master branch 2 times, most recently from c133999 to 83c7a88Compare October 18, 2016 17:02

brendanashworth added 2 commits December 14, 2016 07:24

brendanashworth force-pushed the http-fix-cork branch from ec42085 to 6acff8fCompare December 14, 2016 15:28

mcollina approved these changes Dec 14, 2016
View reviewed changes

MylesBorins force-pushed the master branch from 8df7ee0 to 54fef67Compare February 1, 2017 01:00

jasnell added the stalled Issues and PRs that are stalled. label Mar 1, 2017

refack force-pushed the master branch from 16073c0 to fbe946bCompare April 14, 2017 04:11

mcollina mentioned this pull request Jun 9, 2017
http: always cork outgoing writes #13522
Merged
3 tasks

jasnell closed this Aug 24, 2017

Uh oh!

Uh oh!

Conversation

brendanashworth commented Aug 2, 2016• edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Checklist

Affected core subsystem(s)

Description of change

benchmarks!

Uh oh!

addaleax commented Aug 2, 2016

Uh oh!

ronkorving commented Aug 2, 2016

Uh oh!

brendanashworth commented Aug 3, 2016

Uh oh!

jasnell commented Aug 3, 2016

Uh oh!

mcollina commented Aug 4, 2016

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

brendanashworthOct 11, 2016• edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

mcollinaOct 11, 2016• edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

mcollina commented Aug 4, 2016

Uh oh!

brendanashworth commented Aug 4, 2016

Uh oh!

mcollina commented Aug 4, 2016

Uh oh!

jasnell commented Aug 4, 2016

Uh oh!

addaleax commented Aug 28, 2016

Uh oh!

mcollina commented Aug 28, 2016

Uh oh!

brendanashworth commented Aug 28, 2016

Uh oh!

ronkorving commented Aug 29, 2016

Uh oh!

jbergstroem commented Oct 6, 2016

Uh oh!

mcollina commented Oct 7, 2016

Uh oh!

jbergstroem commented Oct 7, 2016

Uh oh!

brendanashworth commented Oct 7, 2016

Uh oh!

indutny left a comment

Choose a reason for hiding this comment

Uh oh!

mcollina left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

brendanashworth commented Aug 2, 2016•
edited
Loading

brendanashworthOct 11, 2016•
edited
Loading

mcollinaOct 11, 2016•
edited
Loading

brendanashworth commented Dec 14, 2016•
edited
Loading

mscdex commented Jan 7, 2017•
edited
Loading