Return position of `IOSQE_IO_LINK`

[YoSTEALTH]

You know when using IOSQE_IO_LINK tasks are guaranteed to run one after another right? Does that apply for return results as well?

sqe = io_uring_get_sqe(ring)
io_uring_prep_read(sqe, ...)
sqe.flags |= IOSQE_IO_LINK
sqe.user_data = 1

sqe = io_uring_get_sqe(ring)
io_uring_prep_close(sqe, ...)
sqe.user_data = 2

Here we know *read and *close will be run together.

io_uring_cqe_get_data(cqe)
cqe.user_data  # ???

What about return? Will it maintain order as well? Will cqe.user_data return 1 or 2 first?

[axboe]

1 will complete before 2, as 2 cannot even be started before 1 has completed.

[YoSTEALTH]

1 will complete before 2, as 2 cannot even be started before 1 has completed.

That's what I thought as well. When I ran same code multiple times, sometimes 2 cqe would return before 1.

[axboe]

Are you submitting them in one go? Linked sequences must be submitted together, not separately.

[YoSTEALTH]

Are you submitting them in one go? Linked sequences must be submitted together, not separately.

Of course, I spent all of yesterday dealing with it. Just to scrap that code in the end. I wouldn't want to go back to that code again but I figure I let you know.

Return cqe is based in this simple dummy code:

run = 10
skip = 3
jump = 0

for i in range(run):
    if jump > i < run:
        print('i:', i, 'skip')
        continue
    elif i in (2, 6):
        print('i:', i, 'found')
        for x in range(skip):
            print('\tx:', x, i+x)
        jump = i+skip
    else:
        print('i:', i)

# i: 0
# i: 1
# i: 2 found
#     x: 0 2
#     x: 1 3
#     x: 2 4
# i: 3 skip
# i: 4 skip
# i: 5
# i: 6 found
#     x: 0 6
#     x: 1 7
#     x: 2 8
# i: 7 skip
# i: 8 skip
# i: 9

This is more less how the return cqe was being handled, please ignore the ugly troubleshooting code mess :-)

# get count of how many events are ready
cqe_ready = io_uring_cq_ready(ring)
print('cqe_ready:', cqe_ready)

jump = 0
# loop through ready event(s)
for i in range(cqe_ready):
    print('i:', i)
    if jump > i < cqe_ready:
        print('i:', i, 'skip')
        continue
    else:
        print('else-1:', i)
        cqe = cqes[i]
        print('else-2:', i, cqe)
        event = io_uring_cqe_get_data(cqe)
        event.result = cqe.res
        print('i event:', event)

        if event.job & ENTRIES:
            print('i:', i, 'found')
            sqes_len = len(event.holder)
            print('sqes_len:', sqes_len)
            for x in range(sqes_len):
                print('\tx:', x, i+x)
                if x:
                    cqe = cqes[i + x]
                event.holder[x] = cqe.res
            jump = i + sqes_len
        else:
            print('else-3:', i)

[axboe]

Don't follow what that paste is at all, sorry. One thing that may get you out-of-order completions is in case of failures, don't think the ordering is right there if we start failing links. But in terms of non-errored issue and completions, the ordering is strict or various dependencies wouldn't work. Is you read ever a short read? That would be considered a failure case, unless eg HARDLINK is used.

[YoSTEALTH]

There was no error. It was running multiple of io_uring_prep_statx with IOSQE_IO_LINK.

[YoSTEALTH]

It was running this to be more exact

async def get_stats():
    sqes = io_uring_sqe(2)

    stat1 = statx()
    file_path = __file__.encode()
    io_uring_prep_statx(sqes[0], AT_FDCWD, file_path, 0, 0, stat1)
    sqes[0].flags |= IOSQE_ASYNC & IOSQE_IO_LINK

    stat2 = statx()
    zero_path = b'/dev/zero'
    io_uring_prep_statx(sqes[1], AT_FDCWD, zero_path, 0, 0, stat2)
    sqes[1].flags |= IOSQE_ASYNC

[axboe]

sqes[0].flags |= IOSQE_ASYNC & IOSQE_IO_LINK

I think you meant

sqes[0].flags |= IOSQE_ASYNC | IOSQE_IO_LINK

or that statement has zero effect.

[YoSTEALTH]

