8000 Reached unreachable code in possible_dirfd_file · Issue #13 · sectordistrict/intentrace · GitHub
[go: up one dir, main page]
More Web Proxy on the site http://driver.im/
Skip to content

Reached unreachable code in possible_dirfd_file #13

New issue

8000 Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
tanculau opened this issue Mar 23, 2025 · 14 comments
Open

Reached unreachable code in possible_dirfd_file #13

tanculau opened this issue Mar 23, 2025 · 14 comments
Labels
bug Something isn't working

Comments

@tanculau
Copy link
Contributor
thread 'main' panicked at intentrace-0.7.0/src/one_line_formatter.rs:7861:26:
internal error: entered unreachable code
stack backtrace:
   0: rust_begin_unwind
   1: core::panicking::panic_fmt
   2: core::panicking::panic
   3: intentrace::one_line_formatter::<impl intentrace::syscall_object::SyscallObject>::possible_dirfd_file
   4: intentrace::one_line_formatter::<impl intentrace::syscall_object::SyscallObject>::one_line_formatter
   5: intentrace::syscall_returned
   6: intentrace::main

When I added a dbg! before the unreachable and build in debug, I got for commit (86c22cd):

[src/one_line_formatter.rs:7861:27] r = MemFD(
    "smithay-client-toolkit (deleted)",
)

thread 'main' panicked at src/one_line_formatter.rs:7861:36:
internal error: entered unreachable code
stack backtrace:
   0: rust_begin_unwind
             at /rustc/249cb84316401daf040832cdbb8a45e0f5ab6af8/library/std/src/panicking.rs:695:5
   1: core::panicking::panic_fmt
             at /rustc/249cb84316401daf040832cdbb8a45e0f5ab6af8/library/core/src/panicking.rs:75:14
   2: core::panicking::panic
             at /rustc/249cb84316401daf040832cdbb8a45e0f5ab6af8/library/core/src/panicking.rs:145:5
   3: intentrace::one_line_formatter::<impl intentrace::syscall_object::SyscallObject>::possible_dirfd_file
             at ./src/one_line_formatter.rs:7861:36
   4: intentrace::one_line_formatter::<impl intentrace::syscall_object::SyscallObject>::one_line_formatter
             at ./src/one_line_formatter.rs:586:29
   5: intentrace::syscall_object::SyscallObject::format
             at ./src/syscall_object.rs:91:24
   6: intentrace::syscall_returned
             at ./src/main.rs:410:9
   7: intentrace::parent
             at ./src/main.rs:264:33
   8: intentrace::runner
             at ./src/main.rs:122:21
   9: intentrace::main
             at ./src/main.rs:107:5
  10: core::ops::function::FnOnce::call_once
             at .rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/ops/function.rs:250:5

rustc --version
rustc 1.87.0-nightly (249cb8431 2025-03-12)
intentrace -V
intentrace 0.7.0

@sectordistrict
Copy link
Owner

Currently we handle syscalls that use a dirfd anchor using the possible_dirfd_file() function, seems like the problem here is that dirfd isn't a normal file (memfd) which we currently aren't covering.

Is there a way for me to replicate this to investigate further? (for example I want to know which exact syscall caused this, and also what the remaining path string contains)

@tanculau
Copy link
Contributor Author

If you want to replicate it:

fn main() {
    use rustix::fs::{MemfdFlags, SealFlags};

    let name =  c"smithay-client-toolkit";
    let flags = MemfdFlags::ALLOW_SEALING | MemfdFlags::CLOEXEC;
    let fd = rustix::fs::memfd_create(name, flags).unwrap();
    let _ = rustix::fs::fcntl_add_seals(&fd, SealFlags::SHRINK | SealFlags::SEAL);
    let mem_file = std::fs::File::from(fd);
    let _ = unsafe { memmap2::MmapMut::map_mut(&mem_file) }.unwrap();
}
[dependencies]
memmap2 = "0.9.5"
rustix = { version = "1.0.3", features = ["fs"] }

I made a gist.
The first one is the full output of intentrace
The second one is the full output of strace

For the real code I hit:
I think the memfd gets created here
Then it gets opend as a std::fs::File
Then, the new created memfd gets Mmap here

@sectordistrict
Copy link
Owner

Thank you for the detailed report, I was very confused why a memfd was being used like this, turns out it wasn't, and our path resolution in statx was faulty.

@tanculau
Copy link
Contributor Author

Good news, 5dca7e1 fixed the crash

