diff options
author | Christian Kandeler <christian.kandeler@qt.io> | 2016-10-05 13:29:00 +0200 |
---|---|---|
committer | Christian Kandeler <christian.kandeler@qt.io> | 2016-10-10 08:28:53 +0000 |
commit | b2b9d77f5cdfbb5ed19554e2d424b5be75ef8e73 (patch) | |
tree | 78590fea5630b3e2393666c961ed95b1f2f9ec3b /src | |
parent | f2648d82ee1ff9e42bf3a41e10fccc10acbe80d5 (diff) |
Time more operations
Change-Id: I1aa46693cb71fe284083ee5305ce2650de1307ac
Reviewed-by: Jake Petroules <jake.petroules@qt.io>
Diffstat (limited to 'src')
-rw-r--r-- | src/lib/corelib/api/internaljobs.cpp | 1 | ||||
-rw-r--r-- | src/lib/corelib/buildgraph/buildgraphloader.cpp | 1 | ||||
-rw-r--r-- | src/lib/corelib/buildgraph/executor.cpp | 21 | ||||
-rw-r--r-- | src/lib/corelib/buildgraph/executor.h | 3 | ||||
-rw-r--r-- | src/lib/corelib/corelib.qbs | 2 | ||||
-rw-r--r-- | src/lib/corelib/language/itemreader.cpp | 8 | ||||
-rw-r--r-- | src/lib/corelib/language/itemreader.h | 4 | ||||
-rw-r--r-- | src/lib/corelib/language/loader.cpp | 1 | ||||
-rw-r--r-- | src/lib/corelib/language/moduleloader.cpp | 17 | ||||
-rw-r--r-- | src/lib/corelib/language/moduleloader.h | 2 | ||||
-rw-r--r-- | src/lib/corelib/language/projectresolver.cpp | 35 | ||||
-rw-r--r-- | src/lib/corelib/language/projectresolver.h | 12 | ||||
-rw-r--r-- | src/lib/corelib/language/scriptengine.cpp | 12 | ||||
-rw-r--r-- | src/lib/corelib/language/scriptengine.h | 3 | ||||
-rw-r--r-- | src/lib/corelib/logging/logger.cpp | 52 | ||||
-rw-r--r-- | src/lib/corelib/logging/logger.h | 13 | ||||
-rw-r--r-- | src/lib/corelib/tools/profiling.cpp | 126 | ||||
-rw-r--r-- | src/lib/corelib/tools/profiling.h | 82 | ||||
-rw-r--r-- | src/lib/corelib/tools/tools.pri | 2 |
19 files changed, 323 insertions, 74 deletions
diff --git a/src/lib/corelib/api/internaljobs.cpp b/src/lib/corelib/api/internaljobs.cpp index 8b0f5a5c7..339a7fa0f 100644 --- a/src/lib/corelib/api/internaljobs.cpp +++ b/src/lib/corelib/api/internaljobs.cpp @@ -54,6 +54,7 @@ #include <logging/translator.h> #include <tools/buildgraphlocker.h> #include <tools/error.h> +#include <tools/profiling.h> #include <tools/progressobserver.h> #include <tools/preferences.h> #include <tools/qbsassert.h> diff --git a/src/lib/corelib/buildgraph/buildgraphloader.cpp b/src/lib/corelib/buildgraph/buildgraphloader.cpp index 5a4c3d226..a0b769775 100644 --- a/src/lib/corelib/buildgraph/buildgraphloader.cpp +++ b/src/lib/corelib/buildgraph/buildgraphloader.cpp @@ -57,6 +57,7 @@ #include <logging/translator.h> #include <tools/fileinfo.h> #include <tools/persistence.h> +#include <tools/profiling.h> #include <tools/propertyfinder.h> #include <tools/qbsassert.h> diff --git a/src/lib/corelib/buildgraph/executor.cpp b/src/lib/corelib/buildgraph/executor.cpp index cca64efd0..42b96eee6 100644 --- a/src/lib/corelib/buildgraph/executor.cpp +++ b/src/lib/corelib/buildgraph/executor.cpp @@ -58,6 +58,7 @@ #include <logging/translator.h> #include <tools/error.h> #include <tools/fileinfo.h> +#include <tools/profiling.h> #include <tools/progressobserver.h> #include <tools/qbsassert.h> @@ -227,6 +228,9 @@ void Executor::doBuild() = RulesEvaluationContextPtr(new RulesEvaluationContext(m_logger)); m_evalContext = m_project->buildData->evaluationContext; + m_elapsedTimeRules = m_elapsedTimeScanners = m_elapsedTimeInstalling = 0; + m_evalContext->engine()->enableProfiling(m_buildOptions.logElapsedTime()); + InstallOptions installOptions; installOptions.setDryRun(m_buildOptions.dryRun()); installOptions.setInstallRoot(m_productsToBuild.first()->moduleProperties @@ -443,6 +447,8 @@ void Executor::buildArtifact(Artifact *artifact) void Executor::executeRuleNode(RuleNode *ruleNode) { + AccumulatingTimer rulesTimer(m_buildOptions.logElapsedTime() ? &m_elapsedTimeRules : nullptr); + if (!checkNodeProduct(ruleNode)) return; @@ -880,7 +886,10 @@ void Executor::potentiallyRunTransformer(const TransformerPtr &transformer) // Scan all input artifacts. If new dependencies were found during scanning, delay // execution of this transformer. InputArtifactScanner scanner(output, m_inputArtifactScanContext, m_logger); + AccumulatingTimer scanTimer(m_buildOptions.logElapsedTime() + ? &m_elapsedTimeScanners : nullptr); scanner.scan(); + scanTimer.stop(); if (scanner.newDependencyAdded() && checkForUnbuiltDependencies(output)) return; } @@ -926,6 +935,9 @@ void Executor::finishTransformer(const TransformerPtr &transformer) void Executor::possiblyInstallArtifact(const Artifact *artifact) { + AccumulatingTimer installTimer(m_buildOptions.logElapsedTime() + ? &m_elapsedTimeInstalling : nullptr); + if (m_buildOptions.install() && !m_buildOptions.executeRulesOnly() && (m_activeFileTags.isEmpty() || artifactHasMatchingOutputTags(artifact)) && artifact->properties->qbsPropertyValue(QLatin1String("install")).toBool()) { @@ -1034,6 +1046,15 @@ void Executor::finish() EmptyDirectoriesRemover(m_project.data(), m_logger) .removeEmptyParentDirectories(m_artifactsRemovedFromDisk); + if (m_buildOptions.logElapsedTime()) { + m_logger.qbsLog(LoggerInfo, true) << "\t" << Tr::tr("Rule execution took %1.") + .arg(elapsedTimeString(m_elapsedTimeRules)); + m_logger.qbsLog(LoggerInfo, true) << "\t" << Tr::tr("Artifact scanning took %1.") + .arg(elapsedTimeString(m_elapsedTimeScanners)); + m_logger.qbsLog(LoggerInfo, true) << "\t" << Tr::tr("Installing artifacts took %1.") + .arg(elapsedTimeString(m_elapsedTimeInstalling)); + } + emit finished(); } diff --git a/src/lib/corelib/buildgraph/executor.h b/src/lib/corelib/buildgraph/executor.h index 8aecfdd85..1f6bfc7de 100644 --- a/src/lib/corelib/buildgraph/executor.h +++ b/src/lib/corelib/buildgraph/executor.h @@ -172,6 +172,9 @@ private: QTimer * const m_cancelationTimer; QStringList m_artifactsRemovedFromDisk; bool m_partialBuild; + qint64 m_elapsedTimeRules; + qint64 m_elapsedTimeScanners; + qint64 m_elapsedTimeInstalling; const bool m_doTrace; const bool m_doDebug; }; diff --git a/src/lib/corelib/corelib.qbs b/src/lib/corelib/corelib.qbs index e12a37a45..024b0ed8b 100644 --- a/src/lib/corelib/corelib.qbs +++ b/src/lib/corelib/corelib.qbs @@ -370,6 +370,8 @@ QbsLibrary { "processutils.cpp", "processutils.h", "profile.cpp", + "profiling.cpp", + "profiling.h", "progressobserver.cpp", "progressobserver.h", "projectgeneratormanager.cpp", diff --git a/src/lib/corelib/language/itemreader.cpp b/src/lib/corelib/language/itemreader.cpp index 6386aaebc..4f6a315b2 100644 --- a/src/lib/corelib/language/itemreader.cpp +++ b/src/lib/corelib/language/itemreader.cpp @@ -41,6 +41,8 @@ #include "itemreadervisitorstate.h" +#include <tools/profiling.h> + namespace qbs { namespace Internal { @@ -84,6 +86,7 @@ QStringList ItemReader::searchPaths() const Item *ItemReader::readFile(const QString &filePath) { + AccumulatingTimer readFileTimer(m_elapsedTime != -1 ? &m_elapsedTime : nullptr); return m_visitorState->readFile(filePath, searchPaths(), m_pool); } @@ -92,5 +95,10 @@ QSet<QString> ItemReader::filesRead() const return m_visitorState->filesRead(); } +void ItemReader::setEnableTiming(bool on) +{ + m_elapsedTime = on ? 0 : -1; +} + } // namespace Internal } // namespace qbs diff --git a/src/lib/corelib/language/itemreader.h b/src/lib/corelib/language/itemreader.h index 091aa6734..20cfc0e1e 100644 --- a/src/lib/corelib/language/itemreader.h +++ b/src/lib/corelib/language/itemreader.h @@ -82,11 +82,15 @@ public: QSet<QString> filesRead() const; + void setEnableTiming(bool on); + qint64 elapsedTime() const { return m_elapsedTime; } + private: ItemPool *m_pool = nullptr; QStringList m_searchPaths; QStack<QStringList> m_extraSearchPaths; ItemReaderVisitorState * const m_visitorState; + qint64 m_elapsedTime = -1; }; } // namespace Internal diff --git a/src/lib/corelib/language/loader.cpp b/src/lib/corelib/language/loader.cpp index 29eff18a1..bec581a27 100644 --- a/src/lib/corelib/language/loader.cpp +++ b/src/lib/corelib/language/loader.cpp @@ -98,6 +98,7 @@ TopLevelProjectPtr Loader::loadProject(const SetupProjectParameters ¶meters) m_engine->clearExceptions(); m_engine->clearImportsCache(); m_engine->clearRequestedProperties(); + m_engine->enableProfiling(parameters.logElapsedTime()); m_logger.clearWarnings(); QTimer cancelationTimer; diff --git a/src/lib/corelib/language/moduleloader.cpp b/src/lib/corelib/language/moduleloader.cpp index e29314002..3a4611ba1 100644 --- a/src/lib/corelib/language/moduleloader.cpp +++ b/src/lib/corelib/language/moduleloader.cpp @@ -58,6 +58,7 @@ #include <tools/fileinfo.h> #include <tools/preferences.h> #include <tools/profile.h> +#include <tools/profiling.h> #include <tools/progressobserver.h> #include <tools/qbsassert.h> #include <tools/scripttools.h> @@ -231,6 +232,8 @@ ModuleLoaderResult ModuleLoader::load(const SetupProjectParameters ¶meters) m_modulePrototypeItemCache.clear(); m_disabledItems.clear(); m_reader->clearExtraSearchPathsStack(); + m_reader->setEnableTiming(parameters.logElapsedTime()); + m_elapsedTimeProbes = 0; ModuleLoaderResult result; m_pool = result.itemPool.data(); @@ -260,6 +263,7 @@ ModuleLoaderResult ModuleLoader::load(const SetupProjectParameters ¶meters) QSet<QString>() << QDir::cleanPath(parameters.projectFilePath())); result.root = root; result.qbsFiles = m_reader->filesRead(); + printProfilingInfo(); return result; } @@ -975,6 +979,18 @@ ProbeConstPtr ModuleLoader::findCurrentProbe(const CodeLocation &location, bool return ProbeConstPtr(); } +void ModuleLoader::printProfilingInfo() +{ + if (!m_parameters.logElapsedTime()) + return; + m_logger.qbsLog(LoggerInfo, true) << "\t" + << Tr::tr("Project file loading and parsing took %1.") + .arg(elapsedTimeString(m_reader->elapsedTime())); + m_logger.qbsLog(LoggerInfo, true) << "\t" + << Tr::tr("Running Probes took %1.") + .arg(elapsedTimeString(m_elapsedTimeProbes)); +} + void ModuleLoader::mergeExportItems(const ProductContext &productContext) { QVector<Item *> exportItems; @@ -1812,6 +1828,7 @@ void ModuleLoader::createChildInstances(ProductContext *productContext, Item *in void ModuleLoader::resolveProbes(ProductContext *productContext, Item *item) { + AccumulatingTimer probesTimer(m_parameters.logElapsedTime() ? &m_elapsedTimeProbes : nullptr); foreach (Item *child, item->children()) if (child->type() == ItemType::Probe) resolveProbe(productContext, item, child); diff --git a/src/lib/corelib/language/moduleloader.h b/src/lib/corelib/language/moduleloader.h index 8f576786d..04b93dd3e 100644 --- a/src/lib/corelib/language/moduleloader.h +++ b/src/lib/corelib/language/moduleloader.h @@ -261,6 +261,7 @@ private: const QString &sourceCode) const; ProbeConstPtr findCurrentProbe(const CodeLocation &location, bool condition, const QVariantMap &initialProperties) const; + void printProfilingInfo(); ScriptEngine *m_engine; ItemPool *m_pool; @@ -280,6 +281,7 @@ private: SetupProjectParameters m_parameters; Version m_qbsVersion; Item *m_tempScopeItem = nullptr; + qint64 m_elapsedTimeProbes; }; } // namespace Internal diff --git a/src/lib/corelib/language/projectresolver.cpp b/src/lib/corelib/language/projectresolver.cpp index 9913dd863..eeb33662b 100644 --- a/src/lib/corelib/language/projectresolver.cpp +++ b/src/lib/corelib/language/projectresolver.cpp @@ -53,6 +53,7 @@ #include <logging/translator.h> #include <tools/error.h> #include <tools/fileinfo.h> +#include <tools/profiling.h> #include <tools/progressobserver.h> #include <tools/scripttools.h> #include <tools/qbsassert.h> @@ -151,7 +152,10 @@ TopLevelProjectPtr ProjectResolver::resolve() m_productContext = 0; m_moduleContext = 0; - return resolveTopLevelProject(); + m_elapsedTimeModPropEval = m_elapsedTimeAllPropEval = m_elapsedTimeGroups = 0; + const TopLevelProjectPtr tlp = resolveTopLevelProject(); + printProfilingInfo(); + return tlp; } void ProjectResolver::checkCancelation() const @@ -549,6 +553,9 @@ void ProjectResolver::resolveGroup(Item *item, ProjectContext *projectContext) m_evaluator->setCachingEnabled(false); } + AccumulatingTimer groupTimer(m_setupParams.logElapsedTime() + ? &m_elapsedTimeGroups : nullptr); + bool isEnabled = m_evaluator->boolValue(item, QLatin1String("condition")); if (m_productContext->currentGroup) isEnabled = isEnabled && m_productContext->currentGroup->enabled; @@ -925,6 +932,20 @@ void ProjectResolver::matchArtifactProperties(const ResolvedProductPtr &product, } } +void ProjectResolver::printProfilingInfo() +{ + if (!m_setupParams.logElapsedTime()) + return; + m_logger.qbsLog(LoggerInfo, true) << "\t" << Tr::tr("All property evaluation took %1.") + .arg(elapsedTimeString(m_elapsedTimeAllPropEval)); + m_logger.qbsLog(LoggerInfo, true) << "\t" << Tr::tr("Module property evaluation took %1.") + .arg(elapsedTimeString(m_elapsedTimeModPropEval)); + m_logger.qbsLog(LoggerInfo, true) << "\t" + << Tr::tr("Resolving groups (without module property " + "evaluation) took %1.") + .arg(elapsedTimeString(m_elapsedTimeGroups)); +} + static bool hasDependencyCycle(QSet<ResolvedProduct *> *checked, QSet<ResolvedProduct *> *branch, const ResolvedProductPtr &product, @@ -1050,8 +1071,10 @@ void ProjectResolver::applyFileTaggers(const SourceArtifactPtr &artifact, } } -QVariantMap ProjectResolver::evaluateModuleValues(Item *item, bool lookupPrototype) const +QVariantMap ProjectResolver::evaluateModuleValues(Item *item, bool lookupPrototype) { + AccumulatingTimer modPropEvalTimer(m_setupParams.logElapsedTime() + ? &m_elapsedTimeModPropEval : nullptr); QVariantMap moduleValues; foreach (const Item::Module &module, item->modules()) { const QString fullName = module.name.toString(); @@ -1063,15 +1086,17 @@ QVariantMap ProjectResolver::evaluateModuleValues(Item *item, bool lookupPrototy return result; } -QVariantMap ProjectResolver::evaluateProperties(Item *item, bool lookupPrototype) const +QVariantMap ProjectResolver::evaluateProperties(Item *item, bool lookupPrototype) { const QVariantMap tmplt; return evaluateProperties(item, item, tmplt, lookupPrototype); } QVariantMap ProjectResolver::evaluateProperties(Item *item, Item *propertiesContainer, - const QVariantMap &tmplt, bool lookupPrototype) const + const QVariantMap &tmplt, bool lookupPrototype) { + AccumulatingTimer propEvalTimer(m_setupParams.logElapsedTime() + ? &m_elapsedTimeAllPropEval : nullptr); QVariantMap result = tmplt; for (QMap<QString, ValuePtr>::const_iterator it = propertiesContainer->properties().begin(); it != propertiesContainer->properties().end(); ++it) @@ -1129,7 +1154,7 @@ QVariantMap ProjectResolver::evaluateProperties(Item *item, Item *propertiesCont : result; } -QVariantMap ProjectResolver::createProductConfig() const +QVariantMap ProjectResolver::createProductConfig() { m_evaluator->setCachingEnabled(true); QVariantMap cfg = evaluateModuleValues(m_productContext->item); diff --git a/src/lib/corelib/language/projectresolver.h b/src/lib/corelib/language/projectresolver.h index 820cc2a20..817f54522 100644 --- a/src/lib/corelib/language/projectresolver.h +++ b/src/lib/corelib/language/projectresolver.h @@ -105,11 +105,11 @@ private: void resolveProductDependencies(const ProjectContext &projectContext); void postProcess(const ResolvedProductPtr &product, ProjectContext *projectContext) const; void applyFileTaggers(const ResolvedProductPtr &product) const; - QVariantMap evaluateModuleValues(Item *item, bool lookupPrototype = true) const; - QVariantMap evaluateProperties(Item *item, bool lookupPrototype = true) const; + QVariantMap evaluateModuleValues(Item *item, bool lookupPrototype = true); + QVariantMap evaluateProperties(Item *item, bool lookupPrototype = true); QVariantMap evaluateProperties(Item *item, Item *propertiesContainer, const QVariantMap &tmplt, - bool lookupPrototype = true) const; - QVariantMap createProductConfig() const; + bool lookupPrototype = true); + QVariantMap createProductConfig(); QString convertPathProperty(const QString &path, const QString &dirPath) const; QStringList convertPathListProperty(const QStringList &paths, const QString &dirPath) const; ProjectContext createProjectContext(ProjectContext *parentProjectContext) const; @@ -117,6 +117,7 @@ private: const ModuleLoaderResult::ProductInfo &productInfo, bool &disabledDependency); static void matchArtifactProperties(const ResolvedProductPtr &product, const QList<SourceArtifactPtr> &artifacts); + void printProfilingInfo(); Evaluator *m_evaluator; Logger &m_logger; @@ -130,6 +131,9 @@ private: mutable QHash<FileContextConstPtr, ResolvedFileContextPtr> m_fileContextMap; const SetupProjectParameters &m_setupParams; const ModuleLoaderResult &m_loadResult; + qint64 m_elapsedTimeModPropEval; + qint64 m_elapsedTimeAllPropEval; + qint64 m_elapsedTimeGroups; typedef void (ProjectResolver::*ItemFuncPtr)(Item *item, ProjectContext *projectContext); typedef QMap<ItemType, ItemFuncPtr> ItemFuncMap; diff --git a/src/lib/corelib/language/scriptengine.cpp b/src/lib/corelib/language/scriptengine.cpp index 75b7c8aab..5be7b6ad0 100644 --- a/src/lib/corelib/language/scriptengine.cpp +++ b/src/lib/corelib/language/scriptengine.cpp @@ -48,8 +48,10 @@ #include <buildgraph/artifact.h> #include <jsextensions/environmentextension.h> #include <jsextensions/jsextensions.h> +#include <logging/translator.h> #include <tools/error.h> #include <tools/fileinfo.h> +#include <tools/profiling.h> #include <tools/qbsassert.h> #include <QDebug> @@ -107,6 +109,10 @@ ScriptEngine::~ScriptEngine() { qDeleteAll(m_ownedVariantMaps); delete (m_scriptImporter); + if (m_elapsedTimeImporting != -1) { + m_logger.qbsLog(LoggerInfo, true) << Tr::tr("Setting up imports took %1.") + .arg(elapsedTimeString(m_elapsedTimeImporting)); + } } void ScriptEngine::import(const FileContextBaseConstPtr &fileCtx, QScriptValue &targetObject) @@ -159,6 +165,11 @@ void ScriptEngine::addPropertyRequestedFromArtifact(const Artifact *artifact, m_propertiesRequestedFromArtifact[artifact->filePath()] << property; } +void ScriptEngine::enableProfiling(bool enable) +{ + m_elapsedTimeImporting = enable ? 0 : -1; +} + void ScriptEngine::addToPropertyCache(const QString &moduleName, const QString &propertyName, const PropertyMapConstPtr &propertyMap, const QVariant &value) { @@ -243,6 +254,7 @@ void ScriptEngine::setEnvironment(const QProcessEnvironment &env) void ScriptEngine::importFile(const QString &filePath, QScriptValue &targetObject) { + AccumulatingTimer importTimer(m_elapsedTimeImporting != -1 ? &m_elapsedTimeImporting : nullptr); QFile file(filePath); if (Q_UNLIKELY(!file.open(QFile::ReadOnly))) throw ErrorInfo(tr("Cannot open '%1'.").arg(filePath)); diff --git a/src/lib/corelib/language/scriptengine.h b/src/lib/corelib/language/scriptengine.h index 192d337b5..146a4db00 100644 --- a/src/lib/corelib/language/scriptengine.h +++ b/src/lib/corelib/language/scriptengine.h @@ -85,6 +85,8 @@ public: return m_propertiesRequestedFromArtifact; } + void enableProfiling(bool enable); + void setPropertyCacheEnabled(bool enable) { m_propertyCacheEnabled = enable; } bool isPropertyCacheEnabled() const { return m_propertyCacheEnabled; } void addToPropertyCache(const QString &moduleName, const QString &propertyName, @@ -188,6 +190,7 @@ private: QScriptValue m_consoleObject; QScriptValue m_cancelationError; QList<QVariantMap *> m_ownedVariantMaps; + qint64 m_elapsedTimeImporting = -1; }; } // namespace Internal diff --git a/src/lib/corelib/logging/logger.cpp b/src/lib/corelib/logging/logger.cpp index 9a7811fb5..7aadd785b 100644 --- a/src/lib/corelib/logging/logger.cpp +++ b/src/lib/corelib/logging/logger.cpp @@ -43,8 +43,6 @@ #include "logger.h" -#include "translator.h" - #include <QByteArray> #include <QElapsedTimer> #include <QMutex> @@ -227,55 +225,5 @@ LogWriter Logger::qbsLog(LoggerLevel level, bool force) const return LogWriter(m_logSink, level, force); } - -class TimedActivityLogger::TimedActivityLoggerPrivate -{ -public: - Logger logger; - QString activity; - QElapsedTimer timer; -}; - -TimedActivityLogger::TimedActivityLogger(const Logger &logger, const QString &activity, - bool enabled) - : d(0) -{ - if (!enabled) - return; - d = new TimedActivityLoggerPrivate; - d->logger = logger; - d->activity = activity; - d->logger.qbsLog(LoggerInfo) << Tr::tr("Starting activity '%2'.").arg(activity); - d->timer.start(); -} - -void TimedActivityLogger::finishActivity() -{ - if (!d) - return; - qint64 ms = d->timer.elapsed(); - qint64 s = ms/1000; - ms -= s*1000; - qint64 m = s/60; - s -= m*60; - const qint64 h = m/60; - m -= h*60; - QString timeString = QString::fromLocal8Bit("%1ms").arg(ms); - if (h || m || s) - timeString.prepend(QString::fromLocal8Bit("%1s, ").arg(s)); - if (h || m) - timeString.prepend(QString::fromLocal8Bit("%1m, ").arg(m)); - if (h) - timeString.prepend(QString::fromLocal8Bit("%1h, ").arg(h)); - d->logger.qbsLog(LoggerInfo) << Tr::tr("Activity '%2' took %3.").arg(d->activity, timeString); - delete d; - d = 0; -} - -TimedActivityLogger::~TimedActivityLogger() -{ - finishActivity(); -} - } // namespace Internal } // namespace qbs diff --git a/src/lib/corelib/logging/logger.h b/src/lib/corelib/logging/logger.h index e587f8325..ef35198be 100644 --- a/src/lib/corelib/logging/logger.h +++ b/src/lib/corelib/logging/logger.h @@ -134,19 +134,6 @@ private: bool m_storeWarnings = false; }; - -class TimedActivityLogger -{ -public: - TimedActivityLogger(const Logger &logger, const QString &activity, bool enabled); - void finishActivity(); - ~TimedActivityLogger(); - -private: - class TimedActivityLoggerPrivate; - TimedActivityLoggerPrivate *d; -}; - } // namespace Internal } // namespace qbs diff --git a/src/lib/corelib/tools/profiling.cpp b/src/lib/corelib/tools/profiling.cpp new file mode 100644 index 000000000..ede35e2fa --- /dev/null +++ b/src/lib/corelib/tools/profiling.cpp @@ -0,0 +1,126 @@ +/**************************************************************************** +** +** Copyright (C) 2016 The Qt Company Ltd. +** Contact: https://www.qt.io/licensing/ +** +** This file is part of Qbs. +** +** $QT_BEGIN_LICENSE:LGPL$ +** Commercial License Usage +** Licensees holding valid commercial Qt licenses may use this file in +** accordance with the commercial license agreement provided with the +** Software or, alternatively, in accordance with the terms contained in +** a written agreement between you and The Qt Company. For licensing terms +** and conditions see https://www.qt.io/terms-conditions. For further +** information use the contact form at https://www.qt.io/contact-us. +** +** GNU Lesser General Public License Usage +** Alternatively, this file may be used under the terms of the GNU Lesser +** General Public License version 3 as published by the Free Software +** Foundation and appearing in the file LICENSE.LGPL3 included in the +** packaging of this file. Please review the following information to +** ensure the GNU Lesser General Public License version 3 requirements +** will be met: https://www.gnu.org/licenses/lgpl-3.0.html. +** +** GNU General Public License Usage +** Alternatively, this file may be used under the terms of the GNU +** General Public License version 2.0 or (at your option) the GNU General +** Public license version 3 or any later version approved by the KDE Free +** Qt Foundation. The licenses are as published by the Free Software +** Foundation and appearing in the file LICENSE.GPL2 and LICENSE.GPL3 +** included in the packaging of this file. Please review the following +** information to ensure the GNU General Public License requirements will +** be met: https://www.gnu.org/licenses/gpl-2.0.html and +** https://www.gnu.org/licenses/gpl-3.0.html. +** +** $QT_END_LICENSE$ +** +****************************************************************************/ + +#include "profiling.h" + +#include <logging/logger.h> +#include <logging/translator.h> + +#include <QString> + +namespace qbs { +namespace Internal { + +class TimedActivityLogger::TimedActivityLoggerPrivate +{ +public: + Logger logger; + QString activity; + QElapsedTimer timer; +}; + +TimedActivityLogger::TimedActivityLogger(const Logger &logger, const QString &activity, + bool enabled) + : d(0) +{ + if (!enabled) + return; + d = new TimedActivityLoggerPrivate; + d->logger = logger; + d->activity = activity; + d->logger.qbsLog(LoggerInfo, true) << Tr::tr("Starting activity '%2'.").arg(activity); + d->timer.start(); +} + +void TimedActivityLogger::finishActivity() +{ + if (!d) + return; + const QString timeString = elapsedTimeString(d->timer.elapsed()); + d->logger.qbsLog(LoggerInfo, true) + << Tr::tr("Activity '%2' took %3.").arg(d->activity, timeString); + delete d; + d = 0; +} + +TimedActivityLogger::~TimedActivityLogger() +{ + finishActivity(); +} + +AccumulatingTimer::AccumulatingTimer(qint64 *elapsedTime) : m_elapsedTime(elapsedTime) +{ + if (elapsedTime) + m_timer.start(); +} + +AccumulatingTimer::~AccumulatingTimer() +{ + stop(); +} + +void AccumulatingTimer::stop() +{ + if (!m_timer.isValid()) + return; + *m_elapsedTime += m_timer.elapsed(); + m_timer.invalidate(); +} + +QString elapsedTimeString(qint64 elapsedTimeInMs) +{ + qint64 ms = elapsedTimeInMs; + qint64 s = ms/1000; + ms -= s*1000; + qint64 m = s/60; + s -= m*60; + const qint64 h = m/60; + m -= h*60; + QString timeString = QString::fromLocal8Bit("%1ms").arg(ms); + if (h || m || s) + timeString.prepend(QString::fromLocal8Bit("%1s, ").arg(s)); + if (h || m) + timeString.prepend(QString::fromLocal8Bit("%1m, ").arg(m)); + if (h) + timeString.prepend(QString::fromLocal8Bit("%1h, ").arg(h)); + return timeString; +} + +} // namespace Internal +} // namespace qbs diff --git a/src/lib/corelib/tools/profiling.h b/src/lib/corelib/tools/profiling.h new file mode 100644 index 000000000..f532eac2a --- /dev/null +++ b/src/lib/corelib/tools/profiling.h @@ -0,0 +1,82 @@ +/**************************************************************************** +** +** Copyright (C) 2016 The Qt Company Ltd. +** Contact: https://www.qt.io/licensing/ +** +** This file is part of Qbs. +** +** $QT_BEGIN_LICENSE:LGPL$ +** Commercial License Usage +** Licensees holding valid commercial Qt licenses may use this file in +** accordance with the commercial license agreement provided with the +** Software or, alternatively, in accordance with the terms contained in +** a written agreement between you and The Qt Company. For licensing terms +** and conditions see https://www.qt.io/terms-conditions. For further +** information use the contact form at https://www.qt.io/contact-us. +** +** GNU Lesser General Public License Usage +** Alternatively, this file may be used under the terms of the GNU Lesser +** General Public License version 3 as published by the Free Software +** Foundation and appearing in the file LICENSE.LGPL3 included in the +** packaging of this file. Please review the following information to +** ensure the GNU Lesser General Public License version 3 requirements +** will be met: https://www.gnu.org/licenses/lgpl-3.0.html. +** +** GNU General Public License Usage +** Alternatively, this file may be used under the terms of the GNU +** General Public License version 2.0 or (at your option) the GNU General +** Public license version 3 or any later version approved by the KDE Free +** Qt Foundation. The licenses are as published by the Free Software +** Foundation and appearing in the file LICENSE.GPL2 and LICENSE.GPL3 +** included in the packaging of this file. Please review the following +** information to ensure the GNU General Public License requirements will +** be met: https://www.gnu.org/licenses/gpl-2.0.html and +** https://www.gnu.org/licenses/gpl-3.0.html. +** +** $QT_END_LICENSE$ +** +****************************************************************************/ + +#ifndef QBS_PROFILING_H +#define QBS_PROFILING_H + +#include <QElapsedTimer> + +QT_BEGIN_NAMESPACE +class QString; +QT_END_NAMESPACE + +namespace qbs { +namespace Internal { +class Logger; + +QString elapsedTimeString(qint64 elapsedTimeInMs); + +class TimedActivityLogger +{ +public: + TimedActivityLogger(const Logger &logger, const QString &activity, bool enabled); + void finishActivity(); + ~TimedActivityLogger(); + +private: + class TimedActivityLoggerPrivate; + TimedActivityLoggerPrivate *d; +}; + +class AccumulatingTimer +{ +public: + AccumulatingTimer(qint64 *elapsedTime); + ~AccumulatingTimer(); + void stop(); + +private: + QElapsedTimer m_timer; + qint64 * const m_elapsedTime; +}; + +} // namespace Internal +} // namespace qbs + +#endif // Header guard diff --git a/src/lib/corelib/tools/tools.pri b/src/lib/corelib/tools/tools.pri index 7bcf60516..344f9924e 100644 --- a/src/lib/corelib/tools/tools.pri +++ b/src/lib/corelib/tools/tools.pri @@ -24,6 +24,7 @@ HEADERS += \ $$PWD/pathutils.h \ $$PWD/preferences.h \ $$PWD/profile.h \ + $$PWD/profiling.h \ $$PWD/processresult.h \ $$PWD/processresult_p.h \ $$PWD/processutils.h \ @@ -69,6 +70,7 @@ SOURCES += \ $$PWD/processresult.cpp \ $$PWD/processutils.cpp \ $$PWD/profile.cpp \ + $$PWD/profiling.cpp \ $$PWD/progressobserver.cpp \ $$PWD/projectgeneratormanager.cpp \ $$PWD/propertyfinder.cpp \ |