Fixing that and going back to yesterdays code, I can still reproduce the effect. It might not be IOSQE_IO_LINK but io_uring_wait_cqe_nr(ring, cqes, 1) and io_uring_cq_ready(ring). I am assuming since both tasks are linked io_uring_cq_ready will say 2 tasks are ready, but it only says 1 since first part of linked task is done?

[YoSTEALTH]

So its probably a larger problem then previously thought! After trying to fix the code for the past few days, still kept getting that segmentation fault. So I ran the Liburing test.

$ sudo make clean && sudo make -B && sudo make runtests --jobs=8
make[1]: Entering directory '/.../liburing/src'
make[1]: Leaving directory '/.../liburing/src'
make[1]: Entering directory '/.../liburing/test'
make[1]: Leaving directory '/.../liburing/test'
make[1]: Entering directory '/.../liburing/examples'
make[1]: Leaving directory '/.../liburing/examples'
Running configure ...
prefix                        /usr
includedir                    /usr/include
libdir                        /usr/lib
libdevdir                     /usr/lib
relativelibdir                
mandir                        /usr/man
datadir                       /usr/share
stringop_overflow             yes
array_bounds                  yes
__kernel_rwf_t                yes
__kernel_timespec             yes
open_how                      yes
statx                         yes
glibc_statx                   yes
C++                           yes
has_ucontext                  yes
has_memfd_create              yes
liburing_nolibc               no
CC                            gcc
CXX                           g++
make[1]: Entering directory '/.../liburing/src'
     CC setup.ol
     CC queue.ol
     CC register.ol
     CC syscall.ol
     AR liburing.a
ar: creating liburing.a
 RANLIB liburing.a
     CC setup.os
     CC queue.os
     CC register.os
     CC syscall.os
     CC liburing.so.2.2
make[1]: Leaving directory '/.../liburing/src'
make[1]: Entering directory '/.../liburing/test'
     CC helpers.o
     CC ../src/syscall.o
     CC 232c93d07b74.t
     CC 35fa71a030ca.t
     CC 500f9fbadef8.t
     CC 7ad0e4b2f83c.t
     CC 8a9973408177.t
     CC 917257daa0fe.t
     CC a0908ae19763.t
     CC a4c0b3decb33.t
     CC accept.t
     CC accept-link.t
     CC accept-reuse.t
     CC accept-test.t
     CC across-fork.t
     CC b19062a56726.t
     CC b5837bd5311d.t
     CC ce593a6c480a.t
     CC close-opath.t
     CC connect.t
     CC cq-full.t
     CC cq-overflow.t
     CC cq-peek-batch.t
     CC cq-ready.t
     CC cq-size.t
     CC d4ae271dfaae.t
     CC d77a67ed5f27.t
     CC defer.t
     CC double-poll-crash.t
     CC drop-submit.t
     CC eeed8b54e0df.t
     CC empty-eownerdead.t
     CC eventfd.t
     CC eventfd-disable.t
     CC eventfd-reg.t
     CC eventfd-ring.t
     CC exec-target.t
     CC exit-no-cleanup.t
     CC fadvise.t
     CC fallocate.t
     CC fc2a85cb02ef.t
     CC file-register.t
     CC files-exit-hang-poll.t
     CC files-exit-hang-timeout.t
     CC file-update.t
     CC file-verify.t
     CC fixed-buf-iter.t
     CC fixed-link.t
     CC fixed-reuse.t
     CC fpos.t
     CC fsync.t
     CC hardlink.t
     CC io-cancel.t
     CC iopoll.t
     CC io_uring_enter.t
     CC io_uring_register.t
     CC io_uring_setup.t
     CC lfs-openat.t
     CC lfs-openat-write.t
     CC link.t
     CC link_drain.t
     CC link-timeout.t
     CC madvise.t
     CC mkdir.t
     CC msg-ring.t
     CC multicqes_drain.t
     CC nop-all-sizes.t
     CC nop.t
     CC openat2.t
     CC open-close.t
     CC open-direct-link.t
     CC personality.t
     CC pipe-eof.t
     CC pipe-reuse.t
     CC poll.t
     CC poll-cancel.t
     CC poll-cancel-ton.t
     CC poll-link.t
     CC poll-many.t
     CC poll-mshot-update.t
     CC poll-ring.t
     CC poll-v-poll.t
     CC pollfree.t
     CC probe.t
     CC read-write.t
     CC recv-msgall.t
     CC recv-msgall-stream.t
     CC register-restrictions.t
     CC rename.t
     CC ring-leak2.t
     CC ring-leak.t
     CC rsrc_tags.t
     CC rw_merge_test.t
     CC self.t
     CC sendmsg_fs_cve.t
     CC send_recv.t
     CC send_recvmsg.t
     CC shared-wq.t
     CC short-read.t
     CC shutdown.t
     CC sigfd-deadlock.t
     CC skip-cqe.t
     CC socket-rw.t
     CC socket-rw-eagain.t
     CC socket-rw-offset.t
     CC splice.t
     CC sq-full.t
     CXX sq-full-cpp.t
     CC sqpoll-cancel-hang.t
     CC sqpoll-disable-exit.t
     CC sq-poll-dup.t
     CC sqpoll-exit-hang.t
     CC sq-poll-kthread.t
     CC sq-poll-share.t
     CC sqpoll-sleep.t
     CC sq-space_left.t
     CC stdout.t
     CC submit-link-fail.t
     CC submit-reuse.t
     CC symlink.t
     CC teardowns.t
     CC thread-exit.t
     CC timeout.t
     CC timeout-new.t
     CC timeout-overflow.t
     CC tty-write-dpoll.t
     CC unlink.t
     CC wakeup-hang.t
     CC statx.t
