axboe / liburing

Library providing helpers for the Linux kernel io_uring support
MIT License
2.86k stars 402 forks source link

More CQEs still coming after ECONNRESET #1246

Closed cyanide-burnout closed 3 weeks ago

cyanide-burnout commented 4 weeks ago

It seems like io_uring_prep_recv() has more CQEs coming after receiving -ECONNRESET without SQE_F_MORE. Kernel versions 6.1 and 6.10. Unfortunately i cannot provide sample code but could you please make sure that this case handled in the kernel correctly.

axboe commented 4 weeks ago

Would probably be useful with a trace from it, if you can't supply a reproducer. Just do:

# echo 1 > /sys/kernel/debug/tracing/events/io_uring/enable

and then run your test and stop when you hit that condition, and then attach

/sys/kernel/debug/tracing/trace

in here.

axboe commented 4 weeks ago

Could be something like this...

diff --git a/io_uring/net.c b/io_uring/net.c
index f10f5a22d66a..18507658a921 100644
--- a/io_uring/net.c
+++ b/io_uring/net.c
@@ -1133,6 +1133,7 @@ int io_recv(struct io_kiocb *req, unsigned int issue_flags)
    int ret, min_ret = 0;
    bool force_nonblock = issue_flags & IO_URING_F_NONBLOCK;
    size_t len = sr->len;
+   bool mshot_finished;

    if (!(req->flags & REQ_F_POLLED) &&
        (sr->flags & IORING_RECVSEND_POLL_FIRST))
@@ -1187,6 +1188,7 @@ int io_recv(struct io_kiocb *req, unsigned int issue_flags)
        req_set_fail(req);
    }

+   mshot_finished = ret <= 0;
    if (ret > 0)
        ret += sr->done_io;
    else if (sr->done_io)
@@ -1194,7 +1196,7 @@ int io_recv(struct io_kiocb *req, unsigned int issue_flags)
    else
        io_kbuf_recycle(req, issue_flags);

-   if (!io_recv_finish(req, &ret, kmsg, ret <= 0, issue_flags))
+   if (!io_recv_finish(req, &ret, kmsg, mshot_finished, issue_flags))
        goto retry_multishot;

    return ret;
cyanide-burnout commented 3 weeks ago

I have mitigated these cases in my code in userspace. So to me it's not critical for now.

axboe commented 3 weeks ago

Right. But please help out and provide the trace. If there is an issue here, I'd like to fix it.

axboe commented 3 weeks ago

It would at least help if you can describe what leads to this - what kind of connection is this (assuming tcp?), what happens at the sender end, etc. There's really nothing to work with here, unfortunately, which means it'll likely just sit. If you care about potentially getting to the bottom of this issue, then more information is needed.

isilence commented 3 weeks ago

Double on getting a trace and/or reproducer.

It seems like io_uring_prep_recv() has more CQEs coming after receiving -ECONNRESET without SQE_F_MORE.

What was the value of cqe->res for all those following cqes?

isilence commented 3 weeks ago

What's interesting is that at least in the current tree we explicitly set F_MORE for all io_req_post_cqe() calls and non-F_MORE should only be done by the path that terminates requests. There is a chance it's on the user space not handling user_data right or something similar to that.

cyanide-burnout commented 3 weeks ago

Right. But please help out and provide the trace. If there is an issue here, I'd like to fix it.

Cannot prove ATM. I had to offload test mule to play with single connection without load. In this case all seems to be good.

          <idle>-0       [001] d.s3. 783130.782368: io_uring_task_add: ring 0000000006e6abdc, req 00000000dead1d67, user_data 0x7f6d42e4b008, opcode RECV, mask c3
       tetrapack-1189134 [000] ...1. 783130.782447: io_uring_complete: ring 0000000006e6abdc, req 0000000000000000, user_data 0x7f6d42e4b008, result 47, cflags 0x270003 extra1 0 extra2 0 
          <idle>-0       [001] d.s3. 783138.843348: io_uring_task_add: ring 0000000006e6abdc, req 00000000dead1d67, user_data 0x7f6d42e4b008, opcode RECV, mask c3
       tetrapack-1189134 [003] ...1. 783138.843425: io_uring_complete: ring 0000000006e6abdc, req 0000000000000000, user_data 0x7f6d42e4b008, result 47, cflags 0x2a0003 extra1 0 extra2 0 
          <idle>-0       [001] d.s3. 783146.856951: io_uring_task_add: ring 0000000006e6abdc, req 00000000dead1d67, user_data 0x7f6d42e4b008, opcode RECV, mask c3
       tetrapack-1189134 [003] ...1. 783146.857029: io_uring_complete: ring 0000000006e6abdc, req 0000000000000000, user_data 0x7f6d42e4b008, result 47, cflags 0x2b0003 extra1 0 extra2 0 
          <idle>-0       [001] d.s3. 783147.673886: io_uring_task_add: ring 0000000006e6abdc, req 00000000dead1d67, user_data 0x7f6d42e4b008, opcode RECV, mask 0
       tetrapack-1189134 [003] ...1. 783147.673947: io_uring_complete: ring 0000000006e6abdc, req 00000000dead1d67, user_data 0x7f6d42e4b008, result -104, cflags 0x0 extra1 0 extra2 0 
cyanide-burnout commented 3 weeks ago

It would at least help if you can describe what leads to this - what kind of connection is this (assuming tcp?), what happens at the sender end, etc. There's really nothing to work with here, unfortunately, which means it'll likely just sit. If you care about potentially getting to the bottom of this issue, then more information is needed.

Yes, over TCP6 socket. Client establish TCP4 connection, then by some reason it drops connection with RST. Since I cannot prove, I suggest to close the issue.

Thanks for info how to trace on the kernel side.

axboe commented 3 weeks ago

I'll close it for now, feel free to re-open if there's new evidence to share.