Node sometimes locks up when reading from named pipe on Windows

[mika-fischer]

Version

v22.13.1

Platform

Microsoft Windows NT 10.0.26100.0 x64

Subsystem

No response

What steps will reproduce the bug?

Node is sometimes locking up completely. Unfortunately, it happens only in production, and we have not yet been able to reproduce it. However, we received a memory dump of the nodejs process which shows that it hangs in the following call stack:

 	ntdll.dll!NtWaitForSingleObject()	Unbekannt
 	KERNELBASE.dll!WaitForSingleObjectEx()	Unbekannt
 	KERNELBASE.dll!GetOverlappedResult()	Unbekannt
 	node.exe!uv__pipe_read_data(uv_loop_s * loop, uv_pipe_s * handle, unsigned long * bytes_read, unsigned long max_bytes) Zeile 2008	C
 	node.exe!uv__process_pipe_read_req(uv_loop_s * loop, uv_pipe_s * handle, uv_req_s * req) Zeile 2162	C
 	[Inlineframe] node.exe!uv__process_reqs(uv_loop_s *) Zeile 159	C
 	node.exe!uv_run(uv_loop_s * loop, uv_run_mode mode) Zeile 639	C
 	node.exe!node::SpinEventLoopInternal(node::Environment * env) Zeile 42	C++
 	[Inlineframe] node.exe!node::NodeMainInstance::Run(node::ExitCode *) Zeile 110	C++
 	node.exe!node::NodeMainInstance::Run() Zeile 100	C++
 	node.exe!node::StartInternal(int argc, char * * argv) Zeile 1540	C++
 	node.exe!node::Start(int argc, char * * argv) Zeile 1548	C++
 	node.exe!wmain(int argc, wchar_t * * wargv) Zeile 91	C++
 	[Inlineframe] node.exe!invoke_main() Zeile 90	C++
 	node.exe!__scrt_common_main_seh() Zeile 288	C++
 	kernel32.dll!BaseThreadInitThunk()	Unbekannt
 	ntdll.dll!RtlUserThreadStart()	Unbekannt

I looked in the node and libuv issues and it looks very much like libuv/libuv#4738 . Unfortunately, the submitter closed this issue without any input from the developers.

I think this issue is real and under some circumstances, node triggers it and as a result completely locks up.

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

At the customer's site this is reliably reproducable. However, the data used to trigger the issue cannot be shared with us. We'll try to reproduce it locally, but this might prove somewhat difficult. I think libuv/libuv#4738 and the analysis contained within is the key to solving this.

What is the expected behavior? Why is that the expected behavior?

Node should not lock up

What do you see instead?

Node locks up

Additional information

No response

[mika-fischer]

I can now reproduce the issue locally, but it is difficult to create an isolated test case. Still working on that though.

I can, however, already confirm that the issue does not happen with node 22.11.0 (libuv 1.48.0). So the commit mentioned in libuv/libuv#4738 seems more and more likely to be the cause.

[mika-fischer]

Minimal reproducing example below.

Some additional observations:

• The issue is triggered by reading exactly 65536 bytes at once, as hypothesized in Hang issue in Windows named pipes support libuv/libuv#4738
• The code where the hang happens is here:

  node/deps/uv/src/win/pipe.c

  Lines 2000 to 2008 in 41c50bc

  	if (ReadFile(handle->handle, buf.base, max_bytes, bytes_read, &req->u.io.overlapped)) {
  	r = ERROR_SUCCESS;
  	} else {
  	r = GetLastError();
  	*bytes_read = 0;
  	if (r == ERROR_IO_PENDING) {
  	r = CancelIoEx(handle->handle, &req->u.io.overlapped);
  	assert(r || GetLastError() == ERROR_NOT_FOUND);
  	if (GetOverlappedResult(handle->handle, &req->u.io.overlapped, bytes_read, TRUE)) {

• ReadFile returns 0 with GetLastError() == ERROR_IO_PENDING
• CancelIoEx returns 1
• GetOverlappedResult is called and blocks indefinitely...
• AFAICT this should not happen after CancelIoEx succeeds, but I don't have any experience with win32 overlapped io...

import assert from "node:assert";
import { spawn } from "node:child_process";
import { execPath } from "node:process";
import { read, write } from "node:fs";

const REQ_SIZE = 30;
const RES_SIZE = 65_536; // size is important!

function runChild() {
  const write_res = () => {
    write(3, Buffer.alloc(RES_SIZE), (err, bytesWritten) => {
      assert.equal(err, null);
      console.log(`C: write: ${bytesWritten}`);
      assert.equal(bytesWritten, RES_SIZE);
    });
    read_req();
  };
  const read_req = () => {
    read(3, (err, bytesRead) => {
      assert.equal(err, null);
      console.log(`C: read:  ${bytesRead}`);
      assert.equal(bytesRead, REQ_SIZE);
      write_res();
    });
  };
  read_req();
}

function runParent() {
  const pipe = spawn(execPath, [import.meta.filename, "--child"], {
    stdio: ["inherit", "inherit", "inherit", "pipe"],
  }).stdio[3];
  pipe.on("readable", () => {
    const res = pipe.read();
    console.log(`P: read:  ${res.byteLength}`);
    assert.equal(res.byteLength, RES_SIZE);
    setImmediate(write_req); // setImmediate is important!
  });
  const write_req = () => {
    console.log(`P: write: ${REQ_SIZE}`);
    pipe.write(Buffer.alloc(REQ_SIZE));
  };
  write_req();
}

process.argv.includes("--child") ? runChild() : runParent();

[vtjnash]

I think that is expected. Reading and writing on the same handle is not reliable in the Windows kernel and generally programs that use libuv (such as nodejs) should avoid creating those sorts of handles. We have some workarounds in place (uv__pipe_interrupt_read) which work most of the time, but that may require some cooperation from the runtime (nodejs) to make sure it called that function whenever switching between reading and writing. Note that I'm assuming the hang occurred in the parent based on the report stacktrace. If the hang is in the child, that should have been using a different code path, and that might be a different bug instead.

[mika-fischer]

Using two pipes was the first thing I tried in our production code as a workaround and it did not help. I'll update the example above tomorrow to use two pipes.

But nevertheless a complete lockup of the whole node process should not be an acceptable outcome, right?

And yes, it's the parent process that blocks.

[mika-fischer]

Here you go, same problem using two dedicated pipes:

import assert from "node:assert";
import { spawn } from "node:child_process";
import { execPath } from "node:process";
import { read, write } from "node:fs";

const REQ_SIZE = 30;
const RES_SIZE = 65_536; // size is important!

function runChild() {
  const write_res = () => {
    write(4, Buffer.alloc(RES_SIZE), (err, bytesWritten) => {
      assert.equal(err, null);
      console.log(`C: write: ${bytesWritten}`);
      assert.equal(bytesWritten, RES_SIZE);
    });
    read_req();
  };
  const read_req = () => {
    read(3, (err, bytesRead) => {
      assert.equal(err, null);
      console.log(`C: read:  ${bytesRead}`);
      assert.equal(bytesRead, REQ_SIZE);
      write_res();
    });
  };
  read_req();
}

function runParent() {
  const [a, b, c, out_pipe, in_pipe] = spawn(
    execPath,
    [import.meta.filename, "--child"],
    {
      stdio: ["inherit", "inherit", "inherit", "pipe", "pipe"],
    }
  ).stdio;
  in_pipe.on("readable", () => {
    const res = in_pipe.read();
    console.log(`P: read:  ${res.byteLength}`);
    assert.equal(res.byteLength, RES_SIZE);
    setImmediate(write_req); // setImmediate is important!
  });
  const write_req = () => {
    console.log(`P: write: ${REQ_SIZE}`);
    out_pipe.write(Buffer.alloc(REQ_SIZE));
  };
  write_req();
}

process.argv.includes("--child") ? runChild() : runParent();

[mika-fischer]

Oh, and just to be clear, the issue reproduces reliably every time on the first try.

[mika-fischer]

I simplified the code further and I also tried reproducing this with libuv directly, but was so far unable to. See all code at https://github.com/mika-fischer/node-bug-win-pipe-hang

@vtjnash @bnoordhuis Would you mind taking another look? Especially, do you know what my libuv code does differently than my node code that could explain the different behavior?

I don't know how to debug this further, but I think this is a serious regression that should be fixed. At least we can't use node if there's always the risk of the whole process locking up due to this...