make[1]: Leaving directory '/.../liburing/test'
make[1]: Entering directory '/.../liburing/examples'
     CC io_uring-cp
     CC io_uring-test
     CC link-cp
     CC ucontext-cp
make[1]: Leaving directory '/.../liburing/examples'
make[1]: Entering directory '/.../liburing/src'
make[1]: Nothing to be done for 'all'.
make[1]: Leaving directory '/.../liburing/src'
make[1]: Entering directory '/.../liburing/test'
make[1]: Nothing to be done for 'all'.
make[1]: Leaving directory '/.../liburing/test'
make[1]: Entering directory '/.../liburing/examples'
make[1]: Nothing to be done for 'all'.
make[1]: Leaving directory '/.../liburing/examples'
make[1]: Entering directory '/.../liburing/test'
Running test 232c93d07b74.t                                         5 sec
Running test 35fa71a030ca.t                                         5 sec
Running test 500f9fbadef8.t                                         1 sec
Running test 7ad0e4b2f83c.t                                         1 sec
Running test 8a9973408177.t                                         0 sec
Running test 917257daa0fe.t                                         0 sec
Running test a0908ae19763.t                                         0 sec
Running test a4c0b3decb33.t                                         7 sec
Running test accept.t                                               Accept got -11
test_accept_nonblock(before, 1) failed
Test accept.t failed with ret 1
Running test accept-link.t                                          0 sec
Running test accept-reuse.t                                         Test accept-reuse.t failed dmesg check
Running test accept-test.t                                          0 sec
Running test across-fork.t                                          0 sec
Running test b19062a56726.t                                         0 sec
Running test b5837bd5311d.t                                         0 sec
Running test ce593a6c480a.t                                         1 sec
Running test close-opath.t                                          0 sec
Running test connect.t                                              0 sec
Running test cq-full.t                                              0 sec
Running test cq-overflow.t                                          11 sec
Running test cq-peek-batch.t                                        0 sec
Running test cq-ready.t                                             0 sec
Running test cq-size.t                                              0 sec
Running test d4ae271dfaae.t                                         0 sec
Running test d77a67ed5f27.t                                         0 sec
Running test defer.t                                                Test defer.t failed dmesg check
Running test double-poll-crash.t                                    0 sec
Running test drop-submit.t                                          0 sec
Running test eeed8b54e0df.t                                         0 sec
Running test empty-eownerdead.t                                     0 sec
Running test eventfd.t                                              0 sec
Running test eventfd-disable.t                                      0 sec
Running test eventfd-reg.t                                          4 sec
Running test eventfd-ring.t                                         0 sec
Running test exec-target.t                                          0 sec
Running test exit-no-cleanup.t                                      0 sec
Running test fadvise.t                                              0 sec
Running test fallocate.t                                            0 sec
Running test fc2a85cb02ef.t                                         Test needs failslab/fail_futex/fail_page_alloc enabled, skipped
0 sec
Running test file-register.t                                        3 sec
Running test files-exit-hang-poll.t                                 1 sec
Running test files-exit-hang-timeout.t                              1 sec
Running test file-update.t                                          0 sec
Running test file-verify.t                                          3 sec
Running test fixed-buf-iter.t                                       ./runtests.sh: line 67: 76383 Killed                  timeout -s INT -k $TIMEOUT $TIMEOUT "${test_exec[@]}"
Test fixed-buf-iter.t failed with ret 137
Running test fixed-link.t                                           0 sec
Running test fixed-reuse.t                                          Bad pattern ffffffaa at 0
test failed
Test fixed-reuse.t failed with ret 1
Running test fpos.t                                                 inconsistent reads, got 0s:8192 1s:6144
f_pos incorrect, expected 14336 have 7
failed read async=0 blocksize=7
Test fpos.t failed with ret 255
Running test fsync.t                                                0 sec
Running test hardlink.t                                             0 sec
Running test io-cancel.t                                            2 sec
Running test iopoll.t                                               File/device/fs doesn't support polled IO
0 sec
Running test io_uring_enter.t                                       io_uring_enter(5, 1, 0, 4294967295, (nil))
io_uring_enter(-1, 0, 0, 0, (nil))
io_uring_enter(0, 0, 0, 0, (nil))
io_uring_enter(5, 0, 0, 0, (nil))
Allocating 4096 sqes
Submitting 4096 I/Os
Done
Waiting for 4096 events
Reaping 4096 I/Os
Submitting invalid sqe index.
PASS
0 sec
Running test io_uring_register.t                                    RELIMIT_MEMLOCK: 8388608 (8388608)
io_uring_register(-1, 0, (nil), 0)
io_uring_register(5, 0, (nil), 0)
io_uring_register(6, 4294967295, (nil), 0)
io_uring_register(6, 0, 0x7ffed2f9c220, 1)
io_uring_register(6, 0, 0x7ffed2f9c220, 1)
io_uring_register(6, 0, 0x7ffed2f9c220, 1)
Unable to map a huge page.  Try increasing /proc/sys/vm/nr_hugepages by at least 1.
Skipping the hugepage test
reserve file-backed buffers
io_uring_register(6, 0, 0x7ffed2f9c220, 1)
io_uring_register(6, 0, 0x7ff8e51da010, 1000000)
io_uring_register(6, 0, 0x7ff8e51da010, 1024)
Not enough memory for this test, skipping
io_uring_submit:
    opcode: 6
    flags:  0x00000000
    fd:     6
    poll_events: 0x00000005
