http_outgoing.js: Callbacks never called?

[laino]

I am currently in the process of debugging a file descriptor leak in my code which only happens in very rare edge cases.

I have identified some potential problems in http_outgoing.js that could be the cause of it, but
was not able to confirm these with my limited knowledge of the stream internals.

In the order of most to least important:

First case

When the underlying stream was already closed, but a write call was made, the callback should be called with an error indicating that the stream is already closed.
Currently the callback is silently forgotten.

https://github.com/iojs/io.js/blob/4874182065655dcf8a39bfa3e4c9b47bfb9e0f75/lib/_http_outgoing.js#L165

Second Case

When a stream is closed, all callbacks remaining in this.outputCallbacks should be
called. I wasn't able to locate any place where this would happen.

https://github.com/iojs/io.js/blob/4874182065655dcf8a39bfa3e4c9b47bfb9e0f75/lib/_http_outgoing.js#L49

Third case

(Likely not the cause)

If the response shouldn't have a body, please at least schedule my callback for the next tick instead
of just returning:

https://github.com/iojs/io.js/blob/4874182065655dcf8a39bfa3e4c9b47bfb9e0f75/lib/_http_outgoing.js#L428
https://github.com/iojs/io.js/blob/4874182065655dcf8a39bfa3e4c9b47bfb9e0f75/lib/_http_outgoing.js#L438

[brendanashworth]

For all of these .write() calls, I believe the http module takes on the net module's handling of the callback function, which is as follows:

The optional callback parameter will be executed when the data is finally written out - this may not be immediately.

Since in the first case and the third case, the data isn't sent, so the callback shouldn't be called - programs depend on this functionality and may do something when the data is successfully sent and don't check for an error (because one is never sent?).

I'm not too familiar with what you present in the second case, but I have no idea why you might have a fd leak in cases 1 and 3.

[laino]

Since in the first case and the third case, the data isn't sent, so the callback shouldn't be called

The callback should be called with the same or similar error that is used here: https://github.com/iojs/io.js/blob/v1.x/lib/_http_outgoing.js#L397

Meaning, with an error that tells me that the write failed. The cases I have shown are edge cases with the same underlying cause (stream is already closed).

Not doing that would be very bad API design and makes it impossible to detect an already closed stream in some cases without messing with "third party" objects in a very ugly manner.

I'll describe the problem leading to the file descriptor leak: I have a listener closing my own file descriptor when either the stream (which I'm writing to) emits an "end", "error", or "close" event, or calling .write gives an error. As I'd call the code closing my file descriptor bullet-proof (and the file descriptor is indeed closed in normal circumstances), I deduce that there must be cases where I receive neither an "end", "error" nor "close" event and .write doesn't give an error.

Let me clarify: An "end", "error" or "close" event could have already been fired before I attach listeners to the stream.

[brendanashworth]

History on the subject: c9dcf57, f9a0140, 88686a.

Now I see where you're coming from on the first case; this second call should definitely error:

> var req = http.request(...);
undefined
> req.end('test');
true
> req.write('data', function() { /* not called */ });
true
> Error: write after end
    at ClientRequest.OutgoingMessage.write (_http_outgoing.js:392:15)
    at ...
> req.end('data', function() { /* not called */ });
false

Now that you explain where you are getting a fd leak, this may be the cause.

Does this fix it for you? (also wrote a test for a PR)

diff --git a/lib/_http_outgoing.js b/lib/_http_outgoing.js
index 2e64632..a6cc514 100644
--- a/lib/_http_outgoing.js
+++ b/lib/_http_outgoing.js
@@ -496,11 +496,17 @@ OutgoingMessage.prototype.end = function(data, encoding, callback) {
     throw new TypeError('first argument must be a string or Buffer');
   }

+  var self = this;
   if (this.finished) {
-    return false;
+    var err = new Error('end() called after end');
+    process.nextTick(function() {
+      self.emit('error', err);
+      if (callback) callback(err);
+    });
+
+    return true;
   }

-  var self = this;
   function finish() {
     self.emit('finish');
   }

[laino]

This could've been one reason, but I don't think we're quite there yet.

What about this case:

1. I get a new incoming connection
2. The other end kills the connection
3. "close" fires and connection.destroyed is set to true
4. I finally get around to register my "close" listener (but too late)
5. I .write to the stream and land in this codepath: https://github.com/iojs/io.js/blob/4874182065655dcf8a39bfa3e4c9b47bfb9e0f75/lib/_http_outgoing.js#L165
6. I'm dead in the water because I will get no error

[laino]

Note: I'll have a PR for this ready by next week. I'll try to create a POC too.

[laino]

Another note:

It appears that somebody actually intended to handle the "close" event on the underlying connection by changing a property on the stream object, as indicated by the property this._hangupClose which is currently used and/or changed exactly nowhere: https://github.com/iojs/io.js/blob/4874182065655dcf8a39bfa3e4c9b47bfb9e0f75/lib/_http_outgoing.js#L65

What I think should happen when the underlying this.connection closes prematurely:

1. call all remaining this.outputCallbacks with an error indicating that the write failed
2. call callbacks of later .write calls with an error indicating that the write failed

Currently all callbacks are left in limbo somewhere, never informing the user of what happened with his write...

[brendanashworth]

Are you adding your close listener in a different run of the event loop? If so, there wouldn't be a way to avoid losing the event when it is called, afaik.

I'm up for calling back with an error if that happens, it sounds more logical, if you'd like to make a PR for that.

[Trott]

@laino @brendanashworth Offhand, does anyone know if this is still an issue? And if so, is anyone planning to submit a PR to fix?

[brendanashworth]

@Trott its an issue/inconsistency still, here's the PR right now: #2240. The underlying issue is that outgoing HTTP requests don't use streams, but instead fake it, leading to inconsistent behavior. Changing it all to streams (I tried this a little bit) meant breaking some eggs, so #2240 seems like the way to go for now (even though I'd support a base rewrite).

[Trott]

@nodejs/http

[jasnell]

ping @mcollina

[mcollina]

So, I think we can close this.

Currently Writable does behave similarly to this in some cases. The callbacks passed to write() might not be called in certain circumstances. In-flight writes are currently not in Writable (see https://github.com/mcollina/aedes/blob/master/lib/client.js#L248-L252 as an example how to do that).

IMHO fixing this behavior on both cases would cause too much breakage. The problem is that in case of an error, we must emit 'error' and pass the error back to the write callback: the application would receive 2 errors while expecting only one to happen.

Considering the fact that this has not been causing any problems in the last few years, I think it's safe to leave as is: I'm ok to reconsider if there is a need.