Use events to wire upload tracking instead of racing with setImmediate #525

jstewmon · 2018-07-17T16:06:14Z

I could not determine why setImmediate was being used to defer some of the statements in the event emitter wiring, other than the socket connection check, which can be safely done by subscribing to the right events.

szmarczak · 2018-07-17T18:49:28Z

source/request-as-event-emitter.js

@@ -122,8 +120,9 @@ module.exports = (options = {}) => {

 cacheReq.once('request', req => {
 let aborted = false;
- req.once('abort', _ => {
+ req.once('abort', () => {


Refactoring should be done in a separate PR. Just Kidding :P 👍

I considered it, but when I looked at the diff, I didn't think the one line change raised the cognitive burden enough to warrant a separate commit. 😅

szmarczak · 2018-07-17T18:51:00Z

source/request-as-event-emitter.js

 aborted = true;
+ emitter.emit('abort');


Do we really need that? It's aborted only when receives an error/someone cancels the request. The error got throws has nice details though.

It's not needed. I don't know why I put it there. 🤪

I don't know.

brandon93s · 2018-07-17T22:17:43Z

source/request-as-event-emitter.js

- } catch (error) {
- emitter.emit('error', error);
- }
- });


I suspect this was added to control the call stack, ensuring that the method ran to completion before any errors were emitted. This changes that behavior. There doesn't appear to be any tests failing from the change, but I would guess that this introduces behavioral changes.

Originally added in #117.

@brandon93s Thanks for the reference to #117.

It looks like the intent was to ensure the response data was handled after the event listeners that clear timeouts were run.

If a callback is provided for request, it will be the first handler to run.

I can make another pass at this, to evaluate when the timeout clearing handlers are being run.

Does my analysis sound right? See any other issues?

You both are right. The main intent was to emit response ASAP, so @floatdrop used setImmediate as it executes immediately after I/O operations. I'd leave setImmediate unchanged here.

If a callback is provided for request, it will be the first handler to run.

I think @jstewmon is right here. We don't need setImmediate in this case (line 198).

The main intent was to emit response ASAP

That's not how I read it. There are 3 emitters involved, so I'm not sure which one you mean. The emitter response event is emitted from getResponse, so setImmediate here delays that. The req emitter's event isn't affected by this setImmediate.

This is the background information I found:

The version of timed-out being used at the time of #117 listened for the response event of the request to clear the timeout:
https://github.com/floatdrop/timed-out/blob/v2.0.0/index.js#L31

The request object was passed to timed-out, which would setup that listener.

The statement that was deferred with setImmediate called unzipResponse from the http.request callback, which would have run before timed-out's listener.

So my assessment was that the intent was to allow timed-out's listener to run before the response stream was connected to unzipResponse.

Now that timeout.request is waiting for response.end, I think deferring the call to getResponse actually increases the possibility that the timeout will breach.

Since it is quite common to use a request callback, I think a better solution to checking a timeout against the response event would be to use setImmediate in the timer callback to defer the error emission to the check phase of the event loop in case the response had been received but was still queued due to load. At a minimum, the listener that clears the timeout could be subscribed with prependOnceListener to ensure it runs earlier.

I thought there might be some practical purpose other than the ordering of the response handlers (like allowing subscriptions to some event emitter), but I don't see any such purpose, and I think we can clearly see that the response event listener order is no longer applicable.

I think a better solution to checking a timeout against the response event would be to use setImmediate in the timer callback to defer the error emission to the check phase of the event loop in case the response had been received but was still queued due to load.

So the connection was established, because there's a response.

Here's some code to illustrate what I meant about using setImmediate with timers.

You were trying to illustrate the first sentence using the connect timeout, though it had been connected already. Awesome.

Is it possible to receive connect event and response (with some queued data) in the same loop?

Have you carefully reviewed the doc I linked earlier about the event loop phases?

Yes, I have read it several times, not only today.

The point is that if we're checking connect timeout. The connection may have already been established, but its event hasn't fired when the timeout callback is run.

Then the connection is not established. From the docs:

Event: 'connect'
Emitted when a socket connection is successfully established.

socket.connecting
If true - socket.connect(options[, connectListener]) was called and haven't yet finished. Will be set to false before emitting 'connect' event and/or calling socket.connect(options[, connectListener])'s callback.

This is a tricky topic because of the changes in behavior over time.

When I've referred to the response event, I've been talking about the behavior and intent at the time (circa 2015) that the setImmediate deferral was added in #117. The response event is not currently used to clear any timeouts, so it is not relevant to this change.

You were trying to illustrate the first sentence using the connect timeout, though it had been connected already.

No, the statement you quoted was in my original analysis. I was suggesting that there was a more precise way of mitigating #117 than deferring the response piping with setImmediate.

I didn't want to use the response event to illustrate how that suggestion would be implemented because none of the current timeouts depend on the timing of that event. I used the connect event as an example in the current code because it is used to clear the connect timeout.

Is it possible to receive connect event and response (with some queued data) in the same loop?

I don't see any reason why that would not be possible, but their listeners would be notified in FIFO order (connect before response). Does it matter?

Then the connection is not established

The underlying system operation completes before we're notified. That's the purpose of the poll phase - to notify us that the IO operations we listened for are complete.

Now that timeout.request is waiting for response.end, I think deferring the call to getResponse actually increases the possibility that the timeout will breach.

Not true. Before I've copied timed-out into this repo there was pTimeout handling timeout.request, so it started counting immediately after the promise was called (no connection has been made yet). That's just only a note.

The underlying system operation completes before we're notified. That's the purpose of the poll phase - to notify us that the IO operations we listened for are complete.

I still disagree here. It has its own time to establish the connection. But this change is not significant I think. Let's skip this subject.

No, the statement you quoted was in my original analysis. I was suggesting that there was a more precise way of mitigating #117 than deferring the response piping with setImmediate.

So if these are two different things, I've got only one question: what is the better way to avoid bottleneck with emitting the response and handling it? (Line 107) What else if not setImmediate? You haven't implemented it yet. It just delays establishing another connections for now (if there's big amount of requests).

szmarczak · 2018-07-18T10:38:52Z

source/request-as-event-emitter.js

@@ -148,8 +146,7 @@ module.exports = (options = {}) => {
 total: uploadBodySize
 });

- const socket = req.connection;
- if (socket) {
+ req.once('socket', socket => {


Incorrect implementation here. See why:

30c39bc

13d6b68

I've reviewed those issues and do not think this change regresses either of them.

The problem reported in Uncaught TypeError: Cannot read property 'once' of undefined at EventEmitter.ee.once.req #427 and fixed in Check req.connection exists before attaching event listeners #429 was that req.connection may be undefined. I've removed the reference to req.connection in favor of subscribing to the socket event to get the connection. So, this should not regress that issue b/c we don't try to access a property which may be undefined.

The memory leak fix from Fix socket 'connect' memory leak #465 is addressed by the if (socket.connecting) check. It prevents unbounded event subscriptions with keep-alive is enabled on the agent.

I've looked deeply and I think it's safe to do so. Good job!

jstewmon · 2018-07-18T22:50:08Z

source/request-as-event-emitter.js

 });

 if (options.gotTimeout) {
 clearInterval(progressInterval);
 timedOut(req, options.gotTimeout);
 }

- setImmediate(() => {


Note: this setImmediate deferral was introduced in a1eb3f7 in exchange for get being deferred. get is currently deferred (didn't track down the commit), so this does not need to be deferred.

Either get or emitter.emit('request', req) needs to be deferred to give callers a chance to subscribe to the request event.

sindresorhus · 2018-07-25T07:48:01Z

Closing in favor of #534

szmarczak reviewed Jul 17, 2018

View reviewed changes

jstewmon force-pushed the stable-event-wiring branch from 2064ea8 to 16125cc Compare July 17, 2018 19:16

brandon93s reviewed Jul 17, 2018

View reviewed changes

szmarczak requested changes Jul 18, 2018

View reviewed changes

sindresorhus changed the title ~~use events to wire upload tracking instead of racing with setImmediate~~ Use events to wire upload tracking instead of racing with setImmediate Jul 18, 2018

jstewmon commented Jul 18, 2018

View reviewed changes

jstewmon force-pushed the stable-event-wiring branch from 16125cc to 9d4c0e6 Compare July 19, 2018 04:48

This was referenced Jul 19, 2018

Move upload progress plumbing to its own module #531

Merged

Customize timeouts and generally improve the whole thing #534

Merged

use events to wire upload tracking instead of racing with setImmediate

cd76c42

jstewmon force-pushed the stable-event-wiring branch from 9d4c0e6 to cd76c42 Compare July 24, 2018 17:56

sindresorhus closed this Jul 25, 2018

jstewmon deleted the stable-event-wiring branch July 25, 2018 15:19

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Use events to wire upload tracking instead of racing with setImmediate #525

Use events to wire upload tracking instead of racing with setImmediate #525

jstewmon commented Jul 17, 2018 •

edited

Loading

szmarczak Jul 17, 2018

jstewmon Jul 17, 2018

szmarczak Jul 17, 2018

jstewmon Jul 17, 2018

szmarczak Jul 17, 2018

brandon93s Jul 17, 2018

brandon93s Jul 17, 2018

jstewmon Jul 18, 2018

szmarczak Jul 18, 2018

jstewmon Jul 19, 2018 •

edited

Loading

szmarczak Jul 19, 2018

szmarczak Jul 19, 2018

jstewmon Jul 19, 2018

jstewmon Jul 19, 2018 •

edited

Loading

szmarczak Jul 19, 2018

szmarczak Jul 18, 2018

jstewmon Jul 18, 2018

szmarczak Jul 18, 2018

jstewmon Jul 18, 2018 •

edited

Loading

sindresorhus commented Jul 25, 2018

Use events to wire upload tracking instead of racing with setImmediate #525

Use events to wire upload tracking instead of racing with setImmediate #525

Conversation

jstewmon commented Jul 17, 2018 • 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

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

jstewmon Jul 19, 2018 • 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

jstewmon Jul 19, 2018 • 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

Choose a reason for hiding this comment

jstewmon Jul 18, 2018 • edited Loading

Choose a reason for hiding this comment

sindresorhus commented Jul 25, 2018

jstewmon commented Jul 17, 2018 •

edited

Loading

jstewmon Jul 19, 2018 •

edited

Loading

jstewmon Jul 19, 2018 •

edited

Loading

jstewmon Jul 18, 2018 •

edited

Loading