net/http2: use actual Timeout instances #17704

Fishrock123 · 2017-12-16T00:05:12Z

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)

timers, net

This PR is a re-made version of #11154

This makes net.Sockets, Http2Streams, and Http2Sessions use actual Timeout objects in a [kTimeout] symbol property, rather than making the socket/stream/session itself a timer and appending properties to it directly.

This should make the code generally easier to understand, and might also prevent some deopts from properties being changes on the socket itself.

It is possible this could minorly effect performance either better or worse, but benchmarks on net.Socket from #11154 showed little difference.

This also moves some of the Timeout prototype into the internal file but not all of it, perhaps we can do that in a later commit if desirable.

New: Also exposes a timer duration validation function, using enroll()'s validation logic.

~~Unfortunately, sometime in the past few months some HTTP change occured that I haven't been able to get past, so two tests fail.~~ 😕
This change somehow causes a clientError to be emitted in both test-http-server-keep-alive-timeout-slow-client-headers and test-http-server-keep-alive-timeout-slow-server... I added the extra temporary patch to help debug those. It seems to fail to parse the request chunk... somehow. ~~Hopefully @nodejs/http can help...~~

Test failure output in the fold

=== release test-http-server-keep-alive-timeout-slow-client-headers ===
Path: sequential/test-http-server-keep-alive-timeout-slow-client-headers
'HTTP/1.1 200 OK\r\nDate: Fri, 15 Dec 2017 23:34:02 GMT\r\nConnection: keep-alive\r\nContent-Length: 0\r\n\r\n'
{ Error: Parse Error
    at socketOnEnd (_http_server.js:424:20)
    at Socket.emit (events.js:132:15)
    at endReadableNT (_stream_readable.js:1062:12)
    at process._tickCallback (internal/process/next_tick.js:152:19) bytesParsed: 0, code: 'HPE_INVALID_EOF_STATE' }
events.js:112
      throw er; // Unhandled 'error' event
      ^

Error [ERR_STREAM_WRITE_AFTER_END]: write after end
    at writeAfterEnd (_stream_writable.js:237:12)
    at Socket.Writable.write (_stream_writable.js:289:5)
    at Socket.write (net.js:740:40)
pick a07f487c98 net: use actual Timeout instance on Sockets
    at Timeout.setTimeout [as _onTimeout] (/Users/Jeremiah/Documents/node/test/sequential/test-http-server-keep-alive-timeout-slow-client-headers.js:41:14)
    at ontimeout (timers.js:475:11)
    at tryOnTimeout (timers.js:308:5)
    at Timer.listOnTimeout (timers.js:268:5)
Command: out/Release/node /Users/Jeremiah/Documents/node/test/sequential/test-http-server-keep-alive-timeout-slow-client-headers.js
=== release test-http-server-keep-alive-timeout-slow-server ===
Path: sequential/test-http-server-keep-alive-timeout-slow-server
events.js:112
      throw er; // Unhandled 'error' event
      ^

Error: socket hang up
    at createHangUpError (_http_client.js:298:15)
    at Socket.socketOnEnd (_http_client.js:391:23)
    at Socket.emit (events.js:132:15)
    at endReadableNT (_stream_readable.js:1062:12)
    at process._tickCallback (internal/process/next_tick.js:152:19)
Command: out/Release/node /Users/Jeremiah/Documents/node/test/sequential/test-http-server-keep-alive-timeout-slow-server.js

~~CI (going to fail): https://ci.nodejs.org/job/node-test-pull-request/12145/~~

Fishrock123 · 2017-12-16T00:08:42Z

Ok so it looks like the @nodejs/http team is somewhat outdated so... maybe let's try @nodejs/http2 and see if anyone there has an idea of what's up. 🙃

addaleax

net module, timeouts, a broken test … sounds like the perfect thing for @apapirovski to take a look at 🙃

I’ll try to look at the failure myself though.

addaleax · 2017-12-16T12:01:58Z

lib/net.js

