Merge pull request #7882 from zzmp/fix/script-thread-dtor

Wait and cleanly exit the scripting thread

libraries/entities-renderer/src/EntityTreeRenderer.cpp

@@ -13,6 +13,7 @@
 
 #include <QEventLoop>
 #include <QScriptSyntaxCheckResult>
+#include <QThreadPool>
 
 #include <ColorUtils.h>
 #include <AbstractScriptingServicesInterface.h>
@@ -77,9 +78,30 @@ EntityTreeRenderer::~EntityTreeRenderer() {
 
 int EntityTreeRenderer::_entitiesScriptEngineCount = 0;
 
-void EntityTreeRenderer::setupEntitiesScriptEngine() {
-    QSharedPointer<ScriptEngine> oldEngine = _entitiesScriptEngine; // save the old engine through this function, so the EntityScriptingInterface doesn't have problems with it.
-    _entitiesScriptEngine = QSharedPointer<ScriptEngine>(new ScriptEngine(NO_SCRIPT, QString("Entities %1").arg(++_entitiesScriptEngineCount)), &QObject::deleteLater);
+void entitiesScriptEngineDeleter(ScriptEngine* engine) {
+    class WaitRunnable : public QRunnable {
+        public:
+            WaitRunnable(ScriptEngine* engine) : _engine(engine) {}
+            virtual void run() override {
+                _engine->waitTillDoneRunning();
+                _engine->deleteLater();
+            }
+
+        private:
+            ScriptEngine* _engine;
+    };
+
+    // Wait for the scripting thread from the thread pool to avoid hanging the main thread
+    QThreadPool::globalInstance()->start(new WaitRunnable(engine));
+}
+
+void EntityTreeRenderer::resetEntitiesScriptEngine() {
+    // Keep a ref to oldEngine until newEngine is ready so EntityScriptingInterface has something to use
+    auto oldEngine = _entitiesScriptEngine;
+
+    auto newEngine = new ScriptEngine(NO_SCRIPT, QString("Entities %1").arg(++_entitiesScriptEngineCount));
+    _entitiesScriptEngine = QSharedPointer<ScriptEngine>(newEngine, entitiesScriptEngineDeleter);
+
     _scriptingServices->registerScriptEngineWithApplicationServices(_entitiesScriptEngine.data());
     _entitiesScriptEngine->runInThread();
     DependencyManager::get<EntityScriptingInterface>()->setEntitiesScriptEngine(_entitiesScriptEngine.data());
@@ -87,16 +109,16 @@ void EntityTreeRenderer::setupEntitiesScriptEngine() {
 
 void EntityTreeRenderer::clear() {
     leaveAllEntities();
+
     if (_entitiesScriptEngine) {
+        // Unload and stop the engine here (instead of in its deleter) to
+        // avoid marshalling unload signals back to this thread
         _entitiesScriptEngine->unloadAllEntityScripts();
         _entitiesScriptEngine->stop();
     }
 
     if (_wantScripts && !_shuttingDown) {
-        // NOTE: you can't actually need to delete it here because when we call setupEntitiesScriptEngine it will
-        //       assign a new instance to our shared pointer, which will deref the old instance and ultimately call
-        //       the custom deleter which calls deleteLater
-        setupEntitiesScriptEngine();
+        resetEntitiesScriptEngine();
     }
 
     auto scene = _viewState->getMain3DScene();
@@ -125,7 +147,7 @@ void EntityTreeRenderer::init() {
     entityTree->setFBXService(this);
 
     if (_wantScripts) {
-        setupEntitiesScriptEngine();
+        resetEntitiesScriptEngine();
     }
 
     forceRecheckEntities(); // setup our state to force checking our inside/outsideness of entities

libraries/entities-renderer/src/EntityTreeRenderer.h

@@ -126,7 +126,7 @@ protected:
     }
 
 private:
-    void setupEntitiesScriptEngine();
+    void resetEntitiesScriptEngine();
 
     void addEntityToScene(EntityItemPointer entity);
     bool findBestZoneAndMaybeContainingEntities(const glm::vec3& avatarPosition, QVector<EntityItemID>* entitiesContainingAvatar);

libraries/script-engine/src/ScriptEngine.cpp

@@ -136,10 +136,9 @@ static bool hadUncaughtExceptions(QScriptEngine& engine, const QString& fileName
     return false;
 }
 
-ScriptEngine::ScriptEngine(const QString& scriptContents, const QString& fileNameString, bool wantSignals) :
+ScriptEngine::ScriptEngine(const QString& scriptContents, const QString& fileNameString) :
     _scriptContents(scriptContents),
     _timerFunctionMap(),
-    _wantSignals(wantSignals),
     _fileNameString(fileNameString),
     _arrayBufferClass(new ArrayBufferClass(this))
 {
@@ -153,7 +152,7 @@ ScriptEngine::ScriptEngine(const QString& scriptContents, const QString& fileNam
 }
 
 ScriptEngine::~ScriptEngine() {
-    qCDebug(scriptengine) << "Script Engine shutting down (destructor) for script:" << getFilename();
+    qCDebug(scriptengine) << "Script Engine shutting down:" << getFilename();
 
     auto scriptEngines = DependencyManager::get<ScriptEngines>();
     if (scriptEngines) {
@@ -161,16 +160,15 @@ ScriptEngine::~ScriptEngine() {
     } else {
         qCWarning(scriptengine) << "Script destroyed after ScriptEngines!";
     }
-
-    waitTillDoneRunning();
 }
 
 void ScriptEngine::disconnectNonEssentialSignals() {
     disconnect();
-    QThread* receiver;
+    QThread* workerThread;
     // Ensure the thread should be running, and does exist
-    if (_isRunning && _isThreaded && (receiver = thread())) {
-        connect(this, &ScriptEngine::doneRunning, receiver, &QThread::quit);
+    if (_isRunning && _isThreaded && (workerThread = thread())) {
+        connect(this, &ScriptEngine::doneRunning, workerThread, &QThread::quit);
+        connect(workerThread, &QThread::finished, workerThread, &QObject::deleteLater);
     }
 }
 
@@ -229,15 +227,14 @@ void ScriptEngine::runDebuggable() {
                 return;
             }
             stopAllTimers(); // make sure all our timers are stopped if the script is ending
-            if (_wantSignals) {
-                emit scriptEnding();
-                emit finished(_fileNameString, this);
-            }
+
+            emit scriptEnding();
+            emit finished(_fileNameString, this);
             _isRunning = false;
-            if (_wantSignals) {
-                emit runningStateChanged();
-                emit doneRunning();
-            }
+
+            emit runningStateChanged();
+            emit doneRunning();
+
             timer->deleteLater();
             return;
         }
@@ -247,9 +244,7 @@ void ScriptEngine::runDebuggable() {
         if (_lastUpdate < now) {
             float deltaTime = (float)(now - _lastUpdate) / (float)USECS_PER_SECOND;
             if (!_isFinished) {
-                if (_wantSignals) {
-                    emit update(deltaTime);
-                }
+                emit update(deltaTime);
             }
         }
         _lastUpdate = now;
@@ -270,57 +265,72 @@ void ScriptEngine::runInThread() {
     }
 
     _isThreaded = true;
-    QThread* workerThread = new QThread();
-    QString scriptEngineName = QString("Script Thread:") + getFilename();
-    workerThread->setObjectName(scriptEngineName);
 
+    // The thread interface cannot live on itself, and we want to move this into the thread, so
+    // the thread cannot have this as a parent.
+    QThread* workerThread = new QThread();
+    workerThread->setObjectName(QString("Script Thread:") + getFilename());
+    moveToThread(workerThread);
+    
     // NOTE: If you connect any essential signals for proper shutdown or cleanup of
     // the script engine, make sure to add code to "reconnect" them to the
     // disconnectNonEssentialSignals() method
-
-    // when the worker thread is started, call our engine's run..
     connect(workerThread, &QThread::started, this, &ScriptEngine::run);
-
-    // tell the thread to stop when the script engine is done
     connect(this, &ScriptEngine::doneRunning, workerThread, &QThread::quit);
+    connect(workerThread, &QThread::finished, workerThread, &QObject::deleteLater);
 
-    moveToThread(workerThread);
-
-    // Starts an event loop, and emits workerThread->started()
     workerThread->start();
 }
 
 void ScriptEngine::waitTillDoneRunning() {
-    // If the script never started running or finished running before we got here, we don't need to wait for it
     auto workerThread = thread();
-    if (_isThreaded && workerThread) {
-        QString scriptName = getFilename();
-        auto startedWaiting = usecTimestampNow();
 
+    if (_isThreaded && workerThread) {
+        // We should never be waiting (blocking) on our own thread
+        assert(workerThread != QThread::currentThread());
+
+        // Engine should be stopped already, but be defensive
+        stop();
+
+        auto startedWaiting = usecTimestampNow();
         while (workerThread->isRunning()) {
             // NOTE: This will be called on the main application thread from stopAllScripts.
             //       The application thread will need to continue to process events, because
             //       the scripts will likely need to marshall messages across to the main thread, e.g.
             //       if they access Settings or Menu in any of their shutdown code. So:
             // Process events for the main application thread, allowing invokeMethod calls to pass between threads.
-            QCoreApplication::processEvents(); // thread-safe :)
+            QCoreApplication::processEvents();
 
-            // If we've been waiting a second or more, then tell the script engine to stop evaluating
-            static const auto MAX_SCRIPT_EVALUATION_TIME =  USECS_PER_SECOND;
+            // If the final evaluation takes too long, then tell the script engine to stop running
             auto elapsedUsecs = usecTimestampNow() - startedWaiting;
+            static const auto MAX_SCRIPT_EVALUATION_TIME = USECS_PER_SECOND;
             if (elapsedUsecs > MAX_SCRIPT_EVALUATION_TIME) {
-                qCDebug(scriptengine) <<
-                    "Script " << scriptName << " has been running too long [" << elapsedUsecs << " usecs] quitting.";
-                abortEvaluation(); // to allow the thread to quit
                 workerThread->quit();
-                break;
+
+                if (isEvaluating()) {
+                    qCWarning(scriptengine) << "Script Engine has been running too long, aborting:" << getFilename();
+                    abortEvaluation();
+                } else {
+                    qCWarning(scriptengine) << "Script Engine has been running too long, throwing:" << getFilename();
+                    auto context = currentContext();
+                    if (context) {
+                        context->throwError("Timed out during shutdown");
+                    }
+                }
+
+                // Wait for the scripting thread to stop running, as
+                // flooding it with aborts/exceptions will persist it longer
+                static const auto MAX_SCRIPT_QUITTING_TIME = 0.5 * MSECS_PER_SECOND;
+                if (workerThread->wait(MAX_SCRIPT_QUITTING_TIME)) {
+                    workerThread->terminate();
+                }
             }
 
             // Avoid a pure busy wait
             QThread::yieldCurrentThread();
         }
 
-        workerThread->deleteLater();
+        qCDebug(scriptengine) << "Script Engine has stopped:" << getFilename();
     }
 }
 
@@ -356,17 +366,13 @@ void ScriptEngine::scriptContentsAvailable(const QUrl& url, const QString& scrip
     if (QRegularExpression(DEBUG_FLAG).match(scriptContents).hasMatch()) {
         _debuggable = true;
     }
-    if (_wantSignals) {
-        emit scriptLoaded(url.toString());
-    }
+    emit scriptLoaded(url.toString());
 }
 
 // FIXME - switch this to the new model of ScriptCache callbacks
 void ScriptEngine::errorInLoadingScript(const QUrl& url) {
     qCDebug(scriptengine) << "ERROR Loading file:" << url.toString() << "line:" << __LINE__;
-    if (_wantSignals) {
-        emit errorLoadingScript(_fileNameString); // ??
-    }
+    emit errorLoadingScript(_fileNameString); // ??
 }
 
 // Even though we never pass AnimVariantMap directly to and from javascript, the queued invokeMethod of
@@ -783,9 +789,7 @@ QScriptValue ScriptEngine::evaluate(const QString& sourceCode, const QString& fi
     --_evaluatesPending;
 
     const auto hadUncaughtException = hadUncaughtExceptions(*this, program.fileName());
-    if (_wantSignals) {
-        emit evaluationFinished(result, hadUncaughtException);
-    }
+    emit evaluationFinished(result, hadUncaughtException);
     return result;
 }
 
@@ -799,9 +803,7 @@ void ScriptEngine::run() {
     }
 
     _isRunning = true;
-    if (_wantSignals) {
-        emit runningStateChanged();
-    }
+    emit runningStateChanged();
 
     QScriptValue result = evaluate(_scriptContents, _fileNameString);
 
@@ -870,9 +872,7 @@ void ScriptEngine::run() {
         if (_lastUpdate < now) {
             float deltaTime = (float) (now - _lastUpdate) / (float) USECS_PER_SECOND;
             if (!_isFinished) {
-                if (_wantSignals) {
-                    emit update(deltaTime);
-                }
+                emit update(deltaTime);
             }
         }
         _lastUpdate = now;
@@ -881,10 +881,10 @@ void ScriptEngine::run() {
         hadUncaughtExceptions(*this, _fileNameString);
     }
 
+    qCDebug(scriptengine) << "Script Engine stopping:" << getFilename();
+
     stopAllTimers(); // make sure all our timers are stopped if the script is ending
-    if (_wantSignals) {
-        emit scriptEnding();
-    }
+    emit scriptEnding();
 
     if (entityScriptingInterface->getEntityPacketSender()->serversExist()) {
         // release the queue of edit entity messages.
@@ -902,15 +902,11 @@ void ScriptEngine::run() {
         }
     }
 
-    if (_wantSignals) {
-        emit finished(_fileNameString, this);
-    }
+    emit finished(_fileNameString, this);
 
     _isRunning = false;
-    if (_wantSignals) {
-        emit runningStateChanged();
-        emit doneRunning();
-    }
+    emit runningStateChanged();
+    emit doneRunning();
 }
 
 // NOTE: This is private because it must be called on the same thread that created the timers, which is why
@@ -943,14 +939,8 @@ void ScriptEngine::stopAllTimersForEntityScript(const EntityItemID& entityID) {
 
 void ScriptEngine::stop() {
     if (!_isFinished) {
-        if (QThread::currentThread() != thread()) {
-            QMetaObject::invokeMethod(this, "stop");
-            return;
-        }
         _isFinished = true;
-        if (_wantSignals) {
-            emit runningStateChanged();
-        }
+        emit runningStateChanged();
     }
 }
 
@@ -1074,9 +1064,7 @@ QUrl ScriptEngine::resolvePath(const QString& include) const {
 }
 
 void ScriptEngine::print(const QString& message) {
-    if (_wantSignals) {
-        emit printedMessage(message);
-    }
+    emit printedMessage(message);
 }
 
 // If a callback is specified, the included files will be loaded asynchronously and the callback will be called
@@ -1212,13 +1200,9 @@ void ScriptEngine::load(const QString& loadFile) {
     if (_isReloading) {
         auto scriptCache = DependencyManager::get<ScriptCache>();
         scriptCache->deleteScript(url.toString());
-        if (_wantSignals) {
-            emit reloadScript(url.toString(), false);
-        }
+        emit reloadScript(url.toString(), false);
     } else {
-        if (_wantSignals) {
-            emit loadScript(url.toString(), false);
-        }
+        emit loadScript(url.toString(), false);
     }
 }
 
@@ -1307,8 +1291,23 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co
         setParentURL(scriptOrURL);
     }
 
+    const int SANDBOX_TIMEOUT = 0.25 * MSECS_PER_SECOND;
     QScriptEngine sandbox;
-    QScriptValue testConstructor = sandbox.evaluate(program);
+    sandbox.setProcessEventsInterval(SANDBOX_TIMEOUT);
+    QScriptValue testConstructor;
+    {
+        QTimer timeout;
+        timeout.setSingleShot(true);
+        timeout.start(SANDBOX_TIMEOUT);
+        connect(&timeout, &QTimer::timeout, [&sandbox, SANDBOX_TIMEOUT]{
+            auto context = sandbox.currentContext();
+            if (context) {
+                // Guard against infinite loops and non-performant code
+                context->throwError(QString("Timed out (entity constructors are limited to %1ms)").arg(SANDBOX_TIMEOUT));
+            }
+        });
+        testConstructor = sandbox.evaluate(program);
+    }
     if (hadUncaughtExceptions(sandbox, program.fileName())) {
         return;
     }

libraries/script-engine/src/ScriptEngine.h

@@ -67,10 +67,7 @@ public:
 class ScriptEngine : public QScriptEngine, public ScriptUser, public EntitiesScriptEngineProvider {
     Q_OBJECT
 public:
-    ScriptEngine(const QString& scriptContents = NO_SCRIPT,
-                 const QString& fileNameString = QString(""),
-                 bool wantSignals = true);
-
+    ScriptEngine(const QString& scriptContents = NO_SCRIPT, const QString& fileNameString = QString(""));
     ~ScriptEngine();
 
     /// run the script in a dedicated thread. This will have the side effect of evalulating
@@ -83,10 +80,15 @@ public:
     /// run the script in the callers thread, exit when stop() is called.
     void run();
 
-    void waitTillDoneRunning();
-
     QString getFilename() const;
 
+    ////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
+    // NOTE - this is intended to be a public interface for Agent scripts, and local scripts, but not for EntityScripts
+    Q_INVOKABLE void stop();
+
+    // Stop any evaluating scripts and wait for the scripting thread to finish.
+    void waitTillDoneRunning();
+
     ////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
     // NOTE - these are NOT intended to be public interfaces available to scripts, the are only Q_INVOKABLE so we can
     //        properly ensure they are only called on the correct thread
@@ -142,10 +144,6 @@ public:
 
     Q_INVOKABLE void requestGarbageCollection() { collectGarbage(); }
 
-    ////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
-    // NOTE - this is intended to be a public interface for Agent scripts, and local scripts, but not for EntityScripts
-    Q_INVOKABLE void stop();
-
     bool isFinished() const { return _isFinished; } // used by Application and ScriptWidget
     bool isRunning() const { return _isRunning; } // used by ScriptWidget
 
@@ -195,7 +193,6 @@ protected:
     bool _isInitialized { false };
     QHash<QTimer*, CallbackData> _timerFunctionMap;
     QSet<QUrl> _includedURLs;
-    bool _wantSignals { true };
     QHash<EntityItemID, EntityScriptDetails> _entityScripts;
     bool _isThreaded { false };
     QScriptEngineDebugger* _debugger { nullptr };
@@ -203,6 +200,7 @@ protected:
     qint64 _lastUpdate;
 
     void init();
+
     bool evaluatePending() const { return _evaluatesPending > 0; }
     void timerFired();
     void stopAllTimers();

libraries/script-engine/src/ScriptEngines.cpp

@@ -150,6 +150,7 @@ void ScriptEngines::shutdownScripting() {
         // NOTE: typically all script engines are running. But there's at least one known exception to this, the
         // "entities sandbox" which is only used to evaluate entities scripts to test their validity before using
         // them. We don't need to stop scripts that aren't running.
+        // TODO: Scripts could be shut down faster if we spread them across a threadpool.
         if (scriptEngine->isRunning()) {
             qCDebug(scriptengine) << "about to shutdown script:" << scriptName;
 
@@ -158,8 +159,7 @@ void ScriptEngines::shutdownScripting() {
             // and stop. We can safely short circuit this because we know we're in the "quitting" process
             scriptEngine->disconnect(this);
 
-            // Calling stop on the script engine will set it's internal _isFinished state to true, and result
-            // in the ScriptEngine gracefully ending it's run() method.
+            // Gracefully stop the engine's scripting thread
             scriptEngine->stop();
 
             // We need to wait for the engine to be done running before we proceed, because we don't
@@ -171,7 +171,7 @@ void ScriptEngines::shutdownScripting() {
 
             scriptEngine->deleteLater();
 
-            // If the script is stopped, we can remove it from our set
+            // Once the script is stopped, we can remove it from our set
             i.remove();
         }
     }
@@ -427,7 +427,7 @@ ScriptEngine* ScriptEngines::loadScript(const QUrl& scriptFilename, bool isUserL
         return scriptEngine;
     }
 
-    scriptEngine = new ScriptEngine(NO_SCRIPT, "", true);
+    scriptEngine = new ScriptEngine(NO_SCRIPT, "");
     scriptEngine->setUserLoaded(isUserLoaded);
     connect(scriptEngine, &ScriptEngine::doneRunning, this, [scriptEngine] {
         scriptEngine->deleteLater();