[Libreoffice-commits] core.git: comphelper/source desktop/source include/comphelper toolkit/source

Tor Lillqvist (via logerrit) logerrit at kemper.freedesktop.org
Tue Apr 27 10:16:34 UTC 2021


 comphelper/source/misc/profilezone.cxx |   99 ++++++++++++++-------------------
 desktop/source/lib/init.cxx            |    4 -
 include/comphelper/profilezone.hxx     |   54 ++++++++++++------
 toolkit/source/awt/vclxtoolkit.cxx     |    6 +-
 4 files changed, 84 insertions(+), 79 deletions(-)

New commits:
commit 8c80d6f7196ab8cd63c42f6a57b458fdc47fc203
Author:     Tor Lillqvist <tml at collabora.com>
AuthorDate: Thu Apr 15 14:31:40 2021 +0300
Commit:     Tor Lillqvist <tml at collabora.com>
CommitDate: Tue Apr 27 12:15:48 2021 +0200

    Refactor ProfileZone and create Chrome Trace Event Format data
    
    Instead of separate B ("begin") and E ("end") duration events,
    generate X ("complete") events.
    
    Only the event JSON objects are generated, not the surrounding array
    or object.
    
    See
    https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview#heading=h.lc5airzennvk
    
    Online now needs work so that the events are written out to a separate
    file instead of being in the common log file.
    
    Change-Id: Ie9363b4cfda862a70e1928ed16350e50a6fee9a5
    Reviewed-on: https://gerrit.libreoffice.org/c/core/+/114142
    Tested-by: Tor Lillqvist <tml at collabora.com>
    Reviewed-by: Michael Meeks <michael.meeks at collabora.com>
    Reviewed-on: https://gerrit.libreoffice.org/c/core/+/114556
    Tested-by: Jenkins CollaboraOffice <jenkinscollaboraoffice at gmail.com>
    Reviewed-on: https://gerrit.libreoffice.org/c/core/+/114653
    Tested-by: Jenkins
    Reviewed-by: Tor Lillqvist <tml at collabora.com>

