Wasmtime: poll_oneoff with wasi::EVENTTYPE_FD_READ resulting in EBADF

[dunnock]

In the following code compiled using rust 1.40 nightly when passing fd from preopened file I get error code 8 as output event from poll_oneoff. I guess it should not be bad fd since reading from file succeeds?

#![feature(wasi_ext)]
use ::wasi::wasi_unstable as wasi;
use std::os::wasi::io::AsRawFd;
use std::io::prelude::*;

fn main() {
    let mut input = std::fs::File::open("input.txt").expect("file input.txt");
    let mut buf: String = String::new();
    println!("{:?}", input.read_to_string(&mut buf));

    println!("File descriptor: {}", input.as_raw_fd());

    let fd_readwrite = wasi::raw::__wasi_subscription_u_fd_readwrite_t {
        fd: input.as_raw_fd()
    };
    let in_ = [wasi::Subscription {
        userdata: 1,
        type_: wasi::EVENTTYPE_FD_READ,
        u: wasi::raw::__wasi_subscription_u { fd_readwrite },
    }];
    let (res, event) = unsafe {
        let mut out: [wasi::Event; 1] = std::mem::zeroed();
        let res = wasi::poll_oneoff(&in_, &mut out);
        (res, out[0])
    };

    println!("Res = {:?}", res);
    assert_eq!(event.userdata, 1, "event.userdata");
    assert_eq!(event.error, 0, "event.error");
    assert_eq!(event.type_, wasi::EVENTTYPE_FD_READ, "event.type_");
}

Following repo has required setup and test.sh script compiling and running through wasmtime https://github.com/dunnock/poll_oneoff_tests:

poll_oneoff_tests % ./test.sh
    Finished dev [unoptimized + debuginfo] target(s) in 0.07s
Ok(2)
File descriptor: 4
Res = Ok(1)
thread 'main' panicked at 'assertion failed: `(left == right)`
  left: `8`,
 right: `0`: event.error', src/main.rs:97:5
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace.
error: failed to process main module `target/wasm32-wasi/debug/poll_oneoff_tests.wasm`
    caused by: Instantiation error: Trap occurred while invoking start function: wasm trap: unreachable, source location: @19834

with RUST_LOG=trace:

...
TRACE wasmtime_wasi::syscalls              > path_open(dirfd=3, dirflags=1, path=0x110128, path_len=9, oflags=0x0, fs_rights_base=0xf87febe, fs_rights_inheriting=0xf87febe, fs_flags=0x0, fd=0xffa88)
 TRACE wasi_common::hostcalls_impl::fs      > path_open(dirfd=3, dirflags=1, path_ptr=0x110128, path_len=9, oflags=0x0, fs_rights_base=0xf87febe, fs_rights_inheriting=0xf87febe, fs_flags=0x0, fd_out_ptr=0xffa88)
 TRACE wasi_common::hostcalls_impl::fs      >      | (path_ptr,path_len)='input.txt'
 DEBUG wasi_common::hostcalls_impl::fs_helpers > path_get cur_path = "input.txt"
 DEBUG wasi_common::hostcalls_impl::fs_helpers > path_get path_stack = []
 DEBUG wasi_common::sys::unix::hostcalls_impl::fs_helpers > path_get readlinkat path = "input.txt"
 DEBUG wasi_common::sys::unix::hostcalls_impl::fs         > path_open resolved = PathGet { dirfd: File { fd: 7, path: "/Users/max/src/wasm/poll_oneoff_tests/input", read: true, write: false }, path: "input.txt" }
 DEBUG wasi_common::sys::unix::hostcalls_impl::fs         > path_open oflags = O_NOFOLLOW
 DEBUG wasi_common::sys::unix::hostcalls_impl::fs         > path_open new_fd = 8
 DEBUG wasi_common::sys::unix::fdentry_impl               > Fd 8 is a file
 DEBUG wasi_common::sys::unix::fdentry_impl               > Fd 8 is a file
 TRACE wasi_common::hostcalls_impl::fs                    >      | *fd=4
 TRACE wasi_common::hostcalls                             >     -> errno=__WASI_ESUCCESS
 TRACE wasmtime_wasi::syscalls                            > fd_read(fd=4, iovs=0xff9e0, iovs_len=1, nread=0xff9ec)
 TRACE wasi_common::hostcalls_impl::fs                    > fd_read(fd=4, iovs_ptr=0xff9e0, iovs_len=1, nread=0xff9ec)
 TRACE wasi_common::hostcalls_impl::fs                    >      | *nread=2
 TRACE wasi_common::hostcalls                             >     -> errno=__WASI_ESUCCESS
 TRACE wasmtime_wasi::syscalls                            > fd_read(fd=4, iovs=0xff9e0, iovs_len=1, nread=0xff9ec)
 TRACE wasi_common::hostcalls_impl::fs                    > fd_read(fd=4, iovs_ptr=0xff9e0, iovs_len=1, nread=0xff9ec)
 TRACE wasi_common::hostcalls_impl::fs                    >      | *nread=0
 TRACE wasi_common::hostcalls                             >     -> errno=__WASI_ESUCCESS
 TRACE wasmtime_wasi::syscalls                            > fd_write(fd=1, iovs=0xff9e0, iovs_len=1, nwritten=0xff9e8)
 TRACE wasi_common::hostcalls_impl::fs                    > fd_write(fd=1, iovs_ptr=0xff9e0, iovs_len=1, nwritten=0xff9e8)
