tdf#111994 WIN workaround PostMessage delays

Fixes the "Multiple timers in queue" assertion by effectively
removing it.

When debugging it became obvious, that PostMessage returns, even
if the message was not yet added to the message queue.

The assert happens, because we start the timer in the Scheduler
before Invoke(), so it fires, if we block in Invoke(), and then
reset the timer after Invoke, if there were changes to the Task
list.

In this case it fires during Invoke(), the message is added. We
restart the timer, first by stopping it (we wait in
DeleteTimerQueueTimer, to be sure the timer function has either
finished or was not run). And the try to remove the message with
PeekMessageW, which doesn't remove the posted message.

Then the timer is restarted, and when the event is processed, we
end up with an additional timer event, which was asserted.

As a fix this adds a (microsecond) timestamp to the timer message,
which is validated in the WinProc function. So if we stop the
timer too fast, the event is ignored based on the timestamp.

And while at it, the patch moves timer related variables from
SalData into WinSalTimer.

Change-Id: Ib840a421e8bd040d40f39473e1d44491e5b332bd
Reviewed-on: https://gerrit.libreoffice.org/42575Tested-by: Jenkins <ci@libreoffice.org>
Reviewed-by: Jan-Marek Glogowski <glogow@fbihome.de>

vcl/README.scheduler

@@ -129,6 +129,13 @@ Therefore the current solution always starts a (threaded) timer even for the
 instant Idles and syncs to this timer message in the main dispatch loop.
 Using SwitchToThread(), this seem to work reasonably well.
 
+An additional workaround is implemented for the delayed queuing of posted
+messages, where PeekMessage in WinSalTimer::Stop() won't be able remove the
+just posted timer callback message. We handle this by adding a timestamp to
+the timer callback message, which is checked before starting the Scheduler.
+This way we can end with multiple timer callback message in the queue, which
+we were asserting.
+
 == KDE implementation details ==
 
 This implementation also works as intended. But there is a different Yield
@@ -190,3 +197,11 @@ and can process system events.
 
 That's just a theory - it definitely needs more analysis before even attending
 an implementation.
+
+== Re-evaluate the MacOS ImplNSAppPostEvent ==
+
+Probably a solution comparable to the Windows backends delayed PostMessage
+workaround using a validation timestamp is better then the current peek,
+remove, re-postEvent, which has to run in the main thread.
+
+Originally I didn't evaluate, if the event is actually lost or just delayed.

vcl/inc/win/saldata.hxx

@@ -84,8 +84,6 @@ public:
     long*                   mpDitherDiff;           // Dither mapping table
     BYTE*                   mpDitherLow;            // Dither mapping table
     BYTE*                   mpDitherHigh;           // Dither mapping table
-    HANDLE                  mnTimerId;              ///< Windows timer id
-    bool                    mbOnIdleRunScheduler;   ///< Run yield until the scheduler processed the idle
     HHOOK                   mhSalObjMsgHook;        // hook to get interesting msg for SalObject
     HWND                    mhWantLeaveMsg;         // window handle, that want a MOUSELEAVE message
     AutoTimer*              mpMouseLeaveTimer;      // Timer for MouseLeave Test
@@ -178,8 +176,6 @@ void ImplSalYieldMutexRelease();
 
 LRESULT CALLBACK SalFrameWndProcW( HWND hWnd, UINT nMsg, WPARAM wParam, LPARAM lParam );
 
-void EmitTimerCallback();
-
 void SalTestMouseLeave();
 
 bool ImplHandleSalObjKeyMsg( HWND hWnd, UINT nMsg, WPARAM wParam, LPARAM lParam );

vcl/inc/win/saltimer.h

@@ -24,16 +24,39 @@
 
 class WinSalTimer : public SalTimer
 {
+    HANDLE       m_nTimerId;          ///< Windows timer id
+    sal_uInt32   m_nTimerStartTicks;  ///< system ticks at timer start % SAL_MAX_UINT32
+    bool         m_bPollForMessage;   ///< Run yield until a message is caught (most likely the 0ms timer)
+
 public:
-    WinSalTimer() {}
+    WinSalTimer();
     virtual ~WinSalTimer() override;
 
     virtual void Start(sal_uIntPtr nMS) override;
     virtual void Stop() override;
+
+    inline bool IsValidWPARAM( WPARAM wParam ) const;
+
+    inline bool PollForMessage() const;
+
+    // The Impl functions are just public to be called from the static
+    // SalComWndProc on main thread redirect! Otherwise they would be private.
+    // They must be called from the main application thread only!
+
+    void ImplStart( sal_uIntPtr nMS );
+    void ImplStop();
+    void ImplEmitTimerCallback();
 };
 
