`http` requests with `socketPath` lead to `EPIPE` error #41062

mhassan1 · 2021-12-02T18:48:01Z

Version

v16.7.0

Platform

Linux e332ae582690 5.10.47-linuxkit #1 SMP Sat Jul 3 21:51:47 UTC 2021 x86_64 Linux

Subsystem

No response

What steps will reproduce the bug?

Start a server and client using the following scripts:

server.js:

const http = require('http')
http.createServer((req, res) => {
  res.writeHead(200, {'Content-Type': 'text/plain'})
  res.end('ok')
}).listen('sock.sock')

client.js:

const http = require('http')
;(async () => {
  for (let i = 0; i < 1e4; i++) {
    const result = await new Promise((resolve, reject) => {
      const request = http.request({
        method: 'POST',
        socketPath: 'sock.sock',
        headers: {
          'Content-Length': 2
        }
      }, (resp) => {
        resp.statusCode === 200 ? resolve('ok') : reject(new Error(resp.statusCode))
      })
      request.write('{}', null, () => {
        request.end()
      })
    })
    console.log(i, result)
  }
  console.log('done')
})()

On v16.7.0, this leads to an EPIPE error after a few hundred requests. On v16.6.2, it does not hit an EPIPE error after many thousands of requests.

A full Docker Linux reproduction is here: https://github.com/mhassan1/node-16-7-0-request-epipe

How often does it reproduce? Is there a required condition?

It reproduces every time within a few hundred requests.

What is the expected behavior?

No EPIPE.

What do you see instead?

EPIPE after a few hundred requests:

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

Error: write EPIPE
    at afterWriteDispatched (node:internal/stream_base_commons:164:15)
    at writeGeneric (node:internal/stream_base_commons:155:3)
    at Socket._writeGeneric (node:net:780:11)
    at Socket._write (node:net:792:8)
    at writeOrBuffer (node:internal/streams/writable:389:12)
    at _write (node:internal/streams/writable:330:10)
    at Socket.Writable.write (node:internal/streams/writable:334:10)
    at ClientRequest._writeRaw (node:_http_outgoing:362:17)
    at ClientRequest._send (node:_http_outgoing:338:15)
    at ClientRequest.end (node:_http_outgoing:880:10)
Emitted 'error' event on ClientRequest instance at:
    at Socket.socketErrorListener (node:_http_client:447:9)
    at Socket.emit (node:events:394:28)
    at emitErrorNT (node:internal/streams/destroy:157:8)
    at emitErrorCloseNT (node:internal/streams/destroy:122:3)
    at processTicksAndRejections (node:internal/process/task_queues:83:21) {
  errno: -32,
  code: 'EPIPE',
  syscall: 'write'
}

Additional information

This issue is visible when using axios with follow-redirects
This may be the same underlying issue as Simple http proxy with socketPath leads to EPIPE error #40553
This does not reproduce when making requests on a port
This reproduces on v14.18.0 but not v14.17.6

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

mhassan1 · 2021-12-02T18:54:43Z

I believe the key part of the reproduction is the request.write followed by request.end. If I change the following, it no longer reproduces:

// change
request.write('{}', null, () => {
  request.end()
})
// to
request.end('{}')

This may be a viable workaround, although userland packages like follow-redirects and http-proxy will need to change the way they make requests.

lpinca · 2021-12-03T08:44:08Z

From a quick look the problem is in the server code. The socket is destroyed when res.end('ok') is called before the request is full written. It should be

const http = require('http')
http.createServer((req, res) => {
  req.resume()
  res.writeHead(200, {'Content-Type': 'text/plain'})
  req.on('end', () => {
    res.end('ok')
  });
}).listen('sock.sock')

lpinca · 2021-12-03T08:56:06Z

Waiting for the 'end' event as per my previous comment does not seem to make any difference. I think there is a race condition where the socket is closed too early.

lpinca · 2021-12-03T09:17:27Z

I can reproduce with Node.js v16.7.0 but not with Node.js v16.6.2 so I guess this is caused by #39525.

mhassan1 · 2021-12-06T14:13:40Z

@lpinca Do you think this is a bug or an intended change in behavior?

lpinca · 2021-12-06T20:06:05Z

It is a bug. With #41062 (comment) server code no error should be emitted.

mhassan1 · 2021-12-06T20:08:16Z

