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

net: emit 'close' after 'end' #19241

Closed
wants to merge 2 commits into from
Closed

Conversation

lpinca
Copy link
Member

@lpinca lpinca commented Mar 8, 2018

Currently the writable side of the socket is closed as soon as UV_EOF
is read regardless of the state of the socket. This allows the handle
to be closed before 'end' is emitted and thus 'close' can be
emitted before 'end' if the socket is paused.

This commit prevents the handle from being closed until 'end' is
emitted ensuring the correct order of events.

Fixes: #19166

Checklist
  • make -j4 test (UNIX), or vcbuild test (Windows) passes
  • tests and/or benchmarks are included
  • documentation is changed or added
  • commit message follows commit guidelines

@nodejs-github-bot nodejs-github-bot added the net Issues and PRs related to the net subsystem. label Mar 8, 2018
@lpinca
Copy link
Member Author

lpinca commented Mar 8, 2018

@lpinca
Copy link
Member Author

lpinca commented Mar 8, 2018

This is potentially semver-major as the 'close' event is no longer emitted if UV_EOF is read and the socket is paused.

@addaleax
Copy link
Member

addaleax commented Mar 8, 2018

This aligns behavior with other Duplex streams, right? I like that. 👍

Will take a closer look tomorrow

@lpinca
Copy link
Member Author

lpinca commented Mar 8, 2018

Yes, at least it aims to do that.

@jasnell jasnell requested a review from mcollina March 8, 2018 22:48
@mcollina mcollina added the semver-major PRs that contain breaking changes and should be released in the next major version. label Mar 8, 2018
@mcollina
Copy link
Member

mcollina commented Mar 8, 2018

I think this is semver-major.

Copy link
Member

@mcollina mcollina left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@lpinca
Copy link
Member Author

lpinca commented Mar 9, 2018

CI: https://ci.nodejs.org/job/node-test-pull-request/13601/
Windows failures are related, I'll investigate.

@lpinca
Copy link
Member Author

lpinca commented Mar 9, 2018

@addaleax
Copy link
Member

addaleax commented Mar 9, 2018

@lpinca lpinca added this to the 10.0.0 milestone Mar 11, 2018
@mcollina
Copy link
Member

@lpinca can you please check that we follow this pattern also in HTTP, HTTP2, fs, etc?

Also, pump should keep working.

@lpinca
Copy link
Member Author

lpinca commented Mar 12, 2018

can you please check that we follow this pattern also in HTTP, HTTP2, fs, etc?

This is not trivial, it seems to be the case for HTTP but not fs, the 'close' event is emitted as soon as the fd is closed. This is properly documented though. Not sure about HTTP2 I'm not familiar enough with the codebase.

pump is tested by CITGM right? If so it seems this change does not break it.

@mcollina
Copy link
Member

@lpinca pump is not in citgm atm.

@addaleax
Copy link
Member

For HTTP/2, allowHalfOpen is always true, so I don’t think we have to worry about that.

@lpinca
Copy link
Member Author

lpinca commented Mar 12, 2018

@mcollina ok, I'll

  1. Run pump tests locally.
  2. Open a PR in GITGM to add it.

@lpinca
Copy link
Member Author

lpinca commented Mar 12, 2018

pump tests pass locally, also it either calls destroy() or wait for the 'close' event (or end-of-stream callback). When destroy() is called the 'close' event can still be emitted before 'end'. This patch does not handle that case.

I'm a bit hesitant on adding it to CITGM as it seems to be only tested with fs and default stream classes and there is already pumpify for that in CITGM.

@lpinca
Copy link
Member Author

lpinca commented Mar 12, 2018

cc: @mafintosh

@lpinca
Copy link
Member Author

lpinca commented Mar 19, 2018

I would like to land this. It already has 3 TSC approvals but it would be nice to have more opinions.
Ping @nodejs/collaborators @nodejs/streams.

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

Copy link
Member

@benjamingr benjamingr left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Definitely semver-major, changes lgtm

Currently the writable side of the socket is closed as soon as `UV_EOF`
is read regardless of the state of the socket. This allows the handle
to be closed before `'end'` is emitted and thus `'close'` can be
emitted before `'end'` if the socket is paused.

This commit prevents the handle from being closed until `'end'` is
emitted ensuring the correct order of events.

Fixes: nodejs#19166
Wait for the sockets to be connected before closing them and remove
unneeded `setTimeout()`.
@lpinca
Copy link
Member Author

lpinca commented Mar 21, 2018

