HTTPS connection failing because socket has been deleted #9348

othiym23 · 2015-03-06T14:08:25Z

Here are two stacktraces that I have collected within the last few hours from two separate npm users. This failure has been seen on all of OS X, Windows, and Linux.:

104310 verbose stack AssertionError: null == true
104310 verbose stack     at TLSSocket.socketOnData (_http_client.js:308:3)
104310 verbose stack     at TLSSocket.emit (events.js:107:17)
104310 verbose stack     at TLSSocket.Readable.read (_stream_readable.js:373:10)
104310 verbose stack     at TLSSocket.socketCloseListener (_http_client.js:229:10)
104310 verbose stack     at TLSSocket.emit (events.js:129:20)
104310 verbose stack     at TCP.close (net.js:476:12)

102672 verbose stack AssertionError: null == true
102672 verbose stack     at TLSSocket.socketOnData (_http_client.js:308:3)
102672 verbose stack     at TLSSocket.emit (events.js:107:17)
102672 verbose stack     at TLSSocket.Readable.read (_stream_readable.js:373:10)
102672 verbose stack     at TLSSocket.socketCloseListener (_http_client.js:229:10)
102672 verbose stack     at TLSSocket.emit (events.js:129:20)
102672 verbose stack     at TCP.close (net.js:476:12)

See also npm/npm#7349 for more discussion and further links to people encountering this issue, which ultimately traces back to this bare assert in _http_client.js. It's rare enough that it's probably a race condition, and I seem to recall a similar issue getting fixed elsewhere in the not too distant pass. @indutny? Anybody?

The text was updated successfully, but these errors were encountered:

indutny · 2015-03-06T14:38:45Z

The error seems to be originating from socket.parser === null, which may happen on:

close event on socket
parser error
upgrade event without listener
100 status code
error event
end event

I don't think that upgrade or 100 status code may actually happen on npm. So this seems to be an OOB data after 'close'/'error'/'end' event.

othiym23 · 2015-03-06T14:59:10Z

The relevant code in npm uses a custom http.Agent (to enable keep-alive) passed to request, and there are some issues we've been seeing with talking to mochiweb, the CouchDB HTTP server, that affect both node and iojs. My hypothesis is that something weird is happening around error-handling in the new agent keep-alive code, but I haven't had a chance to wireshark it or produce a reduced test case. Not sure the two issues are related, but it sure would be convenient for me if it were. ;)

indutny · 2015-03-06T15:01:12Z

Well, if the error event happens - socket will be destroyed immediately. Anyway, do you know any way to reproduce it? Even some script that does it in like 10000 runs would suffice.

othiym23 · 2015-03-06T17:02:17Z

I'm trying, over on npm/npm#7349. ;) At this point we know about the same amount about what's going on. I'm also away from my computer, so I can't bang on this myself until tonight.

indutny · 2015-03-09T00:12:36Z

Test case:

var net = require('net');
var http = require('http');
var util = require('util');

function Agent() {
  http.Agent.call(this);
}
util.inherits(Agent, http.Agent);

Agent.prototype.createConnection = function() {
  var self = this;
  var socket = new net.Socket();

  socket.on('error', function() {
    socket.push('OH GOSH');
  });

  socket.on('newListener', function onNewListener(name) {
    if (name !== 'error')
      return;
    socket.removeListener('newListener', onNewListener);

    // Let other listeners to be set up too
    process.nextTick(function() {
      self.breakSocket(socket);
    });
  });

  return socket;
};

Agent.prototype.breakSocket = function breakSocket(socket) {
  socket.emit('error', new Error('Intentional error'));
};

var agent = new Agent();

http.request({
  agent: agent
}).once('error', function() {
  console.log('ignore');
});

indutny · 2015-03-09T00:12:39Z

Patch is coming soon.

Read all pending data out of the socket on `error` event and ensure that no `data`/`end` handlers will be invoked on `socket.destroy()`. Otherwise following assertion happens: AssertionError: null == true at TLSSocket.socketOnData (_http_client.js:308:3) at TLSSocket.emit (events.js:107:17) at TLSSocket.Readable.read (_stream_readable.js:373:10) at TLSSocket.socketCloseListener (_http_client.js:229:10) at TLSSocket.emit (events.js:129:20) at TCP.close (net.js:476:12) Fix: nodejs/node-v0.x-archive#9348

indutny · 2015-03-09T00:39:53Z

Suggested fix https://github.com/iojs/io.js/pull/1103/files

Read all pending data out of the socket on `error` event and ensure that no `data`/`end` handlers will be invoked on `socket.destroy()`. Otherwise following assertion happens: AssertionError: null == true at TLSSocket.socketOnData (_http_client.js:308:3) at TLSSocket.emit (events.js:107:17) at TLSSocket.Readable.read (_stream_readable.js:373:10) at TLSSocket.socketCloseListener (_http_client.js:229:10) at TLSSocket.emit (events.js:129:20) at TCP.close (net.js:476:12) Fix: nodejs/node-v0.x-archive#9348 PR-URL: #1103 Reviewed-By: Rod Vagg <rod@vagg.org> Reviewed-By: Nicu Micleușanu <micnic90@gmail.com>

indutny · 2015-03-09T13:27:55Z

The fix has been landed in io.js: nodejs/node@1a3ca82, please backport

Notable changes: * tls: The reported TLS memory leak has been at least partially resolved via various commits in this release. Current testing indicated that there may still be some leak problems. Progress being tracked at: #1075 * http: Fixed an error reported at nodejs/node-v0.x-archive#9348 and npm/npm#7349 Pending data was not being fully read upon an 'error' event leading to an assertion failure on socket.destroy(). (Fedor Indutny) #1103

misterdjules · 2015-03-11T16:48:54Z

Thank you @othiym23 and @indutny, added to the 0.12.1 milestone.

Read all pending data out of the socket on `error` event and ensure that no `data`/`end` handlers will be invoked on `socket.destroy()`. Otherwise following assertion happens: AssertionError: null == true at TLSSocket.socketOnData (_http_client.js:308:3) at TLSSocket.emit (events.js:107:17) at TLSSocket.Readable.read (_stream_readable.js:373:10) at TLSSocket.socketCloseListener (_http_client.js:229:10) at TLSSocket.emit (events.js:129:20) at TCP.close (net.js:476:12) Fix: nodejs#9348 PR-URL: nodejs/node#1103 Reviewed-By: Rod Vagg <rod@vagg.org> Reviewed-By: Nicu Micleușanu <micnic90@gmail.com>

misterdjules · 2015-03-19T00:00:55Z

Thank you very much @indutny!

nodejs/node@1a3ca82 LGTM, and I would land it. However, I just want to wait for a while to see if we get any feedback on npm/npm#7349 (comment) before landing it as a fix for this issue.

misterdjules · 2015-03-25T21:12:23Z

Just for the record, this issue is fixed by nodejs/node@1a3ca82, see npm/npm#7349 (comment).

This change is a backport of 1a3ca82 from io.js. Original commit message: Read all pending data out of the socket on `error` event and ensure that no `data`/`end` handlers will be invoked on `socket.destroy()`. Otherwise following assertion happens: AssertionError: null == true at TLSSocket.socketOnData (_http_client.js:308:3) at TLSSocket.emit (events.js:107:17) at TLSSocket.Readable.read (_stream_readable.js:373:10) at TLSSocket.socketCloseListener (_http_client.js:229:10) at TLSSocket.emit (events.js:129:20) at TCP.close (net.js:476:12) Fix: nodejs#9348 PR-URL: nodejs/node#1103 Reviewed-By: Rod Vagg <rod@vagg.org> Reviewed-By: Nicu Micleușanu <micnic90@gmail.com> Fixes nodejs#9348.

This change is a backport of 1a3ca82 from io.js. Original commit message: Read all pending data out of the socket on `error` event and ensure that no `data`/`end` handlers will be invoked on `socket.destroy()`. Otherwise following assertion happens: AssertionError: null == true at TLSSocket.socketOnData (_http_client.js:308:3) at TLSSocket.emit (events.js:107:17) at TLSSocket.Readable.read (_stream_readable.js:373:10) at TLSSocket.socketCloseListener (_http_client.js:229:10) at TLSSocket.emit (events.js:129:20) at TCP.close (net.js:476:12) Fix: #9348 PR-URL: nodejs/node#1103 Reviewed-By: Rod Vagg <rod@vagg.org> Reviewed-By: Nicu Micleușanu <micnic90@gmail.com> Fixes #9348. Reviewed-By: Julien Gilli <julien.gilli@joyent.com> PR-URL: #14087

misterdjules · 2015-03-28T01:06:14Z

Landed in d6484f3, thank you @indutny and @othiym23!

othiym23 mentioned this issue Mar 6, 2015

yeoman generator and npm errors npm/npm#7349

Closed

indutny mentioned this issue Mar 9, 2015

http_client: ensure empty socket on error nodejs/node#1103

Closed

rvagg mentioned this issue Mar 9, 2015

Release proposal: v1.5.1 nodejs/node#1096

Closed

subfuzion mentioned this issue Mar 9, 2015

Evangelism: Weekly Update March 13th nodejs/evangelism#41

Closed

misterdjules added this to the 0.12.1 milestone Mar 11, 2015

misterdjules added http P-1 labels Mar 11, 2015

misterdjules self-assigned this Mar 16, 2015

misterdjules mentioned this issue Mar 25, 2015

http: fix assert on data/end after socket error #14087

Closed

misterdjules added the in progress label Mar 25, 2015

misterdjules closed this as completed Mar 28, 2015

misterdjules removed the in progress label Mar 28, 2015

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

HTTPS connection failing because socket has been deleted #9348

HTTPS connection failing because socket has been deleted #9348

othiym23 commented Mar 6, 2015

indutny commented Mar 6, 2015

othiym23 commented Mar 6, 2015

indutny commented Mar 6, 2015

othiym23 commented Mar 6, 2015

indutny commented Mar 9, 2015

indutny commented Mar 9, 2015

indutny commented Mar 9, 2015

indutny commented Mar 9, 2015

misterdjules commented Mar 11, 2015

misterdjules commented Mar 19, 2015

misterdjules commented Mar 25, 2015

misterdjules commented Mar 28, 2015

HTTPS connection failing because socket has been deleted #9348

HTTPS connection failing because socket has been deleted #9348

Comments

othiym23 commented Mar 6, 2015

indutny commented Mar 6, 2015

othiym23 commented Mar 6, 2015

indutny commented Mar 6, 2015

othiym23 commented Mar 6, 2015

indutny commented Mar 9, 2015

indutny commented Mar 9, 2015

indutny commented Mar 9, 2015

indutny commented Mar 9, 2015

misterdjules commented Mar 11, 2015

misterdjules commented Mar 19, 2015

misterdjules commented Mar 25, 2015

misterdjules commented Mar 28, 2015