`test_udp_recvmsg_multishot_trunc` fails

[connortsui20]

On my machine, this test fails. I'm running the most recent version of Arch Linux.

If I comment out each assertion one by one, every single assertion gets tripped.

Code is located here.

match i {
    0 => {
        let msg = msg.unwrap();
        assert!(msg.is_payload_truncated());
        assert!(msg.is_name_data_truncated());
        assert_eq!(DATA.len(), msg.incoming_payload_len() as usize);
        assert!(msg.payload_data().is_empty());
        assert!(4 < msg.incoming_name_len());
        assert_eq!(4, msg.name_data().len());
    }

Some potentially helpful error output:

assert_eq!(DATA.len(), msg.incoming_payload_len() as usize);

thread 'main' panicked at io-uring-test/src/tests/net.rs:1551:25:
assertion `left == right` failed
  left: 15
 right: 0

assert!(4 < msg.incoming_name_len(), "Name length: {}", msg.incoming_name_len());

thread 'main' panicked at io-uring-test/src/tests/net.rs:1553:25:
Name length: 0

assert_eq!(4, msg.name_data().len());

thread 'main' panicked at io-uring-test/src/tests/net.rs:1554:25:
assertion `left == right` failed
  left: 4
 right: 0

[quininer]

@SUPERCILEX are you interested in checking this out? It changes in newer kernels.

[SUPERCILEX]

What kernel version is this on? And do the assert!(msg.is_payload_truncated()) assertions fail too? If not, then maybe the kernel just doesn't return anything anymore on truncation. If literally all the assertions fail, then I think it's time to open an io_uring bug because that would be nonsense: the data doesn't fit so it has day it's truncated.

[connortsui20]

@SUPERCILEX Sorry for the delay. Here is my linux version:

~
❯ uname -r
6.8.7-arch1-1

~
❯ cat /etc/os-release
NAME="Arch Linux"
PRETTY_NAME="Arch Linux"
ID=arch
BUILD_ID=rolling
ANSI_COLOR="38;2;23;147;209"
HOME_URL="https://archlinux.org/"
DOCUMENTATION_URL="https://wiki.archlinux.org/"
SUPPORT_URL="https://bbs.archlinux.org/"
BUG_REPORT_URL="https://gitlab.archlinux.org/groups/archlinux/-/issues"
PRIVACY_POLICY_URL="https://terms.archlinux.org/docs/privacy-policy/"
LOGO=archlinux-logo

And yes every single one of those assertions failed for me.

[connortsui20]

Ah sorry one of them does not fail, specifically msg.payload_data().is_empty().

0 => {
    let msg = msg.unwrap();
    if !msg.is_payload_truncated() {
        println!("Payload is not truncated")
    }
    if !msg.is_name_data_truncated() {
        println!("Name is not truncated")
    }
    if !msg.payload_data().is_empty() {
        println!("Payload data is not empty")
    }
    if 4 >= msg.incoming_name_len() {
        println!("Payload name length is >= 4")
    }
    if DATA.len() != msg.incoming_payload_len() as usize {
        println!("Payload len is {}", msg.incoming_payload_len());
    }
    assert_eq!(4, msg.name_data().len());
}

Gives this output:

Payload is not truncated
Name is not truncated
Payload name length is >= 4
Payload len is 0
thread 'main' panicked at io-uring-test/src/tests/net.rs:1564:25:
assertion `left == right` failed
  left: 4
 right: 0
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

[SUPERCILEX]

That just seems so broken to me. Can you try dbg printing the header here: https://github.com/tokio-rs/io-uring/blob/501ee78049fa785eb4f5888252a0983ba6cf78e0/src/types.rs#L415 Also, remove the match statement with the assertions so we can see each message get parsed.

[connortsui20]

@SUPERCILEX Output when commenting out the entire match statement + I added a dbg!(i) and dbg!(msg.unwrap()). It seems like the second branch with i = 1 also trips some of the asserts.

test udp_recvmsg_multishot_trunc
[io-uring-test/src/tests/net.rs:1545:17] i = 0
[src/types.rs:416:9] header = io_uring_recvmsg_out {
    namelen: 0,
    controllen: 0,
    payloadlen: 0,
    flags: 0,
}
[io-uring-test/src/tests/net.rs:1547:17] msg.unwrap() = RecvMsgOut {
    header: io_uring_recvmsg_out {
        namelen: 0,
        controllen: 0,
        payloadlen: 0,
        flags: 0,
    },
    msghdr_name_len: 4,
    name_data: [],
    control_data: [],
    payload_data: [],
}
[io-uring-test/src/tests/net.rs:1545:17] i = 1
[src/types.rs:416:9] header = io_uring_recvmsg_out {
    namelen: 16,
    controllen: 0,
    payloadlen: 15,
    flags: 32,
}
[io-uring-test/src/tests/net.rs:1547:17] msg.unwrap() = RecvMsgOut {
    header: io_uring_recvmsg_out {
        namelen: 16,
        controllen: 0,
        payloadlen: 15,
        flags: 32,
    },
    msghdr_name_len: 4,
    name_data: [
        2,
        0,
        217,
        24,
    ],
    control_data: [],
    payload_data: [],
}

[SUPERCILEX]

Hmmm, that all zero pattern is deeply suspicious. I wonder if we're using the wrong buffer somehow? Can you throw in this for loop below buffer_select?

          for i in 0..3 {
                    let tmp_buf = &buffers[i];
                    dbg!(i);
                    let msg = types::RecvMsgOut::parse(tmp_buf, &msghdr);
                }

My guess is that one of the buffers will be filled in, but buf_id won't be pointing to it.

[connortsui20]

I added a dbg!(msg.unwrap());

[io-uring-test/src/tests/net.rs:1544:21] i = 0
[io-uring-test/src/tests/net.rs:1547:21] msg.unwrap() = RecvMsgOut {
    header: io_uring_recvmsg_out {
        namelen: 16,
        controllen: 0,
        payloadlen: 15,
        flags: 32,
    },
    msghdr_name_len: 4,
    name_data: [
        2,
        0,
        233,
        242,
    ],
    control_data: [],
    payload_data: [],
}
[io-uring-test/src/tests/net.rs:1544:21] i = 1
[io-uring-test/src/tests/net.rs:1547:21] msg.unwrap() = RecvMsgOut {
    header: io_uring_recvmsg_out {
        namelen: 0,
        controllen: 0,
        payloadlen: 0,
        flags: 0,
    },
    msghdr_name_len: 4,
    name_data: [],
    control_data: [],
    payload_data: [],
}
[io-uring-test/src/tests/net.rs:1544:21] i = 2
[io-uring-test/src/tests/net.rs:1547:21] msg.unwrap() = RecvMsgOut {
    header: io_uring_recvmsg_out {
        namelen: 0,
        controllen: 0,
        payloadlen: 0,
        flags: 0,
    },
    msghdr_name_len: 4,
    name_data: [],
    control_data: [],
    payload_data: [],
}
thread 'main' panicked at io-uring-test/src/tests/net.rs:1555:25:
assertion failed: msg.is_payload_truncated()
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

[connortsui20]

I had actually not read what the actual test was doing until just now, so I now have a few questions about this test.

    for (index, buf) in buffers.iter_mut().enumerate() {
        let provide_bufs_e = io_uring::opcode::ProvideBuffers::new(
            (**buf).as_mut_ptr(),
            buf.len() as i32,
            1,
            BUF_GROUP,
            index as u16,
        )
        .build()
        .user_data(11)
        .into();
        unsafe { ring.submission().push(&provide_bufs_e)? };
        ring.submitter().submit_and_wait(1)?;
        let cqes: Vec<io_uring::cqueue::Entry> = ring.completion().map(Into::into).collect();
        assert_eq!(cqes.len(), 1);
        assert_eq!(cqes[0].user_data(), 11);
        assert_eq!(cqes[0].result(), 0);
        assert_eq!(cqes[0].flags(), 0);
    }

Man pages for io_uring_prep_provide_buffers.

The specific thing I have a question about is the BUF_GROUP constant in the ProvideBuffers opcode. Every single time provide buffers is getting called, it is set to the same buffer group ID. Wouldn't executing the ProvideBuffers with the same buf group ID replace the ones that were provided in the previous iterations? Or does this test not care about that?

[SUPERCILEX]

Huh, yeah maybe that's it though I thought it was supposed to be fine. You could try adding the index to the buf group and see if that fixes it.

Also you can print buf_id so see what the kernel is actually picking cuz in your previous message the first buffer had the right data filled in, but it clearly picked something else.

[SUPERCILEX]

Hey, can you try https://github.com/tokio-rs/io-uring/pull/284 and see if it fixes it for you? If so, I was just being a dumdum and the kernel is returning sendmsg responses out of order which I wasn't expecting.

[connortsui20]

Sorry for the delay, I've added a comment directly on the PR.

[connortsui20]

Closed by #284