bug in libuv io_uring causes incorrect event reports to epoll and busy loop

[vtjnash]

bug in libuv io_uring causes incorrect event reports to epoll and busy loop

[giordano]

You want to build julia with

make ... USE_BINARYBUILDER_LIBUV=0

to compile libuv locally, instead of downloading a prebuilt binary (compiled with BinaryBuilder, hence the name of the option), which is the default behaviour.

[vtjnash]

You can additionally set DEPS_GIT=libuv and it will checkout a git repo in deps/srccache/libuv that you can modify locally. (commonly these options are set in a Make.user file in the toplevel folder, so that you don't have to type them on the command line each time). If you do that call make -C deps reinstall-libuv to rebuild it with your changes.

Thanks for taking a look!

[vtjnash]

If you don't have those USE_BINARYBUILDER_LIBUV=0 DEPS_GIT=libuv options in your Make.user, you will need to specify them every time

[santigimeno]

I'm happy to take a look but have no experience with Julia so please, bear with me. Following this I've been able to reproduce the issue by building Julia from commit JuliaLang/julia@e5496e0. Then I wanted to use a modified version of the libuv code on top of JuliaLang@344a3f5 in which I added some logs that print to stderr and added these changes locally with this patch:

diff --git a/deps/libuv.mk b/deps/libuv.mk
index eacabac55e..3b02d6a90e 100644
--- a/deps/libuv.mk
+++ b/deps/libuv.mk
@@ -1,7 +1,7 @@
 ## LIBUV ##
 ifneq ($(USE_BINARYBUILDER_LIBUV),1)
-LIBUV_GIT_URL:=https://github.com/JuliaLang/libuv.git
-LIBUV_TAR_URL=https://api.github.com/repos/JuliaLang/libuv/tarball/$1
+LIBUV_GIT_URL:=https://github.com/santigimeno/libuv.git
+LIBUV_TAR_URL=https://api.github.com/repos/santigimeno/libuv/tarball/$1
 $(eval $(call git-external,libuv,LIBUV,configure,,$(SRCCACHE)))
 
 UV_CFLAGS := -O2
diff --git a/deps/libuv.version b/deps/libuv.version
index 9ae54aa7be..7b980773dc 100644
--- a/deps/libuv.version
+++ b/deps/libuv.version
@@ -3,5 +3,5 @@ LIBUV_JLL_NAME := LibUV
 
 ## source build
 LIBUV_VER := 2
-LIBUV_BRANCH=julia-uv2-1.48.0
-LIBUV_SHA1=afa1c67fa496eb49ade1e520f76fd018a1409eaa
+LIBUV_BRANCH=santi/io_uring
+LIBUV_SHA1=f982cec43c66f115527eea637892984646c7a5da

Then I built everything again but couldn't see the logs so I'm not sure I'm doing it correctly. I appreciate any guidance here.

[santigimeno]

@vtjnash so I did:

$ make USE_BINARYBUILDER_LIBUV=0 DEPS_GIT=libuv

which built everything from my repo and also did the checkout. Then I modify the code in deps/srccache/libuv and then run

$ make -C deps reinstall-libuv

but it didn't seem to rebuild anything. Do I have to do smthg else?

[santigimeno]

I think we're hitting this. From man 7 epoll:

6. Will closing a file descriptor cause it to be removed from all epoll interest lists?

Yes, but be aware of the following point. A file descriptor is a reference to an open file description (see open(2)). Whenever a file descriptor is duplicated via dup(2), dup2(2), fcntl(2) F_DUPFD, or fork(2), a new file descriptor referring to the same open file description is created. An open file description continues to exist until all file descriptors referring to it have been closed.

A file descriptor is removed from an interest list only after all the file descriptors referring to the underlying open file description have been closed. This means that even after a file descriptor that is part of an interest list has been closed, events may be reported for that file descriptor if other file descriptors referring to the same underlying file description remain open. To prevent this happening, the file descriptor must be explicitly removed from the interest list (using epoll_ctl(2) EPOLL_CTL_DEL) before it is duplicated. Alternatively, the application must ensure that all file descriptors are closed (which may be difficult if file descriptors were duplicated behind the scenes by library functions that used dup(2) or fork(2)).

So, we need to make sure the duped fd is closed after the EPOLL_CTL_DEL is performed. I've confirmed this fixes the issue by disabling the batching of IORING_OP_EPOLL_CTL (commenting this line). One possible solution I see is linking the IORING_OP_EPOLL_CTL with a IORING_OP_CLOSE op and then call the close cb, though I don't know if it's worth the effort and maybe just removing the ctl ring is a simpler/better solution. @bnoordhuis wdyt?

[bnoordhuis]

Ha, I knew this was going to be about closed file descriptors just by looking at the issue title. :-)

