Node: ECONNRESET after response

[ronag]

This was for me a bit of surprising behavior. You can get a connection error after a response.

const http = require('http')

const server = http.createServer(function (req, res) {
  req.on('data', () => {})
  setTimeout(() => {
    // Prematurely ending the request. Usually due to a 5xx error.
    res.statusCode = 200
    res.end()
  }, 1000)
})

server.listen(0, function () {
  const req = http.request({
    port: this.address().port,
    method: 'POST',
    path: '/'
  })
  req.on('response', res => {
    console.log("!", res.statusCode)
    clearInterval(interval)
  })
  const interval = setInterval(() => {
    req.write(Buffer.alloc(32))
  }, 1000)
})

Which sometimes prints:

! 200
events.js:167
      throw er; // Unhandled 'error' event
      ^

Error: read ECONNRESET
    at TCP.onStreamRead (internal/stream_base_commons.js:111:27)
Emitted 'error' event at:
    at Socket.socketErrorListener (_http_client.js:391:9)
    at Socket.emit (events.js:182:13)
    at emitErrorNT (internal/streams/destroy.js:82:8)
    at emitErrorAndCloseNT (internal/streams/destroy.js:50:3)
    at process._tickCallback (internal/process/next_tick.js:63:19)

I can't quite decide if this is wrong or right. I feel like it should either be a response or an error, not both... at least it should be consistent and happen just sometimes... Anyone, got any input?

[ronag]

I had to run it a few times to get it to fail:

^Cnxt$ nodemon test.js 
[nodemon] 1.19.0
[nodemon] to restart at any time, enter `rs`
[nodemon] watching: *.*
[nodemon] starting `node test.js`
! 200
^Cnxt$ nodemon test.js 
[nodemon] 1.19.0
[nodemon] to restart at any time, enter `rs`
[nodemon] watching: *.*
[nodemon] starting `node test.js`
! 200
^Cnxt$ nodemon test.js 
[nodemon] 1.19.0
[nodemon] to restart at any time, enter `rs`
[nodemon] watching: *.*
[nodemon] starting `node test.js`
! 200
events.js:167
      throw er; // Unhandled 'error' event
      ^

Error: read ECONNRESET
    at TCP.onStreamRead (internal/stream_base_commons.js:111:27)
Emitted 'error' event at:
    at Socket.socketErrorListener (_http_client.js:391:9)
    at Socket.emit (events.js:182:13)
    at emitErrorNT (internal/streams/destroy.js:82:8)
    at emitErrorAndCloseNT (internal/streams/destroy.js:50:3)
    at process._tickCallback (internal/process/next_tick.js:63:19)
[nodemon] app crashed - waiting for file changes before starting...

[ronag]

Adding a abort after response seems to stop the error from being emitted. Even though https://github.com/nodejs/node/pull/20077 is not merged.

[ronag]

I think we should always emit a ECONNRESET error if we get a response to a request which hasn't .end():ed?

[lpinca]

It probably happens because the client writes right after the server destroyed the socket (after the response was written).

[ronag]

Should this be considered a bug? I can see a lot of potential cases where this can cause surprises... especially where developers might think the requests are "ok", "done", "no worries" after a response and might e.g. remove the error event listener.

[lpinca]

I don't know It's a race condition probably hard to fix.

[ronag]

@lpinca How about one of two possible simple mitigations?

• Don't emit error after response.
• Don't emit response if request is not ended.

[lpinca]

I think both are not viable because there is no guarantee that the full response will be written in a single chunk.

[ronag]

@lpinca just to be clear, what do you think is the correct behavior here?

[lpinca]

Not sure if correct but it makes sense.

[ronag]

Do you mean the current behavior?

[lpinca]

Yes, it's weird but I can see why it happens.

[lpinca]

cc: @nodejs/http

[addaleax]

@lpinca It’s not obvious to me why there’s an ECONNRESET in the first place… why is the socket destroyed rather than cleanly .end()ed?

[lpinca]

Good point, should not be destroyed my bad, seems like a bug then.

[lpinca]

@ronag what version of Node.js? OS?

[ronag]

Node 10.13.0 & OSX

[lpinca]

Thanks, I will test tomorrow on macOS, right now I'm using Node.js v10.15.3 on Fedora 30 and I can't reproduce.

[ronag]

I was able to reproduce on 10.15.3

Now using node v10.15.3 (npm v6.4.1)
nxt$ open test.js ^C
nxt$ node test.js 
! 200
^C
nxt$ node test.js 
! 200
^C
nxt$ 
nxt$ node test.js 
! 200
^C
nxt$ node test.js 
! 200
^C
nxt$ node test.js 
! 200
^C
nxt$ node test.js 
! 200
^C
nxt$ node test.js 
! 200
^C
nxt$ node test.js 
! 200
events.js:174
      throw er; // Unhandled 'error' event
      ^

