[PATCH 1/2] ntdll/tests: Remove traces from threadpool callbacks.
They seem to cause spurious failures. Wine-Bug: https://bugs.winehq.org/show_bug.cgi?id=47843 Signed-off-by: Rémi Bernon <rbernon(a)codeweavers.com> --- This is the first part of a series that re-implements RtlRegisterWait using TpSetWait. When used with WT_EXECUTEINWAITTHREAD, RtlRegisterWait callbacks are supposed to be executed directly in some wait thread that are pooled, as implemented by TpSetWait. RtlRegisterWait currently has a separate implementation that spawns a new thread for every wait, and it causes some deadlocks with applications that rely on the wait serialization induced by the pooling. This series will fix the Rockstar Launcher download progress issue mentioned in the Wine Bug, as well as some frequent deadlocks with Gears Tactics. I'm only sending the tests for now to reduce the number of patches. dlls/ntdll/tests/threadpool.c | 33 +-------------------------------- 1 file changed, 1 insertion(+), 32 deletions(-) diff --git a/dlls/ntdll/tests/threadpool.c b/dlls/ntdll/tests/threadpool.c index 24f32346fbe..4045cfa4081 100644 --- a/dlls/ntdll/tests/threadpool.c +++ b/dlls/ntdll/tests/threadpool.c @@ -119,7 +119,6 @@ static BOOL init_threadpool(void) static DWORD CALLBACK rtl_work_cb(void *userdata) { HANDLE semaphore = userdata; - trace("Running rtl_work callback\n"); ReleaseSemaphore(semaphore, 1, NULL); return 0; } @@ -175,8 +174,6 @@ static void CALLBACK rtl_wait_cb(void *userdata, BOOLEAN timeout) struct rtl_wait_info *info = userdata; DWORD result; - trace("Running rtl_wait callback\n"); - if (!timeout) InterlockedIncrement(&info->userdata); else @@ -196,7 +193,6 @@ static HANDLE rtl_wait_apc_semaphore; static void CALLBACK rtl_wait_apc_cb(ULONG_PTR userdata) { - trace("Running rtl_wait_apc callback\n"); if (rtl_wait_apc_semaphore) ReleaseSemaphore(rtl_wait_apc_semaphore, 1, NULL); } @@ -481,13 +477,11 @@ static void test_RtlRegisterWait(void) static void CALLBACK simple_cb(TP_CALLBACK_INSTANCE *instance, void *userdata) { HANDLE semaphore = userdata; - trace("Running simple callback\n"); ReleaseSemaphore(semaphore, 1, NULL); } static void CALLBACK simple2_cb(TP_CALLBACK_INSTANCE *instance, void *userdata) { - trace("Running simple2 callback\n"); Sleep(50); InterlockedIncrement((LONG *)userdata); } @@ -605,14 +599,12 @@ static void test_tp_simple(void) static void CALLBACK work_cb(TP_CALLBACK_INSTANCE *instance, void *userdata, TP_WORK *work) { - trace("Running work callback\n"); Sleep(100); InterlockedIncrement((LONG *)userdata); } static void CALLBACK work2_cb(TP_CALLBACK_INSTANCE *instance, void *userdata, TP_WORK *work) { - trace("Running work2 callback\n"); Sleep(100); InterlockedExchangeAdd((LONG *)userdata, 0x10000); } @@ -735,7 +727,6 @@ static void test_tp_work_scheduler(void) static void CALLBACK simple_release_cb(TP_CALLBACK_INSTANCE *instance, void *userdata) { HANDLE *semaphores = userdata; - trace("Running simple release callback\n"); ReleaseSemaphore(semaphores, 1, NULL); Sleep(200); /* wait until main thread is in TpReleaseCleanupGroupMembers */ } @@ -743,7 +734,6 @@ static void CALLBACK simple_release_cb(TP_CALLBACK_INSTANCE *instance, void *use static void CALLBACK work_release_cb(TP_CALLBACK_INSTANCE *instance, void *userdata, TP_WORK *work) { HANDLE semaphore = userdata; - trace("Running work release callback\n"); ReleaseSemaphore(semaphore, 1, NULL); Sleep(200); /* wait until main thread is in TpReleaseCleanupGroupMembers */ pTpReleaseWork(work); @@ -752,7 +742,6 @@ static void CALLBACK work_release_cb(TP_CALLBACK_INSTANCE *instance, void *userd static void CALLBACK timer_release_cb(TP_CALLBACK_INSTANCE *instance, void *userdata, TP_TIMER *timer) { HANDLE semaphore = userdata; - trace("Running timer release callback\n"); ReleaseSemaphore(semaphore, 1, NULL); Sleep(200); /* wait until main thread is in TpReleaseCleanupGroupMembers */ pTpReleaseTimer(timer); @@ -762,7 +751,6 @@ static void CALLBACK wait_release_cb(TP_CALLBACK_INSTANCE *instance, void *userd TP_WAIT *wait, TP_WAIT_RESULT result) { HANDLE semaphore = userdata; - trace("Running wait release callback\n"); ReleaseSemaphore(semaphore, 1, NULL); Sleep(200); /* wait until main thread is in TpReleaseCleanupGroupMembers */ pTpReleaseWait(wait); @@ -855,8 +843,6 @@ static void CALLBACK simple_group_cancel_cb(TP_CALLBACK_INSTANCE *instance, void DWORD result; int i; - trace("Running simple group cancel callback\n"); - status = pTpCallbackMayRunLong(instance); ok(status == STATUS_TOO_MANY_THREADS || broken(status == 1) /* Win Vista / 2008 */, "expected STATUS_TOO_MANY_THREADS, got %08x\n", status); @@ -875,8 +861,6 @@ static void CALLBACK work_group_cancel_cb(TP_CALLBACK_INSTANCE *instance, void * HANDLE *semaphores = userdata; DWORD result; - trace("Running work group cancel callback\n"); - ReleaseSemaphore(semaphores[1], 1, NULL); result = WaitForSingleObject(semaphores[0], 200); ok(result == WAIT_TIMEOUT, "WaitForSingleObject returned %u\n", result); @@ -885,7 +869,6 @@ static void CALLBACK work_group_cancel_cb(TP_CALLBACK_INSTANCE *instance, void * static void CALLBACK group_cancel_cleanup_release_cb(void *object, void *userdata) { HANDLE *semaphores = userdata; - trace("Running group cancel cleanup release callback\n"); group_cancel_tid = GetCurrentThreadId(); ok(object == (void *)0xdeadbeef, "expected 0xdeadbeef, got %p\n", object); ReleaseSemaphore(semaphores[0], 1, NULL); @@ -894,7 +877,6 @@ static void CALLBACK group_cancel_cleanup_release_cb(void *object, void *userdat static void CALLBACK group_cancel_cleanup_release2_cb(void *object, void *userdata) { HANDLE *semaphores = userdata; - trace("Running group cancel cleanup release2 callback\n"); group_cancel_tid = GetCurrentThreadId(); ok(object == userdata, "expected %p, got %p\n", userdata, object); ReleaseSemaphore(semaphores[0], 1, NULL); @@ -902,7 +884,6 @@ static void CALLBACK group_cancel_cleanup_release2_cb(void *object, void *userda static void CALLBACK group_cancel_cleanup_increment_cb(void *object, void *userdata) { - trace("Running group cancel cleanup increment callback\n"); group_cancel_tid = GetCurrentThreadId(); InterlockedIncrement((LONG *)userdata); } @@ -1089,7 +1070,6 @@ static void test_tp_group_cancel(void) static void CALLBACK instance_semaphore_completion_cb(TP_CALLBACK_INSTANCE *instance, void *userdata) { HANDLE *semaphores = userdata; - trace("Running instance completion callback\n"); pTpCallbackReleaseSemaphoreOnCompletion(instance, semaphores[0], 1); } @@ -1098,8 +1078,7 @@ static void CALLBACK instance_finalization_cb(TP_CALLBACK_INSTANCE *instance, vo HANDLE *semaphores = userdata; DWORD result; - trace("Running instance finalization callback\n"); - + Sleep(50); result = WaitForSingleObject(semaphores[0], 100); ok(result == WAIT_TIMEOUT, "WaitForSingleObject returned %u\n", result); ReleaseSemaphore(semaphores[1], 1, NULL); @@ -1156,8 +1135,6 @@ static void CALLBACK disassociate_cb(TP_CALLBACK_INSTANCE *instance, void *userd HANDLE *semaphores = userdata; DWORD result; - trace("Running disassociate callback\n"); - pTpDisassociateCallback(instance); result = WaitForSingleObject(semaphores[0], 1000); ok(result == WAIT_OBJECT_0, "WaitForSingleObject returned %u\n", result); @@ -1169,8 +1146,6 @@ static void CALLBACK disassociate2_cb(TP_CALLBACK_INSTANCE *instance, void *user HANDLE *semaphores = userdata; DWORD result; - trace("Running disassociate2 callback\n"); - pTpDisassociateCallback(instance); result = WaitForSingleObject(semaphores[0], 100); ok(result == WAIT_TIMEOUT, "WaitForSingleObject returned %u\n", result); @@ -1182,8 +1157,6 @@ static void CALLBACK disassociate3_cb(TP_CALLBACK_INSTANCE *instance, void *user HANDLE *semaphores = userdata; DWORD result; - trace("Running disassociate3 callback\n"); - pTpDisassociateCallback(instance); result = WaitForSingleObject(semaphores[0], 100); ok(result == WAIT_TIMEOUT, "WaitForSingleObject returned %u\n", result); @@ -1300,7 +1273,6 @@ static void test_tp_disassociate(void) static void CALLBACK timer_cb(TP_CALLBACK_INSTANCE *instance, void *userdata, TP_TIMER *timer) { HANDLE semaphore = userdata; - trace("Running timer callback\n"); ReleaseSemaphore(semaphore, 1, NULL); } @@ -1440,7 +1412,6 @@ struct window_length_info static void CALLBACK window_length_cb(TP_CALLBACK_INSTANCE *instance, void *userdata, TP_TIMER *timer) { struct window_length_info *info = userdata; - trace("Running window length callback\n"); info->ticks = GetTickCount(); ReleaseSemaphore(info->semaphore, 1, NULL); } @@ -1558,8 +1529,6 @@ static void CALLBACK wait_cb(TP_CALLBACK_INSTANCE *instance, void *userdata, TP_WAIT *wait, TP_WAIT_RESULT result) { struct wait_info *info = userdata; - trace("Running wait callback\n"); - if (result == WAIT_OBJECT_0) InterlockedIncrement(&info->userdata); else if (result == WAIT_TIMEOUT) -- 2.30.0
Wine-Bug: https://bugs.winehq.org/show_bug.cgi?id=47843 Signed-off-by: Rémi Bernon <rbernon(a)codeweavers.com> --- dlls/ntdll/tests/threadpool.c | 91 ++++++++++++++++++++++++++++++++++- 1 file changed, 90 insertions(+), 1 deletion(-) diff --git a/dlls/ntdll/tests/threadpool.c b/dlls/ntdll/tests/threadpool.c index 4045cfa4081..e18ad4dd76d 100644 --- a/dlls/ntdll/tests/threadpool.c +++ b/dlls/ntdll/tests/threadpool.c @@ -203,7 +203,7 @@ static void test_RtlRegisterWait(void) struct rtl_wait_info info; HANDLE semaphores[2]; NTSTATUS status; - DWORD result; + DWORD result, threadid; semaphores[0] = CreateSemaphoreW(NULL, 0, 2, NULL); ok(semaphores[0] != NULL, "failed to create semaphore\n"); @@ -294,6 +294,69 @@ static void test_RtlRegisterWait(void) status = RtlDeregisterWait(wait1); ok(!status, "RtlDeregisterWait failed with status %x\n", status); + /* test RtlRegisterWait WT_EXECUTEINWAITTHREAD flag */ + info.userdata = 0; + info.threadid = 0; + status = RtlRegisterWait(&wait1, semaphores[1], rtl_wait_cb, &info, 200, WT_EXECUTEINWAITTHREAD|WT_EXECUTEONLYONCE); + ok(!status, "RtlRegisterWait failed with status %x\n", status); + ReleaseSemaphore(semaphores[1], 1, NULL); + result = WaitForSingleObject(semaphores[0], 200); + ok(result == WAIT_OBJECT_0, "WaitForSingleObject returned %u\n", result); + ok(info.userdata == 1, "expected info.userdata = 1, got %u\n", info.userdata); + ok(info.threadid && info.threadid != GetCurrentThreadId(), "unexpected wait thread id %x\n", info.threadid); + threadid = info.threadid; + result = WaitForSingleObject(semaphores[1], 0); + ok(result == WAIT_TIMEOUT, "WaitForSingleObject returned %u\n", result); + Sleep(50); + status = RtlDeregisterWait(wait1); + ok(!status, "RtlDeregisterWait failed with status %x\n", status); + + info.userdata = 0; + info.threadid = 0; + status = RtlRegisterWait(&wait1, semaphores[1], rtl_wait_cb, &info, 200, WT_EXECUTEINWAITTHREAD|WT_EXECUTEONLYONCE); + ok(!status, "RtlRegisterWait failed with status %x\n", status); + ReleaseSemaphore(semaphores[1], 1, NULL); + result = WaitForSingleObject(semaphores[0], 200); + ok(result == WAIT_OBJECT_0, "WaitForSingleObject returned %u\n", result); + ok(info.userdata == 1, "expected info.userdata = 1, got %u\n", info.userdata); + todo_wine ok(info.threadid == threadid, "unexpected different wait thread id %x\n", info.threadid); + result = WaitForSingleObject(semaphores[1], 0); + ok(result == WAIT_TIMEOUT, "WaitForSingleObject returned %u\n", result); + Sleep(50); + status = RtlDeregisterWait(wait1); + ok(!status, "RtlDeregisterWait failed with status %x\n", status); + + /* test RtlRegisterWait WT_EXECUTEINWAITTHREAD flag with 0 timeout */ + info.userdata = 0; + info.threadid = 0; + status = RtlRegisterWait(&wait1, semaphores[1], rtl_wait_cb, &info, 0, WT_EXECUTEINWAITTHREAD|WT_EXECUTEONLYONCE); + ok(!status, "RtlRegisterWait failed with status %x\n", status); + result = WaitForSingleObject(semaphores[0], 100); + ok(result == WAIT_OBJECT_0, "WaitForSingleObject returned %u\n", result); + ok(info.userdata == 0x10000, "expected info.userdata = 0x10000, got %u\n", info.userdata); + ok(info.threadid == threadid, "unexpected different wait thread id %x\n", info.threadid); + result = WaitForSingleObject(semaphores[1], 0); + ok(result == WAIT_TIMEOUT, "WaitForSingleObject returned %u\n", result); + Sleep(50); + status = RtlDeregisterWait(wait1); + ok(!status, "RtlDeregisterWait failed with status %x\n", status); + + /* test RtlRegisterWait WT_EXECUTEINWAITTHREAD flag with already signaled event */ + info.userdata = 0; + info.threadid = 0; + ReleaseSemaphore(semaphores[1], 1, NULL); + status = RtlRegisterWait(&wait1, semaphores[1], rtl_wait_cb, &info, 200, WT_EXECUTEINWAITTHREAD|WT_EXECUTEONLYONCE); + ok(!status, "RtlRegisterWait failed with status %x\n", status); + result = WaitForSingleObject(semaphores[0], 200); + ok(result == WAIT_OBJECT_0, "WaitForSingleObject returned %u\n", result); + ok(info.userdata == 1, "expected info.userdata = 1, got %u\n", info.userdata); + todo_wine ok(info.threadid == threadid, "unexpected different wait thread id %x\n", info.threadid); + result = WaitForSingleObject(semaphores[1], 0); + ok(result == WAIT_TIMEOUT, "WaitForSingleObject returned %u\n", result); + Sleep(50); + status = RtlDeregisterWait(wait1); + ok(!status, "RtlDeregisterWait failed with status %x\n", status); + /* test for IO threads */ info.userdata = 0; info.threadid = 0; @@ -427,6 +490,19 @@ static void test_RtlRegisterWait(void) result = WaitForSingleObject(semaphores[0], 1000); ok(result == WAIT_OBJECT_0, "WaitForSingleObject returned %u\n", result); + info.userdata = 0; + status = RtlRegisterWait(&wait1, semaphores[1], rtl_wait_cb, &info, INFINITE, WT_EXECUTEINWAITTHREAD|WT_EXECUTEONLYONCE); + ok(!status, "RtlRegisterWait failed with status %x\n", status); + ReleaseSemaphore(semaphores[1], 1, NULL); + result = WaitForSingleObject(semaphores[0], 1000); + ok(result == WAIT_OBJECT_0, "WaitForSingleObject returned %u\n", result); + ok(info.userdata == 1, "expected info.userdata = 1, got %u\n", info.userdata); + status = RtlDeregisterWait(wait1); + ok(status == STATUS_PENDING, "expected STATUS_PENDING, got %x\n", status); + ReleaseSemaphore(semaphores[1], 1, NULL); + result = WaitForSingleObject(semaphores[0], 1000); + ok(result == WAIT_OBJECT_0, "WaitForSingleObject returned %u\n", result); + info.userdata = 0; status = RtlRegisterWait(&wait1, semaphores[1], rtl_wait_cb, &info, INFINITE, WT_EXECUTEONLYONCE); ok(!status, "RtlRegisterWait failed with status %x\n", status); @@ -453,6 +529,19 @@ static void test_RtlRegisterWait(void) result = WaitForSingleObject(semaphores[0], 0); ok(result == WAIT_OBJECT_0, "WaitForSingleObject returned %u\n", result); + info.wait_result = WAIT_TIMEOUT; + info.userdata = 0; + status = RtlRegisterWait(&wait1, semaphores[1], rtl_wait_cb, &info, INFINITE, WT_EXECUTEINWAITTHREAD|WT_EXECUTEONLYONCE); + ok(!status, "RtlRegisterWait failed with status %x\n", status); + ReleaseSemaphore(semaphores[1], 1, NULL); + result = WaitForSingleObject(semaphores[0], 1000); + ok(result == WAIT_OBJECT_0, "WaitForSingleObject returned %u\n", result); + ok(info.userdata == 1, "expected info.userdata = 1, got %u\n", info.userdata); + status = RtlDeregisterWaitEx(wait1, INVALID_HANDLE_VALUE); + ok(!status, "RtlDeregisterWaitEx failed with status %x\n", status); + result = WaitForSingleObject(semaphores[0], 0); + ok(result == WAIT_OBJECT_0, "WaitForSingleObject returned %u\n", result); + info.wait_result = WAIT_OBJECT_0; info.userdata = 0; status = RtlRegisterWait(&wait1, semaphores[1], rtl_wait_cb, &info, INFINITE, WT_EXECUTEONLYONCE); -- 2.30.0
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=85378 Your paranoid android. === w8adm (32 bit report) === ntdll: threadpool.c:1172: Test failed: WaitForSingleObject returned 0 threadpool.c:1212: Test failed: WaitForSingleObject returned 258
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=85377 Your paranoid android. === w1064_2qxl (64 bit report) === ntdll: threadpool.c:1083: Test failed: WaitForSingleObject returned 0 threadpool.c:1123: Test failed: WaitForSingleObject returned 258 === w10pro64_zh_CN (64 bit report) === ntdll: threadpool.c:1083: Test failed: WaitForSingleObject returned 0 threadpool.c:1123: Test failed: WaitForSingleObject returned 258
participants (2)
-
Marvin -
Rémi Bernon