investigate flaky test/parallel/test-http-many-ended-pipelines.js

[Trott]

• Test: test/parallel/test-http-many-ended-pipelines.js
• Platform: macOS 10.14, macOS 10.15
• Console Output:

HTTP/1.1 200 OK
Date: Tue, 09 Feb 2021 08:14:57 GMT
Connection: keep-alive
Keep-Alive: timeout=5
Content-Length: 2

ok
node:events:355
      throw er; // Unhandled 'error' event
      ^

Error: read ECONNRESET
    at TCP.onStreamRead (node:internal/stream_base_commons:211:20)
Emitted 'error' event on Socket instance at:
    at emitErrorNT (node:internal/streams/destroy:192:8)
    at emitErrorCloseNT (node:internal/streams/destroy:157:3)
    at processTicksAndRejections (node:internal/process/task_queues:81:21) {
  errno: -54,
  code: 'ECONNRESET',
  syscall: 'read'
}

• Build Links: https://ci.nodejs.org/job/node-test-commit-osx/38908/nodes=osx1014/testReport/junit/(root)/test/parallel_test_http_many_ended_pipelines/

[Trott]

I'm able to replicate this locally with this command:

tools/test.py -j96 --repeat=1920 test/parallel/test-http-many-ended-pipelines.js

If I remove the -j96, I am unable to replicate it. So that suggests some sort of resource constraint (memory? CPU? network? file descriptors? something) makes the issue more likely to happen.

[Trott]

I know there's been some refactoring of streams and stream-like http/net events, and even some small breaking changes I believe.

@ronag @lpinca Any idea if the bug here is in the test code or if it's probably indicative of a bug in Node.js core?

[lpinca]

It seems to me that the test is flaky by design. The socket might be destroyed server-side while the client is still writing to it.

[ronag]

I think the test is missing a 'error' handler. An ´ECONNRESET` looks like a expected/normal thing here.

[lpinca]

The issue can be exacerbated by increasing numRequests. Setting it to 2000 makes the test always fail on my machine.

Also, there seems to be an unwanted MaxListenersExceededWarning caused by

node/lib/_http_incoming.js

Lines 180 to 183 in 33d3a2e

	const cleanup = finished(this.socket, (e) => {
	cleanup();
	onError(this, e || err, cb);
	});

. I think the condition here

node/lib/_http_incoming.js

Line 178 in 33d3a2e

if (this.socket && this.aborted) {

should prevent finished() from being called again with the same socket argument.

[lpinca]

@ronag, the second issue (the unwanted warnings) seems to be caused by 2da3611. I'm not sure if it makes sense to revert it.

[ronag]

@ronag, the second issue (the unwanted warnings) seems to be caused by 2da3611. I'm not sure if it makes sense to revert it.

I don't think we should revert. I'll see if I can find a better solution.

[jameshilliard]

I'm seeing this error in an application of mine on OSX 10.15.7, seemingly immediately after the client closes a websocket connection.

GET /nats 2ms (unfinished)
node:events:355
      throw er; // Unhandled 'error' event
      ^

Error: read ECONNRESET
    at TCP.onStreamRead (node:internal/stream_base_commons:211:20)
Emitted 'error' event on Socket instance at:
    at emitErrorNT (node:internal/streams/destroy:188:8)
    at emitErrorCloseNT (node:internal/streams/destroy:153:3)
    at processTicksAndRejections (node:internal/process/task_queues:81:21) {
  errno: -54,
  code: 'ECONNRESET',
  syscall: 'read'
}
WARNING - child /Users/jameshilliard/.nvm/versions/node/v15.8.0/bin/node exited with code 1

TCP stream captures from wireshark below.

client->server:

GET /nats HTTP/1.1
Host: 127.0.0.1:5002
Connection: Upgrade
Pragma: no-cache
Cache-Control: no-cache
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.150 Safari/537.36
Upgrade: websocket
Origin: http://127.0.0.1:5002
Sec-WebSocket-Version: 13
Accept-Encoding: gzip, deflate, br
Accept-Language: en-US,en;q=0.9,zh-CN;q=0.8,zh;q=0.7
Cookie: *removed*
Sec-WebSocket-Key: QBAgXK0zfCKz/dMS6Pb6Sw==
Sec-WebSocket-Extensions: permessage-deflate; client_max_window_bits

server->client:

HTTP/1.1 200 OK
Connection: close
content-type: text/plain; charset=UTF-8

Welcome to SockJS!

Any idea what's going on here or how to debug further?

[jameshilliard]

Looks like this is what's triggering it.

Generated javascript is:

  fake_response = function(req, res) {
    var headers;
    headers = {
      'Connection': 'close'
    };
    res.writeHead = function(status, user_headers) {
      var k, r, x;
      if (user_headers == null) {
        user_headers = {};
      }
      r = [];
      r.push('HTTP/' + req.httpVersion + ' ' + status + ' ' + http.STATUS_CODES[status]);
      utils.objectExtend(headers, user_headers);
      for (k in headers) {
        r.push(k + ': ' + headers[k]);
      }
      r = r.concat(['', '']);
      try {
        return res.write(r.join('\r\n'));
      } catch (error1) {
        x = error1;
      }
    };
    return res.setHeader = function(k, v) {
      return headers[k] = v;
    };
  };

There's a try catch block around the return res.write(r.join('\r\n')); but it still crashes nodejs for some reason.

If I remove that try catch block entirely it no longer crashes...but I don't understand why the try catch block doesn't catch the error.

Adding res.on('error', () => {}); fixes this in sockjs it seems.

[Trott]

@jameshilliard In a vanilla callback context, try/catch will catch thrown errors, not error events. Prior to async/await, try/catch was favored for synchronous errors and error events were emitted for asynchronous errors. Since you're not using async/await, those rules apply here.

Your issue is not related to the issue being discussed here. They have the same error code, but a connection reset can be caused by many, many things. I'm going to hide your comments as off-topic. If you need further help, I'd suggest opening an issue in [the SockJS repository[(https://github.com/sockjs/sockjs-node), the help repository or on StackOverflow.

[jameshilliard]

Your issue is not related to the issue being discussed here. They have the same error code, but a connection reset can be caused by many, many things.

Ah, I was assuming nodejs made some change that broke that particular sockjs code.