Do you think it's a bug in libuv or node?

lpinca · 2021-12-06T20:12:01Z

I honestly don't know. The libuv update might have uncovered a latent Node.js bug.

lpinca · 2021-12-06T20:16:55Z

cc: @vtjnash @nodejs/libuv

lpinca · 2021-12-06T20:28:12Z

If I revert libuv/libuv@23bebf0 I can no longer reproduce the issue.

cc: @twose

vtjnash · 2021-12-06T22:06:23Z

It sounds somewhat similar to the bug I fixed in nodejs's TLS around connection management (#36111). That libuv commit is not the primary cause, but it does exacerbate some known bugs in nodejs's network stack. However, it doesn't look like this is using TLS, so that commit won't itself fix this bug. Instead, this is probably the same as the related issues there #39363 and #39683, whereby a malicious client apparently can cause recent versions of nodejs http server to abort the process, by disconnecting network access in the middle of communication.

twose · 2021-12-07T01:58:08Z

I agree with @vtjnash , there are no incompatible or destructive behavior changes in the libuv patch, it just simplifies the code.
And I'm so sorry that I am not familiar with nodejs, so maybe there's nothing I can do to help...

lpinca · 2021-12-07T06:28:02Z

I cannot reproduce the issue if I remove the HTTP layer (using only the net module) ~~and I also cannot reproduce the issue if I use the legacy HTTP parser via the --insecure-http-parser flag~~.

lpinca · 2021-12-07T06:41:36Z

One more thing. I cannot reproduce the issue if the Content-Length header or alternatively request.end() is removed from the client code. My guess is that the server closes the socket after reading the two bytes the of the request body honouring the Content-Length header. The client then tries to write something on the closed socket via request.end() and this raises the EPIPE error.

lpinca · 2021-12-07T19:49:57Z

The problem here is that

node/lib/_http_outgoing.js

Line 883 in 32f7218

this._send('', 'latin1', finish);

might be called right after

node/lib/_http_server.js

Line 823 in 32f7218

socket.destroySoon();

That final empty chunk should technically not be sent as all the data specified by the Content-Length header has already been written.

I'm not sure how to fix this. Replacing socket.destroySoon() with socket.end() as proposed in e6699c6 (#36205) might be an option, but I'm not very comfortable with it for the reasons discussed in #36205. Another option might be to make Socket.prototype._writeGeneric() ignore empty chunks, but there are some TLS tests that fail when I try to do that.

santigimeno · 2021-12-07T20:18:09Z

That final empty chunk should technically not be sent as all the data specified by the Content-Length header has already been written.

Yes, that was my thinking too. This patch seems to fix the issue and the tests, but one which looks easily fixable, seem to be fine with it on Linux. WDYT?

