refs #358, more detailed time measurement in runtime class

src/blackcore/context_runtime.cpp

@@ -19,8 +19,11 @@
 #include "blackmisc/logmessage.h"
 #include "blackcore/context_runtime.h"
 
+#include <QMap>
 #include <QDebug>
 
+using namespace BlackMisc;
+
 namespace BlackCore
 {
     /*
@@ -36,23 +39,25 @@ namespace BlackCore
      */
     void CRuntime::init(const CRuntimeConfig &config)
     {
-        if (m_init) return;
+        if (m_init) { return; }
-        BlackMisc::registerMetadata();
-        BlackMisc::initResources();
-        BlackSim::registerMetadata();
-        BlackCore::registerMetadata();
 
-        this->connect(QCoreApplication::instance(), &QCoreApplication::aboutToQuit, this, &CRuntime::gracefulShutdown);
-
-        // upfront reading of settings, as DBus server already relies on settings
-        QString dbusAddress;
         QMap<QString, int> times;
         QTime time;
         time.start();
 
+        BlackMisc::registerMetadata();
+        BlackMisc::initResources();
+        BlackSim::registerMetadata();
+        BlackCore::registerMetadata();
+        times.insert("Register metadata", time.restart());
+        this->connect(QCoreApplication::instance(), &QCoreApplication::aboutToQuit, this, &CRuntime::gracefulShutdown);
+
+        // upfront reading of settings, as DBus server already relies on settings
+        QString dbusAddress;
+
         // FIXME RW: We are allocating a full settings context in order to get the DBus address.
         // I wonder if this can be done cleaner.
-        if (config.hasDBusAddress()) dbusAddress = config.getDBusAddress(); // bootstrap / explicit
+        if (config.hasDBusAddress()) { dbusAddress = config.getDBusAddress(); } // bootstrap / explicit
         if (config.hasLocalSettings())
         {
             auto *settings = new CContextSettings(config.getModeSettings(), this);
@@ -73,7 +78,7 @@ namespace BlackCore
                 QString e = this->m_dbusConnection.lastError().message();
                 if (!e.isEmpty()) notConnected.append(" ").append(e);
                 Q_ASSERT_X(false, "CRuntime::init", notConnected.toUtf8().constData());
-                qCritical() << notConnected;
+                CLogMessage(this).error(notConnected);
             }
         }
         times.insert("DBus", time.restart());
@@ -105,8 +110,10 @@ namespace BlackCore
         Q_ASSERT(!this->m_contextNetwork || (this->m_contextOwnAircraft->isUsingImplementingObject() == this->m_contextNetwork->isUsingImplementingObject()));
 
         // post inits, wiring things among context (e.g. signal slots)
-        this->initPostSetup();
+        time.restart();
-        qDebug() << "Init times:" << times;
+        this->initPostSetup(times);
+        times.insert("Post setup", time.restart());
+        CLogMessage(this).info("Init times: %1") << qmapToString(times);
 
         // flag
         m_init = true;
@@ -142,10 +149,12 @@ namespace BlackCore
         this->m_dbusServer = new CDBusServer(dBusAddress, this);
     }
 
-    void CRuntime::initPostSetup()
+    void CRuntime::initPostSetup(QMap<QString, int> &times)
     {
         bool c = false;
         Q_UNUSED(c); // for release version
+        QTime time;
+        time.start();
 
         if (this->m_contextSettings && this->m_contextApplication)
         {
@@ -153,6 +162,7 @@ namespace BlackCore
                         this->getIContextApplication(), &IContextApplication::changeSettings);
             Q_ASSERT(c);
         }
+        times.insert("Post setup, connects first", time.restart());
 
         // local simulator?
         if (this->m_contextSimulator && this->m_contextSimulator->isUsingImplementingObject())
@@ -172,6 +182,7 @@ namespace BlackCore
                             this->getCContextSimulator(), &CContextSimulator::ps_updateSimulatorCockpitFromContext);
                 Q_ASSERT(c);
             }
+            times.insert("Post setup, sim.connects", time.restart());
 
             // connect local simulator and settings and load plugin
             if (this->m_contextSettings)
@@ -181,10 +192,12 @@ namespace BlackCore
                 {
                     CLogMessage(this).warning("No simulator plugin loaded");
                 }
+                times.insert("Post setup, load sim. plugin", time.restart());
             }
         }
 
         // only where network and(!) own aircraft run locally
+        // -> in the core or an all local implementation
         if (this->m_contextNetwork && this->m_contextOwnAircraft && this->m_contextNetwork->isUsingImplementingObject() && this->m_contextOwnAircraft->isUsingImplementingObject())
         {
             c = this->connect(this->m_contextNetwork, &IContextNetwork::changedAtcStationOnlineConnectionStatus,
@@ -195,6 +208,7 @@ namespace BlackCore
             c = this->connect(this->m_contextOwnAircraft, &IContextOwnAircraft::changedAircraft,
                               this->getCContextNetwork(),  &CContextNetwork::ps_changedOwnAircraft);
             Q_ASSERT(c);
+            times.insert("Post setup, connects network", time.restart());
         }
     }
 

src/blackmisc/blackmiscfreefunctions.cpp

@@ -248,6 +248,26 @@ QVariant BlackMisc::complexQtTypeFromDbusArgument(const QDBusArgument &argument,
     return QVariant(); // suppress compiler warning
 }
 
+template<class K, class V> QString BlackMisc::qmapToString(const QMap<K, V> &map)
+{
+    QString s;
+    const QString kv("%1: %2 ");
+    QMapIterator<K, V> i(map);
+    while (i.hasNext())
+    {
+        i.next();
+        s.append(
+            kv.arg(i.key()).arg(i.value())
+        );
+    }
+    return s.trimmed();
+}
+
+// forward declare: http://www.parashift.com/c++-faq-lite/separate-template-fn-defn-from-decl.html
+template QString BlackMisc::qmapToString<QString, int>(const QMap<QString, int> &);
+template QString BlackMisc::qmapToString<QString, QString>(const QMap<QString, QString> &);
+template QString BlackMisc::qmapToString<QString, double>(const QMap<QString, double> &);
+
 #ifdef Q_CC_MSVC
 #include <crtdbg.h>
 

src/blackmisc/blackmiscfreefunctions.h

@@ -14,6 +14,7 @@
 
 #include <QDir> // for Q_INIT_RESOURCE
 #include <QList>
+#include <QMap>
 #include <QVariant>
 #include <QDBusArgument>
 
@@ -152,6 +153,9 @@ namespace BlackMisc
     //! Real heap size of an object
     size_t heapSizeOf(const QMetaObject &objectType);
 
+    //! A map converted to string
+    template<class K, class V> QString qmapToString(const QMap<K, V> &map);
+
     //! Get local host name
     const QString &localHostName();