io_uring_register(6, 2, 0x7ffed2f9c16c, 1)
PASS
0 sec
Running test io_uring_setup.t                                       io_uring_setup(0, 0x7ffc1dd1af20), flags: none, feat: none, resv: 0x00000000 0x00000000 0x00000000, sq_thread_cpu: 0
io_uring_setup(1, (nil)), flags: none, feat: none, resv: , sq_thread_cpu: 0
io_uring_setup(1, 0x7ffc1dd1af20), flags: none, feat: none, resv: 0x00000001 0x00000001 0x00000001, sq_thread_cpu: 0
io_uring_setup(1, 0x7ffc1dd1af20), flags: 0xffffffff, feat: none, resv: 0x00000000 0x00000000 0x00000000, sq_thread_cpu: 0
io_uring_setup(1, 0x7ffc1dd1af20), flags: IORING_SETUP_SQ_AFF, feat: none, resv: 0x00000000 0x00000000 0x00000000, sq_thread_cpu: 0
io_uring_setup(1, 0x7ffc1dd1af20), flags: IORING_SETUP_SQPOLL|IORING_SETUP_SQ_AFF, feat: none, resv: 0x00000000 0x00000000 0x00000000, sq_thread_cpu: 24
PASS
0 sec
Running test lfs-openat.t                                           Test lfs-openat.t failed dmesg check
Running test lfs-openat-write.t                                     0 sec
Running test link.t                                                 Test link.t failed dmesg check
Running test link_drain.t                                           Test link_drain.t failed dmesg check
Running test link-timeout.t                                         1 sec
Running test madvise.t                                              0 sec
Running test mkdir.t                                                0 sec
Running test msg-ring.t                                             Skipped
0 sec
Running test multicqes_drain.t                                      Test multicqes_drain.t failed dmesg check
Running test nop-all-sizes.t                                        0 sec
Running test nop.t                                                  Test nop.t failed dmesg check
Running test openat2.t                                              0 sec
Running test open-close.t                                           0 sec
Running test open-direct-link.t                                     bad open -125
test 0 0 0 failed
Test open-direct-link.t failed with ret 1
Running test personality.t                                          Test personality.t failed dmesg check
Running test pipe-eof.t                                             0 sec
Running test pipe-reuse.t                                           0 sec
Running test poll.t                                                 0 sec
Running test poll-cancel.t                                          0 sec
Running test poll-cancel-ton.t                                      0 sec
Running test poll-link.t                                            0 sec
Running test poll-many.t                                            timeout: the monitored command dumped core
./runtests.sh: line 67: 76826 Segmentation fault      timeout -s INT -k $TIMEOUT $TIMEOUT "${test_exec[@]}"
Test poll-many.t failed with ret 139
Running test poll-mshot-update.t                                    timeout: the monitored command dumped core
./runtests.sh: line 67: 76843 Segmentation fault      timeout -s INT -k $TIMEOUT $TIMEOUT "${test_exec[@]}"
Test poll-mshot-update.t failed with ret 139
Running test poll-ring.t                                            0 sec
Running test poll-v-poll.t                                          0 sec
Running test pollfree.t                                             6 sec
Running test probe.t                                                0 sec
Running test read-write.t                                           4 sec
Running test recv-msgall.t                                          0 sec
Running test recv-msgall-stream.t                                   got wrong length: 256
test recv failed
Test recv-msgall-stream.t failed with ret 1
Running test register-restrictions.t                                0 sec
Running test rename.t                                               0 sec
Running test ring-leak2.t                                           1 sec
Running test ring-leak.t                                            1 sec
Running test rsrc_tags.t                                            13 sec
Running test rw_merge_test.t                                        0 sec
Running test self.t                                                 0 sec
Running test sendmsg_fs_cve.t                                       0 sec
Running test send_recv.t                                            0 sec
Running test send_recvmsg.t                                         0 sec
Running test shared-wq.t                                            0 sec
Running test short-read.t                                           0 sec
Running test shutdown.t                                             0 sec
Running test sigfd-deadlock.t                                       0 sec
Running test skip-cqe.t                                             Test skip-cqe.t failed dmesg check
Running test socket-rw.t                                            0 sec
Running test socket-rw-eagain.t                                     0 sec
Running test socket-rw-offset.t                                     0 sec
Running test splice.t                                               0 sec
Running test sq-full.t                                              0 sec
Running test sq-full-cpp.t                                          0 sec
Running test sqpoll-cancel-hang.t                                   1 sec
Running test sqpoll-disable-exit.t                                  0 sec
Running test sq-poll-dup.t                                          1 sec
Running test sqpoll-exit-hang.t                                     1 sec
Running test sq-poll-kthread.t                                      2 sec
Running test sq-poll-share.t                                        2 sec
Running test sqpoll-sleep.t                                         0 sec
Running test sq-space_left.t                                        0 sec
Running test stdout.t                                               This is a pipe test
This is a fixed pipe test
0 sec
Running test submit-link-fail.t                                     0 sec
Running test submit-reuse.t                                         3 sec
Running test symlink.t                                              0 sec
Running test teardowns.t                                            0 sec
Running test thread-exit.t                                          0 sec
Running test timeout.t                                              6 sec
Running test timeout-new.t                                          2 sec
Running test timeout-overflow.t                                     Skipping
0 sec
Running test tty-write-dpoll.t                                      1 sec
Running test unlink.t                                               0 sec
Running test wakeup-hang.t                                          2 sec
Running test statx.t                                                0 sec
Running test statx.t                                                0 sec [0]
Running test sq-full-cpp.t                                          0 sec [0]
Tests failed:  <accept.t> <accept-reuse.t> <defer.t> <fixed-buf-iter.t> <fixed-reuse.t> <fpos.t> <lfs-openat.t> <link.t> <link_drain.t> <multicqes_drain.t> <nop.t> <open-direct-link.t> <personality.t> <poll-many.t> <poll-mshot-update.t> <recv-msgall-stream.t> <skip-cqe.t>
make[1]: *** [Makefile:229: runtests] Error 1
make[1]: Leaving directory '/.../liburing/test'
make: *** [Makefile:21: runtests] Error 2
^C