diff --git a/comphelper/source/misc/profilezone.cxx b/comphelper/source/misc/profilezone.cxx
index dc945c7f715d..3b80f69af38c 100644
--- a/comphelper/source/misc/profilezone.cxx
+++ b/comphelper/source/misc/profilezone.cxx
@@ -21,79 +21,68 @@
 namespace comphelper
 {
 
-std::atomic<bool> ProfileZone::g_bRecording(false);
+std::atomic<bool> ProfileZone::s_bRecording = false;
 
-namespace ProfileRecording
-{
-
-static std::vector<OUString> g_aRecording;    // recorded data
-static long long g_aSumTime(0);  // overall zone time in microsec
-static int g_aNesting;           // level of overlapped zones
-static long long g_aStartTime;                // start time of recording
-static ::osl::Mutex g_aMutex;
+int ProfileZone::s_nNesting = 0; // level of overlapped zones
 
-void startRecording()
+namespace
 {
-    TimeValue systemTime;
-    osl_getSystemTime( &systemTime );
-    ::osl::MutexGuard aGuard( g_aMutex );
-    g_aStartTime = static_cast<long long>(systemTime.Seconds) * 1000000 + systemTime.Nanosec/1000;
-    g_aNesting = 0;
-    ProfileZone::g_bRecording = true;
+    std::vector<OUString> g_aRecording; // recorded data
+    long long g_nSumTime(0);  // overall zone time in microsec
+    long long g_nStartTime;   // start time of recording
+    ::osl::Mutex g_aMutex;
 }
 
-void stopRecording()
+void ProfileZone::startRecording()
 {
-    ProfileZone::g_bRecording = false;
+    TimeValue aSystemTime;
+    osl_getSystemTime(&aSystemTime );
+    ::osl::MutexGuard aGuard(g_aMutex);
+    g_nStartTime = static_cast<long long>(aSystemTime.Seconds) * 1000000 + aSystemTime.Nanosec/1000;
+    s_nNesting = 0;
+    s_bRecording = true;
 }
 
-long long addRecording(const char * aProfileId, long long aCreateTime)
+void ProfileZone::stopRecording()
 {
-    assert( ProfileZone::g_bRecording );
-
-    TimeValue systemTime;
-    osl_getSystemTime( &systemTime );
-    long long aTime = static_cast<long long>(systemTime.Seconds) * 1000000 + systemTime.Nanosec/1000;
-
-    if (!aProfileId)
-        aProfileId = "(null)";
-    OUString aString(aProfileId, strlen(aProfileId), RTL_TEXTENCODING_UTF8);
-
-    OUString sRecordingData(OUString::number(osl_getThreadIdentifier(nullptr)) + " " +
-        OUString::number(aTime/1000000.0) + " " + aString + ": " +
-        (aCreateTime == 0 ? std::u16string_view(u"start") : std::u16string_view(u"stop")) +
-        (aCreateTime != 0 ? (" " + OUString::number((aTime - aCreateTime)/1000.0) + " ms") : OUString("")));
+    s_bRecording = false;
+}
 
-    ::osl::MutexGuard aGuard( g_aMutex );
+void ProfileZone::addRecording()
+{
+    assert(s_bRecording);
+
+    TimeValue aSystemTime;
+    osl_getSystemTime(&aSystemTime);
+    long long nNow = static_cast<long long>(aSystemTime.Seconds) * 1000000 + aSystemTime.Nanosec/1000;
+
+     // Generate a single "Complete Event" (type X)
+    OUString sRecordingData("{"
+                            "\"name\":\"" + OUString(m_sProfileId, strlen(m_sProfileId), RTL_TEXTENCODING_UTF8) + "\","
+                            "\"ph\":\"X\","
+                            "\"ts\":" + OUString::number(m_nCreateTime) + ","
+                            "\"dur\":" + OUString::number(nNow - m_nCreateTime) + ","
+                            "\"pid\":" + OUString::number(m_nPid) + ","
+                            "\"tid\":" + OUString::number(osl_getThreadIdentifier(nullptr)) +
+                            "}");
+    ::osl::MutexGuard aGuard(g_aMutex);
 
     g_aRecording.emplace_back(sRecordingData);
-    if (aCreateTime == 0)
-    {
-        g_aNesting++;
-        return aTime;
-    }
-    // neglect ProfileZones created before startRecording
-    else if (aCreateTime >= g_aStartTime)
-    {
-        if (g_aNesting > 0)
-            g_aNesting--;
-        if (g_aNesting == 0)
-            g_aSumTime += aTime - aCreateTime;
-    }
-    return 0;
+    if (s_nNesting == 0)
+        g_nSumTime += nNow - m_nCreateTime;
 }
 
-css::uno::Sequence<OUString> getRecordingAndClear()
+css::uno::Sequence<OUString> ProfileZone::getRecordingAndClear()
 {
     bool bRecording;
     std::vector<OUString> aRecording;
     {
         ::osl::MutexGuard aGuard( g_aMutex );
-        bRecording = ProfileZone::g_bRecording;
+        bRecording = s_bRecording;
         stopRecording();
         aRecording.swap(g_aRecording);
-        long long aSumTime = g_aSumTime;
-        aRecording.insert(aRecording.begin(), OUString::number(aSumTime/1000000.0));
+        long long nSumTime = g_nSumTime;
+        aRecording.insert(aRecording.begin(), OUString::number(nSumTime/1000000.0));
     }
     // reset start time and nesting level
     if (bRecording)
@@ -101,15 +90,13 @@ css::uno::Sequence<OUString> getRecordingAndClear()
     return ::comphelper::containerToSequence(aRecording);
 }
 
-} // namespace ProfileRecording
-
-void ProfileZone::startConsole() { m_aCreateTime = osl_getGlobalTimer(); }
+void ProfileZone::startConsole() { m_nCreateTime = osl_getGlobalTimer(); }
 
 void ProfileZone::stopConsole()
 {
     sal_uInt32 nEndTime = osl_getGlobalTimer();
     std::cerr << "comphelper::ProfileZone: " << m_sProfileId << " finished in "
-              << nEndTime - m_aCreateTime << " ms" << std::endl;
+              << nEndTime - m_nCreateTime << " ms" << std::endl;
 }
 
 } // namespace comphelper