diff --git a/lib/_http_outgoing.js b/lib/_http_outgoing.js
index 27e290a2b9..d04acb03a7 100644
--- a/lib/_http_outgoing.js
+++ b/lib/_http_outgoing.js
@@ -879,8 +879,8 @@ OutgoingMessage.prototype.end = function end(chunk, encoding, callback) {
   if (this._hasBody && this.chunkedEncoding) {
     this._send('0\r\n' + this._trailer + '\r\n', 'latin1', finish);
   } else {
-    // Force a flush, HACK.
-    this._send('', 'latin1', finish);
+    if (!this._headerSent || chunk)
+      this._send('', 'latin1', finish);
   }

lpinca · 2021-12-07T20:26:09Z

@santigimeno it also fixes the issue on macOS. It seems good to me.

lpinca · 2021-12-07T20:37:24Z

On a second look I think that the patch prevents the 'finish' event from being emitted.

When calling OutgoingMessage.end() with empty data argument, avoid writing to the socket unless there's still pending data to be sent. Fixes: nodejs#41062

santigimeno · 2021-12-08T11:29:01Z

@lpinca you are right. Just sent: #41116 which I think addresses the issue. Let me know what you think. Thanks!

When calling OutgoingMessage.end() with empty data argument, avoid writing to the socket unless there's still pending data to be sent. Fixes: nodejs#41062

When calling OutgoingMessage.end() with empty data argument, avoid writing to the socket unless there's still pending data to be sent. Fixes: #41062 PR-URL: #41116 Reviewed-By: Luigi Pinca <luigipinca@gmail.com> Reviewed-By: Gerhard Stöbich <deb2001-github@yahoo.de> Reviewed-By: James M Snell <jasnell@gmail.com>

When calling OutgoingMessage.end() with empty data argument, avoid writing to the socket unless there's still pending data to be sent. Fixes: nodejs#41062 PR-URL: nodejs#41116 Reviewed-By: Luigi Pinca <luigipinca@gmail.com> Reviewed-By: Gerhard Stöbich <deb2001-github@yahoo.de> Reviewed-By: James M Snell <jasnell@gmail.com>

When calling OutgoingMessage.end() with empty data argument, avoid writing to the socket unless there's still pending data to be sent. Fixes: #41062 PR-URL: #41116 Reviewed-By: Luigi Pinca <luigipinca@gmail.com> Reviewed-By: Gerhard Stöbich <deb2001-github@yahoo.de> Reviewed-By: James M Snell <jasnell@gmail.com>

Mesteery added the http Issues or PRs related to the http subsystem. label Dec 2, 2021

santigimeno mentioned this issue Dec 8, 2021

http: don't write empty data on req/res end() #41116

Merged

nodejs-github-bot closed this as completed in #41116 Dec 10, 2021

F3n67u mentioned this issue Jun 25, 2022

write EPIPE error while proxying Websocket requests #43563

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

`http` requests with `socketPath` lead to `EPIPE` error #41062

`http` requests with `socketPath` lead to `EPIPE` error #41062

mhassan1 commented Dec 2, 2021 •

edited

Loading

mhassan1 commented Dec 2, 2021 •

edited

Loading

lpinca commented Dec 3, 2021

lpinca commented Dec 3, 2021

lpinca commented Dec 3, 2021 •

edited

Loading

mhassan1 commented Dec 6, 2021

lpinca commented Dec 6, 2021

mhassan1 commented Dec 6, 2021

lpinca commented Dec 6, 2021

lpinca commented Dec 6, 2021

lpinca commented Dec 6, 2021

vtjnash commented Dec 6, 2021

twose commented Dec 7, 2021

lpinca commented Dec 7, 2021 •

edited

Loading

lpinca commented Dec 7, 2021 •

edited

Loading

lpinca commented Dec 7, 2021 •

edited

Loading

santigimeno commented Dec 7, 2021

lpinca commented Dec 7, 2021

lpinca commented Dec 7, 2021 •

edited

Loading

santigimeno commented Dec 8, 2021

http requests with socketPath lead to EPIPE error #41062

http requests with socketPath lead to EPIPE error #41062

Comments

mhassan1 commented Dec 2, 2021 • edited Loading

Version

Platform

Subsystem

What steps will reproduce the bug?

How often does it reproduce? Is there a required condition?

What is the expected behavior?

What do you see instead?

Additional information

mhassan1 commented Dec 2, 2021 • edited Loading

lpinca commented Dec 3, 2021

lpinca commented Dec 3, 2021

lpinca commented Dec 3, 2021 • edited Loading

mhassan1 commented Dec 6, 2021

lpinca commented Dec 6, 2021

mhassan1 commented Dec 6, 2021

lpinca commented Dec 6, 2021

lpinca commented Dec 6, 2021

lpinca commented Dec 6, 2021

vtjnash commented Dec 6, 2021

twose commented Dec 7, 2021

lpinca commented Dec 7, 2021 • edited Loading

lpinca commented Dec 7, 2021 • edited Loading

lpinca commented Dec 7, 2021 • edited Loading

santigimeno commented Dec 7, 2021

lpinca commented Dec 7, 2021

lpinca commented Dec 7, 2021 • edited Loading

santigimeno commented Dec 8, 2021

`http` requests with `socketPath` lead to `EPIPE` error #41062

`http` requests with `socketPath` lead to `EPIPE` error #41062

mhassan1 commented Dec 2, 2021 •

edited

Loading

mhassan1 commented Dec 2, 2021 •

edited

Loading

lpinca commented Dec 3, 2021 •

edited

Loading

lpinca commented Dec 7, 2021 •

edited

Loading

lpinca commented Dec 7, 2021 •

edited

Loading

lpinca commented Dec 7, 2021 •

edited

Loading

lpinca commented Dec 7, 2021 •

edited

Loading