-void ImplSalStartTimer( sal_uIntPtr nMS );
-void ImplSalStopTimer();
+inline bool WinSalTimer::IsValidWPARAM( WPARAM aWPARAM ) const
+{
+    return aWPARAM == m_nTimerStartTicks;
+}
+
+inline bool WinSalTimer::PollForMessage() const
+{
+    return m_bPollForMessage;
+}
 
 #endif
 

vcl/win/app/salinst.cxx

@@ -247,8 +247,6 @@ SalData::SalData()
     mpDitherDiff = nullptr;     // Dither mapping table
     mpDitherLow = nullptr;      // Dither mapping table
     mpDitherHigh = nullptr;     // Dither mapping table
-    mnTimerId = nullptr;        // windows timer id
-    mbOnIdleRunScheduler = false; // if yield is idle, run the scheduler
     mhSalObjMsgHook = nullptr;  // hook to get interesting msg for SalObject
     mhWantLeaveMsg = nullptr;   // window handle, that want a MOUSELEAVE message
     mpMouseLeaveTimer = nullptr; // Timer for MouseLeave Test
@@ -490,7 +488,8 @@ ImplSalYield( bool bWait, bool bHandleAllCurrentEvents )
 {
     MSG aMsg;
     bool bWasMsg = false, bOneEvent = false;
-    SalData *const pSalData = GetSalData();
+    ImplSVData *const pSVData = ImplGetSVData();
+    WinSalTimer* pTimer = static_cast<WinSalTimer*>( pSVData->maSchedCtx.mpSalTimer );
 
     int nMaxEvents = bHandleAllCurrentEvents ? 100 : 1;
     do
@@ -506,21 +505,22 @@ ImplSalYield( bool bWait, bool bHandleAllCurrentEvents )
             // busy loop to catch the 0ms timeout
             // We don't need to busy loop, if we wait anyway.
             // Even if we didn't process the event directly, report it.
-            if ( pSalData->mbOnIdleRunScheduler && !bWait )
+            if ( pTimer && pTimer->PollForMessage() && !bWait )
             {
                 SwitchToThread();
                 nMaxEvents++;
                 bOneEvent = true;
                 bWasMsg = true;
             }
-    } while( --nMaxEvents && bOneEvent );
+    }
+    while( --nMaxEvents && bOneEvent );
 
     // Also check that we don't wait when application already has quit