For my understanding, this concerns a file descriptor that is watched by epoll but then closed by julia (?) by means of uv_fs_close (?) or a close system call that doesn't go through libuv?

[santigimeno]

For my understanding, this concerns a file descriptor that is watched by epoll but then closed by julia (?) by means of uv_fs_close (?) or a close system call that doesn't go through libuv?

Not sure what Julia does but I was interpreting it more like this: we're batching IORING_OP_EPOLL_CTL reqs, it might happen that the close() syscall (using the glibc wrapper) is performed before the EPOLL_CTL_DEL.

[vtjnash]

No, this fd is entirely the responsibility of libuv, with the caveat that this was stdin, so it is a pipe shared with other processes

[santigimeno]

Not sure what Julia does but I was interpreting it more like this: we're batching IORING_OP_EPOLL_CTL reqs, it might happen that the close() syscall (using the glibc wrapper) is performed before the EPOLL_CTL_DEL.

I'm thinking:

uv__stream_close()
       |---> uv__io_close() -> uv__platform_invalidate_fd() -> uv__epoll_ctl_prep() # IORING_OP_EPOLL_CTL(DEL) is batched but not yet flushed
       |---> uv__close() is called before io_uring_enter(getevents) 

[bnoordhuis]

@vtjnash so it's basically uv_pipe_open(&handle, dup(STDIN_FILENO)), uv_read_start(...), and eventually uv_close(...)? Hm, I would expect that to Just Work for the reason Santi mentioned.

[vtjnash]

Yes, which I think should be broken for the reasons Santi mentioned (it is batched but not flushed yet)?

[santigimeno]

So, here's a reproducer of the issue. It crashes with current v1.x, it doesn't if the EPOLL_CTL_DEL are executed immediately. To experience the busy loop, as mentioned in the comments, just comment the assert() and the close() calls.

#include <assert.h>
#include <stdio.h>
#include <stdlib.h>
#include <unistd.h>
#include <uv.h>

uv_pipe_t pipe1;
uv_pipe_t pipe2;
uv_idle_t idle_handle;
static int iters;
int duped_fd;
int newpipefds[2];

void alloc_buffer(uv_handle_t *handle, size_t suggested_size, uv_buf_t *buf) {
  *buf = uv_buf_init((char*) malloc(suggested_size), suggested_size);
}

void read_data2(uv_stream_t *stream, ssize_t nread, const uv_buf_t *buf) {
  if (nread < 0) {
    assert(nread == UV_EOF);
    close(duped_fd);
    uv_close((uv_handle_t*)&pipe2, NULL);
    uv_close((uv_handle_t*)&idle_handle, NULL);
  } else {
    // If nread == 0 is because of POLLHUP received still from pipefds[0] file
    // description which is still referenced in duped_fd. It should not happen
    // if close(pipe1) was called after EPOLL_CTL_DEL. Comment this assert to
    // expose the busy loop.
    assert(nread > 0);
  }
}

void idle_cb(uv_idle_t* handle) {
  if (++iters == 1) {
    uv_pipe_init(uv_default_loop(), &pipe2, 0);

    pipe(newpipefds);

    uv_pipe_open(&pipe2, newpipefds[0]);

    uv_read_start((uv_stream_t*)&pipe2, alloc_buffer, read_data2);
  } else {
    // Comment this close for the busy loop to happen.
    close(newpipefds[1]);
    uv_idle_stop(handle);
  }
}

void read_data(uv_stream_t *stream, ssize_t nread, const uv_buf_t *buf) {
  assert(nread == UV_EOF);
  uv_close((uv_handle_t*)stream, NULL);
  uv_idle_start(&idle_handle, idle_cb);
}

int main() {
  uv_loop_t *loop = uv_default_loop();

  uv_pipe_init(loop, &pipe1, 0);
  uv_idle_init(loop, &idle_handle);

  int pipefds[2];
  pipe(pipefds);

  uv_pipe_open(&pipe1, pipefds[0]);
  int duped_fd = dup(pipefds[0]);

  uv_read_start((uv_stream_t*)&pipe1, alloc_buffer, read_data);

  // Close the write end of the pipe so POLLHUP is generated
  close(pipefds[1]);

  return uv_run(loop, UV_RUN_DEFAULT);
}

[bnoordhuis]

Oh darn, the bug is obvious now that I look at it more closely. You're right, Santi, uv__platform_invalidate_fd() should not delay the EPOLL_CTL_DEL system call. I'll submit a fix.

(Funny, I wrote that code last year but I didn't remember I made it do that.)