Qmake: Do not delay initial parsing

And add some logging to make the situation debuggable.

There are a lot of reasons that currently trigger (or attempt to
trigger) parsing, including two unconditional ones on build system
construction and fromMap. Some can be avoided, but keeping track of
which one will be the "needed" one gets tricky without additional state.

So turn it around and try to reparse "immediately" until such a parse
finished. The parser itself is robust enough to deflect repeated
runs before the first one finishes.

Change-Id: Ic992b8730fa3a09ca14532cdd9bdbab4c245cb41
Reviewed-by: Christian Kandeler <christian.kandeler@qt.io>
Reviewed-by: Christian Stenger <christian.stenger@qt.io>

src/plugins/qmakeprojectmanager/qmakeproject.cpp

@@ -73,6 +73,7 @@
 #include <QDebug>
 #include <QDir>
 #include <QFileSystemWatcher>
+#include <QLoggingCategory>
 
 using namespace QmakeProjectManager::Internal;
 using namespace ProjectExplorer;
@@ -84,6 +85,8 @@ namespace Internal {
 
 const int UPDATE_INTERVAL = 3000;
 
+static Q_LOGGING_CATEGORY(qmakeBuildSystemLog, "qtc.qmake.buildsystem", QtWarningMsg);
+
 /// Watches folders for QmakePriFile nodes
 /// use one file system watcher to watch all folders
 /// such minimizing system ressouce usage
@@ -186,7 +189,7 @@ QmakeBuildSystem::QmakeBuildSystem(QmakeBuildConfiguration *bc)
     m_qmakeVfs->setTextCodec(codec);
 
     m_asyncUpdateTimer.setSingleShot(true);
-    m_asyncUpdateTimer.setInterval(UPDATE_INTERVAL);
+    m_asyncUpdateTimer.setInterval(0);
     connect(&m_asyncUpdateTimer, &QTimer::timeout, this, &QmakeBuildSystem::asyncUpdate);
 
     m_rootProFile = std::make_unique<QmakeProFile>(this, projectFilePath());
@@ -455,12 +458,11 @@ void QmakeBuildSystem::scheduleAsyncUpdateFile(QmakeProFile *file, QmakeProFile:
 
 void QmakeBuildSystem::scheduleUpdateAllNowOrLater()
 {
-    if (m_firstParseNeeded) {
+    qCDebug(qmakeBuildSystemLog) <<  __FUNCTION__ << m_firstParseNeeded;
-        m_firstParseNeeded = false;
+    if (m_firstParseNeeded)
         scheduleUpdateAll(QmakeProFile::ParseNow);
-    } else {
+    else
         scheduleUpdateAll(QmakeProFile::ParseLater);
-    }
 }
 
 void QmakeBuildSystem::scheduleUpdateAll(QmakeProFile::AsyncUpdateDelay delay)
@@ -491,13 +493,17 @@ void QmakeBuildSystem::scheduleUpdateAll(QmakeProFile::AsyncUpdateDelay delay)
 
 void QmakeBuildSystem::startAsyncTimer(QmakeProFile::AsyncUpdateDelay delay)
 {
-   if (!m_buildConfiguration->isActive())
+   if (!m_buildConfiguration->isActive()) {
+        qCDebug(qmakeBuildSystemLog) <<  __FUNCTION__ << "skipped, not active";
         return;
+   }
+
+    const int interval = qMin(m_asyncUpdateTimer.interval(),
+                              delay == QmakeProFile::ParseLater ? UPDATE_INTERVAL : 0);
+    qCDebug(qmakeBuildSystemLog) <<  __FUNCTION__ << interval;
 
     m_asyncUpdateTimer.stop();
-    m_asyncUpdateTimer.setInterval(qMin(m_asyncUpdateTimer.interval(),
+    m_asyncUpdateTimer.setInterval(interval);
-                                        delay == QmakeProFile::ParseLater ? UPDATE_INTERVAL : 0));
-
     m_asyncUpdateTimer.start();
 }
 
@@ -544,6 +550,9 @@ void QmakeBuildSystem::decrementPendingEvaluateFutures()
             m_guard.markAsSuccess(); // Qmake always returns (some) data, even when it failed:-)
             m_guard = {}; // This triggers emitParsingFinished by destroying the previous guard.
 
+            qCDebug(qmakeBuildSystemLog) <<  __FUNCTION__ << "first parse succeeded";
+            m_firstParseNeeded = false;
+
             emitBuildSystemUpdated();
         }
     }
@@ -557,6 +566,7 @@ bool QmakeBuildSystem::wasEvaluateCanceled()
 void QmakeBuildSystem::asyncUpdate()
 {
     m_asyncUpdateTimer.setInterval(UPDATE_INTERVAL);
+    qCDebug(qmakeBuildSystemLog) <<  __FUNCTION__;
 
     if (m_invalidateQmakeVfsContents) {
         m_invalidateQmakeVfsContents = false;