diff options
author | Cristian Adam <cristian.adam@qt.io> | 2022-03-04 19:42:46 +0100 |
---|---|---|
committer | Cristian Adam <cristian.adam@qt.io> | 2022-03-21 12:40:33 +0000 |
commit | a1929bd9d7d29223a4523d727510fd90a7ff57b4 (patch) | |
tree | bb45e9e5638f6bbf277c71429850f1e4f478d6c1 | |
parent | 047253b6a8764efe996e4f86591c7b3dd9f6a878 (diff) |
ClangCodeModel: Add some more timing debug information
By setting QT_LOGGING_RULES=qtc.clangcodemodel.clangd.timing=true I can get
values like:
qtc.clangcodemodel.clangd.timing: highlighting: Start to end: 2953 ms
qtc.clangcodemodel.clangd.timing: ClangdCompletionAssistProcessor took: 7343 ms
The first tells you how long Creator took to turn clangd's semantic tokens into
full highlighting info, and the second how long it took for Ctrl+Space.
Change-Id: I99bd04c2889bb7da98c04537eab06d6ed6117167
Reviewed-by: Christian Kandeler <christian.kandeler@qt.io>
-rw-r--r-- | src/plugins/clangcodemodel/clangdclient.cpp | 35 |
1 files changed, 28 insertions, 7 deletions
diff --git a/src/plugins/clangcodemodel/clangdclient.cpp b/src/plugins/clangcodemodel/clangdclient.cpp index 894f22aaa9..6d343c62a2 100644 --- a/src/plugins/clangcodemodel/clangdclient.cpp +++ b/src/plugins/clangcodemodel/clangdclient.cpp @@ -997,9 +997,12 @@ public: m_started = true; m_finalized = false; qCDebug(clangdLogTiming).noquote().nospace() << m_task << ": starting"; + + // Used by ThreadedSubtaskTimer to mark the end of the whole highlighting operation + m_startTimer.restart(); } qCDebug(clangdLogTiming).noquote().nospace() << m_task << ": subtask started at " - << QDateTime::currentDateTime().toString(); + << QDateTime::currentDateTime().time().toString("hh:mm:ss.zzz"); QTC_CHECK(!m_timer.isValid()); m_timer.start(); } @@ -1012,7 +1015,7 @@ public: if (--m_subtasks > 0) // See startSubtask(). return; qCDebug(clangdLogTiming).noquote().nospace() << m_task << ": subtask stopped at " - << QDateTime::currentDateTime().toString(); + << QDateTime::currentDateTime().time().toString("hh:mm:ss.zzz"); QTC_CHECK(m_timer.isValid()); m_elapsedMs += m_timer.elapsed(); m_timer.invalidate(); @@ -1020,9 +1023,12 @@ public: stopTask(); } + QElapsedTimer startTimer() const { return m_startTimer; } + private: const QString m_task; QElapsedTimer m_timer; + QElapsedTimer m_startTimer; qint64 m_elapsedMs = 0; int m_subtasks = 0; bool m_started = false; @@ -1052,7 +1058,7 @@ public: class ThreadedSubtaskTimer { public: - ThreadedSubtaskTimer(const QString &task) : m_task(task) + ThreadedSubtaskTimer(const QString &task, const TaskTimer &taskTimer) : m_task(task), m_taskTimer(taskTimer) { qCDebug(clangdLogTiming).noquote().nospace() << m_task << ": starting thread"; m_timer.start(); @@ -1062,10 +1068,15 @@ public: { qCDebug(clangdLogTiming).noquote().nospace() << m_task << ": took " << m_timer.elapsed() << " ms in dedicated thread"; + + qCDebug(clangdLogTiming).noquote().nospace() << m_task << ": Start to end: " + << m_taskTimer.startTimer().elapsed() << " ms"; } + private: const QString m_task; QElapsedTimer m_timer; + const TaskTimer &m_taskTimer; }; class MemoryTreeModel; @@ -1191,6 +1202,13 @@ public: : LanguageClientCompletionAssistProcessor(client, snippetsGroup) , m_client(client) { + m_timer.start(); + } + + ~ClangdCompletionAssistProcessor() + { + qCDebug(clangdLogTiming).noquote().nospace() + << "ClangdCompletionAssistProcessor took: " << m_timer.elapsed() << " ms"; } private: @@ -1208,6 +1226,7 @@ private: const QList<LanguageServerProtocol::CompletionItem> &items) const override; ClangdClient * const m_client; + QElapsedTimer m_timer; }; QList<AssistProposalItemInterface *> @@ -2653,9 +2672,10 @@ static void semanticHighlighter(QFutureInterface<HighlightingResult> &future, const QList<ExpandedSemanticToken> &tokens, const QString &docContents, const AstNode &ast, const QPointer<TextDocument> &textDocument, - int docRevision, const QVersionNumber &clangdVersion) + int docRevision, const QVersionNumber &clangdVersion, + const TaskTimer &taskTimer) { - ThreadedSubtaskTimer t("highlighting"); + ThreadedSubtaskTimer t("highlighting", taskTimer); if (future.isCanceled()) { future.reportFinished(); return; @@ -2921,9 +2941,10 @@ void ClangdClient::Private::handleSemanticTokens(TextDocument *doc, const auto runner = [tokens, filePath = doc->filePath(), text = doc->document()->toPlainText(), ast, doc = QPointer(doc), rev = doc->document()->revision(), - clangdVersion = q->versionNumber()] { + clangdVersion = q->versionNumber(), + this] { return Utils::runAsync(semanticHighlighter, filePath, tokens, text, ast, doc, rev, - clangdVersion); + clangdVersion, highlightingTimer); }; if (isTesting) { |