Bad news, I got now an

thread 'main' panicked at src/one_line_formatter.rs:3413:30:
called `Option::unwrap()` on a `None` value
stack backtrace:
   0: rust_begin_unwind
             at /rustc/249cb84316401daf040832cdbb8a45e0f5ab6af8/library/std/src/panicking.rs:695:5
   1: core::panicking::panic_fmt
             at /rustc/249cb84316401daf040832cdbb8a45e0f5ab6af8/library/core/src/panicking.rs:75:14
   2: core::panicking::panic
             at /rustc/249cb84316401daf040832cdbb8a45e0f5ab6af8/library/core/src/panicking.rs:145:5
   3: core::option::unwrap_failed
             at /rustc/249cb84316401daf040832cdbb8a45e0f5ab6af8/library/core/src/option.rs:2015:5
   4: core::option::Option<T>::unwrap
             at .rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/option.rs:978:21
   5: intentrace::one_line_formatter::<impl intentrace::syscall_object::SyscallObject>::one_line_formatter
             at ./src/one_line_formatter.rs:3409:44
   6: intentrace::syscall_object::SyscallObject::format
             at ./src/syscall_object.rs:91:24
   7: intentrace::syscall_returned
             at ./src/main.rs:410:9
   8: intentrace::parent
             at ./src/main.rs:264:33
   9: intentrace::runner
             at ./src/main.rs:122:21
  10: intentrace::main
             at ./src/main.rs:107:5
  11: core::ops::function::FnOnce::call_once
             at .rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/ops/function.rs:250:5

Altough I think this should be another issue

@tanculau
Copy link
Contributor Author

I'm not sure because it is quite hard to pinpoint where the faulty syscall is, but I think it should be caused here

This could maybe the backtrace

#0  syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1  0x0000555555f027e4 in std::sys::pal::unix::futex::futex_wait (futex=0x555558ca1388, expected=4, timeout=...) at src/sys/pal/unix/futex.rs:72
#2  std::sys::sync::condvar::futex::Condvar::wait_optional_timeout (self=0x555558ca1388, mutex=0x555558ca1380, timeout=...) at src/sys/sync/condvar/futex.rs:49
#3  std::sys::sync::condvar::futex::Condvar::wait (self=0x555558ca1388, mutex=0x555558ca1380) at src/sys/sync/condvar/futex.rs:33
#4  0x0000555555bde0e9 in std::sync::poison::condvar::Condvar::wait<bool> (self=0x555558ca1388, guard=...) at  .rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sync/poison/condvar.rs:191
#5  rayon_core::sleep::Sleep::sleep<rayon_core::registry::{impl#10}::wait_until_cold::{closure_env#0}> (self=<optimized out>, latch=0x55555640ef80, has_injected_jobs=..., idle_state=<optimized out>) at src/sleep/mod.rs:188
#6  rayon_core::sleep::Sleep::no_work_found<rayon_core::registry::{impl#10}::wait_until_cold::{closure_env#0}> (self=<optimized out>, latch=0x55555640ef80, has_injected_jobs=..., idle_state=<optimized out>) at src/sleep/mod.rs:107
#7  rayon_core::registry::WorkerThread::wait_until_cold (self=0x7ffec15fb900, latch=0x55555640ef80) at src/registry.rs:798
#8  0x0000555555bdbbd5 in rayon_core::registry::WorkerThread::wait_until<rayon_core::latch::OnceLatch> (self=0x7ffec15fb900, latch=<optimized out>) at src/registry.rs:769
#9  rayon_core::registry::WorkerThread::wait_until_out_of_work (self=0x7ffec15fb900) at src/registry.rs:818
#10 rayon_core::registry::main_loop (thread=...) at src/registry.rs:923
#11 rayon_core::registry::ThreadBuilder::run (self=...) at src/registry.rs:53
#12 0x0000555555bda818 in rayon_core::registry::{impl#2}::spawn::{closure#0} () at src/registry.rs:98
#13 std::sys::backtrace::__rust_begin_short_backtrace<rayon_core::registry::{impl#2}::spawn::{closure_env#0}, ()> (f=...) at  .rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sys/backtrace.rs:152
#14 std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure#0}<rayon_core::registry::{impl#2}::spawn::{closure_env#0}, ()> () at  .rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/thread/mod.rs:559
#15 core::panic::unwind_safe::{impl#23}::call_once<(), std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<rayon_core::registry::{impl#2}::spawn::{closure_env#0}, ()>> (self=<error reading variable: Cannot access memory at address 0x80>)
    at  .rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/panic/unwind_safe.rs:272