-    if ( bWait && !bWasMsg && !ImplGetSVData()->maAppData.mbAppQuit )
+    if ( bWait && !bWasMsg && !pSVData->maAppData.mbAppQuit )
     {
         if ( GetMessageW( &aMsg, nullptr, 0, 0 ) )
         {
-            // Ignore the scheduler wakeup message
+            bWasMsg = true;
             TranslateMessage( &aMsg );
             ImplSalDispatchMessage( &aMsg );
         }
@@ -582,17 +582,17 @@ LRESULT CALLBACK SalComWndProc( HWND, UINT nMsg, WPARAM wParam, LPARAM lParam, i
             break;
         case SAL_MSG_STARTTIMER:
         {
-            sal_uLong nTime = GetTickCount();
-            if ( nTime < (sal_uLong) lParam )
-                nTime = (sal_uLong) lParam - nTime;
+            sal_uInt64 nTime = tools::Time::GetSystemTicks();
+            if ( nTime < (sal_uInt64) lParam )
+                nTime = (sal_uInt64) lParam - nTime;
             else
                 nTime = 0;
-            ImplSalStartTimer( nTime );
+            static_cast<WinSalTimer*>(ImplGetSVData()->maSchedCtx.mpSalTimer)->ImplStart( nTime );
             rDef = FALSE;
             break;
         }
         case SAL_MSG_STOPTIMER:
-            ImplSalStopTimer();
+            static_cast<WinSalTimer*>(ImplGetSVData()->maSchedCtx.mpSalTimer)->ImplStop();
             break;
         case SAL_MSG_CREATEFRAME:
             nRet = reinterpret_cast<LRESULT>(ImplSalCreateFrame( GetSalData()->mpFirstInstance, reinterpret_cast<HWND>(lParam), (SalFrameStyleFlags)wParam ));
@@ -639,14 +639,22 @@ LRESULT CALLBACK SalComWndProc( HWND, UINT nMsg, WPARAM wParam, LPARAM lParam, i
             rDef = FALSE;
             break;
         case SAL_MSG_TIMER_CALLBACK:
+        {
+            WinSalTimer *const pTimer = static_cast<WinSalTimer*>( ImplGetSVData()->maSchedCtx.mpSalTimer );
+            assert( pTimer != nullptr );
             MSG aMsg;
+            bool bValidMSG = pTimer->IsValidWPARAM( wParam );
             // PM_QS_POSTMESSAGE is needed, so we don't process the SendMessage from DoYield!
-            while ( PeekMessageW(&aMsg, nullptr, SAL_MSG_TIMER_CALLBACK,
+            while ( PeekMessageW(&aMsg, GetSalData()->mpFirstInstance->mhComWnd, SAL_MSG_TIMER_CALLBACK,
                                  SAL_MSG_TIMER_CALLBACK, PM_REMOVE | PM_NOYIELD | PM_QS_POSTMESSAGE) )
-                SAL_WARN("vcl", "Multiple timer messages in queue");
-            GetSalData()->mbOnIdleRunScheduler = false;
-            EmitTimerCallback();
+            {
+                assert( !bValidMSG && "Unexpected non-last valid message" );
+                bValidMSG = pTimer->IsValidWPARAM( aMsg.wParam );
+            }
+            if ( bValidMSG )
+                pTimer->ImplEmitTimerCallback();
             break;
+        }
     }
 
     return nRet;

vcl/win/app/saltimer.cxx

@@ -31,31 +31,29 @@ static void CALLBACK SalTimerProc(PVOID pParameter, BOOLEAN bTimerOrWaitFired);
 // deletion of timer (which is extremely likely, given that
 // INVALID_HANDLE_VALUE waits for the callback to run on the main thread),
 // this must run on the main thread too
-void ImplSalStopTimer()
+void WinSalTimer::ImplStop()
 {
     SalData *const pSalData = GetSalData();
-    assert( !pSalData->mpFirstInstance || pSalData->mnAppThreadId == GetCurrentThreadId() );
+    const WinSalInstance *pInst = pSalData->mpFirstInstance;
+    assert( !pInst || pSalData->mnAppThreadId == GetCurrentThreadId() );
 
-    HANDLE hTimer = pSalData->mnTimerId;
-    if (hTimer)
-    {
-        pSalData->mnTimerId = nullptr;
-        DeleteTimerQueueTimer(nullptr, hTimer, INVALID_HANDLE_VALUE);
-    }
+    const HANDLE hTimer = m_nTimerId;
+    if ( nullptr == hTimer )
+        return;
 
-    // remove all pending SAL_MSG_TIMER_CALLBACK messages
-    // we always have to do this, since ImplSalStartTimer with 0ms just queues
-    // a new SAL_MSG_TIMER_CALLBACK message
+    m_nTimerId = nullptr;
+    m_nTimerStartTicks = 0;
+    DeleteTimerQueueTimer( nullptr, hTimer, INVALID_HANDLE_VALUE );
+    m_bPollForMessage = false;
+
+    // remove as many pending SAL_MSG_TIMER_CALLBACK messages as possible
     // PM_QS_POSTMESSAGE is needed, so we don't process the SendMessage from DoYield!
     MSG aMsg;
-    int nMsgCount = 0;
-    while ( PeekMessageW(&aMsg, nullptr, SAL_MSG_TIMER_CALLBACK,
-                         SAL_MSG_TIMER_CALLBACK, PM_REMOVE | PM_NOYIELD | PM_QS_POSTMESSAGE) )
-        nMsgCount++;
-    assert( nMsgCount <= 1 );
+    while ( PeekMessageW(&aMsg, pInst->mhComWnd, SAL_MSG_TIMER_CALLBACK,
+                         SAL_MSG_TIMER_CALLBACK, PM_REMOVE | PM_NOYIELD | PM_QS_POSTMESSAGE) );
 }
 
-void ImplSalStartTimer( sal_uLong nMS )
+void WinSalTimer::ImplStart( sal_uLong nMS )
 {
     SalData* pSalData = GetSalData();
     assert( !pSalData->mpFirstInstance || pSalData->mnAppThreadId == GetCurrentThreadId() );
@@ -65,17 +63,26 @@ void ImplSalStartTimer( sal_uLong nMS )
         nMS = SAL_MAX_UINT32;
 
     // cannot change a one-shot timer, so delete it and create a new one
-    ImplSalStopTimer();
+    ImplStop();
 
-    // keep the scheduler running, if a 0ms timer / Idle is scheduled
-    pSalData->mbOnIdleRunScheduler = ( 0 == nMS );
+    // keep the yield running, if a 0ms Idle is scheduled
+    m_bPollForMessage = ( 0 == nMS );
+    m_nTimerStartTicks = tools::Time::GetMonotonicTicks() % SAL_MAX_UINT32;
     // probably WT_EXECUTEONLYONCE is not needed, but it enforces Period
     // to be 0 and should not hurt; also see
     // https://www.microsoft.com/msj/0499/pooling/pooling.aspx
-    CreateTimerQueueTimer(&pSalData->mnTimerId, nullptr, SalTimerProc, nullptr,
+    CreateTimerQueueTimer(&m_nTimerId, nullptr, SalTimerProc,
+                          (void*) m_nTimerStartTicks,
                           nMS, 0, WT_EXECUTEINTIMERTHREAD | WT_EXECUTEONLYONCE);
 }
 
+WinSalTimer::WinSalTimer()
+    : m_nTimerId( nullptr )
+    , m_nTimerStartTicks( 0 )
+    , m_bPollForMessage( false )
+{
+}
+
 WinSalTimer::~WinSalTimer()
 {
     Stop();
@@ -83,28 +90,28 @@ WinSalTimer::~WinSalTimer()
 
 void WinSalTimer::Start( sal_uLong nMS )
 {
-    SalData* pSalData = GetSalData();
-    if ( pSalData->mpFirstInstance && pSalData->mnAppThreadId != GetCurrentThreadId() )
+    WinSalInstance *pInst = GetSalData()->mpFirstInstance;
+    if ( pInst && !pInst->IsMainThread() )
     {
-        BOOL const ret = PostMessageW(pSalData->mpFirstInstance->mhComWnd,
-            SAL_MSG_STARTTIMER, 0, (LPARAM)GetTickCount() + nMS);
+        BOOL const ret = PostMessageW(pInst->mhComWnd,
+            SAL_MSG_STARTTIMER, 0, (LPARAM) tools::Time::GetSystemTicks() + nMS);
         SAL_WARN_IF(0 == ret, "vcl", "ERROR: PostMessage() failed!");
     }
     else
-        ImplSalStartTimer( nMS );
+        ImplStart( nMS );
 }
 
 void WinSalTimer::Stop()
 {
-    SalData* pSalData = GetSalData();
-    if ( pSalData->mpFirstInstance && pSalData->mnAppThreadId != GetCurrentThreadId() )
+    WinSalInstance *pInst = GetSalData()->mpFirstInstance;
+    if ( pInst && !pInst->IsMainThread() )
     {
-        BOOL const ret = PostMessageW(pSalData->mpFirstInstance->mhComWnd,
+        BOOL const ret = PostMessageW(pInst->mhComWnd,
             SAL_MSG_STOPTIMER, 0, 0);
         SAL_WARN_IF(0 == ret, "vcl", "ERROR: PostMessage() failed!");
     }
     else
-        ImplSalStopTimer();
+        ImplStop();
 }
 
 /** This gets invoked from a Timer Queue thread.
@@ -112,20 +119,18 @@ void WinSalTimer::Stop()
 Don't acquire the SolarMutex to avoid deadlocks, just wake up the main thread
 at better resolution than 10ms.
 */
-static void CALLBACK SalTimerProc(PVOID, BOOLEAN)
+static void CALLBACK SalTimerProc(PVOID data, BOOLEAN)
 {
     __try
     {
-        SalData* pSalData = GetSalData();
-
         // always post message when the timer fires, we will remove the ones
         // that happened during execution of the callback later directly from
         // the message queue
-        BOOL const ret = PostMessageW(pSalData->mpFirstInstance->mhComWnd,
-                                      SAL_MSG_TIMER_CALLBACK, 0, 0);
+        BOOL const ret = PostMessageW(GetSalData()->mpFirstInstance->mhComWnd,
+                                      SAL_MSG_TIMER_CALLBACK, (WPARAM) data, 0);
 #if OSL_DEBUG_LEVEL > 0
         if (0 == ret) // SEH prevents using SAL_WARN here?
-            fputs("ERROR: PostMessage() failed!", stderr);
+            fputs("ERROR: PostMessage() failed!\n", stderr);
 #endif
     }
     __except(WinSalInstance::WorkaroundExceptionHandlingInUSER32Lib(GetExceptionCode(), GetExceptionInformation()))
@@ -133,22 +138,14 @@ static void CALLBACK SalTimerProc(PVOID, BOOLEAN)
     }
 }
 
-/** Called in the main thread.
-
-We assured that by posting the message from the SalTimeProc only, the real
-call then happens when the main thread gets SAL_MSG_TIMER_CALLBACK.
-*/
-void EmitTimerCallback()
+void WinSalTimer::ImplEmitTimerCallback()
 {
     // Test for MouseLeave
     SalTestMouseLeave();
 
-    ImplSVData *pSVData = ImplGetSVData();
-    if ( ! pSVData->maSchedCtx.mpSalTimer )
-        return;
-
+    m_bPollForMessage = false;
     ImplSalYieldMutexAcquireWithWait();
-    pSVData->maSchedCtx.mpSalTimer->CallCallback();
+    CallCallback();
     ImplSalYieldMutexRelease();
 }