win,pipe: support vectored writes, fix IPC deadlock

[piscisaureus]

Fixes: #794
Fixes: #1099
Refs: nodejs/node#7657
Refs: electron/electron#10107
Refs: parcel-bundler/parcel#637
Refs: parcel-bundler/parcel#900
Refs: parcel-bundler/parcel#1137

[bzoz]

"more bytes more bytes"

[piscisaureus]

fixed

[bzoz]

CI: https://ci.nodejs.org/view/libuv/job/libuv-test-commit/847/
CI-node: https://ci.nodejs.org/view/libuv/job/libuv-in-node/20/

[bzoz]

CI is red, on Linux it complains about undefined reference to ipc_helper_heavy_traffic_deadlock_bug, on Windows one of the test is failing:

not ok 150 - pipe_getsockname_blocking
# exit code -1073741819
# Output from process `pipe_getsockname_blocking`: (no output)

[piscisaureus]

@bnoordhuis
I am at a loss about why the test added in be7978d fails on linux.
It seems that writev() blocks after writing ~160kb of data to the socket.
I would not expect it to do that; it is properly set to nonblocking mode, so why doesn't it fail with EAGAIN?

[santigimeno]

Some comments, style mainly.

[santigimeno]

We're using this header now.

[piscisaureus]

Right, thanks, copypasta.

[piscisaureus]

fixed

[santigimeno]

style: separate declaration from assignment

[piscisaureus]

loop was unused anyway, so I removed it.

[santigimeno]

Add this file to checksparse.sh as well?

[piscisaureus]

fixed

[santigimeno]

style: drop braces

[piscisaureus]

fixed

[santigimeno]

style: drop braces

[piscisaureus]

fixed

[santigimeno]

style: drop braces

[piscisaureus]

fixed

[santigimeno]

style: drop braces

[piscisaureus]

fixed

[santigimeno]

Just curious: we're using uv_translate_sys_error while in the rest on the function the error is returned directly

[piscisaureus]

Yeah, that looks incorrect. The code path is likely never taken, I don't think WaitForSingleObject can conceivably fail, unless hEvent is invalid, in which case there is a bug elsewhere.

[piscisaureus]

fixed

[santigimeno]

It seems that writev() blocks after writing ~160kb of data to the socket.

I haven't analyzed the test but by calling the test with strace it does not seem that way: it seems every call to writev completes. These are the last lines before the test runner kills the test due to exceed the timeout

[pid  4225] 12:42:38.858250 <... writev resumed> ) = 24576
[pid  4223] 12:42:38.858257 <... epoll_wait resumed> [{EPOLLIN, {u32=11, u64=11}}], 1024, -1) = 1
[pid  4225] 12:42:38.858267 writev(0, [{iov_base="********************************"..., iov_len=8192}, {iov_base="********************************"..., iov_len=8192}, {iov_base="********************************"..., iov_len=8192}], 3 <unfinished ...>
[pid  4223] 12:42:38.858282 recvmsg(11,  <unfinished ...>
[pid  4225] 12:42:38.858293 <... writev resumed> ) = 24576
[pid  4223] 12:42:38.858306 <... recvmsg resumed> {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="********************************"..., iov_len=65536}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_CMSG_CLOEXEC) = 49152
[pid  4225] 12:42:38.858318 brk(0x556880b48000 <unfinished ...>
[pid  4223] 12:42:38.858353 epoll_wait(4,  <unfinished ...>
[pid  4225] 12:42:38.858751 <... brk resumed> ) = 0x556880b48000
[pid  4225] 12:42:38.858766 epoll_wait(4, [{EPOLLOUT, {u32=0, u64=0}}], 1024, 0) = 1
[pid  4225] 12:42:38.858792 epoll_ctl(4, EPOLL_CTL_DEL, 0, 0x7ffe5796edb0) = 0
[pid  4225] 12:42:38.858822 epoll_wait(4,

[piscisaureus]

@santigimeno If you run the test without supervision of the test harness (out/Debug/run-tests ipc_heavy_traffic_deadlock_bug ipc_heavy_traffic_deadlock_bug), does it complete for you on linux?

[gireeshpunathil]

I see two potential issues:

• ASSERT(nread >= 0); in read_cb : I guess we cannot guarantee this given the uv_read can return negative values on error?
• it is so possible that the test takes longer than the prescribed timeout by the runner?

[santigimeno]

What I see is that the child process receives all the data and exits correctly but the parent process is stuck. It looks some pending handle needs to be closed.

[piscisaureus]

@gireeshpunathil

ASSERT(nread >= 0); in read_cb : I guess we cannot guarantee this given the uv_read can return negative values on error?

Where in the code is this / should it be?

It is so possible that the test takes longer than the prescribed timeout by the runner?

I think that's unlikely. The tests makes 256 write calls and sends a grand total of 6mb of data to the child process. The child process does the same in the other direction. That should not even take a second.

[gireeshpunathil]

I believe nread here is overloaded with the number of bytes written | error code from the syscall (which can be negative)

[piscisaureus]

That's correct. The assert is here to check that there were no read errors (we don't expect any).

[gireeshpunathil]

@piscisaureus - highlighted the point above. Agreed on the timeout stuff, shouldn't take that much ( I was speculating). Now that @santigimeno has spotted a hang, I guess that looks to be the right direction.

[santigimeno]

The ipc channel needs to be closed. This patch fixes the issue locally for me:

diff --git a/test/test-ipc-heavy-traffic-deadlock-bug.c b/test/test-ipc-heavy-traffic-deadlock-bug.c
index 62868e6a..d1b54bff 100644
--- a/test/test-ipc-heavy-traffic-deadlock-bug.c
+++ b/test/test-ipc-heavy-traffic-deadlock-bug.c
@@ -81,6 +81,15 @@ static void alloc_cb(uv_handle_t* handle,
 static void read_cb(uv_stream_t* handle, ssize_t nread, const uv_buf_t* buf) {
   ssize_t i;
   int r;
+  uv_shutdown_t shut_req;
+
+  if (nread == UV_EOF) {
+    ASSERT(bytes_read == XFER_SIZE);
+    r = uv_read_stop(handle);
+    ASSERT(r == 0);
+    uv_close((uv_handle_t*)handle, NULL);
+    return;
+  }
 
   ASSERT(nread >= 0);
   bytes_read += nread;
@@ -91,7 +100,7 @@ static void read_cb(uv_stream_t* handle, ssize_t nread, const uv_buf_t* buf) {
   free(buf->base);
 
   if (bytes_read >= XFER_SIZE) {
-    r = uv_read_stop(handle);
+    uv_shutdown(&shut_req, handle, NULL);
     ASSERT(r == 0);
   }
 }