Error: read ECONNRESET
    at TCP.onStreamRead (internal/stream_base_commons.js:111:27)
Emitted 'error' event at:
    at Socket.socketErrorListener (_http_client.js:392:9)
    at Socket.emit (events.js:189:13)
    at emitErrorNT (internal/streams/destroy.js:82:8)
    at emitErrorAndCloseNT (internal/streams/destroy.js:50:3)
    at process._tickCallback (internal/process/next_tick.js:63:19)

[ronag]

I tried fedora 30 in docker and was unable to reproduce

[lpinca]

Expand

$ while [ $? == 0 ]; do node test.js; done
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
! 200
^C

I've only added setTimeout(() => server.close(), 100); after clearInterval() to make it exit.

[ronag]

Using the following example I am able to reproduce the scenario every time on OSX:

const http = require('http')

const server = http.createServer(function (req, res) {
  res.end()
})

server.listen(0, function () {
  const req = http.request({
    port: this.address().port,
    method: 'POST',
    path: '/'
  })
  req.on('response', res => {
    req.write(Buffer.alloc(32))
  })
  req.write(Buffer.alloc(32))
})

[ronag]

Found even smaller repro (updated previous comment)

[ronag]

Seems related to OSX. Can't reproduce on debian (docker node:latest) either.

[Himself65]

Using the following example I am able to reproduce the scenario every time on OSX:

const http = require('http')

const server = http.createServer(function (req, res) {
  res.end()
})

server.listen(0, function () {
  const req = http.request({
    port: this.address().port,
    method: 'POST',
    path: '/'
  })
  req.on('response', res => {
    req.write(Buffer.alloc(32))
  })
  req.write(Buffer.alloc(32))
})

It's crashed on my Windows with node v10.13.5

C:\Users\himself65\Desktop\Github\test>node index2.js
events.js:174
      throw er; // Unhandled 'error' event
      ^

Error: read ECONNRESET
    at TCP.onStreamRead (internal/stream_base_commons.js:111:27)
Emitted 'error' event at:
    at Socket.socketErrorListener (_http_client.js:392:9)
    at Socket.emit (events.js:189:13)
    at emitErrorNT (internal/streams/destroy.js:82:8)
    at emitErrorAndCloseNT (internal/streams/destroy.js:50:3)
    at process._tickCallback (internal/process/next_tick.js:63:19)

[lpinca]

Can reproduce on both Windows and macOS but it seems my original guess is correct.

The socket is destroyed when res.end() is called
https://github.com/nodejs/node/blob/ac95c2f0f12d71bb27502767c38c1e770a3ec25d/lib/_http_server.js#L615

because the connection is not kept alive. Perhaps we should make req.write() throw/emit an error if used after the 'response' event is received.

[ronag]

because the connection is not kept alive. Perhaps we should make req.write() throw/emit an error if used after the 'response' event is received.

Sounds like a good idea. However, it still leaves things a bit tricky to use:

const req = http.request({ ... })

src
  .pipe(req)
  .on('error', onError)
  .on('response', res => {
    src.unpipe(req) // IMPORTANT or you might get unexpected errors
  })

Could maybe req.write be a noop (i.e. dump) or return false after a response has been received? (yes, it sounds bad in my ear as well)

[aPoCoMiLogin]

For me it also occurs on linux (docker node:11.15.0-alpine image), at really low rate, but still target server had responded in time with 200 status code, but still got "socket hang up".

[billymcintosh]

Baremetal linux here & v10.10.0. I am sending a few 100mb of Buffer.from(stringified_json).

[ronag]

@lpinca @mcollina This issue has stalled? Can we raise this to node/http? It seems like a more fundamental issue.

[lpinca]

@nodejs/http

[ronag]

@benjamingr can you provide any guidance here?

[benjamingr]

Hey just to be clear I am willing to review the PRs because I want stuff to not be stuck and I like your work but I am not an expert nor do I have a strong opinion on what we should do (other than fix the Mac bug and throw better on it as others have mentioned)

Definitely take Anna's word over mine in terms of correct behavior here :)

[mcollina]

I'm not convinced this is a bug on the client at all, i.e. ECONNRESET can happen at any time and we should not specifically guard against any platform specific case on the client (minus the discussion on 'aborted' in some other issue/pr).

The example in https://github.com/nodejs/node/issues/27916#issuecomment-496025563 is _clearly_ showing that:

1. the server is not interested in the input.
2. Calling res.end() means "that server should consider this message complete".
3. the client and the server are lacking handling 'error' and 'abort' events.

I think that if the server is still receiving a body after res.end() then the server handler has a bug.

