Skip to content

mio (and tokio) sockets are completely broken under wine #1444

New issue
New issue
Closed
Closed
mio (and tokio) sockets are completely broken under wine#1444
Labels
bug
@whitequark

Description

@whitequark
whitequark
opened on Jan 24, 2021

Testcase:

#[tokio::main]
async fn main() {
    let addr = std::net::SocketAddr::from(([0,0,0,0], 1234));
    tokio::net::TcpListener::bind(addr).await.unwrap();
}

On Windows, it succeeds:

> mio-bug.exe

On wine (any version), it crashes:

$ wine mio-bug.exe
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Os { code: 2, kind: NotFound, message: "File not found." }', src\main.rs:3:88
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

Note the very unusual and confusing ENOENT error code. To understand how it gets produced, we can use the following command:

$ strace -e '!write' env WINEDEBUG=relay,ws2_32 wine mio-bug.exe
unedited part of the log 
0140:Call ws2_32.socket(00000002,00000001,00000000) ret=14007a67d
0140:Call ntdll.RtlAllocateHeap(00010000,00000008,00000048) ret=7f42dbcaae68
0140:Ret  ntdll.RtlAllocateHeap() retval=00058a00 ret=7f42dbcaae68
0140:Call ntdll.RtlInitUnicodeString(0021ddd0,7f42dbcb7b40 L"\\Device\\Afd") ret=7f42dbcaa8cc
0140:Ret  ntdll.RtlInitUnicodeString() retval=00000018 ret=7f42dbcaa8cc
0140:Call ntdll.NtOpenFile(0021ddb8,c0100000,0021ddf0,0021dde0,00000000,00000000) ret=7f42dbcaa947
rt_sigprocmask(SIG_BLOCK, [HUP INT USR1 USR2 ALRM CHLD IO], [], 8) = 0
writev(3, [{iov_base=",\0\0\0\26\0\0\0\0\0\0\0\0\0\20\300\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., iov_len=64}, {iov_base="\\\0D\0e\0v\0i\0c\0e\0\\\0A\0f\0d\0", iov_len=22}], 2) = 86
read(4, "\0\0\0\0\0\0\0\0\200\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 64) = 64
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
0140:Ret  ntdll.NtOpenFile() retval=00000000 ret=7f42dbcaa947
0140:Call ntdll.NtDeviceIoControlFile(00000080,00000000,00000000,00000000,0021dde0,00128320,0021ddc0,00000010,00000000,00000000) ret=7f42dbcaa9ab
rt_sigprocmask(SIG_BLOCK, [HUP INT USR1 USR2 ALRM CHLD IO], [], 8) = 0
writev(3, [{iov_base="\201\0\0\0\20\0\0\0\0\0\0\0 \203\22\0\200\0\0\0\0\0\0\0\340\335!\0\0\0\0\0"..., iov_len=64}, {iov_base="\2\0\0\0\1\0\0\0\6\0\0\0\0\0\0\0", iov_len=16}], 2) = 80
read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 64) = 64
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
0140:Ret  ntdll.NtDeviceIoControlFile() retval=00000000 ret=7f42dbcaa9ab
0140:Ret  ws2_32.socket() retval=00000080 ret=14007a67d
0140:Call ws2_32.ioctlsocket(00000080,8004667e,0021dfd4) ret=14007a778
rt_sigprocmask(SIG_BLOCK, [HUP INT USR1 USR2 ALRM CHLD IO], [], 8) = 0
read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 64) = 64
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, [HUP INT USR1 USR2 ALRM CHLD IO], [], 8) = 0
read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 64) = 64
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
0140:Ret  ws2_32.ioctlsocket() retval=00000000 ret=14007a778
0140:Call ucrtbase.memset(0021dc70,00000000,00000004) ret=14009031b
0140:Ret  ucrtbase.memset() retval=0021dc70 ret=14009031b
0140:Call ucrtbase.memset(0021dd58,00000000,00000008) ret=14007ab78
0140:Ret  ucrtbase.memset() retval=0021dd58 ret=14007ab78
0140:Call ws2_32.bind(00000080,0021e088,00000010) ret=140073798
0140:Call ntdll.wine_server_handle_to_fd(00000080,00000000,0021de50,00000000) ret=7f42dbcac3b7
rt_sigprocmask(SIG_BLOCK, [HUP INT USR1 USR2 ALRM CHLD IO], [], 8) = 0
rt_sigprocmask(SIG_BLOCK, [HUP INT USR1 USR2 ALRM CHLD IO], [HUP INT USR1 USR2 ALRM CHLD IO], 8) = 0
read(4, "\0\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\237\1\22\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 64) = 64
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 ALRM CHLD IO], NULL, 8) = 0
recvmsg(9, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\200\0\0\0", iov_len=4}], msg_iovlen=1, msg_control=[{cmsg_len=20, cmsg_level=SOL_SOCKET, cmsg_type=SCM_RIGHTS, cmsg_data=[72]}], msg_controllen=24, msg_flags=MSG_CMSG_CLOEXEC}, MSG_CMSG_CLOEXEC) = 4
fcntl(72, F_SETFD, FD_CLOEXEC)          = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
0140:Ret  ntdll.wine_server_handle_to_fd() retval=00000000 ret=7f42dbcac3b7
bind(72, {sa_family=AF_INET, sin_port=htons(1234), sin_addr=inet_addr("0.0.0.0")}, 16) = 0
0140:Call ntdll.wine_server_release_fd(00000080,00000048) ret=7f42dbcac429
close(72)                               = 0
0140:Ret  ntdll.wine_server_release_fd() retval=00000000 ret=7f42dbcac429
0140:Ret  ws2_32.bind() retval=00000000 ret=140073798
0140:Call ws2_32.listen(00000080,00000400) ret=1400739a7
0140:Call ntdll.wine_server_handle_to_fd(00000080,00000001,0021ddf0,00000000) ret=7f42dbca5b57
rt_sigprocmask(SIG_BLOCK, [HUP INT USR1 USR2 ALRM CHLD IO], [], 8) = 0
rt_sigprocmask(SIG_BLOCK, [HUP INT USR1 USR2 ALRM CHLD IO], [HUP INT USR1 USR2 ALRM CHLD IO], 8) = 0
read(4, "\0\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\237\1\22\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 64) = 64
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 ALRM CHLD IO], NULL, 8) = 0
recvmsg(9, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\200\0\0\0", iov_len=4}], msg_iovlen=1, msg_control=[{cmsg_len=20, cmsg_level=SOL_SOCKET, cmsg_type=SCM_RIGHTS, cmsg_data=[72]}], msg_controllen=24, msg_flags=MSG_CMSG_CLOEXEC}, MSG_CMSG_CLOEXEC) = 4
fcntl(72, F_SETFD, FD_CLOEXEC)          = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
0140:Ret  ntdll.wine_server_handle_to_fd() retval=00000000 ret=7f42dbca5b57
getsockname(72, {sa_family=AF_INET, sin_port=htons(1234), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
listen(72, 1024)                        = 0
rt_sigprocmask(SIG_BLOCK, [HUP INT USR1 USR2 ALRM CHLD IO], [], 8) = 0
read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 64) = 64
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
0140:Call ntdll.wine_server_release_fd(00000080,00000048) ret=7f42dbca5bce
close(72)                               = 0
0140:Ret  ntdll.wine_server_release_fd() retval=00000000 ret=7f42dbca5bce
0140:Ret  ws2_32.listen() retval=00000000 ret=1400739a7
0140:Call ucrtbase.memcpy(0021db98,00035c30,00000008) ret=14008e0c9
0140:Ret  ucrtbase.memcpy() retval=0021db98 ret=14008e0c9
0140:Call ucrtbase.memcpy(00035c30,0021dca8,00000008) ret=14008e0c9
0140:Ret  ucrtbase.memcpy() retval=00035c30 ret=14008e0c9
0140:Call ucrtbase.memcpy(0021dc18,00035c30,00000008) ret=14008e0c9
0140:Ret  ucrtbase.memcpy() retval=0021dc18 ret=14008e0c9
0140:Call ucrtbase.memcpy(00035c30,0021dd28,00000008) ret=14008e0c9
0140:Ret  ucrtbase.memcpy() retval=00035c30 ret=14008e0c9
0140:Call ntdll.RtlAcquireSRWLockExclusive(0003b570) ret=14003e1be
0140:Ret  ntdll.RtlAcquireSRWLockExclusive() retval=00000000 ret=14003e1be
0140:Call KERNEL32.GetProcessHeap() ret=1400a0415
0140:Ret  KERNEL32.GetProcessHeap() retval=00010000 ret=1400a0415
0140:Call ntdll.RtlAllocateHeap(00010000,00000000,00000c00) ret=14008e83b
0140:Ret  ntdll.RtlAllocateHeap() retval=00058a60 ret=14008e83b
0140:Call ucrtbase.memcpy(0021d570,0021d638,00000038) ret=14001eeb5
0140:Ret  ucrtbase.memcpy() retval=0021d570 ret=14001eeb5
0140:Call ucrtbase.memcpy(0021d3a0,0021d470,00000038) ret=14002c897
0140:Ret  ucrtbase.memcpy() retval=0021d3a0 ret=14002c897
0140:Call ucrtbase.memcpy(0021d438,0021d3a0,00000038) ret=14002c8b8
0140:Ret  ucrtbase.memcpy() retval=0021d438 ret=14002c8b8
0140:Call ucrtbase.memcpy(0021d538,0021d438,00000038) ret=140015700
0140:Ret  ucrtbase.memcpy() retval=0021d538 ret=140015700
0140:Call ucrtbase.memcpy(0021d5f0,0021d528,00000048) ret=14001eee6
0140:Ret  ucrtbase.memcpy() retval=0021d5f0 ret=14001eee6
0140:Call ucrtbase.memcpy(0021d9b0,0021d5f0,00000048) ret=14005a57c
0140:Ret  ucrtbase.memcpy() retval=0021d9b0 ret=14005a57c
0140:Call ucrtbase.memcpy(0021d620,0021d950,00000058) ret=14004b545
0140:Ret  ucrtbase.memcpy() retval=0021d620 ret=14004b545
0140:Call ucrtbase.memcpy(0021d520,0021d620,00000058) ret=14002c5f7
0140:Ret  ucrtbase.memcpy() retval=0021d520 ret=14002c5f7
0140:Call ucrtbase.memcpy(0021d5c8,0021d520,00000058) ret=14002c618
0140:Ret  ucrtbase.memcpy() retval=0021d5c8 ret=14002c618
0140:Call ucrtbase.memcpy(0021d8f8,0021d5c8,00000058) ret=14004b576
0140:Ret  ucrtbase.memcpy() retval=0021d8f8 ret=14004b576
0140:Call ucrtbase.memcpy(00058a60,0021d5e0,00000060) ret=1400719ae
0140:Ret  ucrtbase.memcpy() retval=00058a60 ret=1400719ae
0140:Call ntdll.RtlReleaseSRWLockExclusive(0003b570) ret=14003e19e
0140:Ret  ntdll.RtlReleaseSRWLockExclusive() retval=00000000 ret=14003e19e
0140:Call ntdll.RtlAcquireSRWLockExclusive(0003b520) ret=140078bae
0140:Ret  ntdll.RtlAcquireSRWLockExclusive() retval=00000000 ret=140078bae
0140:Call ntdll.NtCreateFile(0021cbe8,00100000,1400b9d28,0021cbf0,00000000,00000000,00000003,00000001,00000000,00000000,00000000) ret=14008569f
rt_sigprocmask(SIG_BLOCK, [HUP INT USR1 USR2 ALRM CHLD IO], [], 8) = 0
writev(3, [{iov_base=",\0\0\0\36\0\0\0\0\0\0\0\0\0\20\0\0\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0"..., iov_len=64}, {iov_base="\\\0D\0e\0v\0i\0c\0e\0\\\0A\0f\0d\0\\\0M\0i\0o\0", iov_len=30}], 2) = 94
read(4, "4\0\0\300\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 64) = 64
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
0140:Ret  ntdll.NtCreateFile() retval=c0000034 ret=14008569f
0140:Call ntdll.RtlNtStatusToDosError(c0000034) ret=1400856b9
0140:Ret  ntdll.RtlNtStatusToDosError() retval=00000002 ret=1400856b9
0140:Call ntdll.RtlReleaseSRWLockExclusive(0003b520) ret=140078b8e
0140:Ret  ntdll.RtlReleaseSRWLockExclusive() retval=00000000 ret=140078b8e
0140:Call ntdll.RtlAcquireSRWLockExclusive(0003b570) ret=14003e1be
0140:Ret  ntdll.RtlAcquireSRWLockExclusive() retval=00000000 ret=14003e1be
0140:Call ntdll.RtlReleaseSRWLockExclusive(0003b570) ret=14003e19e
0140:Ret  ntdll.RtlReleaseSRWLockExclusive() retval=00000000 ret=14003e19e
0140:Call ws2_32.closesocket(00000080) ret=14008f78e
0140:Call ntdll.wine_server_handle_to_fd(00000080,00000001,0021dcec,00000000) ret=7f42dbca3ed4
rt_sigprocmask(SIG_BLOCK, [HUP INT USR1 USR2 ALRM CHLD IO], [], 8) = 0
rt_sigprocmask(SIG_BLOCK, [HUP INT USR1 USR2 ALRM CHLD IO], [HUP INT USR1 USR2 ALRM CHLD IO], 8) = 0
read(4, "\0\0\0\0\0\0\0\0\3\0\0\0\1\0\0\0\237\1\22\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 64) = 64
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 ALRM CHLD IO], NULL, 8) = 0
recvmsg(9, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\200\0\0\0", iov_len=4}], msg_iovlen=1, msg_control=[{cmsg_len=20, cmsg_level=SOL_SOCKET, cmsg_type=SCM_RIGHTS, cmsg_data=[72]}], msg_controllen=24, msg_flags=MSG_CMSG_CLOEXEC}, MSG_CMSG_CLOEXEC) = 4
fcntl(72, F_SETFD, FD_CLOEXEC)          = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
dup(72)                                 = 75
0140:Ret  ntdll.wine_server_handle_to_fd() retval=00000000 ret=7f42dbca3ed4
0140:Call ntdll.wine_server_release_fd(00000080,0000004b) ret=7f42dbca3ef0
close(75)                               = 0
0140:Ret  ntdll.wine_server_release_fd() retval=00000000 ret=7f42dbca3ef0
0140:Call KERNEL32.CloseHandle(00000080) ret=7f42dbca3f4c
0140:Call ntdll.NtClose(00000080) ret=7b04ed99
rt_sigprocmask(SIG_BLOCK, [HUP INT USR1 USR2 ALRM CHLD IO], [], 8) = 0
read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 64) = 64
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
close(72)                               = 0
0140:Ret  ntdll.NtClose() retval=00000000 ret=7b04ed99
0140:Ret  KERNEL32.CloseHandle() retval=00000001 ret=7f42dbca3f4c
0140:Ret  ws2_32.closesocket() retval=00000000 ret=14008f78e

The error code is produced by this part in the middle:

0140:Call ntdll.NtCreateFile(0021cbe8,00100000,1400b9d28,0021cbf0,00000000,00000000,00000003,00000001,00000000,00000000,00000000) ret=14008569f
rt_sigprocmask(SIG_BLOCK, [HUP INT USR1 USR2 ALRM CHLD IO], [], 8) = 0
writev(3, [{iov_base=",\0\0\0\36\0\0\0\0\0\0\0\0\0\20\0\0\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0"..., iov_len=64}, {iov_base="\\\0D\0e\0v\0i\0c\0e\0\\\0A\0f\0d\0\\\0M\0i\0o\0", iov_len=30}], 2) = 94
read(4, "4\0\0\300\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 64) = 64
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
0140:Ret  ntdll.NtCreateFile() retval=c0000034 ret=14008569f
0140:Call ntdll.RtlNtStatusToDosError(c0000034) ret=1400856b9
0140:Ret  ntdll.RtlNtStatusToDosError() retval=00000002 ret=1400856b9

This corresponds to the following lines in mio:

mio/src/sys/windows/afd.rs

Lines 177 to 194 in 04050db

let status = NtCreateFile(
&mut afd_helper_handle as *mut _,
SYNCHRONIZE,
&AFD_HELPER_ATTRIBUTES as *const _ as *mut _,
&mut iosb,
null_mut(),
0 as ULONG,
FILE_SHARE_READ | FILE_SHARE_WRITE,
FILE_OPEN,
0 as ULONG,
null_mut(),
0 as ULONG,
);
if status != STATUS_SUCCESS {
return Err(io::Error::from_raw_os_error(
RtlNtStatusToDosError(status) as i32
));
}

The reason this call fails is because, while wine does have \Device\Afd, mio uses \Device\Afd\Mio for reasons it never bothers to explain, and wine implements \Device\Afd as an empty directory.

I would normally consider something like this a defect in wine, but not in this case. Not only you are using a completely undocumented internal Winsock API in ways that are neither clear nor explained (here or in the wepoll codebase), but you also never mention the fact that error codes (the complete list of which you do not know because the API is undocumented) are passed to downstream consumers without any filtering, sanity checking, or indication (the human readable string in io::Error would be a great place to include the word "AFD"), and if that wasn't bad enough, this is the only backend provided by mio/tokio for networking on Windows. As far as I see, there is no workaround that can be added e.g. to an application using hyper, even if I can patch mio during the build (what am I supposed to do, rewrite the entire backend myself to use overlapped operations?)

Could you please stop for a moment and imagine how much time I have spent tracking down that ENOENT in async code of a third party Rust application I have never seen before? Not a single thing in Linux, WinAPI, wine, tokio, hyper, or std can possibly return a ENOENT error for a networking operation, so of course networking was the last thing I would blame. (Mio does return NotFound in a few places, but those are clearly distinct since they are not OS errors.) That was made harder by the fact that Wine makes debugging more complex, and also because I could at first only reproduce this as a deeply netsed part of a larger modular application that included, among other things, two copies of the Chromium Embedding Framework that ran concurrently to the crashing code.

This is the poster example of why you should not use undocumented APIs: it makes your code more fragile, harder to understand, harder to contribute to, and borderline impossible to debug for downstream users. I will never get these twenty hours of my life back. Don't do this! And if you for some reason have to do it, wrap it in hazard tape and provide a slow but obviously correct fallback.

Metadata

Metadata

Assignees

No one assigned

    Labels

    bug

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions