QtcProcess: Consolidate the log debug code

Reuse starting() signal for doing initial debug printout.
Keep dynamic properties in QtcProcessPrivate only, so
no need for passing it.

Change-Id: I170ea96c37e1b9904037851799316de629bfb86e
Reviewed-by: hjk <hjk@qt.io>

src/libs/utils/qtcprocess.cpp

@@ -201,33 +201,8 @@ private:
     bool ensureProgramExists(const QString &program);
 };
 
-static QString blockingMessage(const QVariant &variant)
-{
-    if (!variant.isValid())
-        return "non blocking";
-    if (variant.toInt() == int(EventLoopMode::On))
-        return "blocking with event loop";
-    return "blocking without event loop";
-}
-
 void DefaultImpl::start()
 {
-    if (processLog().isDebugEnabled()) {
-        using namespace std::chrono;
-        const quint64 msSinceEpoc =
-                duration_cast<milliseconds>(system_clock::now().time_since_epoch()).count();
-        setProperty(QTC_PROCESS_STARTTIME, msSinceEpoc);
-
-        static std::atomic_int startCounter = 0;
-        const int currentNumber = startCounter.fetch_add(1);
-        qCDebug(processLog).nospace().noquote()
-                << "Process " << currentNumber << " starting ("
-                << qPrintable(blockingMessage(property(QTC_PROCESS_BLOCKING_TYPE)))
-                << "): "
-                << m_setup.m_commandLine.toUserOutput();
-        setProperty(QTC_PROCESS_NUMBER, currentNumber);
-    }
-
     QString program;
     QStringList arguments;
     if (!dissolveCommand(&program, &arguments))
@@ -261,7 +236,7 @@ bool DefaultImpl::dissolveCommand(QString *program, QStringList *arguments)
         m_setup.m_nativeArguments = args;
         // Note: Arguments set with setNativeArgs will be appended to the ones
         // passed with start() below.
-        *arguments = QStringList();
+        *arguments = {};
     } else {
         if (!success) {
             const ProcessResultData result = {0,
@@ -637,8 +612,12 @@ public:
             m_killTimer.stop();
             sendControlSignal(ControlSignal::Kill);
         });
+        setupDebugLog();
     }
 
+    void setupDebugLog();
+    void storeEventLoopDebugInfo(const QVariant &value);
+
     ProcessInterface *createProcessInterface()
     {
         if (m_setup.m_terminalMode != TerminalMode::Off)
@@ -1008,38 +987,6 @@ QtcProcess::QtcProcess(QObject *parent)
     static int qProcessProcessErrorMeta = qRegisterMetaType<QProcess::ProcessError>();
     Q_UNUSED(qProcessExitStatusMeta)
     Q_UNUSED(qProcessProcessErrorMeta)
-
-    if (processLog().isDebugEnabled()) {
-        connect(this, &QtcProcess::done, [this] {
-            if (!d->m_process.get())
-                return;
-            const QVariant n = d->m_process.get()->property(QTC_PROCESS_NUMBER);
-            if (!n.isValid())
-                return;
-            using namespace std::chrono;
-            const quint64 msSinceEpoc =
-                    duration_cast<milliseconds>(system_clock::now().time_since_epoch()).count();
-            const quint64 msStarted =
-                    d->m_process.get()->property(QTC_PROCESS_STARTTIME).toULongLong();
-            const quint64 msElapsed = msSinceEpoc - msStarted;
-
-            const int number = n.toInt();
-            qCDebug(processLog).nospace() << "Process " << number << " finished: "
-                                          << "result=" << int(result())
-                                          << ", ex=" << exitCode()
-                                          << ", " << cleanedStdOut().size() << " bytes stdout: "
-                                          << cleanedStdOut().left(20)
-                                          << ", " << cleanedStdErr().size() << " bytes stderr: "
-                                          << cleanedStdErr().left(1000)
-                                          << ", " << msElapsed << " ms elapsed";
-            if (processStdoutLog().isDebugEnabled() && !cleanedStdOut().isEmpty())
-                qCDebug(processStdoutLog).nospace()
-                        << "Process " << number << " sdout: " << cleanedStdOut();
-            if (processStderrLog().isDebugEnabled() && !cleanedStdErr().isEmpty())
-                qCDebug(processStderrLog).nospace()
-                        << "Process " << number << " stderr: " << cleanedStdErr();
-        });
-    }
 }
 
 QtcProcess::~QtcProcess()
