comphelper: add a profiling API

Using the guard style ProfileZone aZone("foo").

Test macro:

Sub TimeLog
toolkit = createUnoService("com.sun.star.awt.Toolkit")
toolkit.startRecording()
toolkit.processEventsToIdle()
toolkit.stopRecording()
a = toolkit.getRecordingAndClear()
s = ""
For Each i in a
s = s + i + ", "
Next i
Print s
End Sub

Change-Id: Iceaf9143d0387c87e7936dc67eecbbf71ee8d74a
Reviewed-on: https://gerrit.libreoffice.org/38786
Reviewed-by: Miklos Vajna <vmiklos@collabora.co.uk>
Reviewed-by: Noel Grandin <noel.grandin@collabora.co.uk>
Tested-by: Jenkins <ci@libreoffice.org>

2 files changed, 106 insertions, 0 deletions

diff --git a/comphelper/Library_comphelper.mk b/comphelper/Library_comphelper.mk
index 03c8a61b5a47..9d2b6c5961f4 100644
--- a/comphelper/Library_comphelper.mk
+++ b/comphelper/Library_comphelper.mk
@@ -117,6 +117,7 @@ $(eval $(call gb_Library_add_exception_objects,comphelper,\
     comphelper/source/misc/numbers \
     comphelper/source/misc/officeresourcebundle \
     comphelper/source/misc/officerestartmanager \
+    comphelper/source/misc/profilezone \
     comphelper/source/misc/proxyaggregation \
     comphelper/source/misc/random \
     comphelper/source/misc/scopeguard \
diff --git a/comphelper/source/misc/profilezone.cxx b/comphelper/source/misc/profilezone.cxx
new file mode 100644
index 000000000000..e9e9caafca24
--- /dev/null
+++ b/comphelper/source/misc/profilezone.cxx
@@ -0,0 +1,105 @@
+/* -*- Mode: C; tab-width: 4; indent-tabs-mode: nil; c-basic-offset: 4 -*- */
+/*
+ * This file is part of the LibreOffice project.
+ *
+ * This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at http://mozilla.org/MPL/2.0/.
+ */
+
+#include <comphelper/sequence.hxx>
+#include <comphelper/profilezone.hxx>
+#include <osl/time.h>
+#include <osl/thread.h>
+
+namespace comphelper
+{
+
+namespace ProfileRecording
+{
+
+static bool g_bRecording(false);              // true during recording
+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;
+
+void startRecording(bool bStartRecording)
+{
+    ::osl::MutexGuard aGuard( g_aMutex );
+    if (bStartRecording)
+    {
+        TimeValue systemTime;
+        osl_getSystemTime( &systemTime );
+        g_aStartTime = (long long) systemTime.Seconds * 1000000 + systemTime.Nanosec/1000;
+        g_aNesting = 0;
+    }
+    g_bRecording = bStartRecording;
+}
+
+long long addRecording(const char * aProfileId, long long aCreateTime)
+{
+    ::osl::MutexGuard aGuard( g_aMutex );
+    if ( g_bRecording )
+    {
+        TimeValue systemTime;
+        osl_getSystemTime( &systemTime );
+        long long aTime = (long long) systemTime.Seconds * 1000000 + systemTime.Nanosec/1000;
+        OUString aString(aProfileId, strlen(aProfileId), RTL_TEXTENCODING_UTF8);
+        g_aRecording.push_back(
+            OUString::number(osl_getThreadIdentifier(nullptr)) + " " +
+            OUString::number(aTime/1000000.0) + " " + aString + ": " +
+            (aCreateTime == 0 ? OUString("start") : OUString("stop"))
+        );
+        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;
+}
+
+css::uno::Sequence<OUString> getRecordingAndClear()
+{
+    bool bRecording;
+    std::vector<OUString> aRecording;
+    {
+        ::osl::MutexGuard aGuard( g_aMutex );
+        bRecording = g_bRecording;
+        startRecording(false);
+        aRecording.swap(g_aRecording);
+        long long aSumTime = g_aSumTime;
+        aRecording.insert(aRecording.begin(), OUString::number(aSumTime/1000000.0));
+    }
+    // reset start time and nesting level
+    startRecording(bRecording);
+    return ::comphelper::containerToSequence(aRecording);
+}
+
+} // namespace ProfileRecording
+
+
+ProfileZone::ProfileZone(const char * sProfileId) :
+    m_sProfileId(sProfileId)
+{
+    m_aCreateTime = ProfileRecording::addRecording(sProfileId, 0);
+}
+
+ProfileZone::~ProfileZone()
+{
+    ProfileRecording::addRecording(m_sProfileId, m_aCreateTime);
+}
+
+} // namespace comphelper
+
+/* vim:set shiftwidth=4 softtabstop=4 expandtab: */