From a8e7defb015adc5d986f9e60815a1babb1b232ba Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Herm=C3=A8s=20B=C3=A9lusca-Ma=C3=AFto?= Date: Sun, 29 Dec 2019 15:10:19 +0100 Subject: [PATCH] [WIN32SS:USER] Some minimal work and fixes concerning message queues timeouts. CORE-15147 - Rename CLIENTTHREADINFO::tickLastMsgChecked into timeLastRead as documented in https://reactos.org/wiki/Techwiki:Win32k/CLIENTTHREADINFO . This is the last time the message queue was read. - This is the structure member one must compare against the current tick count timestamp in order to heuristically determine whether a message queue thread is hung!! Fix MsqIsHung() in accordance, add extra debug logging in order to help us determining which of our code present regular GUI hangs, and add as well an extra "TimeOut" parameter so as not to hardcode a fixed value within that function but instead allowing its caller to specify possible different values. - THREADINFO::timeLast is on the contrary the last message time stamp, and will definitively differ from CLIENTTHREADINFO::timeLastRead . It should only be used for information purposes! - Accordingly, in NtUserGetThreadState()::THREADSTATE_UPTIMELASTREAD and in InitThreadCallback(), only (re-)initialize the timeLastRead member of the CLIENTTHREADINFO structure of the THREADINFO of interest. - In co_IntPeekMessage(), update more often the timeLastRead timestamp whenever the current message queue has been read (but NOT timeLast!! That one will be updated ONLY WHEN a message is found!). - In co_IntSendMessageTimeoutSingle() first check whether the window to which we send the message is being destroyed, before checking for queue hangs etc. Collapse the logic checks for queue hang and increase the hang timeout check to 4 times MSQ_HUNG (== 4 * 5 seconds) and display a debug trace. --- win32ss/include/ntuser.h | 2 +- win32ss/user/ntuser/ghost.c | 2 +- win32ss/user/ntuser/main.c | 6 ++--- win32ss/user/ntuser/message.c | 39 ++++++++++++++------------- win32ss/user/ntuser/misc.c | 5 ++-- win32ss/user/ntuser/msgqueue.c | 27 ++++++++++++++++--- win32ss/user/ntuser/msgqueue.h | 2 +- win32ss/user/ntuser/painting.c | 2 +- win32ss/user/ntuser/simplecall.c | 2 +- win32ss/user/ntuser/win32.h | 3 ++- win32ss/user/ntuser/window.c | 2 +- win32ss/user/user32/windows/message.c | 2 +- 12 files changed, 57 insertions(+), 37 deletions(-) diff --git a/win32ss/include/ntuser.h b/win32ss/include/ntuser.h index 81a0b914409..d92796dd3d9 100644 --- a/win32ss/include/ntuser.h +++ b/win32ss/include/ntuser.h @@ -167,7 +167,7 @@ typedef struct _CLIENTTHREADINFO WORD fsWakeBits; WORD fsWakeBitsJournal; WORD fsWakeMask; - ULONG tickLastMsgChecked; + ULONG timeLastRead; // Last time the message queue was read. DWORD dwcPumpHook; } CLIENTTHREADINFO, *PCLIENTTHREADINFO; diff --git a/win32ss/user/ntuser/ghost.c b/win32ss/user/ntuser/ghost.c index fcb70a4c77c..d206df25fc6 100644 --- a/win32ss/user/ntuser/ghost.c +++ b/win32ss/user/ntuser/ghost.c @@ -162,7 +162,7 @@ BOOL FASTCALL IntMakeHungWindowGhosted(HWND hwndHung) return FALSE; // not a window } - if (!MsqIsHung(pHungWnd->head.pti)) + if (!MsqIsHung(pHungWnd->head.pti, MSQ_HUNG)) { DPRINT1("Not hung window\n"); return FALSE; // not hung window diff --git a/win32ss/user/ntuser/main.c b/win32ss/user/ntuser/main.c index 27964ba20fb..95ab58474c9 100644 --- a/win32ss/user/ntuser/main.c +++ b/win32ss/user/ntuser/main.c @@ -467,6 +467,7 @@ InitThreadCallback(PETHREAD Thread) IntReferenceProcessInfo(ptiCurrent->ppi); pTeb->Win32ThreadInfo = ptiCurrent; ptiCurrent->pClientInfo = (PCLIENTINFO)pTeb->Win32ClientInfo; + ptiCurrent->pcti = &ptiCurrent->cti; /* Mark the process as having threads */ ptiCurrent->ppi->W32PF_flags |= W32PF_THREADCONNECTED; @@ -503,7 +504,8 @@ InitThreadCallback(PETHREAD Thread) goto error; } - ptiCurrent->timeLast = EngGetTickCount32(); + ptiCurrent->pcti->timeLastRead = EngGetTickCount32(); + ptiCurrent->MessageQueue = MsqCreateMessageQueue(ptiCurrent); if (ptiCurrent->MessageQueue == NULL) { @@ -524,8 +526,6 @@ InitThreadCallback(PETHREAD Thread) if (Process == gpepCSRSS || !gpepCSRSS) ptiCurrent->TIF_flags = TIF_CSRSSTHREAD | TIF_DONTATTACHQUEUE; - ptiCurrent->pcti = &ptiCurrent->cti; - /* Initialize the CLIENTINFO */ pci = (PCLIENTINFO)pTeb->Win32ClientInfo; RtlZeroMemory(pci, sizeof(*pci)); diff --git a/win32ss/user/ntuser/message.c b/win32ss/user/ntuser/message.c index 2fd47c4fd8d..aad83242943 100644 --- a/win32ss/user/ntuser/message.c +++ b/win32ss/user/ntuser/message.c @@ -829,8 +829,8 @@ co_IntPeekMessage( PMSG Msg, do { - pti->timeLast = EngGetTickCount32(); - pti->pcti->tickLastMsgChecked = pti->timeLast; + /* Update the last message-queue access time */ + pti->pcti->timeLastRead = EngGetTickCount32(); // Post mouse moves while looping through peek messages. if (pti->MessageQueue->QF_flags & QF_MOUSEMOVED) @@ -874,7 +874,7 @@ co_IntPeekMessage( PMSG Msg, 0, Msg )) { - return TRUE; + goto GotMessage; } /* Only check for quit messages if not posted messages pending. */ @@ -893,7 +893,7 @@ co_IntPeekMessage( PMSG Msg, pti->pcti->fsWakeBits &= ~QS_ALLPOSTMESSAGE; pti->pcti->fsChangeBits &= ~QS_ALLPOSTMESSAGE; } - return TRUE; + goto GotMessage; } /* Check for hardware events. */ @@ -906,7 +906,7 @@ co_IntPeekMessage( PMSG Msg, ProcessMask, Msg)) { - return TRUE; + goto GotMessage; } /* Now check for System Event messages. */ @@ -946,7 +946,7 @@ co_IntPeekMessage( PMSG Msg, Msg, RemoveMessages)) { - return TRUE; + goto GotMessage; } /* This is correct, check for the current threads timers waiting to be @@ -962,6 +962,9 @@ co_IntPeekMessage( PMSG Msg, } while (TRUE); +GotMessage: + /* Update the last message-queue access time */ + pti->pcti->timeLastRead = EngGetTickCount32(); return TRUE; } @@ -1423,16 +1426,6 @@ co_IntSendMessageTimeoutSingle( HWND hWnd, RETURN( TRUE); } - if (MsqIsHung(ptiSendTo)) - { - if (uFlags & SMTO_ABORTIFHUNG) - { - // FIXME: Set window hung and add to a list. - /* FIXME: Set a LastError? */ - RETURN( FALSE); - } - } - if (Window->state & WNDS_DESTROYED) { /* FIXME: Last error? */ @@ -1440,6 +1433,14 @@ co_IntSendMessageTimeoutSingle( HWND hWnd, RETURN( FALSE); } + if ((uFlags & SMTO_ABORTIFHUNG) && MsqIsHung(ptiSendTo, 4 * MSQ_HUNG)) + { + // FIXME: Set window hung and add to a list. + /* FIXME: Set a LastError? */ + ERR("Window %p (%p) (pti %p) is hung!\n", hWnd, Window, ptiSendTo); + RETURN( FALSE); + } + do { Status = co_MsqSendMessage( ptiSendTo, @@ -1452,13 +1453,13 @@ co_IntSendMessageTimeoutSingle( HWND hWnd, MSQ_NORMAL, uResult ); } - while ((STATUS_TIMEOUT == Status) && + while ((Status == STATUS_TIMEOUT) && (uFlags & SMTO_NOTIMEOUTIFNOTHUNG) && - !MsqIsHung(ptiSendTo)); // FIXME: Set window hung and add to a list. + !MsqIsHung(ptiSendTo, MSQ_HUNG)); // FIXME: Set window hung and add to a list. if (Status == STATUS_TIMEOUT) { - if (0 && MsqIsHung(ptiSendTo)) + if (0 && MsqIsHung(ptiSendTo, MSQ_HUNG)) { TRACE("Let's go Ghost!\n"); IntMakeHungWindowGhosted(hWnd); diff --git a/win32ss/user/ntuser/misc.c b/win32ss/user/ntuser/misc.c index 03707cd8829..99066d90fda 100644 --- a/win32ss/user/ntuser/misc.c +++ b/win32ss/user/ntuser/misc.c @@ -296,10 +296,9 @@ NtUserGetThreadState( { PTHREADINFO pti; pti = PsGetCurrentThreadWin32Thread(); - pti->timeLast = EngGetTickCount32(); - pti->pcti->tickLastMsgChecked = pti->timeLast; + pti->pcti->timeLastRead = EngGetTickCount32(); + break; } - break; case THREADSTATE_GETINPUTSTATE: ret = LOWORD(IntGetQueueStatus(QS_POSTMESSAGE|QS_TIMER|QS_PAINT|QS_SENDMESSAGE|QS_INPUT)) & (QS_KEY | QS_MOUSEBUTTON); diff --git a/win32ss/user/ntuser/msgqueue.c b/win32ss/user/ntuser/msgqueue.c index 2baa5a5ae49..04d2e06ef94 100644 --- a/win32ss/user/ntuser/msgqueue.c +++ b/win32ss/user/ntuser/msgqueue.c @@ -2089,8 +2089,8 @@ co_MsqPeekHardwareMessage(IN PTHREADINFO pti, { pti->TIF_flags |= TIF_MSGPOSCHANGED; } - pti->ptLast = msg.pt; pti->timeLast = msg.time; + pti->ptLast = msg.pt; MessageQueue->ExtraInfo = ExtraInfo; Ret = TRUE; break; @@ -2191,13 +2191,32 @@ co_MsqWaitForNewMessages(PTHREADINFO pti, PWND WndFilter, } BOOL FASTCALL -MsqIsHung(PTHREADINFO pti) +MsqIsHung(PTHREADINFO pti, DWORD TimeOut) { - if (EngGetTickCount32() - pti->timeLast > MSQ_HUNG && + DWORD dwTimeStamp = EngGetTickCount32(); + if (dwTimeStamp - pti->pcti->timeLastRead > TimeOut && !(pti->pcti->fsWakeMask & QS_INPUT) && !PsGetThreadFreezeCount(pti->pEThread) && !(pti->ppi->W32PF_flags & W32PF_APPSTARTING)) - return TRUE; + { + ERR("\nMsqIsHung(pti %p, TimeOut %lu)\n" + "pEThread %p, ThreadsProcess %p, ImageFileName '%s'\n" + "dwTimeStamp = %lu\n" + "pti->pcti->timeLastRead = %lu\n" + "pti->timeLast = %lu\n" + "PsGetThreadFreezeCount(pti->pEThread) = %lu\n", + pti, TimeOut, + pti->pEThread, + pti->pEThread ? pti->pEThread->ThreadsProcess : NULL, + (pti->pEThread && pti->pEThread->ThreadsProcess) + ? pti->pEThread->ThreadsProcess->ImageFileName : "(None)", + dwTimeStamp, + pti->pcti->timeLastRead, + pti->timeLast, + PsGetThreadFreezeCount(pti->pEThread)); + + return TRUE; + } return FALSE; } diff --git a/win32ss/user/ntuser/msgqueue.h b/win32ss/user/ntuser/msgqueue.h index 0927354165b..f66122fa412 100644 --- a/win32ss/user/ntuser/msgqueue.h +++ b/win32ss/user/ntuser/msgqueue.h @@ -127,7 +127,7 @@ enum internal_event_message extern LIST_ENTRY usmList; -BOOL FASTCALL MsqIsHung(PTHREADINFO pti); +BOOL FASTCALL MsqIsHung(PTHREADINFO pti, DWORD TimeOut); VOID CALLBACK HungAppSysTimerProc(HWND,UINT,UINT_PTR,DWORD); NTSTATUS FASTCALL co_MsqSendMessage(PTHREADINFO ptirec, HWND Wnd, UINT Msg, WPARAM wParam, LPARAM lParam, diff --git a/win32ss/user/ntuser/painting.c b/win32ss/user/ntuser/painting.c index c1f7cad77ac..eb2815c6442 100644 --- a/win32ss/user/ntuser/painting.c +++ b/win32ss/user/ntuser/painting.c @@ -1092,7 +1092,7 @@ UpdateThreadWindows(PWND pWnd, PTHREADINFO pti, HRGN hRgn) } else { - if (IsThreadSuspended(pwndTemp->head.pti) || MsqIsHung(pwndTemp->head.pti)) + if (IsThreadSuspended(pwndTemp->head.pti) || MsqIsHung(pwndTemp->head.pti, MSQ_HUNG)) { UpdateTheadChildren(pwndTemp, hRgn); } diff --git a/win32ss/user/ntuser/simplecall.c b/win32ss/user/ntuser/simplecall.c index 7cd2c8490d9..462bbe15bb7 100644 --- a/win32ss/user/ntuser/simplecall.c +++ b/win32ss/user/ntuser/simplecall.c @@ -515,7 +515,7 @@ NtUserCallTwoParam( { break; } - if (MsqIsHung(Window->head.pti)) + if (MsqIsHung(Window->head.pti, MSQ_HUNG)) { // TODO: Make the window ghosted and activate. break; diff --git a/win32ss/user/ntuser/win32.h b/win32ss/user/ntuser/win32.h index 4fede2b1f99..f8ef4ef20ad 100644 --- a/win32ss/user/ntuser/win32.h +++ b/win32ss/user/ntuser/win32.h @@ -97,7 +97,7 @@ typedef struct _THREADINFO struct _USER_SENT_MESSAGE *pusmCurrent; /* Queue of messages sent to the queue. */ LIST_ENTRY SentMessagesListHead; // psmsReceiveList - /* Last time PeekMessage() was called. */ + /* Last message time and ID */ LONG timeLast; ULONG_PTR idLast; /* True if a WM_QUIT message is pending. */ @@ -124,6 +124,7 @@ typedef struct _THREADINFO PKEVENT pEventQueueServer; LIST_ENTRY PtiLink; INT iCursorLevel; + /* Last message cursor position */ POINT ptLast; INT cEnterCount; diff --git a/win32ss/user/ntuser/window.c b/win32ss/user/ntuser/window.c index ee65215959d..9994a6b23ea 100644 --- a/win32ss/user/ntuser/window.c +++ b/win32ss/user/ntuser/window.c @@ -4057,7 +4057,7 @@ NtUserQueryWindow(HWND hWnd, DWORD Index) break; case QUERY_WINDOW_ISHUNG: - Result = (DWORD_PTR)MsqIsHung(pWnd->head.pti); + Result = (DWORD_PTR)MsqIsHung(pWnd->head.pti, MSQ_HUNG); break; case QUERY_WINDOW_REAL_ID: diff --git a/win32ss/user/user32/windows/message.c b/win32ss/user/user32/windows/message.c index a96b799456c..2f94caa5f2c 100644 --- a/win32ss/user/user32/windows/message.c +++ b/win32ss/user/user32/windows/message.c @@ -2162,7 +2162,7 @@ PeekMessageWorker( PMSG pMsg, { // Not waiting for idle event. if (!pcti->fsChangeBits && !pcti->fsWakeBits) { // No messages are available. - if ((GetTickCount() - pcti->tickLastMsgChecked) > 1000) + if ((GetTickCount() - pcti->timeLastRead) > 1000) { // Up the msg read count if over 1 sec. NtUserGetThreadState(THREADSTATE_UPTIMELASTREAD); }