[RFC PATCH v3 0/5] Fix sock_recv reordering issue (#52401): unknown_status + wineserver call approach
<preamble> This is my forth attempt to tackle the issue #52401 [1]: "Improper synchronization in sock_recv/sock_send leads to arbitrary reordering of completion of I/O requests", which was initially reported (outside Bugzilla) by Dongwan Kim [2]. Basically, the old process of sock_recv is: 1. Perform the I/O synchronously. 2. Report the result back to the server, or queue up the request in the server. 3. If blocking, wait for I/O to complete. The new process of sock_recv would be: 1. Queue up the request in the server. 2. Perform the I/O synchronously. 3. Report the result back to the server, 4. If blocking, wait for I/O to complete. Everything except the actual I/O requires communicating with wineserver. My goal here is to fix the issue without introducing extra calls to wineserver. (However, if it turns out that this goal is not of utmost significance, then this patch serie can be easily modified so that it issues separate server calls.) The previous approaches are listed here: - Add a new select type called SELECT_SIGNAL_WAIT_ASYNC [3]. Zebediah has pointed out [4] that it is not very elegant to (ab-)use the synchronization machinery for communicating the async result. - Use APC_ASYNC_IO to perform the synchronous I/O [5]. This ended up with a total of 11 patches, and turned out to be rather too complicated for a simple task. - Add a new wineserver call, and use "add_queue" hook to save a round trip to the server [6]. </preamble> Each of the above turned out to be either too intrusive, complicated, or hard to verify. Per suggestion by Zebediah [7], this is my (hopefully) last approach: keep the new wineserver call, but keep out the implicit STATUS_PENDING transition from "add_queue"; also, (re-)use the "unknown_status" field. Changelog: - v1 -> v2: fix async queue hang on synchronous failure - v2 -> v3: rewrite handling of pending/failed asyncs. [1] https://bugs.winehq.org/show_bug.cgi?id=52401 [2] https://www.winehq.org/pipermail/wine-devel/2021-May/186454.html [3] https://www.winehq.org/pipermail/wine-devel/2022-January/204695.html [4] https://www.winehq.org/pipermail/wine-devel/2022-January/204710.html [5] https://www.winehq.org/pipermail/wine-devel/2022-January/205168.html [6] https://www.winehq.org/pipermail/wine-devel/2022-January/205193.html [7] https://www.winehq.org/pipermail/wine-devel/2022-January/205738.html Jinoh Kang (5): server: Allow calling async_handoff() with status code STATUS_ALERTED. server: Add a new server request "notify_async_direct_result." server: Attempt to complete I/O request immediately in recv_socket. ntdll: Don't call try_recv before server call in sock_recv. server: Replace redundant recv_socket status fields with force_async boolean field. dlls/ntdll/unix/socket.c | 37 ++++++++------- dlls/ntdll/unix/sync.c | 22 +++++++++ dlls/ntdll/unix/unix_private.h | 1 + dlls/ws2_32/tests/sock.c | 8 ++-- server/async.c | 85 ++++++++++++++++++++++++++++++++++ server/protocol.def | 14 +++++- server/sock.c | 40 +++++++++++----- 7 files changed, 172 insertions(+), 35 deletions(-) -- 2.34.1
If the server detects that an I/O request could be completed immediately (e.g. the socket to read from already has incoming data), it can now return STATUS_ALERTED to allow opportunistic synchronous I/O. The Unix side will then attempt to perform I/O in nonblocking mode and report back the I/O status to the server with signal_wait_async(). If the operation returns e.g. EAGAIN or EWOULDBLOCK, the client can opt to either abandon the request (by specifying an error status) or poll for it in the server as usual (by waiting on the wait handle). Without such mechanism in place, the client cannot safely perform immediately satiable I/O operations synchronously, since it can potentially conflict with other pending I/O operations that have already been queued. Signed-off-by: Jinoh Kang <jinoh.kang.kr(a)gmail.com> --- Notes: v2 -> v3: set async->alerted = 1 server/async.c | 24 ++++++++++++++++++++++++ 1 file changed, 24 insertions(+) diff --git a/server/async.c b/server/async.c index 7aef28355f0..e169bb23225 100644 --- a/server/async.c +++ b/server/async.c @@ -338,6 +338,30 @@ obj_handle_t async_handoff( struct async *async, data_size_t *result, int force_ return async->wait_handle; } + if (!async->pending && get_error() == STATUS_ALERTED) + { + /* Give the client opportunity to complete synchronously. + * If it turns out that the I/O request is not actually immediately satiable, + * the client may then choose to re-queue the async (with STATUS_PENDING). + */ + async->unknown_status = 1; + + /* Deactivate async so that it can be safely queued. + * Otherwise, the async will be erroneously alerted the next time + * someone calls async_wake_up() on the queue. + * + * Don't use async_terminate() here since we'd like to leave the IOSB + * status as STATUS_PENDING. Also we certainly don't want APC_ASYNC_IO + * to fire in any circumstances. + */ + async->terminated = 1; + async->alerted = 1; + + async_reselect( async ); + + return async->wait_handle; + } + async->initial_status = get_error(); if (!async->pending && NT_ERROR( get_error() )) -- 2.34.1
Some I/O operations need a way to "queue" the async to the target object first, even if the operation itself is to be completed synchronously. After synchronous completion, it needs a way to notify the IO_STATUS_BLOCK values back to the server. Add a new wineserver request, "notify_async_direct_result", which notifies direct (i.e. synchronous) completion of async from the same thread. Signed-off-by: Jinoh Kang <jinoh.kang.kr(a)gmail.com> --- Notes: v1 -> v2: dequeue async after failed completion v2 -> v3: rewrite handling of pending/failed asyncs. server/async.c | 61 +++++++++++++++++++++++++++++++++++++++++++++ server/protocol.def | 10 ++++++++ 2 files changed, 71 insertions(+) diff --git a/server/async.c b/server/async.c index e169bb23225..9f063283b8c 100644 --- a/server/async.c +++ b/server/async.c @@ -752,3 +752,64 @@ DECL_HANDLER(get_async_result) } set_error( iosb->status ); } + +/* Notify direct completion of async and close the wait handle */ +DECL_HANDLER(notify_async_direct_result) +{ + struct async *async = (struct async *)get_handle_obj( current->process, req->handle, 0, &async_ops ); + + if (!async) return; + + if (async->iosb && async->unknown_status && !async->pending && + async->terminated && async->alerted) + { + /* async->terminated is 1, so async_terminate() won't do anything. + * We need to set the status and result for ourselves. + */ + async->iosb->status = req->status; + async->iosb->result = req->information; + + /* Set status for async_handoff(). */ + set_error( async->iosb->status ); + + /* The async_handoff() call prior to the current server request was + * effectively a no-op since async->unknown_status is 1. Calling it + * again with async->unknown_status = 0 will do the remaining steps. + * + * NOTE: async_handoff() is being called with async->terminated = 1. + */ + async->unknown_status = 0; + async_handoff( async, NULL, 0 ); + + /* If the I/O has completed successfully, the client would have already + * set the IOSB. Therefore, we can skip waiting on wait_handle and do + * async_set_result() directly. + */ + async_set_result( &async->obj, async->iosb->status, async->iosb->result ); + + /* Close wait handle here to avoid extra server round trip if the I/O + * has completed successfully. + * + * - If STATUS_PENDING, async_handoff() decides whether to close + * the wait handle for us. + * - If failed (NT_ERROR), async_handoff() always closes + * the wait_handle, which means async->wait_handle == 0. + */ + if (async->wait_handle && async->iosb->status != STATUS_PENDING) + { + close_handle( async->thread->process, async->wait_handle ); + async->wait_handle = 0; + } + + /* The wait handle is preserved only when the status is STATUS_PENDING + * and async->blocking is set (i.e. we're going to block on it). + */ + reply->handle = async->wait_handle; + + /* async_set_result() may have overriden the status value. Reset it. */ + set_error( async->iosb->status ); + } + else set_error( STATUS_ACCESS_DENIED ); + + release_object( &async->obj ); +} diff --git a/server/protocol.def b/server/protocol.def index 02e73047f9b..2c3b8dbc619 100644 --- a/server/protocol.def +++ b/server/protocol.def @@ -2163,6 +2163,16 @@ enum message_type @END +/* Notify direct completion of async and close the wait handle */ +(a)REQ(notify_async_direct_result) + obj_handle_t handle; /* wait handle */ + unsigned int status; /* completion status */ + apc_param_t information; /* IO_STATUS_BLOCK Information */ +(a)REPLY + obj_handle_t handle; /* wait handle, or NULL if closed */ +(a)END + + /* Perform a read on a file object */ @REQ(read) async_data_t async; /* async I/O parameters */ -- 2.34.1
Make recv_socket alert the async immediately if poll() call detects that there are incoming data in the socket, bypassing the wineserver's main polling loop. Signed-off-by: Jinoh Kang <jinoh.kang.kr(a)gmail.com> --- dlls/ntdll/unix/socket.c | 22 ++++++++++++++++++---- dlls/ntdll/unix/sync.c | 22 ++++++++++++++++++++++ dlls/ntdll/unix/unix_private.h | 1 + server/protocol.def | 1 + server/sock.c | 23 ++++++++++++++++++++++- 5 files changed, 64 insertions(+), 5 deletions(-) diff --git a/dlls/ntdll/unix/socket.c b/dlls/ntdll/unix/socket.c index 71dfcdd1114..336f655e19e 100644 --- a/dlls/ntdll/unix/socket.c +++ b/dlls/ntdll/unix/socket.c @@ -686,6 +686,7 @@ static NTSTATUS sock_recv( HANDLE handle, HANDLE event, PIO_APC_ROUTINE apc, voi NTSTATUS status; unsigned int i; ULONG options; + BOOL may_restart, alerted; if (unix_flags & MSG_OOB) { @@ -756,16 +757,29 @@ static NTSTATUS sock_recv( HANDLE handle, HANDLE event, PIO_APC_ROUTINE apc, voi status = wine_server_call( req ); wait_handle = wine_server_ptr_handle( reply->wait ); options = reply->options; - if ((!NT_ERROR(status) || wait_handle) && status != STATUS_PENDING) + may_restart = reply->may_restart; + } + SERVER_END_REQ; + + alerted = status == STATUS_ALERTED; + if (alerted) + { + status = try_recv( fd, async, &information ); + if (status == STATUS_DEVICE_NOT_READY && may_restart) + status = STATUS_PENDING; + } + + if (status != STATUS_PENDING) + { + if (!NT_ERROR(status) || wait_handle) { io->Status = status; io->Information = information; } + release_fileio( &async->io ); } - SERVER_END_REQ; - - if (status != STATUS_PENDING) release_fileio( &async->io ); + if (alerted) status = notify_async( &wait_handle, status, information ); if (wait_handle) status = wait_async( wait_handle, options & FILE_SYNCHRONOUS_IO_ALERT ); return status; } diff --git a/dlls/ntdll/unix/sync.c b/dlls/ntdll/unix/sync.c index 442243d8bcf..4cb30479322 100644 --- a/dlls/ntdll/unix/sync.c +++ b/dlls/ntdll/unix/sync.c @@ -2510,3 +2510,25 @@ NTSTATUS WINAPI NtWaitForAlertByThreadId( const void *address, const LARGE_INTEG } #endif + +/* Notify direct completion of async and close the wait handle if it is no longer needed. + * This function is a no-op (returns status as-is) if the supplied handle is NULL. + */ +NTSTATUS notify_async( HANDLE *optional_handle, NTSTATUS status, ULONG_PTR information ) +{ + NTSTATUS ret; + + if (!*optional_handle) return status; + + SERVER_START_REQ( notify_async_direct_result ) + { + req->handle = wine_server_obj_handle( *optional_handle ); + req->status = status; + req->information = information; + ret = wine_server_call( req ); + *optional_handle = wine_server_ptr_handle( reply->handle ); + } + SERVER_END_REQ; + + return ret; +} diff --git a/dlls/ntdll/unix/unix_private.h b/dlls/ntdll/unix/unix_private.h index a79edabc37c..e8e158b5591 100644 --- a/dlls/ntdll/unix/unix_private.h +++ b/dlls/ntdll/unix/unix_private.h @@ -274,6 +274,7 @@ extern NTSTATUS get_device_info( int fd, struct _FILE_FS_DEVICE_INFORMATION *inf extern void init_files(void) DECLSPEC_HIDDEN; extern void init_cpu_info(void) DECLSPEC_HIDDEN; extern void add_completion( HANDLE handle, ULONG_PTR value, NTSTATUS status, ULONG info, BOOL async ) DECLSPEC_HIDDEN; +extern NTSTATUS notify_async( HANDLE *optional_handle, NTSTATUS status, ULONG_PTR information ); extern void dbg_init(void) DECLSPEC_HIDDEN; diff --git a/server/protocol.def b/server/protocol.def index 2c3b8dbc619..72a7f4a85b5 100644 --- a/server/protocol.def +++ b/server/protocol.def @@ -1456,6 +1456,7 @@ enum server_fd_type @REPLY obj_handle_t wait; /* handle to wait on for blocking recv */ unsigned int options; /* device open options */ + int may_restart; /* May restart async? */ @END diff --git a/server/sock.c b/server/sock.c index 40fb0cac535..14d95451420 100644 --- a/server/sock.c +++ b/server/sock.c @@ -3397,6 +3397,7 @@ DECL_HANDLER(recv_socket) { struct sock *sock = (struct sock *)get_handle_obj( current->process, req->async.handle, 0, &sock_ops ); unsigned int status = req->status; + int pending = 0; timeout_t timeout = 0; struct async *async; struct fd *fd; @@ -3422,6 +3423,25 @@ DECL_HANDLER(recv_socket) if ((status == STATUS_PENDING || status == STATUS_DEVICE_NOT_READY) && sock->rd_shutdown) status = STATUS_PIPE_DISCONNECTED; + /* NOTE: If read_q is not empty, we cannot really tell if the already queued asyncs + * NOTE: will not consume all available data; if there's no data available, + * NOTE: the current request won't be immediately satiable. */ + if ((status == STATUS_PENDING || status == STATUS_DEVICE_NOT_READY) && !async_queued( &sock->read_q )) + { + struct pollfd pollfd; + pollfd.fd = get_unix_fd( sock->fd ); + pollfd.events = req->oob ? POLLPRI : POLLIN; + pollfd.revents = 0; + if (poll(&pollfd, 1, 0) >= 0 && pollfd.revents) + { + /* Give the client opportunity to complete synchronously. + * If it turns out that the I/O request is not actually immediately satiable, + * the client may then choose to re-queue the async (with STATUS_PENDING). */ + pending = status == STATUS_PENDING; + status = STATUS_ALERTED; + } + } + sock->pending_events &= ~(req->oob ? AFD_POLL_OOB : AFD_POLL_READ); sock->reported_events &= ~(req->oob ? AFD_POLL_OOB : AFD_POLL_READ); @@ -3438,7 +3458,7 @@ DECL_HANDLER(recv_socket) if (timeout) async_set_timeout( async, timeout, STATUS_IO_TIMEOUT ); - if (status == STATUS_PENDING) + if (status == STATUS_PENDING || status == STATUS_ALERTED) queue_async( &sock->read_q, async ); /* always reselect; we changed reported_events above */ @@ -3446,6 +3466,7 @@ DECL_HANDLER(recv_socket) reply->wait = async_handoff( async, NULL, 0 ); reply->options = get_fd_options( fd ); + reply->may_restart = pending && status == STATUS_ALERTED; release_object( async ); } release_object( sock ); -- 2.34.1
Otherwise, try_recv() call from sock_recv() may race against try_recv() call from async_recv_proc(), shuffling the packet order. Wine-Bug: https://bugs.winehq.org/show_bug.cgi?id=52401 Signed-off-by: Jinoh Kang <jinoh.kang.kr(a)gmail.com> --- dlls/ntdll/unix/socket.c | 12 ++---------- dlls/ws2_32/tests/sock.c | 8 ++++---- 2 files changed, 6 insertions(+), 14 deletions(-) diff --git a/dlls/ntdll/unix/socket.c b/dlls/ntdll/unix/socket.c index 336f655e19e..a46e84616ec 100644 --- a/dlls/ntdll/unix/socket.c +++ b/dlls/ntdll/unix/socket.c @@ -737,16 +737,8 @@ static NTSTATUS sock_recv( HANDLE handle, HANDLE event, PIO_APC_ROUTINE apc, voi } } - status = try_recv( fd, async, &information ); - - if (status != STATUS_SUCCESS && status != STATUS_BUFFER_OVERFLOW && status != STATUS_DEVICE_NOT_READY) - { - release_fileio( &async->io ); - return status; - } - - if (status == STATUS_DEVICE_NOT_READY && force_async) - status = STATUS_PENDING; + status = force_async ? STATUS_PENDING : STATUS_DEVICE_NOT_READY; + information = 0; SERVER_START_REQ( recv_socket ) { diff --git a/dlls/ws2_32/tests/sock.c b/dlls/ws2_32/tests/sock.c index 054e597b719..4199676f460 100644 --- a/dlls/ws2_32/tests/sock.c +++ b/dlls/ws2_32/tests/sock.c @@ -7750,8 +7750,8 @@ static void test_shutdown(void) WSASetLastError(0xdeadbeef); ret = recv(server, buffer, sizeof(buffer), 0); - todo_wine ok(ret == -1, "got %d\n", ret); - todo_wine ok(WSAGetLastError() == WSAESHUTDOWN, "got error %u\n", WSAGetLastError()); + ok(ret == -1, "got %d\n", ret); + ok(WSAGetLastError() == WSAESHUTDOWN, "got error %u\n", WSAGetLastError()); ret = send(server, "test", 5, 0); ok(ret == 5, "got %d\n", ret); @@ -7845,8 +7845,8 @@ static void test_shutdown(void) WSASetLastError(0xdeadbeef); ret = recv(server, buffer, sizeof(buffer), 0); - todo_wine ok(ret == -1, "got %d\n", ret); - todo_wine ok(WSAGetLastError() == WSAESHUTDOWN, "got error %u\n", WSAGetLastError()); + ok(ret == -1, "got %d\n", ret); + ok(WSAGetLastError() == WSAESHUTDOWN, "got error %u\n", WSAGetLastError()); WSASetLastError(0xdeadbeef); ret = send(server, "test", 5, 0); -- 2.34.1
Hi, While running your changed tests, I think I found new failures. Being a bot and all I'm not very good at pattern recognition, so I might be wrong, but could you please double-check? Full results can be found at: https://testbot.winehq.org/JobDetails.pl?Key=106284 Your paranoid android. === debian11 (64 bit WoW report) === ws2_32: sock.c:5267: Test failed: expected timeout
The 'status' field of recv_socket_request is always either STATUS_PENDING or STATUS_DEVICE_NOT_READY, and the 'total' field is always zero. Replace the 'status' field with 'force_async' boolean field, and get rid of the 'total' field entirely. Also, clean up the recv_socket handler code a bit. Signed-off-by: Jinoh Kang <jinoh.kang.kr(a)gmail.com> --- dlls/ntdll/unix/socket.c | 7 ++----- server/protocol.def | 3 +-- server/sock.c | 23 +++++++++-------------- 3 files changed, 12 insertions(+), 21 deletions(-) diff --git a/dlls/ntdll/unix/socket.c b/dlls/ntdll/unix/socket.c index a46e84616ec..c6ab6c7646b 100644 --- a/dlls/ntdll/unix/socket.c +++ b/dlls/ntdll/unix/socket.c @@ -737,13 +737,9 @@ static NTSTATUS sock_recv( HANDLE handle, HANDLE event, PIO_APC_ROUTINE apc, voi } } - status = force_async ? STATUS_PENDING : STATUS_DEVICE_NOT_READY; - information = 0; - SERVER_START_REQ( recv_socket ) { - req->status = status; - req->total = information; + req->force_async = force_async; req->async = server_async( handle, &async->io, event, apc, apc_user, iosb_client_ptr(io) ); req->oob = !!(unix_flags & MSG_OOB); status = wine_server_call( req ); @@ -753,6 +749,7 @@ static NTSTATUS sock_recv( HANDLE handle, HANDLE event, PIO_APC_ROUTINE apc, voi } SERVER_END_REQ; + information = 0; alerted = status == STATUS_ALERTED; if (alerted) { diff --git a/server/protocol.def b/server/protocol.def index 72a7f4a85b5..2de8bcd0a50 100644 --- a/server/protocol.def +++ b/server/protocol.def @@ -1451,8 +1451,7 @@ enum server_fd_type @REQ(recv_socket) int oob; /* are we receiving OOB data? */ async_data_t async; /* async I/O parameters */ - unsigned int status; /* status of initial call */ - unsigned int total; /* number of bytes already read */ + int force_async; /* Force asynchronous mode? */ @REPLY obj_handle_t wait; /* handle to wait on for blocking recv */ unsigned int options; /* device open options */ diff --git a/server/sock.c b/server/sock.c index 14d95451420..fbf76870a51 100644 --- a/server/sock.c +++ b/server/sock.c @@ -3396,8 +3396,8 @@ struct object *create_socket_device( struct object *root, const struct unicode_s DECL_HANDLER(recv_socket) { struct sock *sock = (struct sock *)get_handle_obj( current->process, req->async.handle, 0, &sock_ops ); - unsigned int status = req->status; - int pending = 0; + unsigned int status = STATUS_PENDING; + int pending = req->force_async; timeout_t timeout = 0; struct async *async; struct fd *fd; @@ -3405,8 +3405,8 @@ DECL_HANDLER(recv_socket) if (!sock) return; fd = sock->fd; - /* recv() returned EWOULDBLOCK, i.e. no data available yet */ - if (status == STATUS_DEVICE_NOT_READY && !sock->nonblocking) + /* Synchronous, *blocking* I/O requested? */ + if (!req->force_async && !sock->nonblocking) { /* Set a timeout on the async if necessary. * @@ -3417,16 +3417,16 @@ DECL_HANDLER(recv_socket) if (is_fd_overlapped( fd )) timeout = (timeout_t)sock->rcvtimeo * -10000; - status = STATUS_PENDING; + pending = 1; } - if ((status == STATUS_PENDING || status == STATUS_DEVICE_NOT_READY) && sock->rd_shutdown) + if (status == STATUS_PENDING && sock->rd_shutdown) status = STATUS_PIPE_DISCONNECTED; /* NOTE: If read_q is not empty, we cannot really tell if the already queued asyncs * NOTE: will not consume all available data; if there's no data available, * NOTE: the current request won't be immediately satiable. */ - if ((status == STATUS_PENDING || status == STATUS_DEVICE_NOT_READY) && !async_queued( &sock->read_q )) + if (status == STATUS_PENDING && !async_queued( &sock->read_q )) { struct pollfd pollfd; pollfd.fd = get_unix_fd( sock->fd ); @@ -3437,22 +3437,17 @@ DECL_HANDLER(recv_socket) /* Give the client opportunity to complete synchronously. * If it turns out that the I/O request is not actually immediately satiable, * the client may then choose to re-queue the async (with STATUS_PENDING). */ - pending = status == STATUS_PENDING; status = STATUS_ALERTED; } } + if (!pending && status == STATUS_PENDING) status = STATUS_DEVICE_NOT_READY; + sock->pending_events &= ~(req->oob ? AFD_POLL_OOB : AFD_POLL_READ); sock->reported_events &= ~(req->oob ? AFD_POLL_OOB : AFD_POLL_READ); if ((async = create_request_async( fd, get_fd_comp_flags( fd ), &req->async ))) { - if (status == STATUS_SUCCESS) - { - struct iosb *iosb = async_get_iosb( async ); - iosb->result = req->total; - release_object( iosb ); - } set_error( status ); if (timeout) -- 2.34.1
participants (2)
-
Jinoh Kang -
Marvin