Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

http2 sessions aren't cleaned up properly, server can't close #18176

Closed
grantila opened this issue Jan 16, 2018 · 13 comments
Closed

http2 sessions aren't cleaned up properly, server can't close #18176

grantila opened this issue Jan 16, 2018 · 13 comments
Labels
http2 Issues or PRs related to the http2 subsystem.

Comments

@grantila
Copy link

  • Version: 9.4.0
  • Platform: Darwin 17.3.0
  • Subsystem: http2

9.4 (most likely #17406) broke my unit tests in fetch-h2, sessions not being closed/destroyed properly anymore. I tried to call close( ) before destroy( ) on my sessions, which would cause horrible code to support older Node.js versions:

if ( typeof session.close === 'function' ) session.close( );
session.destroy( );

but that didn't help.

Case:
My unit tests create a server and a client, does things, and then cleans up the client and server connections by terminating their corresponding sessions using session.destroy( ). Finally, I wait for the server to be closed, using server.close( resolve ); (in a promise constructor as you see). This now fails - the close callback of the server is never called. According to its spec, it'll be called when all connections are gone, so I suspect the sessions aren't cleaned up properly when destroy( ) is called.

Do you have any unit tests in Node.js that does something similar - expecting sessions to actually be cleaned up, and/or for an (H2) server's close(cb) to actually call its callback? Otherwise, I'd strongly recommend having such.

I don't have time (right now) to write a minimal code example for this, but might be able to do so eventually.

Before http2 exits its experimental status, I'd also prefer a condensed paragraph in the docs of the lifecycle management of servers, sessions and streams. It's now spread out to all different functions, callbacks and events in the very large documentation page, making an overview of the lifecycles extremely hard to grasp, and getting the lifecycle handling right is key to us users to be able to write robust code.

@jasnell
Copy link
Member

jasnell commented Jan 16, 2018

Will investigate :-)

@jasnell
Copy link
Member

jasnell commented Jan 16, 2018

I'm unable to reproduce any problem locally and the server close callbacks are being invoked. I've extended a couple of somewhat randomly selected tests and added server.close checks. Running CI now.

@jasnell
Copy link
Member

jasnell commented Jan 16, 2018

The CI run for 18182 is green with at least 4 tests that check that server.close() callbacks are being fired so things appear to be working correctly. Can I ask you to put together a more complete test case that reliably demonstrates the issue?

@jasnell jasnell added the http2 Issues or PRs related to the http2 subsystem. label Jan 16, 2018
@grantila
Copy link
Author

Yuck, that's terrible, I'm starting to think it could be on my side, but it only appears on 9.4, and there was a pretty substancial rewrite of things there, so it's most likely related at least... It could also be a misunderstanding of mine about how the session flow really did/does work.

I'll try to pin down and bisect when this happens and what exactly is causing it so that I can write a minimal reproducable test, but as we know, from a complex code base, it's sometimes easier said than done.
But I'm on it. Thanks for taking your time!

@grantila
Copy link
Author

I can see with my system monitor (and some sleeps before and after I close my client session) that when I destroy() (or both .close(); .destroy();) the client session, the socket isn't closed, it's left open! This is why my server won't close either, most likely.

Could be that I have event handlers registered, I do register handlers for practically all events... I would expect them to be de-registered as I destroy the session though, and the socket to be closed. That's an idea anyway as to what could be the reasons for this. I'll keep investigating an isolated example.

@grantila
Copy link
Author

Can't reproduce with a minimal client, but surely, when I setup an external server and run my unit test against it, it is the client that doesn't close the socket on session.destroy(); in 9.4. In a simple client example it does.
The whole purpose of fetch-h2 is to be a client wrapper, so there's a lot of code regarding client session handling :/

@jasnell
Copy link
Member

jasnell commented Jan 17, 2018

session.destroy() specifically destroys the socket here if destroy() is called with an error. It uses socket.end(), however, if no error is passed to destroy(). That is supposed to allow the socket to close naturally on it's own. It's possible that there is something else in your wrapper that is keeping it active, however, so that's what I would look for.

In general, with the changes introduced in 9.4, session.destroy() should only be used in exception cases. Use session.close() to tear down the session normally.

@askuzminov
Copy link