@lpinca
Copy link
Member Author

lpinca commented Mar 21, 2018

Landed in 0ac4ef9...9b7a691.

lpinca added a commit that referenced this pull request Mar 21, 2018
Wait for the sockets to be connected before closing them and remove
unneeded `setTimeout()`.

PR-URL: #19241
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
lpinca added a commit that referenced this pull request Mar 21, 2018
Currently the writable side of the socket is closed as soon as `UV_EOF`
is read regardless of the state of the socket. This allows the handle
to be closed before `'end'` is emitted and thus `'close'` can be
emitted before `'end'` if the socket is paused.

This commit prevents the handle from being closed until `'end'` is
emitted ensuring the correct order of events.

PR-URL: #19241
Fixes: #19166
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
@lpinca lpinca closed this Mar 21, 2018
@lpinca lpinca deleted the emit/close-after-end branch March 21, 2018 17:32
@brettkiefer
Copy link
Contributor

brettkiefer commented Jun 10, 2018

@lpinca On redis/ioredis#633 I'm seeing that the socket is not in a paused state (that is, its isPaused() returns false) but does have a writable of true when we hit onReadableStreamEnd, causing the close event to never fire and resulting in a stuck IORedis cluster client. Is that an intentional result of this change, or would you generally still expect to see a 'close' event emitted for a non-paused socket?

If the answer is that this is not an intentional new behavior, I'll try to boil it down to more minimal repro case (one that doesn't involve spinning up a Redis cluster).

@lpinca
Copy link
Member Author

lpinca commented Jun 10, 2018

If the socket is still writable it's expected, 'close' should not be emitted if the socket is writable.

@brettkiefer
Copy link
Contributor

@lpinca Ok, thanks! It looks like what is happening here is that when we connect with a timeout that fires off an end on the connecting socket and then delay the socket connection so that afterConnect fires after end, we get the ordering:

Socket.end from client code on timeout (calls down to stream.Duplex.prototype.end, setting this.writable to false and this._writableState.ending to true)

Socket.afterConnect(sets this.writable to true when we connect without error)

Socket.onReadableStreamEnd (calls this.end)

Socket.end (calls stream.Duplex.prototype.end)

Writable.prototype.end (does NOT call endWritable because this._writableState.ending is already true from the previous call to socket.end, so this.writable stays true)

socket.maybeDestroy (does not call socket.destroy because socket.writable is true, so this.destroy is never called and close is never emitted)

So that causes the socket to never call Socket.destroy, where before this change it would have called destroySoon immediately, masking the bug (at least it looks to me like a bug) with this.writable being set to true by afterConnect even though the rest of the state indicates that it should not be.

Does that make sense to you? It may be that I have an incorrect expectation that calling Socket.end on a socket before it finishes connecting will eventually result in the socket emitting close, but that seems to me to be the correct behavior. I realize that this is really not a bug with your change, but the interaction, resulting in close never being called in this case, seems like it might be worth attention -- I just thought I'd run it by you first since you touched it last and probably have the best sense for the expected behavior.

@lpinca
Copy link
Member Author

lpinca commented Jun 11, 2018

@brettkiefer yes it makes sense, this is an interesting race condition. afterConnect() should not blindly override the value of this.writable imho.

A dirty workaround would be to call socket.destroy() instead of socket.end() on timeout but I agree that this is a bug and should be fixed.

@brettkiefer
Copy link
Contributor

@lpinca Thanks. that sounds like a good idea. I'll see what IORedis might accept as a workaround and get an issue submitted against Node.js tomorrow (unless you think you can give better context, in which case please feel free) and link it here.

I don't immediately see any internal state on the socket that looks appropriate for switching behavior in afterConnect (although I guess it peeks at the _writableState in a couple of places) so I'm not sure what an appropriate PR would be, but at least it seems like it's worth surfacing the issue.

@lpinca
Copy link
Member Author

lpinca commented Jun 11, 2018

Here is a test case for the issue you are describing:

const net = require('net');

const server = net.createServer();

server.listen(() => {
  const socket = net.createConnection(server.address().port);

  socket.on('connect', () => console.log('connect'));
  socket.on('end', () => console.log('end'));
  socket.on('close', () => console.log('close'));
  socket.end();
});

No 'close' event is emitted in this case, but I think it should.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
net Issues and PRs related to the net subsystem. semver-major PRs that contain breaking changes and should be released in the next major version.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

'close' event called before 'end' in paused stream
7 participants