vcl: improve scheduler debugging information.

Change-Id: I6f7d7d3b5b027097417a15804a42aaaab4a03158
Reviewed-on: https://gerrit.libreoffice.org/20185
Reviewed-by: Michael Meeks <michael.meeks@collabora.com>
Tested-by: Michael Meeks <michael.meeks@collabora.com>

2 files changed, 18 insertions, 0 deletions

diff --git a/vcl/source/app/scheduler.cxx b/vcl/source/app/scheduler.cxx
index 743de911cd22..8e548bc5cb42 100644
--- a/vcl/source/app/scheduler.cxx
+++ b/vcl/source/app/scheduler.cxx
@@ -163,6 +163,12 @@ void Scheduler::ProcessTaskScheduling( bool bTimerOnly )
     // tdf#91727 - NB. bTimerOnly is ultimately not used
     if ((pSchedulerData = ImplSchedulerData::GetMostImportantTask(bTimerOnly)))
     {
+        // FIXME: move into a helper.
+        const char *pSchedulerName = pSchedulerData->mpScheduler->mpDebugName;
+        if (!pSchedulerName)
+            pSchedulerName = "unknown";
+        SAL_INFO("vcl.schedule", "Invoke task " << pSchedulerName);
+
         pSchedulerData->mnUpdateTime = tools::Time::GetSystemTicks();
         pSchedulerData->Invoke();
     }
@@ -178,6 +184,7 @@ sal_uInt64 Scheduler::CalculateMinimumTimeout( bool &bHasActiveIdles )
     sal_uInt64         nTime = tools::Time::GetSystemTicks();
     sal_uInt64         nMinPeriod = MaximumTimeoutMs;
 
+    SAL_INFO("vcl.schedule", "Calculating minimum timeout:");
     pSchedulerData = pSVData->mpFirstSchedulerData;
     while ( pSchedulerData )
     {
@@ -217,10 +224,13 @@ sal_uInt64 Scheduler::CalculateMinimumTimeout( bool &bHasActiveIdles )
             pSVData->mpSalTimer->Stop();
         nMinPeriod = MaximumTimeoutMs;
         pSVData->mnTimerPeriod = nMinPeriod;
+        SAL_INFO("vcl.schedule", "Unusual - no more timers available - stop timer");
     }
     else
     {
         Scheduler::ImplStartTimer(nMinPeriod, true);
+        SAL_INFO("vcl.schedule", "Calculated minimum timeout as " << nMinPeriod << " and " <<
+                 (const char *)(bHasActiveIdles ? "has active idles" : "no idles"));
     }
 
     return nMinPeriod;
diff --git a/vcl/source/app/svapp.cxx b/vcl/source/app/svapp.cxx
index 808e743bdbc9..e9c4b01a0c27 100644
--- a/vcl/source/app/svapp.cxx
+++ b/vcl/source/app/svapp.cxx
@@ -477,6 +477,9 @@ inline void ImplYield(bool i_bWait, bool i_bAllEvents, sal_uLong const nReleased
 {
     ImplSVData* pSVData = ImplGetSVData();
 
+    SAL_INFO("vcl.schedule", "Enter ImplYield: " << (i_bWait ? "wait" : "no wait") <<
+             ": " << (i_bAllEvents ? "all events" : "one event") << ": " << nReleased);
+
     bool bHasActiveIdles = false;
     sal_uInt64 nMinTimeout = 0;
     if (nReleased == 0) // else thread doesn't have SolarMutex so avoid race
@@ -505,6 +508,9 @@ inline void ImplYield(bool i_bWait, bool i_bAllEvents, sal_uLong const nReleased
             i_bWait && !pSVData->maAppData.mbAppQuit,
             i_bAllEvents, nReleased);
 
+    SAL_INFO("vcl.schedule", "DoYield with " << (bHasActiveIdles ? "active idles" : "no ides") <<
+             " returns: " << (eResult == SalYieldResult::EVENT ? "processed event" : "timeout"));
+
     pSVData->maAppData.mnDispatchLevel--;
 
     DBG_TESTSOLARMUTEX(); // must be locked on return from Yield
@@ -515,6 +521,8 @@ inline void ImplYield(bool i_bWait, bool i_bAllEvents, sal_uLong const nReleased
     // flush lazy deleted objects
     if( pSVData->maAppData.mnDispatchLevel == 0 )
         vcl::LazyDelete::flush();
+
+    SAL_INFO("vcl.schedule", "Leave ImplYield");
 }
 
 void Application::Reschedule( bool i_bAllEvents )