A process fixed-buf-iter.t kept running at 100% none stop. Tried to end process wouldn't stop, had to restart the system.

Tested it on Linux 5.17.3, also tried it on Linux 5.15.32, same segmentation fault.

Tried ./configure --nolibc as well, same issue.

Using the current Liburing master.

[ammarfaizi2]

A process fixed-buf-iter.t kept running at 100% none stop. Tried to end process wouldn't stop, had to restart the system.

This soft lockup bug has already been fixed, see the full story here: https://github.com/axboe/liburing/issues/549

Please upgrade your kernel to 5.17.5.

[YoSTEALTH]

Please upgrade your kernel to 5.17.5.

Tried few times, error.

[axboe]

Tried few times, error.

You need to be a lot more specific, what does that mean?

In general, the liburing tests can be split into a few categories:

1) Testing a bug that was resolved. The fixed-buf-iter falls into that category. These should always work, unless the kernel doesn't have the fix. Eg it'll break in 5.17.3, but .5 will work. 2) Testing new features. Generally these try to take care to fail gracefully on older kernels, but it isn't always the case. Hence seeing test failures on older kernels for some of these is expected, though we do fix that up when we find out. Generally nothing to worry about, it just means the liburing test itself should be improved.

[YoSTEALTH]

The distro I use provide 5.17.3 as their latest. I manually download and install their 5.17.5 releases and those been failing to load kernel on reboot. I have installed from few different repos already.