@@ -1145,10 +1092,6 @@ void QtcProcess::start()
     d->m_process->m_setup = d->m_setup;
     d->m_process->m_setup.m_commandLine = d->fullCommandLine();
     d->m_process->m_setup.m_environment = d->fullEnvironment();
-    if (processLog().isDebugEnabled()) {
-        // Pass a dynamic property with info about blocking type
-        d->m_process->setProperty(QTC_PROCESS_BLOCKING_TYPE, property(QTC_PROCESS_BLOCKING_TYPE));
-    }
     d->emitGuardedSignal(&QtcProcess::starting);
     d->m_process->start();
 }
@@ -1840,16 +1783,14 @@ static bool isGuiThread()
 
 void QtcProcess::runBlocking(EventLoopMode eventLoopMode)
 {
-    if (processLog().isDebugEnabled()) {
     // Attach a dynamic property with info about blocking type
-        setProperty(QTC_PROCESS_BLOCKING_TYPE, int(eventLoopMode));
-    }
+    d->storeEventLoopDebugInfo(int(eventLoopMode));
 
     QtcProcess::start();
-    if (processLog().isDebugEnabled()) {
+
     // Remove the dynamic property so that it's not reused in subseqent start()
-        setProperty(QTC_PROCESS_BLOCKING_TYPE, QVariant());
-    }
+    d->storeEventLoopDebugInfo({});
+
     if (eventLoopMode == EventLoopMode::On) {
         // Start failure is triggered immediately if the executable cannot be found in the path.
         // In this case the process is left in NotRunning state.
@@ -2032,6 +1973,70 @@ void QtcProcessPrivate::handleDone(const ProcessResultData &data)
     m_applicationMainThreadId = 0;
 }
 
+static QString blockingMessage(const QVariant &variant)
+{
+    if (!variant.isValid())
+        return "non blocking";
+    if (variant.toInt() == int(EventLoopMode::On))
+        return "blocking with event loop";
+    return "blocking without event loop";
+}
+
+void QtcProcessPrivate::setupDebugLog()
+{
+    if (!processLog().isDebugEnabled())
+        return;
+
+    auto now = [] {
+        using namespace std::chrono;
+        return duration_cast<milliseconds>(system_clock::now().time_since_epoch()).count();
+    };
+
+    connect(q, &QtcProcess::starting, this, [=] {
+        const quint64 msNow = now();
+        setProperty(QTC_PROCESS_STARTTIME, msNow);
+
+        static std::atomic_int startCounter = 0;
+        const int currentNumber = startCounter.fetch_add(1);
+        qCDebug(processLog).nospace().noquote()
+                << "Process " << currentNumber << " starting ("
+                << qPrintable(blockingMessage(property(QTC_PROCESS_BLOCKING_TYPE)))
+                << "): " << m_setup.m_commandLine.toUserOutput();
+        setProperty(QTC_PROCESS_NUMBER, currentNumber);
+    });
+
+    connect(q, &QtcProcess::done, this, [=] {
+        if (!m_process.get())
+            return;
+        const QVariant n = property(QTC_PROCESS_NUMBER);
+        if (!n.isValid())
+            return;
+        const quint64 msNow = now();
+        const quint64 msStarted = property(QTC_PROCESS_STARTTIME).toULongLong();
+        const quint64 msElapsed = msNow - msStarted;
+
+        const int number = n.toInt();
+        const QString stdOut = q->cleanedStdOut();
+        const QString stdErr = q->cleanedStdErr();
+        qCDebug(processLog).nospace()
+                << "Process " << number << " finished: result=" << int(m_result)
+                << ", ex=" << m_resultData.m_exitCode
+                << ", " << stdOut.size() << " bytes stdout: " << stdOut.left(20)
+                << ", " << stdErr.size() << " bytes stderr: " << stdErr.left(1000)
+                << ", " << msElapsed << " ms elapsed";
+        if (processStdoutLog().isDebugEnabled() && !stdOut.isEmpty())
+            qCDebug(processStdoutLog).nospace() << "Process " << number << " sdout: " << stdOut;
+        if (processStderrLog().isDebugEnabled() && !stdErr.isEmpty())
+            qCDebug(processStderrLog).nospace() << "Process " << number << " stderr: " << stdErr;
+    });
+}
+
+void QtcProcessPrivate::storeEventLoopDebugInfo(const QVariant &value)
+{
+    if (processLog().isDebugEnabled())
+        setProperty(QTC_PROCESS_BLOCKING_TYPE, value);
+}
+
 } // namespace Utils
 
 #include "qtcprocess.moc"