From 76f61468e69020bb42f8b726e78635ec4d4b8a57 Mon Sep 17 00:00:00 2001 From: jan Iversen Date: Mon, 28 May 2018 16:25:39 +0200 Subject: [PATCH] mobile: add timer to measure startup. Subsurface-mobile has a long startup time; in order to isolate the problem(s) a timer is added to see where time is "lost". The collected startup times are added to the clipboard together with the other logs, allowing test users to report back. All this is only enabled when compiling with -DENABLE_STARTUP_TIMING Closes #1340 [Dirk Hohndel: collapsed multiple commits and minor white space cleanups, added missing QMutex variable] Signed-off-by: Jan Iversen Signed-off-by: Dirk Hohndel --- core/ssrf.h | 15 +++++++++++++ mobile-widgets/qmlmanager.cpp | 10 +++++++++ subsurface-mobile-helper.cpp | 11 ++++++++++ subsurface-mobile-main.cpp | 41 +++++++++++++++++++++++++++++++++++ 4 files changed, 77 insertions(+) diff --git a/core/ssrf.h b/core/ssrf.h index 7f65f2dc5..20dc569a4 100644 --- a/core/ssrf.h +++ b/core/ssrf.h @@ -12,6 +12,21 @@ extern "C" { #endif #ifdef __cplusplus + +#ifdef SUBSURFACE_MOBILE +#ifdef ENABLE_STARTUP_TIMING +// Declare generic function, will be seen only in CPP code +// Use void parameters to avoid extra includes +extern void log_stp(const char *ident, QString *buf); + +#define LOG_STP(x) log_stp(x, NULL) +#define LOG_STP_CLIPBOARD(x) log_stp(NULL, x) +#else +#define LOG_STP(x) +#define LOG_STP_CLIPBOARD(x) +#endif // ENABLE_STARTUP_TIMING +#endif // SUBSURFACE_MOBILE + } #else diff --git a/mobile-widgets/qmlmanager.cpp b/mobile-widgets/qmlmanager.cpp index 4a15f26e0..33376656b 100644 --- a/mobile-widgets/qmlmanager.cpp +++ b/mobile-widgets/qmlmanager.cpp @@ -32,6 +32,8 @@ #include "qt-models/tankinfomodel.h" #include "core/downloadfromdcthread.h" +#include "core/ssrf.h" + QMLManager *QMLManager::m_instance = NULL; #define RED_FONT QLatin1Literal("") @@ -138,6 +140,7 @@ QMLManager::QMLManager() : m_locationServiceEnabled(false), alreadySaving(false), m_device_data(new DCDeviceData(this)) { + LOG_STP("qmlmgr starting"); m_instance = this; m_lastDevicePixelRatio = qApp->devicePixelRatio(); timer.start(); @@ -164,6 +167,7 @@ QMLManager::QMLManager() : m_locationServiceEnabled(false), + " at " + QDateTime::currentDateTime().toString()); } #endif + LOG_STP("qmlmgr log started"); set_error_cb(&showErrorFromC); appendTextToLog("Starting " + getUserAgent()); appendTextToLog(QStringLiteral("built with libdivecomputer v%1").arg(dc_version(NULL))); @@ -172,11 +176,13 @@ QMLManager::QMLManager() : m_locationServiceEnabled(false), git_libgit2_version(&git_maj, &git_min, &git_rev); appendTextToLog(QStringLiteral("built with libgit2 %1.%2.%3").arg(git_maj).arg(git_min).arg(git_rev)); setStartPageText(tr("Starting...")); + LOG_STP("qmlmgr start page"); // ensure that we start the BTDiscovery - this should be triggered by the export of the class // to QML, but that doesn't seem to always work BTDiscovery *btDiscovery = BTDiscovery::instance(); m_btEnabled = btDiscovery->btAvailable(); + LOG_STP("qmlmgr bt available"); connect(&btDiscovery->localBtDevice, &QBluetoothLocalDevice::hostModeStateChanged, this, &QMLManager::btHostModeChange); setShowPin(false); @@ -185,10 +191,13 @@ QMLManager::QMLManager() : m_locationServiceEnabled(false), progress_callback = &progressCallback; connect(locationProvider, SIGNAL(haveSourceChanged()), this, SLOT(hasLocationSourceChanged())); setLocationServiceAvailable(locationProvider->hasLocationsSource()); + LOG_STP("qmlmgr gps started"); set_git_update_cb(&gitProgressCB); + LOG_STP("qmlmgr git update"); // make sure we know if the current cloud repo has been successfully synced syncLoadFromCloud(); + LOG_STP("qmlmgr sync load cloud"); } void QMLManager::applicationStateChanged(Qt::ApplicationState state) @@ -352,6 +361,7 @@ void QMLManager::copyAppLogToClipboard() QTextStream in(&f); copyString += in.readAll(); } + LOG_STP_CLIPBOARD(©String); copyString += "---------- finish ----------\n"; // and copy to clipboard diff --git a/subsurface-mobile-helper.cpp b/subsurface-mobile-helper.cpp index 38b6be9f4..5fe83acd9 100644 --- a/subsurface-mobile-helper.cpp +++ b/subsurface-mobile-helper.cpp @@ -29,6 +29,8 @@ #include "mobile-widgets/qml/kirigami/src/kirigamiplugin.h" +#include "core/ssrf.h" + QObject *qqWindowObject = NULL; void set_non_bt_addresses() { @@ -51,6 +53,7 @@ void init_ui() void run_ui() { + LOG_STP("run_ui starting"); qmlRegisterType("org.subsurfacedivelog.mobile", 1, 0, "QMLManager"); qmlRegisterType("org.subsurfacedivelog.mobile", 1, 0, "QMLProfile"); @@ -63,6 +66,7 @@ void run_ui() qmlRegisterType("org.subsurfacedivelog.mobile", 1, 0, "MapLocation"); QQmlApplicationEngine engine; + LOG_STP("run_ui qml engine started"); KirigamiPlugin::getInstance().registerTypes(); #if defined(__APPLE__) && !defined(Q_OS_IOS) // when running the QML UI on a Mac the deployment of the QML Components seems @@ -79,11 +83,13 @@ void run_ui() #endif engine.addImportPath("qrc://imports"); DiveListModel diveListModel; + LOG_STP("run_ui diveListModel started"); DiveListSortModel *sortModel = new DiveListSortModel(0); sortModel->setSourceModel(&diveListModel); sortModel->setDynamicSortFilter(true); sortModel->setSortRole(DiveListModel::DiveDateRole); sortModel->sort(0, Qt::DescendingOrder); + LOG_STP("run_ui diveListModel sorted"); GpsListModel gpsListModel; QSortFilterProxyModel *gpsSortModel = new QSortFilterProxyModel(0); gpsSortModel->setSourceModel(&gpsListModel); @@ -95,11 +101,13 @@ void run_ui() ctxt->setContextProperty("gpsModel", gpsSortModel); ctxt->setContextProperty("vendorList", vendorList); set_non_bt_addresses(); + LOG_STP("run_ui set_non_bt_adresses"); ctxt->setContextProperty("connectionListModel", &connectionListModel); ctxt->setContextProperty("logModel", MessageHandlerModel::self()); engine.load(QUrl(QStringLiteral("qrc:///qml/main.qml"))); + LOG_STP("run_ui qml loaded"); qqWindowObject = engine.rootObjects().value(0); if (!qqWindowObject) { fprintf(stderr, "can't create window object\n"); @@ -112,8 +120,10 @@ void run_ui() QScreen *screen = qml_window->screen(); QObject::connect(qml_window, &QQuickWindow::screenChanged, QMLManager::instance(), &QMLManager::screenChanged); QMLManager *manager = QMLManager::instance(); + LOG_STP("run_ui qmlmanager instance started"); // now that the log file is initialized... show_computer_list(); + LOG_STP("run_ui show_computer_list"); manager->setDevicePixelRatio(qml_window->devicePixelRatio(), qml_window->screen()); manager->dlSortModel = sortModel; @@ -124,6 +134,7 @@ void run_ui() qml_window->setWidth(800); #endif qml_window->show(); + LOG_STP("run_ui running exec"); qApp->exec(); } diff --git a/subsurface-mobile-main.cpp b/subsurface-mobile-main.cpp index 878dc59ea..131e1d493 100644 --- a/subsurface-mobile-main.cpp +++ b/subsurface-mobile-main.cpp @@ -19,14 +19,50 @@ #include #include +// Implementation of STP logging +#include "core/ssrf.h" +#ifdef ENABLE_STARTUP_TIMING +#include +#include +#include +void log_stp(const char *ident, QString *buf) +{ + static bool firstCall = true; + static QElapsedTimer stpDuration; + static QString stpText; + static QMutex logMutex; + + QMutexLocker l(&logMutex); + + if (firstCall) { + firstCall = false; + stpDuration.start(); + } + if (ident) + stpText += QString("STP ") \ + .append(QString::number(stpDuration.elapsed())) \ + .append(" ms, ") \ + .append(ident) \ + .append("\n"); + if (buf) { + *buf += "---------- startup timer ----------\n"; + *buf += stpText; + } +} +#endif // ENABLE_STARTUP_TIMING + + int main(int argc, char **argv) { + LOG_STP("main starting"); + int i; QGuiApplication::setAttribute(Qt::AA_EnableHighDpiScaling); QLoggingCategory::setFilterRules(QStringLiteral("qt.bluetooth* = true")); // Start application new QApplication(argc, argv); + LOG_STP("main Qt started"); // and get comand line arguments QStringList arguments = QCoreApplication::arguments(); @@ -41,6 +77,7 @@ int main(int argc, char **argv) } } git_libgit2_init(); + LOG_STP("main git loaded"); setup_system_prefs(); if (QLocale().measurementSystem() == QLocale::MetricSystem) default_prefs.units = SI_units; @@ -51,8 +88,11 @@ int main(int argc, char **argv) fill_computer_list(); parse_xml_init(); + LOG_STP("main xml parsed"); taglist_init_global(); + LOG_STP("main taglist done"); init_ui(); + LOG_STP("main init_ui done"); if (prefs.default_file_behavior == LOCAL_DEFAULT_FILE) set_filename(prefs.default_filename); else @@ -66,6 +106,7 @@ int main(int argc, char **argv) init_proxy(); + LOG_STP("main call run_ui (continue in qmlmanager)"); if (!quit) run_ui(); exit_ui();