#16 std::panicking::try<(), core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<rayon_core::registry::{impl#2}::spawn::{closure_env#0}, ()>>> (f=<error reading variable: Cannot access memory at address 0x80>)
    at  .rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panicking.rs:501
#17 std::panic::catch_unwind<core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<rayon_core::registry::{impl#2}::spawn::{closure_env#0}, ()>>, ()> (f=<error reading variable: Cannot access memory at address 0x80>)
    at  .rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panic.rs:359
#18 std::thread::{impl#0}::spawn_unchecked_::{closure#1}<rayon_core::registry::{impl#2}::spawn::{closure_env#0}, ()> () at  .rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/thread/mod.rs:557
#19 core::ops::function::FnOnce::call_once<std::thread::{impl#0}::spawn_unchecked_::{closure_env#1}<rayon_core::registry::{impl#2}::spawn::{closure_env#0}, ()>, ()> ()
    at  .rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/ops/function.rs:250
#20 0x0000555555efe7d7 in alloc::boxed::{impl#28}::call_once<(), dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global> (self=..., args=<optimized out>)
    at  .rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/alloc/src/boxed.rs:1970
#21 alloc::boxed::{impl#28}::call_once<(), alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global>, alloc::alloc::Global> (self=0x555558d1dc30, args=<optimized out>)
    at  .rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/alloc/src/boxed.rs:1970
#22 std::sys::pal::unix::thread::{impl#2}::new::thread_start (main=0x555558d1dc30) at src/sys/pal/unix/thread.rs:109
#23 0x00007ffff7d0070a in start_thread (arg=<optimized out>) at pthread_create.c:448
#24 0x00007ffff7d84aac in __GI___clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78

The SyscallObject causing this is

[src/one_line_formatter.rs:3416:33] &self = SyscallObject {
    sysno: ppoll,
    category: AsyncIO,
    skeleton: [
        Array_Of_Struct,
        Unsigned_Numeric,
        Pointer_To_Struct,
        Pointer_To_Struct,
        Length_Of_Bytes_Specific,
    ],
    result: (
        Some(
            64,
        ),
        Numeric_Or_Errno,
    ),
    process_pid: Pid(
        1315654,
    ),
    errno: None,
    state: Entering,
    paused: false,
}

The problem should be that syscall_objects.rs:875 read_bytes returns the Errno EIO which is not catched

@tanculau
Copy link
Contributor Author

Using this at one_line_formatter.rs:3468

if timeout > 0 {
    let timespec = SyscallObject::read_bytes_as_struct::<16, timespec>(
        REGISTERS.get()[2] as usize,
        self.process_pid as _,
    );
    self.general_text(", and timeout ");
    if let Some(timespec) = timespec {
        self.format_timespec(timespec.tv_sec, timespec.tv_nsec);
    } else {
        self.write_text(
            "could not get timeout"
                .custom_color(get_thread_local_color!(OUR_YELLOW)),
        );
    }
} else {
    self.general_text(", and ");
    self.write_text(
        "wait forever".custom_color(get_thread_local_color!(OUR_YELLOW)),
    );
}

fixed at least the crash for me. Why it cannot read the timespec, I don't know.

@sectordistrict
Copy link
Owner

Why it cannot read the timespec, I don't know.

I also can't tell, for now I'll display a blinking error, similar to your workaround

Thanks again for the detailed reporting

sectordistrict added a commit that referenced this issue Mar 24, 2025
@tanculau
Copy link
Contributor Author

Question, does ppoll work for you?

I see on all ppoll either immediately or [intentrace: could not get timeout]

1337420 ppoll - block for new events on the 0 provided file descriptors, or any signal from the provided signal mask, and timeout immediately |=> 18446744073709551578 file descriptors with new events
1337420 ppoll - block for new events on the 3 provided file descriptors, or any signal from the provided signal mask, and timeout [intentrace: could not get timeout] |=> 18446744073709551578 file descriptors with new events

I think the ppoll is used by the mesa.

Possible backtrace