diff --git a/desktop/source/lib/init.cxx b/desktop/source/lib/init.cxx
index d2a7b1351a35..23400d906628 100644
--- a/desktop/source/lib/init.cxx
+++ b/desktop/source/lib/init.cxx
@@ -6077,7 +6077,7 @@ public:
     virtual void Invoke() override
     {
         const css::uno::Sequence<OUString> aEvents =
-            comphelper::ProfileRecording::getRecordingAndClear();
+            comphelper::ProfileZone::getRecordingAndClear();
         OStringBuffer aOutput;
         for (const auto &s : aEvents)
         {
@@ -6159,7 +6159,7 @@ static int lo_initialize(LibreOfficeKit* pThis, const char* pAppPath, const char
     // Turn profile zones on early
     if (bProfileZones && eStage == SECOND_INIT)
     {
-        comphelper::ProfileRecording::startRecording();
+        comphelper::ProfileZone::startRecording();
         new ProfileZoneDumper();
     }
 
diff --git a/include/comphelper/profilezone.hxx b/include/comphelper/profilezone.hxx
index 0c0df2089c98..3988199cdf6b 100644
--- a/include/comphelper/profilezone.hxx
+++ b/include/comphelper/profilezone.hxx
@@ -14,6 +14,8 @@
 
 #include <atomic>
 
+#include <osl/process.h>
+#include <osl/time.h>
 #include <com/sun/star/uno/Sequence.h>
 #include <comphelper/comphelperdllapi.h>
 #include <rtl/ustring.hxx>
@@ -22,29 +24,21 @@
 
 namespace comphelper
 {
-namespace ProfileRecording
-{
-COMPHELPER_DLLPUBLIC void startRecording();
-COMPHELPER_DLLPUBLIC void stopRecording();
-
-COMPHELPER_DLLPUBLIC long long addRecording(const char* aProfileId, long long aCreateTime);
-
-COMPHELPER_DLLPUBLIC css::uno::Sequence<OUString> getRecordingAndClear();
-
-} // namespace ProfileRecording
-
 class COMPHELPER_DLLPUBLIC ProfileZone
 {
 private:
+    static std::atomic<bool> s_bRecording; // true during recording
+    static int s_nNesting;
     const char* m_sProfileId;
-    long long m_aCreateTime;
+    long long m_nCreateTime;
     bool m_bConsole;
     void startConsole();
     void stopConsole();
+    int m_nPid;
 
-public:
-    static std::atomic<bool> g_bRecording; // true during recording
+    void addRecording();
 
+public:
     /**
      * Starts measuring the cost of a C++ scope.
      *
@@ -61,10 +55,26 @@ public:
      * committing.
      */
     ProfileZone(const char* sProfileId, bool bConsole = false)
-        : m_sProfileId(sProfileId)
-        , m_aCreateTime(g_bRecording ? ProfileRecording::addRecording(sProfileId, 0) : 0)
+        : m_sProfileId(sProfileId ? sProfileId : "(null)")
         , m_bConsole(bConsole)
     {
+        if (s_bRecording)
+        {
+            TimeValue systemTime;
+            osl_getSystemTime(&systemTime);
+            m_nCreateTime
+                = static_cast<long long>(systemTime.Seconds) * 1000000 + systemTime.Nanosec / 1000;
+
+            oslProcessInfo aProcessInfo;
+            aProcessInfo.Size = sizeof(oslProcessInfo);
+            if (osl_getProcessInfo(nullptr, osl_Process_IDENTIFIER, &aProcessInfo)
+                == osl_Process_E_None)
+                m_nPid = aProcessInfo.Ident;
+
+            s_nNesting++;
+        }
+        else
+            m_nCreateTime = 0;
         if (m_bConsole)
         {
             startConsole();
@@ -72,13 +82,21 @@ public:
     }
     ~ProfileZone()
     {
-        if (g_bRecording)
-            ProfileRecording::addRecording(m_sProfileId, m_aCreateTime);
+        if (s_bRecording)
+        {
+            s_nNesting--;
+            addRecording();
+        }
         if (m_bConsole)
         {
             stopConsole();
         }
     }
+
+    static void startRecording();
+    static void stopRecording();
+
+    static css::uno::Sequence<OUString> getRecordingAndClear();
 };
 
 } // namespace comphelper
diff --git a/toolkit/source/awt/vclxtoolkit.cxx b/toolkit/source/awt/vclxtoolkit.cxx
index 18ae78f9f925..7d99f52287ab 100644
--- a/toolkit/source/awt/vclxtoolkit.cxx
+++ b/toolkit/source/awt/vclxtoolkit.cxx
@@ -2562,17 +2562,17 @@ void SAL_CALL VCLXToolkit::pause(sal_Int32 nMilliseconds)
 
 void SAL_CALL VCLXToolkit::startRecording()
 {
-    ::comphelper::ProfileRecording::startRecording();
+    comphelper::ProfileZone::startRecording();
 }
 
 void SAL_CALL VCLXToolkit::stopRecording()
 {
-    ::comphelper::ProfileRecording::stopRecording();
+    comphelper::ProfileZone::stopRecording();
 }
 
 css::uno::Sequence< OUString > VCLXToolkit::getRecordingAndClear()
 {
-    return ::comphelper::ProfileRecording::getRecordingAndClear();
+    return comphelper::ProfileZone::getRecordingAndClear();
 }
 
 // css:awt:XToolkitRobot


More information about the Libreoffice-commits mailing list