Clang: Allow to time high-level functions

...by enabling the logging rule:

    qtc.clangbackend.timers=true

Change-Id: I085c6bbebc0343b74bcb90119d1ebb80ad49518d
Reviewed-by: Erik Verbruggen <erik.verbruggen@theqtcompany.com>

src/libs/clangbackendipc/clangbackendipcdebugutils.cpp

@@ -35,12 +35,15 @@
 #include <utf8string.h>
 
 #include <QDir>
+#include <QLoggingCategory>
 #include <QString>
 #include <QTemporaryDir>
 #include <QTemporaryFile>
 
 namespace {
 
+Q_LOGGING_CATEGORY(timersLog, "qtc.clangbackend.timers");
+
 class DebugInspectionDir : public QTemporaryDir
 {
 public:
@@ -96,4 +99,16 @@ Utf8String debugId(const FileContainer &fileContainer)
     return id;
 }
 
+VerboseScopeDurationTimer::VerboseScopeDurationTimer(const char *id)
+    : id(id)
+{
+    if (timersLog().isDebugEnabled())
+        timer.start();
+}
+
+VerboseScopeDurationTimer::~VerboseScopeDurationTimer()
+{
+    qCDebug(timersLog) << id << "needed" << timer.elapsed() << "ms";
+}
+
 } // namespace ClangBackEnd

src/libs/clangbackendipc/clangbackendipcdebugutils.h

@@ -31,6 +31,10 @@
 #ifndef CLANGBACKENDIPCDEBUGUTILS_H
 #define CLANGBACKENDIPCDEBUGUTILS_H
 
+#include "clangbackendipc_global.h"
+
+#include <QElapsedTimer>
+
 class FileContainer;
 class Utf8String;
 
@@ -39,6 +43,19 @@ namespace ClangBackEnd {
 Utf8String debugWriteFileForInspection(const Utf8String &fileContent, const Utf8String &id);
 Utf8String debugId(const FileContainer &fileContainer);
 
+class CMBIPC_EXPORT VerboseScopeDurationTimer
+{
+public:
+    VerboseScopeDurationTimer(const char *id = 0);
+    ~VerboseScopeDurationTimer();
+
+private:
+    const char * const id;
+    QElapsedTimer timer;
+};
+
 } // namespace ClangBackEnd
 
+#define TIME_SCOPE_DURATION(id) ClangBackEnd::VerboseScopeDurationTimer scopeDurationTimer(id)
+
 #endif // CLANGBACKENDIPCDEBUGUTILS_H

src/libs/clangbackendipc/connectionclient.cpp

@@ -30,6 +30,7 @@
 
 #include "connectionclient.h"
 
+#include "clangbackendipcdebugutils.h"
 #include "cmbcompletecodecommand.h"
 #include "cmbregistertranslationunitsforcodecompletioncommand.h"
 #include "cmbunregistertranslationunitsforcodecompletioncommand.h"
@@ -76,6 +77,8 @@ ConnectionClient::~ConnectionClient()
 
 bool ConnectionClient::connectToServer()
 {
+    TIME_SCOPE_DURATION("ConnectionClient::connectToServer");
+
     startProcess();
     resetProcessAliveTimer();
     const bool isConnected = connectToLocalSocket();
@@ -123,6 +126,8 @@ void ConnectionClient::setProcessAliveTimerInterval(int processTimerInterval)
 
 void ConnectionClient::startProcess()
 {
+    TIME_SCOPE_DURATION("ConnectionClient::startProcess");
+
     if (!isProcessIsRunning()) {
         connectProcessFinished();
         connectStandardOutputAndError();
@@ -216,6 +221,8 @@ void ConnectionClient::printStandardError()
 
 void ConnectionClient::finishProcess()
 {
+    TIME_SCOPE_DURATION("ConnectionClient::finishProcess");
+
     processAliveTimer.stop();
 
     disconnectProcessFinished();

src/plugins/clangcodemodel/clangbackendipcintegration.cpp

@@ -236,13 +236,10 @@ static bool areCommandsRegistered = false;
 
 void IpcCommunicator::initializeBackend()
 {
-    // TODO: Add a asynchron API to ConnectionClient, otherwise we might hang here
-
     if (!areCommandsRegistered) {
         areCommandsRegistered = true;
         Commands::registerCommands();
     }
-    QElapsedTimer timer; timer.start();
 
     const QString clangBackEndProcessPath = backendProcessPath();
     qCDebug(log) << "Starting" << clangBackEndProcessPath;
@@ -254,12 +251,9 @@ void IpcCommunicator::initializeBackend()
     connect(&m_connection, &ConnectionClient::processRestarted,
             this, &IpcCommunicator::onBackendRestarted);
 
-    if (m_connection.connectToServer()) {
-        qCDebug(log) << "...started and connected in" << timer.elapsed() << "ms.";
+    // TODO: Add a asynchron API to ConnectionClient, otherwise we might hang here
+    if (m_connection.connectToServer())
         initializeBackendWithCurrentData();
-    } else {
-        qCDebug(log) << "...failed.";
-    }
 }
 
 void IpcCommunicator::registerEmptyProjectForProjectLessFiles()

src/tools/clangbackend/ipcsource/clangipcserver.cpp

@@ -30,6 +30,7 @@
 
 #include "clangipcserver.h"
 
+#include <clangbackendipcdebugutils.h>
 #include <cmbcodecompletedcommand.h>
 #include <cmbcompletecodecommand.h>
 #include <cmbregisterprojectsforcodecompletioncommand.h>
@@ -64,6 +65,8 @@ void ClangIpcServer::end()
 
 void ClangIpcServer::registerTranslationUnitsForCodeCompletion(const ClangBackEnd::RegisterTranslationUnitForCodeCompletionCommand &command)
 {
+    TIME_SCOPE_DURATION("ClangIpcServer::registerTranslationUnitsForCodeCompletion");
+
     try {
         translationUnits.createOrUpdate(command.fileContainers());
         unsavedFiles.createOrUpdate(command.fileContainers());
@@ -76,6 +79,8 @@ void ClangIpcServer::registerTranslationUnitsForCodeCompletion(const ClangBackEn
 
 void ClangIpcServer::unregisterTranslationUnitsForCodeCompletion(const ClangBackEnd::UnregisterTranslationUnitsForCodeCompletionCommand &command)
 {
+    TIME_SCOPE_DURATION("ClangIpcServer::unregisterTranslationUnitsForCodeCompletion");
+
     try {
         translationUnits.remove(command.fileContainers());
     } catch (const TranslationUnitDoesNotExistException &exception) {
@@ -89,6 +94,8 @@ void ClangIpcServer::unregisterTranslationUnitsForCodeCompletion(const ClangBack
 
 void ClangIpcServer::registerProjectPartsForCodeCompletion(const RegisterProjectPartsForCodeCompletionCommand &command)
 {
+    TIME_SCOPE_DURATION("ClangIpcServer::registerProjectPartsForCodeCompletion");
+
     try {
         projects.createOrUpdate(command.projectContainers());
     } catch (const std::exception &exception) {
@@ -98,6 +105,8 @@ void ClangIpcServer::registerProjectPartsForCodeCompletion(const RegisterProject
 
 void ClangIpcServer::unregisterProjectPartsForCodeCompletion(const UnregisterProjectPartsForCodeCompletionCommand &command)
 {
+    TIME_SCOPE_DURATION("ClangIpcServer::unregisterProjectPartsForCodeCompletion");
+
     try {
         projects.remove(command.projectPartIds());
     } catch (const ProjectPartDoNotExistException &exception) {
@@ -109,6 +118,8 @@ void ClangIpcServer::unregisterProjectPartsForCodeCompletion(const UnregisterPro
 
 void ClangIpcServer::completeCode(const ClangBackEnd::CompleteCodeCommand &command)
 {
+    TIME_SCOPE_DURATION("ClangIpcServer::completeCode");
+
     try {
         CodeCompleter codeCompleter(translationUnits.translationUnit(command.filePath(), command.projectPartId()));