#0  __syscall_cancel_arch () at ../sysdeps/unix/sysv/linux/x86_64/syscall_cancel.S:56
#1  0x00007ffff7cfce33 in __internal_syscall_cancel (a1=<optimized out>, a2=<optimized out>, a3=<optimized out>, a4=<optimized out>, a5=a5@entry=8, a6=a6@entry=0, nr=271) at cancellation.c:49
#2  0x00007ffff7cfce74 in __syscall_cancel (a1=<optimized out>, a2=<optimized out>, a3=<optimized out>, a4=<optimized out>, a5=a5@entry=8, a6=a6@entry=0, nr=271) at cancellation.c:75
#3  0x00007ffff7d77a06 in __GI_ppoll (fds=<optimized out>, nfds=<optimized out>, timeout=<optimized out>, sigmask=<optimized out>) at ../sysdeps/unix/sysv/linux/ppoll.c:42
#4  0x00007ffff511fead in ppoll () at /usr/include/bits/poll2.h:101
#5  wl_display_poll () at ../mesa-25.0.2/src/loader/loader_wayland_helper.c:56
#6  0x00007ffff5120132 in wl_display_dispatch_queue_timeout () at ../mesa-25.0.2/src/loader/loader_wayland_helper.c:114
#7  0x00007ffff512026c in loader_wayland_dispatch () at ../mesa-25.0.2/src/loader/loader_wayland_helper.c:162
#8  0x00007ffff4d414d3 in dispatch_present_id_queue () at ../mesa-25.0.2/src/vulkan/wsi/wsi_common_wayland.c:1942
#9  0x00007ffff4d43053 in wsi_wl_swapchain_queue_present () at ../mesa-25.0.2/src/vulkan/wsi/wsi_common_wayland.c:2437
#10 0x00007ffff4d39058 in wsi_common_queue_present () at ../mesa-25.0.2/src/vulkan/wsi/wsi_common.c:1578
...

@tanculau
Copy link
Contributor Author

It always tries to read the timeout at 0x4040 and fails, so I think it is reading events from the mesa driver where ptrace cannot read it. Also cannot read the address with gdb.

All other addresses are like something 0x7FFF51BCB030.

@sectordistrict
Copy link
Owner

One thing that's peculiar to me is that usage of ppoll in mesa - for example: here - and other places in the source all hard code nfds as 1, but in your screenshot they're displayed as 0 & 3.

What I did now for struct reading was switch from ptrace's read interface to process_vm_readv, this will affect a lot of other syscalls, and technically shouldn't matter for this specific error, and should only improve performance, but I want to see if it does anything, can you see if the last commit does anything different?

@tanculau
Copy link
Contributor Author
5668 ppoll - block for new events on the 1 provided file descriptors, and timeout immediately |=> timed out before any events

thread 'main' panicked at src/syscall_object.rs:970:21:
not yet implemented
stack backtrace:
   0: rust_begin_unwind
             at /rustc/249cb84316401daf040832cdbb8a45e0f5ab6af8/library/std/src/panicking.rs:695:5
   1: core::panicking::panic_fmt
             at /rustc/249cb84316401daf040832cdbb8a45e0f5ab6af8/library/core/src/panicking.rs:75:14
   2: core::panicking::panic
             at /rustc/249cb84316401daf040832cdbb8a45e0f5ab6af8/library/core/src/panicking.rs:145:5
   3: intentrace::syscall_object::SyscallObject::read_bytes_as_struct
             at ./src/syscall_object.rs:970:21
   4: intentrace::one_line_formatter::<impl intentrace::syscall_object::SyscallObject>::one_line_formatter
             at ./src/one_line_formatter.rs:3411:33
   5: intentrace::syscall_object::SyscallObject::format
             at ./src/syscall_object.rs:91:24
   6: intentrace::syscall_returned
             at ./src/main.rs:410:9
   7: intentrace::parent
             at ./src/main.rs:264:33
   8: intentrace::runner
             at ./src/main.rs:122:21
   9: intentrace::main
             at ./src/main.rs:107:5
  10: core::ops::function::FnOnce::call_once
             at .rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/ops/function.rs:250:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