I want to have liburing + io_uring stable so I can actually make sure the code I wrote works. I have rewritten and went through everything line by line thinking I did something wrong.

[axboe]

OK, so it's a failure to boot the new kernel. Unfortunately this is really beyond what we can help with.

For your linking case, I'll say that I'd be hugely surprised if it isn't a bug in your code. I don't expect any basic errors in that code on the io_uring side, and we have test cases for it too. So I'd probably just focus on figuring out what is going wrong with your code, and 5.17.3 should be fine for that.

[YoSTEALTH]

io_uring_cqe_get_data returns cqe: {'user_data': 4294967296, 'res': 2, 'flags': 3}. I have not set that user_data value, not sure where its coming from! That's when the segfault happens, since its trying to build an object that doesn't exist. Any ideas?

[ammarfaizi2]

io_uring_cqe_get_data returns cqe: {'user_data': 4294967296, 'res': 2, 'flags': 3}. I have not set that user_data value, not sure where its coming from! That's when the segfault happens, since its trying to build an object that doesn't exist. Any ideas?

Are you sure it is not a duplicate of https://github.com/axboe/liburing/issues/575 ?

If the app doesn't set it, it should not be reading it.

[YoSTEALTH]

@ammarfaizi2 No

io_uring_wait_cqe_nr(&ring, &cqes, 2)
cqe_ready = io_uring_cq_ready(&ring)  # assume `2` is ready

# works:
for index in range(cqe_ready):
    cqe = cqes[0]
    # ...
    io_uring_cq_advance(&ring, 1)

# does not work!!!
for index in range(cqe_ready):
    cqe = cqes[index]
    # ...
io_uring_cq_advance(&ring, cqe_ready)

Processing single entry always worked, the whole goal was to process multiple entries/array at once.

[YoSTEALTH]

Got it working with io_uring_peek_batch_cqe.

When I get a change to upgrade to the latest Linux will run the test again and post the results.

Going to close this since its turned into a weird roller coaster ride.

Thanks @ammarfaizi2 @axboe for your patience and support.

[ksergey]

Are you submitting them in one go? Linked sequences must be submitted together, not separately.

@axboe Is it mean that linking will not work with IORING_SETUP_SQPOLL flag?

[axboe]

@axboe Is it mean that linking will not work with IORING_SETUP_SQPOLL flag?

No, it'll work fine with that, the SQ entries prepared aren't visible to the SQPOLL thread until you do io_uring_submit().

[ksergey]

@axboe thanks