I think we should either:

1. wait in ending the response (including that destroySoon() call) until the request body is fully received (or dumped)
2. throw on end() if we have not finished receiving the body.

I think 1 is less disruptive, and it will fix this bug.

[lpinca]

To be honest I would prefer to keep it as is.

[mcollina]

@lpinca I’m ok with that as well.

[ronag]

What are your thoughts there? In my opinion we have a perfectly valid (even if not fully sensical) use case which will throw an error...

[ronag]

e.g. I have an example in WebDAV where the PROPFIND method can send a JSON body but the server doesn't always care about the body and will sometimes just end the response with a valid reply while the client might still be sending the JSON body.

The client should (in my opinion) not fail in this case and just continue working without error.

[lpinca]

Add and 'error' listener and handle it somehow even if the handler is a noop. Let the user decide what to do with it.

[ronag]

I disagree... anyhow I think we should at least update the docs somehow. According to the current flow ECONNRESET should not happen on the request object after response.

[patoi]

Is this related? It seems a long-standing issue.
https://github.com/nodejs/node/issues/12339#issuecomment-439918312

[mcollina]

@patoi they are likely related.

[billymcintosh]

Baremetal linux here & v10.10.0. I am sending a few 100mb of Buffer.from(stringified_json).

With reference to the above; I ensured the server that I was sending to could handle my payload (and more) - and it has been solid as a rock. No errors in a month.

[ang-st]

Is this related? It seems a long-standing issue.

I can confirm it's long standing as I can track it back from V7. I experience it at least once a day actually and so far i'm struggling at catching it outside process.on('uncaughtException', ..) as the backtrace is not meaningfull

{ Error: read ECONNRESET
    at TLSWrap.onStreamRead (internal/stream_base_commons.js:171:27) errno: 'ECONNRESET', code: 'ECONNRESET', syscall: 'read' }
 1: 0x95bd00 node::Abort() [node]
 2: 0x9c7b99  [node]
 3: 0xbc6d2a  [node]
 4: 0xbc78d9 v8::internal::Builtin_HandleApiCall(int, v8::internal::Object**, v8::internal::Isolate*) [node]
 5: 0x88ad594fc5d

Hope you guys will find a usable solution soon :)

[Sanbornzhang]

when server reject request should close http connection. it works, but still have some issue.

 res.set("Connection", "close");

But this issue is:

• when server down or the server is not interested in the input. the client should't crash .

emit error is better than crash!

[freeall]

@ang-st that's my big issues as well. It's fair to throw the error, but the stack trace is basically "there's an error somewhere in your program" which isn't helpful.

I don't enough about node core to know if it's very difficult to show where the error initiated (e.g. .pipe/.write) or even just the name of the variable.

[jasnell]

@ronag ... any updates on this one?

[ronag]

Tried making sense of this again but I think it will need a bit more time than I have at the moment. Added it to my list and will revisit this at opportunity.

[niftylettuce]

I also have this issue, Node v12.18.2 on our API server for https://forwardemail.net.

[niftylettuce]

Pretty sure this is related to tuning https://github.com/forwardemail/forwardemail.net/commit/9deef22f3b9ca5e9e1e1843b33d8114b3798dd2b.

[niftylettuce]

After deploying the previous fix, the number of occurrences went down drastically. I also just deployed this https://github.com/forwardemail/forwardemail.net/commit/f931682688d4c38c50568fbccfd433ba209f4ce9

_whack-a-mole_

[niftylettuce]

I have yet to see the issue since I have deployed the previous comment, but I will follow up if so.

[niftylettuce]

Issue came back up, none of the above comments were fixes. Please ignore.

[MarcGodard]

So I recently started seeing this in my console (terminal and server logs) after a switch to firefox browser, and noticed that it happens a lot when the tools are closed or disable cache is disabled. With cache disabled, I don't seem to have an issue. Sorry if this is the wrong venue for this question, but how do I debug this?

I also get this accompanying error:

Error: write EPIPE
    at afterWriteDispatched (internal/stream_base_commons.js:154:25)
    at writevGeneric (internal/stream_base_commons.js:137:3)
    at Socket._writeGeneric (net.js:784:11)
    at Socket._writev (net.js:793:8)
    at doWrite (_stream_writable.js:401:12)
    at clearBuffer (_stream_writable.js:519:5)
    at Socket.Writable.uncork (_stream_writable.js:338:7)
    at ServerResponse.OutgoingMessage.uncork (_http_outgoing.js:244:17)
    at connectionCorkNT (_http_outgoing.js:690:8)
    at processTicksAndRejections (internal/process/task_queues.js:84:21) {
  errno: 'EPIPE',
  code: 'EPIPE',
  syscall: 'write'
}