Ok(2)
 TRACE wasi_common::hostcalls_impl::fs                    >      | *nwritten=6
 TRACE wasi_common::hostcalls                             >     -> errno=__WASI_ESUCCESS
 TRACE wasmtime_wasi::syscalls                            > fd_write(fd=1, iovs=0xff9e0, iovs_len=1, nwritten=0xff9e8)
 TRACE wasi_common::hostcalls_impl::fs                    > fd_write(fd=1, iovs_ptr=0xff9e0, iovs_len=1, nwritten=0xff9e8)
File descriptor: 4
 TRACE wasi_common::hostcalls_impl::fs                    >      | *nwritten=19
 TRACE wasi_common::hostcalls                             >     -> errno=__WASI_ESUCCESS
 TRACE wasmtime_wasi::syscalls                            > poll_oneoff(in=0xffc08, out=0xffcf8, nsubscriptions=1, nevents=0xffaf0)
 TRACE wasi_common::hostcalls_impl::misc                  > poll_oneoff(input=0xffc08, output=0xffcf8, nsubscriptions=1, nevents=0xffaf0)
 TRACE wasi_common::hostcalls_impl::misc                  >      | *nevents=1
 TRACE wasi_common::hostcalls                             >     -> errno=__WASI_ESUCCESS
 TRACE wasmtime_wasi::syscalls                            > fd_write(fd=1, iovs=0xff9e0, iovs_len=1, nwritten=0xff9e8)
 TRACE wasi_common::hostcalls_impl::fs                    > fd_write(fd=1, iovs_ptr=0xff9e0, iovs_len=1, nwritten=0xff9e8)
Res = Ok(1)
...

[kubkon]

Hey @dunnock! Thanks for submitting the issue, it's much appreciated! BTW, since this type of an issue pertains mainly our WASI implementation, it'd be awesome if you could submit any more issues of this type you encounter in the future in our [wasi-common] repo :-)

Anyhow, I've got a fix for this erroneous behaviour you've encountered with poll_oneoff, and I'll do my best to merge it into upstream either tonight or tomorrow morning. To shed some more light on the problem, it turns out that in our implementation of poll_oneoff we're calling the host's [poll] syscall with incorrect value for the file descriptor. What I mean by this is that we pass in the WASI-local fd (which is just a wrapper for a host fd), whereas we should pass in the wrapped host fd.

Here's the link to the PR that tracks the resolution of this issue in [wasi-common]: CraneStation/wasi-common#137

When the fix lands in [wasi-common] and I update wasmtime with the required changes, I shall let you know first thing! :-)

[dunnock]

Oh I see, right I should have submitted to wasi-common, will do my best next time. Thanks @kubkon for really quick turnaround and detailed explanation. I was trying to dig deeper, but hostcalls_impl::poll_oneoff seemed ok, now it's clear there is internal fd. And since stdin.fd==0 that's why it's worked as expected. Thanks again!

[kubkon]

@dunnock quick update: fix is under review now. I've cc'd you into PRs that I thought may be of interest to you, but nonetheless, for posterity, here are all relevant PRs:

• test case based on @dunnock's [poll_oneoff_tests]: CraneStation/wasi-misc-tests#38
• fix in [wasi-common] crate: CraneStation/wasi-common#137
• required changes in wasmtime: #449

[dunnock]

Thanks @kubkon, that's definitely of interest, that clarifies code and repositories structure better now. And thanks for pushing this so quick!