Fix unwanted "concurrency" in Executor.v1.4.51.4

Script engine evaluation is interrupted once a second to check for
cancel requests. At this time, jobs can finish, leading to the
onJobFinished() slot being called while we are in the middle of
executeRuleNode(). Possible effects:
    - The job that just finished was the only currently running one,
      and its transformer outputs have no parents. Then the Executor
      will think it's done, and higher-level code will free the
      evaluation context (and with it the engine). When script execution
      continues after the current round of events processing, a null
      pointer or freed memory will be accessed.
    - The job's transformer outputs do have parent artifacts. In this
      case, we are suddenly and most unexpectedly in executeRuleNode()
      twice, with the potential for all kinds of stunning behavior.
Fix the problem by checking in the onJobFinished() slot whether the
rules evaluation context is currently active and delaying slot execution
if it is.

Task-number: QBS-932
Change-Id: I03ca4f4ad844357e49d5acaddff066395a7f95cf
Reviewed-by: Joerg Bornemann <joerg.bornemann@theqtcompany.com>

9 files changed, 114 insertions, 11 deletions

diff --git a/src/lib/corelib/buildgraph/executor.cpp b/src/lib/corelib/buildgraph/executor.cpp
index 8a028f0dd..7cfc3137a 100644
--- a/src/lib/corelib/buildgraph/executor.cpp
+++ b/src/lib/corelib/buildgraph/executor.cpp
@@ -435,6 +435,7 @@ void Executor::buildArtifact(Artifact *artifact)
 
 void Executor::executeRuleNode(RuleNode *ruleNode)
 {
+    QBS_CHECK(!m_evalContext->isActive());
     ArtifactSet changedInputArtifacts;
     if (ruleNode->rule()->isDynamic()) {
         foreach (Artifact *artifact, m_changedSourceArtifacts) {
@@ -891,20 +892,28 @@ void Executor::possiblyInstallArtifact(const Artifact *artifact)
 
 void Executor::onJobFinished(const qbs::ErrorInfo &err)
 {
-    if (err.hasError()) {
-        if (m_buildOptions.keepGoing()) {
-            ErrorInfo fullWarning(err);
-            fullWarning.prepend(Tr::tr("Ignoring the following errors on user request:"));
-            m_logger.printWarning(fullWarning);
-        } else {
-            if (!m_error.hasError())
-                m_error = err; // All but the first one could be due to canceling.
-        }
-    }
-
     try {
         ExecutorJob * const job = qobject_cast<ExecutorJob *>(sender());
         QBS_CHECK(job);
+        if (m_evalContext->isActive()) {
+            m_logger.qbsDebug() << "Executor job finished while rule execution is pausing. "
+                                   "Delaying slot execution.";
+            QMetaObject::invokeMethod(job, "finished", Qt::QueuedConnection,
+                                      Q_ARG(qbs::ErrorInfo, err));
+            return;
+        }
+
+        if (err.hasError()) {
+            if (m_buildOptions.keepGoing()) {
+                ErrorInfo fullWarning(err);
+                fullWarning.prepend(Tr::tr("Ignoring the following errors on user request:"));
+                m_logger.printWarning(fullWarning);
+            } else {
+                if (!m_error.hasError())
+                    m_error = err; // All but the first one could be due to canceling.
+            }
+        }
+
         finishJob(job, !err.hasError());
     } catch (const ErrorInfo &error) {
         handleError(error);
@@ -914,6 +923,7 @@ void Executor::onJobFinished(const qbs::ErrorInfo &err)
 void Executor::finish()
 {
     QBS_ASSERT(m_state != ExecutorIdle, /* ignore */);
+    QBS_ASSERT(!m_evalContext || !m_evalContext->isActive(), /* ignore */);
 
     QList<ResolvedProductPtr> unbuiltProducts;
     foreach (const ResolvedProductPtr &product, m_productsToBuild) {
diff --git a/src/lib/corelib/buildgraph/rulesevaluationcontext.cpp b/src/lib/corelib/buildgraph/rulesevaluationcontext.cpp
index 1f412b454..eed00cdac 100644
--- a/src/lib/corelib/buildgraph/rulesevaluationcontext.cpp
+++ b/src/lib/corelib/buildgraph/rulesevaluationcontext.cpp
@@ -58,6 +58,11 @@ RulesEvaluationContext::~RulesEvaluationContext()
     delete m_engine;
 }
 
+bool RulesEvaluationContext::isActive() const
+{
+    return m_initScopeCalls > 0;
+}
+
 void RulesEvaluationContext::initializeObserver(const QString &description, int maximumProgress)
 {
     if (m_observer)
diff --git a/src/lib/corelib/buildgraph/rulesevaluationcontext.h b/src/lib/corelib/buildgraph/rulesevaluationcontext.h
index 274d9bcae..f00b2c44d 100644
--- a/src/lib/corelib/buildgraph/rulesevaluationcontext.h
+++ b/src/lib/corelib/buildgraph/rulesevaluationcontext.h
@@ -61,6 +61,7 @@ public:
 
     ScriptEngine *engine() const { return m_engine; }
     QScriptValue scope() const { return m_scope; }
+    bool isActive() const;
 
     void setObserver(ProgressObserver *observer) { m_observer = observer; }
     ProgressObserver *observer() const { return m_observer; }
diff --git a/tests/auto/blackbox/testdata/concurrent-executor/concurrent-executor.qbs b/tests/auto/blackbox/testdata/concurrent-executor/concurrent-executor.qbs
new file mode 100644
index 000000000..672576263
--- /dev/null
+++ b/tests/auto/blackbox/testdata/concurrent-executor/concurrent-executor.qbs
@@ -0,0 +1,71 @@
+import qbs
+import qbs.File
+import qbs.TextFile
+import "util.js" as Utils
+
+Product {
+    type: ["final1", "final2"]
+    Group {
+        files: ["dummy1.input"]
+        fileTags: ["input1"]
+    }
+    Group {
+        files: ["dummy2.input"]
+        fileTags: ["input2"]
+    }
+    Rule {
+        inputs: ["input1"]
+        Artifact {
+            filePath: project.buildDirectory + "/dummy1.final"
+            fileTags: ["final1"]
+        }
+        prepare: {
+            var cmds = [];
+            for (var i = 0; i < 10; ++i) {
+                var cmd = new JavaScriptCommand();
+                cmd.silent = true;
+                cmd.createFile = i == 9;
+                cmd.sourceCode = function() {
+                    if (createFile) {
+                        print("Creating file");
+                        var file = new TextFile(output.filePath, TextFile.WriteOnly);
+                        file.close();
+                    }
+                };
+                cmds.push(cmd);
+            }
+            return cmds;
+        }
+    }
+    Rule {
+        inputs: ["input2"]
+        Artifact {
+            filePath: "dummy.intermediate"
+            fileTags: ["intermediate"]
+        }
+        prepare: {
+            var cmd = new JavaScriptCommand();
+            cmd.silent = true;
+            cmd.sourceCode = function() { };
+            return [cmd];
+        }
+    }
+    Rule {
+        inputs: ["intermediate"]
+        Artifact {
+            filePath: "dummy2.final"
+            fileTags: ["final2"]
+        }
+        prepare: {
+            do
+                Utils.sleep(6000);
+            while (!File.exists(project.buildDirectory + "/dummy1.final"));
+            var cmd = new JavaScriptCommand();
+            cmd.silent = true;
+            cmd.sourceCode = function() { };
+            return [cmd];
+        }
+    }
+}
+
+
diff --git a/tests/auto/blackbox/testdata/concurrent-executor/dummy1.input b/tests/auto/blackbox/testdata/concurrent-executor/dummy1.input
new file mode 100644
index 000000000..e69de29bb
--- /dev/null
+++ b/tests/auto/blackbox/testdata/concurrent-executor/dummy1.input
diff --git a/tests/auto/blackbox/testdata/concurrent-executor/dummy2.input b/tests/auto/blackbox/testdata/concurrent-executor/dummy2.input
new file mode 100644
index 000000000..e69de29bb
--- /dev/null
+++ b/tests/auto/blackbox/testdata/concurrent-executor/dummy2.input
diff --git a/tests/auto/blackbox/testdata/concurrent-executor/util.js b/tests/auto/blackbox/testdata/concurrent-executor/util.js
new file mode 100644
index 000000000..a37a8cbb1
--- /dev/null
+++ b/tests/auto/blackbox/testdata/concurrent-executor/util.js
@@ -0,0 +1,8 @@
+function sleep(timeInMs)
+{
+    var referenceTime = new Date();
+    var time = null;
+    do {
+        time = new Date();
+    } while (time - referenceTime < timeInMs);
+}
diff --git a/tests/auto/blackbox/tst_blackbox.cpp b/tests/auto/blackbox/tst_blackbox.cpp
index 5d801dd86..7723332b2 100644
--- a/tests/auto/blackbox/tst_blackbox.cpp
+++ b/tests/auto/blackbox/tst_blackbox.cpp
@@ -654,6 +654,13 @@ void TestBlackbox::clean()
         QVERIFY2(symlinkExists(symLink), qPrintable(symLink));
 }
 
+void TestBlackbox::concurrentExecutor()
+{
+    QDir::setCurrent(testDataDir + "/concurrent-executor");
+    QCOMPARE(runQbs(QStringList() << "-j" << "2"), 0);
+    QVERIFY2(!m_qbsStderr.contains("ASSERT"), m_qbsStderr.constData());
+}
+
 void TestBlackbox::renameDependency()
 {
     QDir::setCurrent(testDataDir + "/renameDependency");
diff --git a/tests/auto/blackbox/tst_blackbox.h b/tests/auto/blackbox/tst_blackbox.h
index 8d575fdd5..adec827f2 100644
--- a/tests/auto/blackbox/tst_blackbox.h
+++ b/tests/auto/blackbox/tst_blackbox.h
@@ -101,6 +101,7 @@ private slots:
     void changeInDisabledProduct();
     void checkProjectFilePath();
     void clean();
+    void concurrentExecutor();
     void dependenciesProperty();
     void dynamicMultiplexRule();
     void dynamicRuleOutputs();