@@ -381,14 +387,36 @@ Socket.prototype.read = function(n) {
 };

 Socket.prototype.setTimeout = function(msecs, callback) {
+  // Type checking identical to timers.enroll()


This might be enough code to factor it out into some internal function, wdyt?

Might be a good idea yeah.

dougwilson · 2017-12-16T15:33:48Z

I think this PR may break the "mysql" module. I want to run the test suite, but not sure on the process. I assume this change won't be in a prebuilt nightly until it is merged, is that right?

Fishrock123 · 2017-12-16T16:17:10Z

I assume this change won't be in a prebuilt nightly until it is merged, is that right?

Correct. You'd need to build your own version of node probably. I could do an "RC" with it technically but I'm not super familiar with that process.

@dougwilson Is "mysql" in citgm?

dougwilson · 2017-12-16T16:28:15Z

Is "mysql" in citgm?

I don't see it listed. Not sure if it qualifies to be in there or not. I've looked around through the changes and how mysql is using the timers and I don't think it will be an issue. I was thinking it hooked into the socket timers but I think it is using the timers on it's own objects. I'll build a copy, no worries 👍

Fishrock123 · 2017-12-16T18:06:39Z

Ok, extracted the type checking. Not quite sure how that commit triggered it but it seems to have exposed that I also need to update the patch to include HTTP/2...

addaleax · 2017-12-16T19:32:41Z

Here’s a citgm mysql run: https://ci.nodejs.org/view/Node.js-citgm/job/citgm-smoker/1156/

There do appear to be some errors related to domains/async tracking in there…

Fishrock123 · 2017-12-16T21:21:32Z

@addaleax It appears that already occurs on master: https://ci.nodejs.org/view/Node.js-citgm/job/citgm-smoker/1157/

apapirovski · 2017-12-16T21:24:15Z

To be fair, that test is pretty brittle...

assert.equal(domain.active, null, 'query is not bound to domain');

Not sure we have any responsibility there.

dougwilson · 2017-12-16T21:36:48Z

I've never used domains and am not familiar. Domain support was contributed to the module a long time ago. What should the test be instead?

apapirovski · 2017-12-16T21:52:06Z

@dougwilson I'm looking into this more, after running it a few times, I don't think it's related to what I had initially thought. Will update when I have more info.

Fishrock123 · 2017-12-17T05:31:45Z

Added an http2 patch. I REALLY wish manual timers were never used there. We should probably just ban using enroll(), honestly.

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

Fishrock123 · 2017-12-17T05:33:20Z

lib/internal/http2/core.js

    if (msecs === 0) {
-      unenroll(this);
+      clearTimeout(this[kTimeout]);
+
      if (callback !== undefined) {


I feel like these conditionals are probably not how the API should work, but I'll leave that for another PR.

Fishrock123 · 2017-12-17T05:38:01Z

lib/internal/http2/core.js

+      this[kTimeout] = setUnrefTimeout(() => {
+        this._onTimeout();
+      }, msecs);
+      if (this[kSession]) this[kSession][kUpdateTimer]();


Seems messy but it doesn't seem like [kUpdateTimer] should create new timers? 😕

Maybe this is actually a bug? @jasnell should HTTP2Stream#setTimeout() create a new timeout on the session, if there is a session?

@Fishrock123 that line is to differentiate between HTTP2Stream and HTTP2Session, as this code is attached to both prototypes.

Understood, but why refresh the session timer from the stream with it's existing timeout? Is that really intended from here without updating the session's timeout duration to a potential new duration?

The session timeout needs to be refreshed every time any of the associated streams moves data, as the socket is there.

mcollina

LGTM

Fishrock123 · 2017-12-18T16:14:30Z

OK, I fixed the http tests issue. Turns out I was leaking timeouts but that should be fixed now by clearing an existing timeout before creating a new one.

apapirovski

This is great! 👍

apapirovski · 2017-12-18T16:17:02Z

lib/internal/http2/core.js

-      this[kUpdateTimer]();
+      clearTimeout(this[kTimeout]);
+      this[kTimeout] = setUnrefTimeout(() => {
+        this._onTimeout();


This won't be feasible for http but for http2, I think we could move this off the publicly available _onTimeout and instead onto a Symbol.

Also, I would prefer if this was bound instead of using an arrow function but that's just a minor nit.

Prefer that to be done in a separate commit. I'll switch to bind(), IIRC perf was good enough now?

Prefer that to be done in a separate commit.

I figured it could go here since this PR is what enables us to no longer use a publicly exposed method but either way works for me. 👍

Hmm, true. Not sure how I feel about it.

apapirovski · 2017-12-18T16:17:54Z

lib/net.js

  if (msecs === 0) {
-    timers.unenroll(this);
+    clearTimeout(this[kTimeout]);


Can we just move this outside of the condition since it's in both branches?

apapirovski · 2017-12-18T16:22:21Z

lib/internal/http2/core.js

+      this[kTimeout] = setUnrefTimeout(() => {
+        this._onTimeout();
+      }, msecs);
+      if (this[kSession]) this[kSession][kUpdateTimer]();


Does this actually need the conditional? Couldn't it just call this[kUpdateTimer](); like before?

that if (this[kSession]) is roughly equal to if (this instanceof HTTP2Stream)

It just seems like we could just straight up call this[kUpdateTimer]() since it has the same check in it. If this is about avoiding the _unrefActive then this call could just be moved before this[kTimeout] is declared.

What if there is no session then?

There is no point in calling this[kUpdateTimer](); on the Stream - you'll just insert the stream timer twice... Might as well move the extra conditional bit here.

A sort-of follow-up to nodejs#17704, this removes the last internal use of enroll().

A sort-of follow-up to nodejs#17704, this removes the last internal use of enroll(). PR-URL: nodejs#17800 Reviewed-By: Colin Ihrig <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Ruben Bridgewater <[email protected]> Reviewed-By: Evan Lucas <[email protected]> Reviewed-By: Minwoo Jung <[email protected]> Reviewed-By: Luigi Pinca <[email protected]> Reviewed-By: Anna Henningsen <[email protected]>

A sort-of follow-up to #17704, this removes the last internal use of enroll(). PR-URL: #17800 Reviewed-By: Colin Ihrig <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Ruben Bridgewater <[email protected]> Reviewed-By: Evan Lucas <[email protected]> Reviewed-By: Minwoo Jung <[email protected]> Reviewed-By: Luigi Pinca <[email protected]> Reviewed-By: Anna Henningsen <[email protected]>

apapirovski · 2018-02-26T15:44:28Z

@Fishrock123 Did you have a plan to backport parts of this? I noticed #18062 and #18065 depend on some of the changes here, including the fact that there's a new lib/internal/timers.js file.

There are also follow up PRs that landed since that aren't semver-major but depend on some of the changes here.

I would be happy to help, if needed.

Fishrock123 · 2018-02-26T16:00:52Z

No, I don’t really have time to do backports...

apapirovski · 2018-02-26T16:03:27Z

No worries. I'll try to figure out a way we can get this backported. I assume we should be able to do it if we just exclude the net changes.

A bug was introduced in nodejs#17704 which meant that subsequent calls to enroll would unset the new _idleTimeout and the enrolled object could never again function as a timer.

A bug was introduced in #17704 which meant that subsequent calls to enroll would unset the new _idleTimeout and the enrolled object could never again function as a timer. PR-URL: #19936 Reviewed-By: Benjamin Gruenbaum <[email protected]> Reviewed-By: Ruben Bridgewater <[email protected]> Reviewed-By: Rich Trott <[email protected]> Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Jeremiah Senkpiel <[email protected]>

Fishrock123 added this to the 10.0.0 milestone Dec 16, 2017

nodejs-github-bot added build Issues and PRs related to build files or the CI. net Issues and PRs related to the net subsystem. timers Issues and PRs related to the timers subsystem / setImmediate, setInterval, setTimeout. labels Dec 16, 2017

Fishrock123 removed the build Issues and PRs related to build files or the CI. label Dec 16, 2017

addaleax approved these changes Dec 16, 2017

View reviewed changes

Fishrock123 commented Dec 17, 2017

View reviewed changes

Fishrock123 changed the title ~~net: use actual Timeout instances on Sockets~~ net/http2: use actual Timeout instances Dec 17, 2017

Fishrock123 added the http2 Issues or PRs related to the http2 subsystem. label Dec 17, 2017

mcollina approved these changes Dec 18, 2017

View reviewed changes

jasnell approved these changes Dec 18, 2017

View reviewed changes

Fishrock123 force-pushed the use-timeout-in-net-socket branch from dbfcce7 to c396b24 Compare December 18, 2017 16:14

apapirovski approved these changes Dec 18, 2017

View reviewed changes

Fishrock123 mentioned this pull request Dec 21, 2017

http: convert utcDate to use setTimeout #17800

Closed

2 tasks

Fishrock123 added a commit to Fishrock123/node that referenced this pull request Dec 21, 2017

http: convert utcDate to use setTimeout

1672f00

A sort-of follow-up to nodejs#17704, this removes the last internal use of enroll().

targos mentioned this pull request Jan 9, 2018

http2: backport changes to v9.x-staging #18050

Closed

4 tasks

addaleax added the backport-requested-v9.x label Mar 5, 2018

addaleax mentioned this pull request Oct 20, 2018

http2: simplify timeout tracking #19206

Closed

2 tasks

net/http2: use actual Timeout instances #17704

net/http2: use actual Timeout instances #17704

Conversation

Fishrock123 commented Dec 16, 2017 • edited Loading

Checklist

Affected core subsystem(s)

Fishrock123 commented Dec 16, 2017 • edited Loading

addaleax left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dougwilson commented Dec 16, 2017

Fishrock123 commented Dec 16, 2017 • edited Loading

dougwilson commented Dec 16, 2017

Fishrock123 commented Dec 16, 2017

addaleax commented Dec 16, 2017

Fishrock123 commented Dec 16, 2017

apapirovski commented Dec 16, 2017

dougwilson commented Dec 16, 2017

apapirovski commented Dec 16, 2017

Fishrock123 commented Dec 17, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Fishrock123 Dec 17, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

mcollina left a comment

Choose a reason for hiding this comment

Fishrock123 commented Dec 18, 2017

apapirovski left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

apapirovski commented Feb 26, 2018

Fishrock123 commented Feb 26, 2018

apapirovski commented Feb 26, 2018

Fishrock123 commented Dec 16, 2017 •

edited

Loading

Fishrock123 commented Dec 16, 2017 •

edited

Loading

Fishrock123 commented Dec 16, 2017 •

edited

Loading

Fishrock123 Dec 17, 2017 •

edited

Loading