sectordistrict added a commit that referenced this issue Mar 24, 2025
@sectordistrict sectordistrict added the bug Something isn't working label Mar 24, 2025
@tanculau
Copy link
Contributor Author
src/one_line_formatter.rs:3409:29] &self = SyscallObject {
    sysno: ppoll,
    category: AsyncIO,
    skeleton: [
        Array_Of_Struct,
        Unsigned_Numeric,
        Pointer_To_Struct,
        Pointer_To_Struct,
        Length_Of_Bytes_Specific,
    ],
    result: (
        Some(
            0,
        ),
        Numeric_Or_Errno,
    ),
    process_pid: Pid(
        13032,
    ),
    errno: None,
    state: Entering,
    paused: false,
}
[src/one_line_formatter.rs:3410:29] REGISTERS.get()[0] as usize = 140737255853440
[src/one_line_formatter.rs:3411:29] REGISTERS.get()[1] as usize = 1
[src/one_line_formatter.rs:3412:29] REGISTERS.get()[2] as usize = 140737255853344
[src/syscall_object.rs:840:26] RemoteIoVec { base, len } = RemoteIoVec {
    base: 140737255853344,
    len: 16,
}
[src/syscall_object.rs:856:15] process_vm_readv(child, &mut [IoSliceMut::new(&mut bytes_buffer)],
&[remote_iov],) = Ok(
    16,
)
13032 ppoll - block for new events on the 1 provided file descriptors, and timeout immediately |=> timed out before any events
[src/one_line_formatter.rs:3409:29] &self = SyscallObject {
    sysno: ppoll,
    category: AsyncIO,
    skeleton: [
        Array_Of_Struct,
        Unsigned_Numeric,
        Pointer_To_Struct,
        Pointer_To_Struct,
        Length_Of_Bytes_Specific,
    ],
    result: (
        Some(
            64,
        ),
        Numeric_Or_Errno,
    ),
    process_pid: Pid(
        13032,
    ),
    errno: None,
    state: Entering,
    paused: false,
}
[src/one_line_formatter.rs:3410:29] REGISTERS.get()[0] as usize = 3
[src/one_line_formatter.rs:3411:29] REGISTERS.get()[1] as usize = 140737255853440
[src/one_line_formatter.rs:3412:29] REGISTERS.get()[2] as usize = 16448
[src/syscall_object.rs:840:26] RemoteIoVec { base, len } = RemoteIoVec {
    base: 16448,
    len: 16,
}
[src/syscall_object.rs:856:15] process_vm_readv(child, &mut [IoSliceMut::new(&mut bytes_buffer)],
&[remote_iov],) = Err(
    EFAULT,
)

Still the same address, just Errno is now EFAULT

FD 1 works
FD 3 still has address 0x4040 which cannot be accessed

@tanculau
Copy link
Contributor Author

strace output

