vcl: improve scheduler debugging information.

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

drawinglayer/source/primitive2d/textlayoutdevice.cxx

@@ -73,7 +73,8 @@ namespace
     };
 
     ImpTimedRefDev::ImpTimedRefDev(scoped_timed_RefDev& rOwnerOfMe)
-    :   mrOwnerOfMe(rOwnerOfMe),
+    :   Timer( "Timer to destroy drawinglayer reference device" ),
+        mrOwnerOfMe(rOwnerOfMe),
         mpVirDev(nullptr),
         mnUseCount(0L)
     {

framework/source/services/autorecovery.cxx

@@ -1257,6 +1257,7 @@ AutoRecovery::AutoRecovery(const css::uno::Reference< css::uno::XComponentContex
     , m_bListenForConfigChanges (false                                          )
     , m_nAutoSaveTimeIntervall  (0                                                  )
     , m_eJob                    (AutoRecovery::E_NO_JOB                             )
+    , m_aTimer                  ( "Auto save timer" )
     , m_aAsyncDispatcher        ( LINK( this, AutoRecovery, implts_asyncDispatch )  )
     , m_eTimerType              (E_DONT_START_TIMER                                 )
     , m_nIdPool                 (0                                                  )

include/sal/log-areas.dox

@@ -432,6 +432,7 @@ certain functionality.
 @li @c vcl.osx.print
 @li @c vcl.quartz
 @li @c vcl.screensaverinhibitor
+@li @c vcl.schedule - scheduler / main-loop information
 @li @c vcl.scrollbar - Scroll Bars
 @li @c vcl.sm - Session Manager
 @li @c vcl.unity

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;

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 )