nodejs / node

Node.js JavaScript runtime ✨🐢🚀✨
https://nodejs.org
Other
107.8k stars 29.71k forks source link

ECONNRESET after response #27916

Closed ronag closed 1 year ago

ronag commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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

lpinca commented 5 years ago

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

ronag commented 5 years ago

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 commented 5 years ago

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

ronag commented 5 years ago

@lpinca How about one of two possible simple mitigations?

lpinca commented 5 years ago

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

ronag commented 5 years ago

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

lpinca commented 5 years ago

Not sure if correct but it makes sense.

ronag commented 5 years ago

Do you mean the current behavior?

lpinca commented 5 years ago

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

lpinca commented 5 years ago

cc: @nodejs/http

addaleax commented 5 years ago

@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 commented 5 years ago

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

lpinca commented 5 years ago

@ronag what version of Node.js? OS?

ronag commented 5 years ago

Node 10.13.0 & OSX

lpinca commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

I tried fedora 30 in docker and was unable to reproduce

lpinca commented 5 years ago
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 commented 5 years ago

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 commented 5 years ago

Found even smaller repro (updated previous comment)

ronag commented 5 years ago

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

himself65 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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

ronag commented 5 years ago

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

lpinca commented 5 years ago

@nodejs/http

ronag commented 5 years ago

@benjamingr can you provide any guidance here?

benjamingr commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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

mcollina commented 5 years ago

@lpinca I’m ok with that as well.

ronag commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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

mcollina commented 5 years ago

@patoi they are likely related.

billymcintosh commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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

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

But this issue is:

emit error is better than crash!

freeall commented 4 years ago

@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 commented 4 years ago

@ronag ... any updates on this one?

ronag commented 4 years ago

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 commented 4 years ago

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

niftylettuce commented 4 years ago

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