tls: fix writeQueueSize prop, long write timeouts #15791

apapirovski · 2017-10-06T01:19:49Z

This PR addresses a long-standing issue of _handle.writeQueueSize in TLS not representing the actual write queue (#15005), as well as the fact that long-lasting writes on both net & tls (http & https) will currently timeout if a socket timeout is set (#15082). The latter has been reported as being in relation to the keep alive timeout but in reality it's just a broad issue that is the most obvious with keep-alive since it's much shorter at 5s (vs 120s).

Make writeQueueSize represent the actual size of the write queue within the TLS socket.
Add tls test to confirm that bufferSize works as expected.

Second commit:

Add getWriteQueueSize on TLSWrap which updates and returns queue size (net & tls).
Make _onTimeout check whether an active write is ongoing and if so, call _unrefTimer rather than emitting a timeout event.
Add http & https test that checks whether long-lasting (but active) writes timeout or can finish writing as expected.

Haven't worked in C++ in a very, very long time so would definitely appreciate any and all feedback there.

Checklist

make -j4 test (UNIX), or vcbuild test (Windows) passes
tests and/or benchmarks are included
commit message follows commit guidelines

Affected core subsystem(s)

http, https, net, test, tls

mscdex · 2017-10-06T03:14:51Z

/cc @indutny

apapirovski · 2017-10-07T17:01:52Z

Just a minor update to use fixtures.readKey instead. (Indirectly benefiting and learning from code-and-learn 👍)

/cc @mcollina

mcollina · 2017-10-07T17:08:46Z

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

mcollina · 2017-10-07T17:11:35Z

Is updating this state have a performance impact? Have you tried to run our benchmarks? I think we can run them on CI if you do not have the spare CPU cycles (they take a long time).

apapirovski · 2017-10-07T18:20:02Z

I ran all the benchmarks and didn't see any discernible difference at a 100 runs. The way it's handled, it only updates it once when DoWrite is called and then when it's finished (flushed). Similar to the way it's handled in the regular net socket.

apapirovski · 2017-10-07T19:18:43Z

Might need to refactor the test a bit as it's failing on SmartOS. Will get it done this weekend. The rest seem fine.

apapirovski · 2017-10-08T06:31:12Z

I've updated the tests to, hopefully, be less flaky. Would appreciate if we could get another CI started. Thanks!

joyeecheung · 2017-10-08T06:40:25Z

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

apapirovski · 2017-10-08T14:09:41Z

Well, this might take a while. If anyone has any ideas on making these less timeout dependant (while still testing the timeout bug), I'm all ears.

apapirovski · 2017-10-08T14:53:28Z

Ok, I think this should work... ? I can run a stress test on the test on my local system now and it doesn't fail (before only 50% succeeded). Since it's still in sequential (and should stay there), I'm hoping that'll make it not fail on the slower systems.

joyeecheung · 2017-10-08T15:11:04Z

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

apapirovski · 2017-10-08T17:22:36Z

Well, this seems to succeed everywhere but SmartOS so I guess an improvement... Anyone have any suggestions by any chance? Going to try setting up a SmartOS box to test on...

apapirovski · 2017-10-08T20:24:22Z

Ok, one last try. If this doesn't fix SmartOS then there's a deeper issue that might not have anything to do with the test itself. I can run this for an hour on my system (96 instances at a time) without any failures (previous version would fail like 2.5% of the time).

(And master still fails this test 100% of the time.)

mcollina · 2017-10-09T07:45:46Z

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

apapirovski · 2017-10-09T11:48:17Z

Oops, I accidentally deleted a few characters before committing the http version of the test so it was testing with readSize of 3333 instead of 333333. No wonder it failed. Could we run the CI just on SmartOS (and OS X)?

If that doesn't work, I have one other potential direction to take this test...

mcollina · 2017-10-10T07:52:46Z

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

apapirovski · 2017-10-10T15:10:06Z

Thanks for starting it @mcollina. No luck this time either :( No clue if there's a bug in http on SmartOS related to writeQueueSize or if it's just the test. Almost done setting up a SmartOS box so I guess I'll find out...

apapirovski · 2017-10-10T16:04:42Z

Having a SmartOS box really made this easy to fix. Should be good for another CI run now.

mcollina · 2017-10-10T16:06:21Z

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

apapirovski · 2017-10-10T16:35:33Z

Thanks! Looks like it worked this time (the SmartOS failure is unrelated, it's in parallel/test-benchmark-string_decoder). Now to get some reviews... :)

ping @indutny since you know the most about the TLS code.

Add updateWriteQueueSize which updates and returns queue size (net & tls). Make _onTimeout check whether an active write is ongoing and if so, call _unrefTimer rather than emitting a timeout event. Add http & https test that checks whether long-lasting (but active) writes timeout or can finish writing as expected. PR-URL: nodejs#15791 Fixes: nodejs#15082 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: Refael Ackermann <[email protected]> Reviewed-By: Fedor Indutny <[email protected]>

This commit handles the case where _onTimeout is called with a null handle. Refs: #15791 Fixes: #16484 PR-URL: #16489 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Colin Ihrig <[email protected]> Reviewed-By: Refael Ackermann <[email protected]>

This commit handles the case where _onTimeout is called with a null handle. Refs: nodejs#15791 Fixes: nodejs#16484 PR-URL: nodejs#16489 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Colin Ihrig <[email protected]> Reviewed-By: Refael Ackermann <[email protected]>

Make writeQueueSize represent the actual size of the write queue within the TLS socket. Add tls test to confirm that bufferSize works as expected. PR-URL: nodejs/node#15791 Fixes: nodejs/node#15005 Refs: nodejs/node#15006 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: Refael Ackermann <[email protected]> Reviewed-By: Fedor Indutny <[email protected]>

Add updateWriteQueueSize which updates and returns queue size (net & tls). Make _onTimeout check whether an active write is ongoing and if so, call _unrefTimer rather than emitting a timeout event. Add http & https test that checks whether long-lasting (but active) writes timeout or can finish writing as expected. PR-URL: nodejs/node#15791 Fixes: nodejs/node#15082 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: Refael Ackermann <[email protected]> Reviewed-By: Fedor Indutny <[email protected]>

This commit handles the case where _onTimeout is called with a null handle. Refs: nodejs/node#15791 Fixes: nodejs/node#16484 PR-URL: nodejs/node#16489 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Colin Ihrig <[email protected]> Reviewed-By: Refael Ackermann <[email protected]>

Make writeQueueSize represent the actual size of the write queue within the TLS socket. Add tls test to confirm that bufferSize works as expected. PR-URL: nodejs/node#15791 Fixes: nodejs/node#15005 Refs: nodejs/node#15006 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: Refael Ackermann <[email protected]> Reviewed-By: Fedor Indutny <[email protected]>

Add updateWriteQueueSize which updates and returns queue size (net & tls). Make _onTimeout check whether an active write is ongoing and if so, call _unrefTimer rather than emitting a timeout event. Add http & https test that checks whether long-lasting (but active) writes timeout or can finish writing as expected. PR-URL: nodejs/node#15791 Fixes: nodejs/node#15082 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: Refael Ackermann <[email protected]> Reviewed-By: Fedor Indutny <[email protected]>

This commit handles the case where _onTimeout is called with a null handle. Refs: nodejs/node#15791 Fixes: nodejs/node#16484 PR-URL: nodejs/node#16489 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Colin Ihrig <[email protected]> Reviewed-By: Refael Ackermann <[email protected]>

Make writeQueueSize represent the actual size of the write queue within the TLS socket. Add tls test to confirm that bufferSize works as expected. PR-URL: nodejs#15791 Fixes: nodejs#15005 Refs: nodejs#15006 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: Refael Ackermann <[email protected]> Reviewed-By: Fedor Indutny <[email protected]>

Add updateWriteQueueSize which updates and returns queue size (net & tls). Make _onTimeout check whether an active write is ongoing and if so, call _unrefTimer rather than emitting a timeout event. Add http & https test that checks whether long-lasting (but active) writes timeout or can finish writing as expected. PR-URL: nodejs#15791 Fixes: nodejs#15082 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: Refael Ackermann <[email protected]> Reviewed-By: Fedor Indutny <[email protected]>

This commit handles the case where _onTimeout is called with a null handle. Refs: nodejs#15791 Fixes: nodejs#16484 PR-URL: nodejs#16489 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Colin Ihrig <[email protected]> Reviewed-By: Refael Ackermann <[email protected]>

Make writeQueueSize represent the actual size of the write queue within the TLS socket. Add tls test to confirm that bufferSize works as expected. Backport-PR-URL: #16420 PR-URL: #15791 Fixes: #15005 Refs: #15006 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: Refael Ackermann <[email protected]> Reviewed-By: Fedor Indutny <[email protected]>

Add updateWriteQueueSize which updates and returns queue size (net & tls). Make _onTimeout check whether an active write is ongoing and if so, call _unrefTimer rather than emitting a timeout event. Add http & https test that checks whether long-lasting (but active) writes timeout or can finish writing as expected. Backport-PR-URL: #16420 PR-URL: #15791 Fixes: #15082 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: Refael Ackermann <[email protected]> Reviewed-By: Fedor Indutny <[email protected]>

This commit handles the case where _onTimeout is called with a null handle. Backport-PR-URL: #16420 Refs: #15791 Fixes: #16484 PR-URL: #16489 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Colin Ihrig <[email protected]> Reviewed-By: Refael Ackermann <[email protected]>

Make writeQueueSize represent the actual size of the write queue within the TLS socket. Add tls test to confirm that bufferSize works as expected. Backport-PR-URL: #16420 PR-URL: #15791 Fixes: #15005 Refs: #15006 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: Refael Ackermann <[email protected]> Reviewed-By: Fedor Indutny <[email protected]>

Add updateWriteQueueSize which updates and returns queue size (net & tls). Make _onTimeout check whether an active write is ongoing and if so, call _unrefTimer rather than emitting a timeout event. Add http & https test that checks whether long-lasting (but active) writes timeout or can finish writing as expected. Backport-PR-URL: #16420 PR-URL: #15791 Fixes: #15082 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: Refael Ackermann <[email protected]> Reviewed-By: Fedor Indutny <[email protected]>

This commit handles the case where _onTimeout is called with a null handle. Backport-PR-URL: #16420 Refs: #15791 Fixes: #16484 PR-URL: #16489 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Colin Ihrig <[email protected]> Reviewed-By: Refael Ackermann <[email protected]>

nodejs-github-bot added c++ Issues and PRs that require attention from people who are familiar with C++. lib / src Issues and PRs related to general changes in the lib or src directory. labels Oct 6, 2017

apapirovski force-pushed the patch-http-keep-alive-timeout branch from bdc43c5 to fdf7a79 Compare October 7, 2017 17:00

apapirovski force-pushed the patch-http-keep-alive-timeout branch from 06f4d9f to 875872d Compare October 8, 2017 14:51

apapirovski force-pushed the patch-http-keep-alive-timeout branch from 875872d to 8969906 Compare October 8, 2017 20:20

apapirovski force-pushed the patch-http-keep-alive-timeout branch from 8969906 to daf7931 Compare October 9, 2017 11:47

mcollina requested review from refack, BridgeAR and addaleax October 10, 2017 17:28

apapirovski force-pushed the patch-http-keep-alive-timeout branch from e00c69c to caa179d Compare October 12, 2017 14:02

joyeecheung mentioned this pull request Oct 25, 2017

net.js broken in node 8.8 #16484

Closed

apapirovski mentioned this pull request Oct 25, 2017

net: fix timeout with null handle #16489

Closed

3 tasks

apapirovski added dont-land-on-v4.x and removed backport-requested-v4.x labels Jan 10, 2018

MylesBorins mentioned this pull request Jan 24, 2018

v6.13.0 proposal #18342

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

tls: fix writeQueueSize prop, long write timeouts #15791

tls: fix writeQueueSize prop, long write timeouts #15791

apapirovski commented Oct 6, 2017 •

edited

Loading

mscdex commented Oct 6, 2017

apapirovski commented Oct 7, 2017

mcollina commented Oct 7, 2017

mcollina commented Oct 7, 2017

apapirovski commented Oct 7, 2017 via email •

edited

Loading

apapirovski commented Oct 7, 2017 via email

apapirovski commented Oct 8, 2017

joyeecheung commented Oct 8, 2017

apapirovski commented Oct 8, 2017 •

edited

Loading

apapirovski commented Oct 8, 2017 •

edited

Loading

joyeecheung commented Oct 8, 2017

apapirovski commented Oct 8, 2017

apapirovski commented Oct 8, 2017 •

edited

Loading

mcollina commented Oct 9, 2017

apapirovski commented Oct 9, 2017 •

edited

Loading

mcollina commented Oct 10, 2017

apapirovski commented Oct 10, 2017

apapirovski commented Oct 10, 2017

mcollina commented Oct 10, 2017

apapirovski commented Oct 10, 2017

tls: fix writeQueueSize prop, long write timeouts #15791

tls: fix writeQueueSize prop, long write timeouts #15791

Conversation

apapirovski commented Oct 6, 2017 • edited Loading

Checklist

Affected core subsystem(s)

mscdex commented Oct 6, 2017

apapirovski commented Oct 7, 2017

mcollina commented Oct 7, 2017

mcollina commented Oct 7, 2017

apapirovski commented Oct 7, 2017 via email • edited Loading

apapirovski commented Oct 7, 2017 via email

apapirovski commented Oct 8, 2017

joyeecheung commented Oct 8, 2017

apapirovski commented Oct 8, 2017 • edited Loading

apapirovski commented Oct 8, 2017 • edited Loading

joyeecheung commented Oct 8, 2017

apapirovski commented Oct 8, 2017

apapirovski commented Oct 8, 2017 • edited Loading

mcollina commented Oct 9, 2017

apapirovski commented Oct 9, 2017 • edited Loading

mcollina commented Oct 10, 2017

apapirovski commented Oct 10, 2017

apapirovski commented Oct 10, 2017

mcollina commented Oct 10, 2017

apapirovski commented Oct 10, 2017

apapirovski commented Oct 6, 2017 •

edited

Loading

apapirovski commented Oct 7, 2017 via email •

edited

Loading

apapirovski commented Oct 8, 2017 •

edited

Loading

apapirovski commented Oct 8, 2017 •

edited

Loading

apapirovski commented Oct 8, 2017 •

edited

Loading

apapirovski commented Oct 9, 2017 •

edited

Loading