askuzminov commented Jan 17, 2018

The server stops correctly, if there are no sessions. But if you make a request, do not close the browser and afterwards try to close the server, nothing will happen:

const http2 = require('http2');
const fs = require('fs');

const server2 = http2.createSecureServer({
  key: fs.readFileSync('./localhost-privkey.pem'),
  cert: fs.readFileSync('./localhost-cert.pem')
});

let count = 0;

server2.on('stream', (stream, headers) => {

  if (count) {
    console.log('Closing...');
    server2.close(() => {
      console.log('Closed'); // Don't fire
    });
  }

  stream.respond({
    'content-type': 'application/json',
    ':status': 200
  });
  stream.end('test');

  count++;
});

server2.listen(3000);

Macos 10.13.2 (17C205) - nodejs 9.4.0
Request from Chrome 63.

@jasnell
Copy link
Member

jasnell commented Jan 17, 2018

The reason for that is because server.close() attempts a graceful shutdown, allowing existing sockets to closet naturally before completing the shutdown. If the client keeps those open -- which certainly can happen with http/2 -- then the server won't shut down. The way to handle that is to use setTimeout. If a client really is misbehaving, the server can use socket.destroy() or session.destroy() to force it closed.

@grantila
Copy link
Author

Not sure what's going on, but I see that pushed frames won't work since 9.4 either. On a client session, I register a listener for 'stream', and on that stream I now get the 'aborted' event and not the 'push' event.

Don't know if this is a timing issue or what, but 9.4 certainly changed everything. All my unit tests passed in <= 9.3 and now practically all fail. It's certainly unpleasant that what seemed to work perfectly, is now a hundred percent borked, and I have no idea why...

Is there a way to perform a kind of strace for Node, i.e. to run a program and see exactly what functions calls are being made to core modules, so that I can more easily reproduce it? Wading through tons of complex logic to figure out what event is being registered etc, is... not efficient.

@askuzminov
Copy link

askuzminov commented Jan 17, 2018

const sessions = [];
server.on('session', session => {
  sessions.push(session);
});

// after several requests
for (const session of sessions) {
  session.destroy();
}
server.close(fn) // does not work

@grantila
Copy link
Author

@askuzminov yeah that's practically what I do in fetch-h2 too, to re-use the same session for multiple requests. Except I keep them in a Map and clear it before I close the server, so there shouldn't be a reference anywhere (although even if there was, destroying the session should work, regardless of references and event listeners floating around)...
Guess it's 9.4 that's actually misbehaving.

BridgeAR pushed a commit to BridgeAR/node that referenced this issue Jan 19, 2018
Verify that server close callbacks are being called

PR-URL: nodejs#18182
Refs: nodejs#18176
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Ruben Bridgewater <ruben@bridgewater.de>
evanlucas pushed a commit that referenced this issue Jan 30, 2018
Verify that server close callbacks are being called

PR-URL: #18182
Refs: #18176
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Ruben Bridgewater <ruben@bridgewater.de>
evanlucas pushed a commit that referenced this issue Jan 30, 2018
Verify that server close callbacks are being called

PR-URL: #18182
Refs: #18176
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Ruben Bridgewater <ruben@bridgewater.de>
kjin pushed a commit to kjin/node that referenced this issue May 1, 2018
Verify that server close callbacks are being called

PR-URL: nodejs#18182
Refs: nodejs#18176
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Ruben Bridgewater <ruben@bridgewater.de>
MylesBorins pushed a commit that referenced this issue May 2, 2018
Verify that server close callbacks are being called

Backport-PR-URL: #20456
PR-URL: #18182
Refs: #18176
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Ruben Bridgewater <ruben@bridgewater.de>
MayaLekova pushed a commit to MayaLekova/node that referenced this issue May 8, 2018
Verify that server close callbacks are being called

PR-URL: nodejs#18182
Refs: nodejs#18176
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Ruben Bridgewater <ruben@bridgewater.de>
@jasnell
Copy link
Member

jasnell commented Aug 10, 2018

I believe this is resolved. We can reopen the issue if not.

@jasnell jasnell closed this as completed Aug 10, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
http2 Issues or PRs related to the http2 subsystem.
Projects
None yet
Development

No branches or pull requests

3 participants