[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_FD_TO_HANDLE, 0x7ffe47811990) = 0
[pid 19366] close(24)                   = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_TRANSF
8000
ER, 0x7ffe47811980) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_TRANSFER, 0x7ffe47811980) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_RESET, 0x7ffe47811ee0) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_TIMELINE_WAIT, 0x7ffe47812620) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_HANDLE_TO_FD, 0x7ffe47812730) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_RESET, 0x7ffe47812740) = 0
[pid 19366] ioctl(25, BINDER_SET_IDLE_TIMEOUT or DMA_BUF_IOCTL_IMPORT_SYNC_FILE, 0x7ffe478127a0) = 0
[pid 19366] close(21)                   = 0
[pid 19366] ppoll([{fd=3, events=POLLIN}], 1, {tv_sec=0, tv_nsec=0}, NULL, 8) = 0 (Timeout)
[pid 19366] sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="/\0\0\0\1\0\24\0R\0\0\0\0\0\0\0\0\0\0\0/\0\0\0\2\0\30\0\0\0\0\0"..., iov_len=64}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT|MSG_NOSIGNAL) = 64
[pid 19425] <... epoll_wait resumed>[{events=EPOLLIN, data=0x100000001}], 1024, -1) = 1
[pid 19366] write(9, "\2\0\0\0\0\0\0\0", 8 <unfinished ...>
[pid 19425] read(20,  <unfinished ...>
[pid 19366] <... write resumed>)        = 8
[pid 19425] <... read resumed>0x73c956df2720, 8) = -1 EAGAIN (Resource temporarily unavailable)
[pid 19366] timerfd_settime(6, 0, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}},  <unfinished ...>
[pid 19425] epoll_ctl(19, EPOLL_CTL_MOD, 20, {events=EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP|EPOLLONESHOT, data=0xffffffffffffffff} <unfinished ...>
[pid 19366] <... timerfd_settime resumed>{it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}}) = 0
[pid 19425] <... epoll_ctl resumed>)    = 0
[pid 19366] epoll_ctl(4, EPOLL_CTL_MOD, 6, {events=EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP|EPOLLONESHOT, data=0xffffffffffffffff}) = 0
[pid 19425] futex(0x592455ffb638, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 912, NULL, FUTEX_BITSET_MATCH_ANY <unfinished ...>
[pid 19366] epoll_wait(4, [{events=EPOLLIN, data=0x1}, {events=EPOLLIN, data=0x200000000}], 1024, -1) = 2
[pid 19366] read(5, 0x7ffe47818780, 8)  = -1 EAGAIN (Resource temporarily unavailable)
[pid 19366] epoll_ctl(4, EPOLL_CTL_MOD, 5, {events=EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP|EPOLLONESHOT, data=0xffffffffffffffff}) = 0
[pid 19366] recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="P\0\0\0\0\0\10\0", iov_len=3988}, {iov_base="", iov_len=108}], msg_iovlen=2, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 8
[pid 19366] recvmsg(3, {msg_namelen=0}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable)
[pid 19366] futex(0x592455ffb638, FUTEX_WAKE_PRIVATE, 2147483647) = 1
[pid 19425] <... futex resumed>)        = 0
[pid 19366] read(9,  <unfinished ...>
[pid 19425] futex(0x592455ffb5e8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 19366] <... read resumed>"\2\0\0\0\0\0\0\0", 8) = 8
[pid 19425] <... futex resumed>)        = 0
[pid 19425] timerfd_settime(22, 0, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}},  <unfinished ...>
[pid 19366] ioctl(28, DMA_BUF_IOCTL_EXPORT_SYNC_FILE <unfinished ...>
[pid 19425] <... timerfd_settime resumed>{it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}}) = 0
[pid 19366] <... ioctl resumed>, 0x7ffe47811840) = 0
[pid 19425] epoll_ctl(19, EPOLL_CTL_MOD, 22, {events=EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP|EPOLLONESHOT, data=0xffffffffffffffff} <unfinished ...>
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_CREATE <unfinished ...>
[pid 19425] <... epoll_ctl resumed>)    = 0
[pid 19366] <... ioctl resumed>, 0x7ffe478117b0) = 0
[pid 19425] epoll_wait(19,  <unfinished ...>
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_FD_TO_HANDLE, 0x7ffe47811820) = 0
[pid 19366] close(21)                   = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_WAIT, 0x7ffe478116d0) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_DESTROY, 0x7ffe478118f0) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_RESET, 0x7ffe478118e0) = 0
[pid 19366] ioctl(14, DRM_IOCTL_AMDGPU_CS, 0x7ffe4780ddf0) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_QUERY, 0x7ffe4780e5d0) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_WAIT, 0x7ffe478125a0) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_RESET, 0x7ffe478127a0) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_TIMELINE_WAIT, 0x7ffe47811dc0) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_HANDLE_TO_FD, 0x7ffe47811980) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_HANDLE_TO_FD, 0x7ffe47811980) = 0
[pid 19366] ioctl(21, SYNC_IOC_MERGE, 0x7ffe47811c20) = 0
[pid 19366] close(21)                   = 0
[pid 19366] close(23)                   = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_FD_TO_HANDLE, 0x7ffe47811990) = 0
[pid 19366] close(24)                   = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_TRANSFER, 0x7ffe47811980) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_TRANSFER, 0x7ffe47811980) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_RESET, 0x7ffe47811ee0) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_TIMELINE_WAIT, 0x7ffe47812620) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_HANDLE_TO_FD, 0x7ffe47812730) = 0
[pid 19366] ioctl(14, DRM_IOCTL_SYNCOBJ_RESET, 0x7ffe47812740) = 0
[pid 19366] ioctl(28, BINDER_SET_IDLE_TIMEOUT or DMA_BUF_IOCTL_IMPORT_SYNC_FILE, 0x7ffe478127a0) = 0
[pid 19366] close(21)                   = 0
[pid 19366] ppoll([{fd=3, events=POLLIN}], 1, {tv_sec=0, tv_nsec=0}, NULL, 8) = 0 (Timeout)
[pid 19366] poll([{fd=3, events=POLLIN}], 1, -1

It seems strace can find the timeout, but I cannot find ppoll with fd 1....

Personally I don't think that if sometimes the timeout isn't printed out correctly is a real issue.

Also, I think it is quite hard to reproduce (I think you need an AMD GPU + Wayland + maybe specific GPU)

@sectordistrict
Copy link
Owner

Yeah, my current plan is to leave this until I go through all Async IO syscalls one-by-one in the future, I also want to wait until I refactor helper functions as that would help even more

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants