From b15956278c680bf94c38dbd3b8a259f0fc431d4b Mon Sep 17 00:00:00 2001 From: humbletim Date: Thu, 16 Feb 2017 07:32:32 -0500 Subject: [PATCH 01/17] separate out supporting changes into 21114-part2 branch --- .../src/scripts/EntityScriptServer.cpp | 4 +- .../src/EntityTreeRenderer.cpp | 6 +- .../script-engine/src/BaseScriptEngine.cpp | 321 +++++++++++ .../script-engine/src/BaseScriptEngine.h | 86 +++ libraries/script-engine/src/ScriptCache.h | 3 + libraries/script-engine/src/ScriptEngine.cpp | 535 +++++++++++------- libraries/script-engine/src/ScriptEngine.h | 36 +- libraries/script-engine/src/ScriptEngines.cpp | 35 +- libraries/shared/src/PathUtils.cpp | 27 +- libraries/shared/src/PathUtils.h | 5 + 10 files changed, 834 insertions(+), 224 deletions(-) create mode 100644 libraries/script-engine/src/BaseScriptEngine.cpp create mode 100644 libraries/script-engine/src/BaseScriptEngine.h diff --git a/assignment-client/src/scripts/EntityScriptServer.cpp b/assignment-client/src/scripts/EntityScriptServer.cpp index 930b3946c6..866efa6328 100644 --- a/assignment-client/src/scripts/EntityScriptServer.cpp +++ b/assignment-client/src/scripts/EntityScriptServer.cpp @@ -395,7 +395,7 @@ void EntityScriptServer::selectAudioFormat(const QString& selectedCodecName) { } void EntityScriptServer::resetEntitiesScriptEngine() { - auto engineName = QString("Entities %1").arg(++_entitiesScriptEngineCount); + auto engineName = QString("about:Entities %1").arg(++_entitiesScriptEngineCount); auto newEngine = QSharedPointer(new ScriptEngine(ScriptEngine::ENTITY_SERVER_SCRIPT, NO_SCRIPT, engineName)); auto webSocketServerConstructorValue = newEngine->newFunction(WebSocketServerClass::constructor); @@ -477,7 +477,7 @@ void EntityScriptServer::checkAndCallPreload(const EntityItemID& entityID, const if (!scriptUrl.isEmpty()) { scriptUrl = ResourceManager::normalizeURL(scriptUrl); qCDebug(entity_script_server) << "Loading entity server script" << scriptUrl << "for" << entityID; - ScriptEngine::loadEntityScript(_entitiesScriptEngine, entityID, scriptUrl, reload); + _entitiesScriptEngine->loadEntityScript(entityID, scriptUrl, reload); } } } diff --git a/libraries/entities-renderer/src/EntityTreeRenderer.cpp b/libraries/entities-renderer/src/EntityTreeRenderer.cpp index 1265aabbf2..ff39536923 100644 --- a/libraries/entities-renderer/src/EntityTreeRenderer.cpp +++ b/libraries/entities-renderer/src/EntityTreeRenderer.cpp @@ -101,7 +101,7 @@ 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(ScriptEngine::ENTITY_CLIENT_SCRIPT, NO_SCRIPT, QString("Entities %1").arg(++_entitiesScriptEngineCount)); + auto newEngine = new ScriptEngine(ScriptEngine::ENTITY_CLIENT_SCRIPT, NO_SCRIPT, QString("about:Entities %1").arg(++_entitiesScriptEngineCount)); _entitiesScriptEngine = QSharedPointer(newEngine, entitiesScriptEngineDeleter); _scriptingServices->registerScriptEngineWithApplicationServices(_entitiesScriptEngine.data()); @@ -148,7 +148,7 @@ void EntityTreeRenderer::reloadEntityScripts() { _entitiesScriptEngine->unloadAllEntityScripts(); foreach(auto entity, _entitiesInScene) { if (!entity->getScript().isEmpty()) { - ScriptEngine::loadEntityScript(_entitiesScriptEngine, entity->getEntityItemID(), entity->getScript(), true); + _entitiesScriptEngine->loadEntityScript(entity->getEntityItemID(), entity->getScript(), true); } } } @@ -950,7 +950,7 @@ void EntityTreeRenderer::checkAndCallPreload(const EntityItemID& entityID, const if (entity && entity->shouldPreloadScript() && _entitiesScriptEngine) { QString scriptUrl = entity->getScript(); scriptUrl = ResourceManager::normalizeURL(scriptUrl); - ScriptEngine::loadEntityScript(_entitiesScriptEngine, entityID, scriptUrl, reload); + _entitiesScriptEngine->loadEntityScript(entityID, scriptUrl, reload); entity->scriptHasPreloaded(); } } diff --git a/libraries/script-engine/src/BaseScriptEngine.cpp b/libraries/script-engine/src/BaseScriptEngine.cpp new file mode 100644 index 0000000000..4342205414 --- /dev/null +++ b/libraries/script-engine/src/BaseScriptEngine.cpp @@ -0,0 +1,321 @@ +// +// BaseScriptEngine.cpp +// libraries/script-engine/src +// +// Created by Timothy Dedischew on 02/01/17. +// Copyright 2017 High Fidelity, Inc. +// +// Distributed under the Apache License, Version 2.0. +// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html +// + +#include "BaseScriptEngine.h" + +#include +#include +#include +#include +#include +#include + +#include "ScriptEngineLogging.h" +#include "Profile.h" + +const QString BaseScriptEngine::_SETTINGS_ENABLE_EXTENDED_EXCEPTIONS { + "com.highfidelity.experimental.enableExtendedJSExceptions" +}; + +const QString BaseScriptEngine::SCRIPT_EXCEPTION_FORMAT { "[%0] %1 in %2:%3" }; +const QString BaseScriptEngine::SCRIPT_BACKTRACE_SEP { "\n " }; + +// engine-aware JS Error copier and factory +QScriptValue BaseScriptEngine::makeError(const QScriptValue& _other, const QString& type) { + auto other = _other; + if (other.isString()) { + other = newObject(); + other.setProperty("message", _other.toString()); + } + auto proto = globalObject().property(type); + if (!proto.isFunction()) { + proto = globalObject().property(other.prototype().property("constructor").property("name").toString()); + } + if (!proto.isFunction()) { +#ifdef DEBUG_JS_EXCEPTIONS + qCDebug(scriptengine) << "BaseScriptEngine::makeError -- couldn't find constructor for" << type << " -- using Error instead"; +#endif + proto = globalObject().property("Error"); + } + if (other.engine() != this) { + // JS Objects are parented to a specific script engine instance + // -- this effectively ~clones it locally by routing through a QVariant and back + other = toScriptValue(other.toVariant()); + } + // ~ var err = new Error(other.message) + auto err = proto.construct(QScriptValueList({other.property("message")})); + + // transfer over any existing properties + QScriptValueIterator it(other); + while (it.hasNext()) { + it.next(); + err.setProperty(it.name(), it.value()); + } + return err; +} + +// check syntax and when there are issues returns an actual "SyntaxError" with the details +QScriptValue BaseScriptEngine::lintScript(const QString& sourceCode, const QString& fileName, const int lineNumber) { + const auto syntaxCheck = checkSyntax(sourceCode); + if (syntaxCheck.state() != QScriptSyntaxCheckResult::Valid) { + auto err = globalObject().property("SyntaxError") + .construct(QScriptValueList({syntaxCheck.errorMessage()})); + err.setProperty("fileName", fileName); + err.setProperty("lineNumber", syntaxCheck.errorLineNumber()); + err.setProperty("expressionBeginOffset", syntaxCheck.errorColumnNumber()); + err.setProperty("stack", currentContext()->backtrace().join(SCRIPT_BACKTRACE_SEP)); + { + const auto error = syntaxCheck.errorMessage(); + const auto line = QString::number(syntaxCheck.errorLineNumber()); + const auto column = QString::number(syntaxCheck.errorColumnNumber()); + // for compatibility with legacy reporting + const auto message = QString("[SyntaxError] %1 in %2:%3(%4)").arg(error, fileName, line, column); + err.setProperty("formatted", message); + } + return err; + } + return undefinedValue(); +} + +// this pulls from the best available information to create a detailed snapshot of the current exception +QScriptValue BaseScriptEngine::cloneUncaughtException(const QString& extraDetail) { + if (!hasUncaughtException()) { + return QScriptValue(); + } + auto exception = uncaughtException(); + // ensure the error object is engine-local + auto err = makeError(exception); + + // not sure why Qt does't offer uncaughtExceptionFileName -- but the line number + // on its own is often useless/wrong if arbitrarily married to a filename. + // when the error object already has this info, it seems to be the most reliable + auto fileName = exception.property("fileName").toString(); + auto lineNumber = exception.property("lineNumber").toInt32(); + + // the backtrace, on the other hand, seems most reliable taken from uncaughtExceptionBacktrace + auto backtrace = uncaughtExceptionBacktrace(); + if (backtrace.isEmpty()) { + // fallback to the error object + backtrace = exception.property("stack").toString().split(SCRIPT_BACKTRACE_SEP); + } + // the ad hoc "detail" property can be used now to embed additional clues + auto detail = exception.property("detail").toString(); + if (detail.isEmpty()) { + detail = extraDetail; + } else if (!extraDetail.isEmpty()) { + detail += "(" + extraDetail + ")"; + } + if (lineNumber <= 0) { + lineNumber = uncaughtExceptionLineNumber(); + } + if (fileName.isEmpty()) { + // climb the stack frames looking for something useful to display + for(auto ctx = currentContext(); ctx && fileName.isEmpty(); ctx = ctx->parentContext()) { + QScriptContextInfo info { ctx }; + if (!info.fileName().isEmpty()) { + // take fileName:lineNumber as a pair + fileName = info.fileName(); + lineNumber = info.lineNumber(); + if (backtrace.isEmpty()) { + backtrace = ctx->backtrace(); + } + break; + } + } + } + err.setProperty("fileName", fileName); + err.setProperty("lineNumber", lineNumber ); + err.setProperty("detail", detail); + err.setProperty("stack", backtrace.join(SCRIPT_BACKTRACE_SEP)); + +#ifdef DEBUG_JS_EXCEPTIONS + err.setProperty("_fileName", exception.property("fileName").toString()); + err.setProperty("_stack", uncaughtExceptionBacktrace().join(SCRIPT_BACKTRACE_SEP)); + err.setProperty("_lineNumber", uncaughtExceptionLineNumber()); +#endif + return err; +} + +QString BaseScriptEngine::formatException(const QScriptValue& exception) { + QString note { "UncaughtException" }; + QString result; + + if (!exception.isObject()) { + return result; + } + const auto message = exception.toString(); + const auto fileName = exception.property("fileName").toString(); + const auto lineNumber = exception.property("lineNumber").toString(); + const auto stacktrace = exception.property("stack").toString(); + + if (_enableExtendedJSExceptions.get()) { + // This setting toggles display of the hints now being added during the loading process. + // Example difference: + // [UncaughtExceptions] Error: Can't find variable: foobar in atp:/myentity.js\n... + // [UncaughtException (construct {1eb5d3fa-23b1-411c-af83-163af7220e3f})] Error: Can't find variable: foobar in atp:/myentity.js\n... + if (exception.property("detail").isValid()) { + note += " " + exception.property("detail").toString(); + } + } + + result = QString(SCRIPT_EXCEPTION_FORMAT).arg(note, message, fileName, lineNumber); + if (!stacktrace.isEmpty()) { + result += QString("\n[Backtrace]%1%2").arg(SCRIPT_BACKTRACE_SEP).arg(stacktrace); + } + return result; +} + +QScriptValue BaseScriptEngine::evaluateInClosure(const QScriptValue& closure, const QScriptProgram& program) { + PROFILE_RANGE(script, "evaluateInClosure"); + if (QThread::currentThread() != thread()) { + qCCritical(scriptengine) << "*** CRITICAL *** ScriptEngine::evaluateInClosure() is meant to be called from engine thread only."; + // note: a recursive mutex might be needed around below code if this method ever becomes Q_INVOKABLE + return QScriptValue(); + } + + //_debugDump("evaluateInClosure.closure", closure); + + const auto fileName = program.fileName(); + const auto shortName = QUrl(fileName).fileName(); + + QScriptValue result; + QScriptValue oldGlobal; + auto global = closure.property("global"); + if (global.isObject()) { +#ifdef DEBUG_JS + qCDebug(scriptengine) << " setting global = closure.global" << shortName; +#endif + oldGlobal = globalObject(); + setGlobalObject(global); + } + + auto ctx = pushContext(); + + auto thiz = closure.property("this"); + if (thiz.isObject()) { +#ifdef DEBUG_JS + qCDebug(scriptengine) << " setting this = closure.this" << shortName; +#endif + ctx->setThisObject(thiz); + } + + ctx->pushScope(closure); +#ifdef DEBUG_JS + qCDebug(scriptengine) << QString("[%1] evaluateInClosure %2").arg(isEvaluating()).arg(shortName); +#endif + { + ExceptionEmitter tryCatch(this, __FUNCTION__); + result = BaseScriptEngine::evaluate(program); + if (tryCatch.hasPending()) { + auto err = tryCatch.pending(); +#ifdef DEBUG_JS_EXCEPTIONS + qCWarning(scriptengine) << __FUNCTION__ << "---------- hasCaught:" << err.toString() << result.toString(); + err.setProperty("_result", result); +#endif + result = err; + } + } +#ifdef DEBUG_JS + qCDebug(scriptengine) << QString("[%1] //evaluateInClosure %2").arg(isEvaluating()).arg(shortName); +#endif + popContext(); + + if (oldGlobal.isValid()) { +#ifdef DEBUG_JS + qCDebug(scriptengine) << " restoring global" << shortName; +#endif + setGlobalObject(oldGlobal); + } + + return result; +} + +// Lambda + +QScriptValue BaseScriptEngine::newLambdaFunction(std::function operation, const QScriptValue& data, const QScriptEngine::ValueOwnership& ownership) { + auto lambda = new Lambda(this, operation, data); + auto object = newQObject(lambda, ownership); + auto call = object.property("call"); + call.setPrototype(object); // ctx->callee().prototype() === Lambda QObject + call.setData(data); // ctx->callee().data() will === data param + return call; +} +QString Lambda::toString() const { + return QString("[Lambda%1]").arg(data.isValid() ? " " + data.toString() : data.toString()); +} + +Lambda::~Lambda() { +#ifdef DEBUG_JS_LAMBDA_FUNCS + qDebug() << "~Lambda" << "this" << this; +#endif +} + +Lambda::Lambda(QScriptEngine *engine, std::function operation, QScriptValue data) + : engine(engine), operation(operation), data(data) { +#ifdef DEBUG_JS_LAMBDA_FUNCS + qDebug() << "Lambda" << data.toString(); +#endif +} +QScriptValue Lambda::call() { + return operation(engine->currentContext(), engine); +} + +// BaseScriptEngine::ExceptionEmitter + +void BaseScriptEngine::_emitUnhandledException(const QScriptValue& exception) { + emit unhandledException(exception); +} +BaseScriptEngine::ExceptionEmitter::ExceptionEmitter(BaseScriptEngine* engine, const QString& debugName) + : _engine(engine), _debugName(debugName) { +} +bool BaseScriptEngine::ExceptionEmitter::hasPending() { + return _engine->hasUncaughtException(); +} +QScriptValue BaseScriptEngine::ExceptionEmitter::pending() { + return _engine->cloneUncaughtException(_debugName); +} +QScriptValue BaseScriptEngine::ExceptionEmitter::consume() { + if (hasPending()) { + _consumedException = pending(); + _engine->clearExceptions(); + } + return _consumedException; +} +bool BaseScriptEngine::ExceptionEmitter::wouldEmit() { + return !_engine->isEvaluating() && _engine->hasUncaughtException(); +} +BaseScriptEngine::ExceptionEmitter::~ExceptionEmitter() { + if (wouldEmit()) { + _engine->_emitUnhandledException(consume()); + } +} + + +#ifdef DEBUG_JS +void BaseScriptEngine::_debugDump(const QString& header, const QScriptValue& object, const QString& footer) { + if (!header.isEmpty()) { + qCDebug(scriptengine) << header; + } + if (!object.isObject()) { + qCDebug(scriptengine) << "(!isObject)" << object.toVariant().toString() << object.toString(); + return; + } + QScriptValueIterator it(object); + while (it.hasNext()) { + it.next(); + qCDebug(scriptengine) << it.name() << ":" << it.value().toString(); + } + if (!footer.isEmpty()) { + qCDebug(scriptengine) << footer; + } +} +#endif + diff --git a/libraries/script-engine/src/BaseScriptEngine.h b/libraries/script-engine/src/BaseScriptEngine.h new file mode 100644 index 0000000000..3ff4c22e4b --- /dev/null +++ b/libraries/script-engine/src/BaseScriptEngine.h @@ -0,0 +1,86 @@ +// +// BaseScriptEngine.h +// libraries/script-engine/src +// +// Created by Timothy Dedischew on 02/01/17. +// Copyright 2017 High Fidelity, Inc. +// +// Distributed under the Apache License, Version 2.0. +// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html +// + +#ifndef hifi_BaseScriptEngine_h +#define hifi_BaseScriptEngine_h + +#include +#include +#include + +#include "SettingHandle.h" + +// common base class for extending QScriptEngine itself +class BaseScriptEngine : public QScriptEngine { + Q_OBJECT +public: + static const QString SCRIPT_EXCEPTION_FORMAT; + static const QString SCRIPT_BACKTRACE_SEP; + + BaseScriptEngine() {} + + Q_INVOKABLE QScriptValue evaluateInClosure(const QScriptValue& locals, const QScriptProgram& program); + + Q_INVOKABLE QScriptValue lintScript(const QString& sourceCode, const QString& fileName, const int lineNumber = 1); + Q_INVOKABLE QScriptValue makeError(const QScriptValue& other = QScriptValue(), const QString& type = "Error"); + Q_INVOKABLE QString formatException(const QScriptValue& exception); + QScriptValue cloneUncaughtException(const QString& detail = QString()); + +signals: + void unhandledException(const QScriptValue& exception); + +protected: + void _emitUnhandledException(const QScriptValue& exception); + QScriptValue newLambdaFunction(std::function operation, const QScriptValue& data = QScriptValue(), const QScriptEngine::ValueOwnership& ownership = QScriptEngine::AutoOwnership); + + static const QString _SETTINGS_ENABLE_EXTENDED_EXCEPTIONS; + Setting::Handle _enableExtendedJSExceptions { _SETTINGS_ENABLE_EXTENDED_EXCEPTIONS, true }; +#ifdef DEBUG_JS + static void _debugDump(const QString& header, const QScriptValue& object, const QString& footer = QString()); +#endif + + // ExceptionEmitter can be placed above calls that might throw JS exceptions and it'll + // automatically signal BaseScriptEngine when falling out of scope (recursion aware). + class ExceptionEmitter { + public: + ExceptionEmitter(BaseScriptEngine* engine, const QString& debugName = QString()); + // is there a pending exception? + bool hasPending(); + QScriptValue pending(); + // would it be emitted at scope's end? + bool wouldEmit(); + // consume and return the pending exception + QScriptValue consume(); + ~ExceptionEmitter(); + protected: + BaseScriptEngine* _engine; + QString _debugName; + QScriptValue _consumedException; + }; +}; + +// Lambda helps create callable QScriptValues out of std::functions: +// (just meant for use from within the script engine itself) +class Lambda : public QObject { + Q_OBJECT +public: + Lambda(QScriptEngine *engine, std::function operation, QScriptValue data); + ~Lambda(); + public slots: + QScriptValue call(); + QString toString() const; +private: + QScriptEngine* engine; + std::function operation; + QScriptValue data; +}; + +#endif // hifi_BaseScriptEngine_h diff --git a/libraries/script-engine/src/ScriptCache.h b/libraries/script-engine/src/ScriptCache.h index 6cc318cc15..511d392409 100644 --- a/libraries/script-engine/src/ScriptCache.h +++ b/libraries/script-engine/src/ScriptCache.h @@ -43,6 +43,9 @@ class ScriptCache : public QObject, public Dependency { public: static const QString STATUS_INLINE; static const QString STATUS_CACHED; + static bool isSuccessStatus(const QString& status) { + return status == "Success" || status == STATUS_INLINE || status == STATUS_CACHED; + } void clearCache(); Q_INVOKABLE void clearATPScriptsFromCache(); diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index f1ff4c4686..262823a85d 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -49,6 +49,7 @@ #include "ArrayBufferViewClass.h" #include "BatchLoader.h" +#include "BaseScriptEngine.h" #include "DataViewClass.h" #include "EventTypes.h" #include "FileScriptingInterface.h" // unzip project @@ -68,9 +69,12 @@ #include "MIDIEvent.h" -const QString BaseScriptEngine::SCRIPT_EXCEPTION_FORMAT { "[UncaughtException] %1 in %2:%3" }; static const QScriptEngine::QObjectWrapOptions DEFAULT_QOBJECT_WRAP_OPTIONS = QScriptEngine::ExcludeDeleteLater | QScriptEngine::ExcludeChildObjects; +static const QScriptValue::PropertyFlags READONLY_PROP_FLAGS { QScriptValue::ReadOnly | QScriptValue::Undeletable }; +static const QScriptValue::PropertyFlags HIDDEN_PROP_FLAGS { READONLY_PROP_FLAGS | QScriptValue::SkipInEnumeration }; + + static const bool HIFI_AUTOREFRESH_FILE_SCRIPTS { true }; @@ -89,13 +93,9 @@ static QScriptValue debugPrint(QScriptContext* context, QScriptEngine* engine){ } qCDebug(scriptengineScript).noquote() << "script:print()<<" << message; // noquote() so that \n is treated as newline - message = message.replace("\\", "\\\\") - .replace("\n", "\\n") - .replace("\r", "\\r") - .replace("'", "\\'"); - - // FIXME - this approach neeeds revisiting. print() comes here, which ends up doing an evaluate? - engine->evaluate("Script.print('" + message + "')"); + // FIXME - this approach neeeds revisiting. print() comes here, which ends up calling Script.print? + engine->globalObject().property("Script").property("print") + .call(engine->nullValue(), QScriptValueList({ message })); return QScriptValue(); } @@ -139,52 +139,15 @@ QString encodeEntityIdIntoEntityUrl(const QString& url, const QString& entityID) return url + " [EntityID:" + entityID + "]"; } -QString BaseScriptEngine::lintScript(const QString& sourceCode, const QString& fileName, const int lineNumber) { - const auto syntaxCheck = checkSyntax(sourceCode); - if (syntaxCheck.state() != syntaxCheck.Valid) { - const auto error = syntaxCheck.errorMessage(); - const auto line = QString::number(syntaxCheck.errorLineNumber()); - const auto column = QString::number(syntaxCheck.errorColumnNumber()); - const auto message = QString("[SyntaxError] %1 in %2:%3(%4)").arg(error, fileName, line, column); - return message; - } - return QString(); -} - -QString BaseScriptEngine::formatUncaughtException(const QString& overrideFileName) { - QString message; - if (hasUncaughtException()) { - const auto error = uncaughtException(); - const auto backtrace = uncaughtExceptionBacktrace(); - const auto exception = error.toString(); - auto filename = overrideFileName; - if (filename.isEmpty()) { - QScriptContextInfo ctx { currentContext() }; - filename = ctx.fileName(); - } - const auto line = QString::number(uncaughtExceptionLineNumber()); - - message = QString(SCRIPT_EXCEPTION_FORMAT).arg(exception, overrideFileName, line); - if (!backtrace.empty()) { - static const auto lineSeparator = "\n "; - message += QString("\n[Backtrace]%1%2").arg(lineSeparator, backtrace.join(lineSeparator)); - } - } - return message; -} - -QString ScriptEngine::reportUncaughtException(const QString& overrideFileName) { - QString message; - if (!hasUncaughtException()) { - return message; - } - message = formatUncaughtException(overrideFileName.isEmpty() ? _fileNameString : overrideFileName); +QString ScriptEngine::logException(const QScriptValue& exception) { + auto message = formatException(exception); scriptErrorMessage(qPrintable(message)); return message; } int ScriptEngine::processLevelMaxRetries { ScriptRequest::MAX_RETRIES }; ScriptEngine::ScriptEngine(Context context, const QString& scriptContents, const QString& fileNameString) : + BaseScriptEngine(), _context(context), _scriptContents(scriptContents), _timerFunctionMap(), @@ -194,8 +157,14 @@ ScriptEngine::ScriptEngine(Context context, const QString& scriptContents, const DependencyManager::get()->addScriptEngine(this); connect(this, &QScriptEngine::signalHandlerException, this, [this](const QScriptValue& exception) { - reportUncaughtException(); - clearExceptions(); + if (hasUncaughtException()) { + // the engine's uncaughtException() seems to produce much better stack traces here + emit unhandledException(cloneUncaughtException("signalHandlerException")); + clearExceptions(); + } else { + // ... but may not always be available -- so if needed we fallback to the passed exception + emit unhandledException(exception); + } }); setProcessEventsInterval(MSECS_PER_SECOND); @@ -203,7 +172,16 @@ ScriptEngine::ScriptEngine(Context context, const QString& scriptContents, const qCDebug(scriptengine) << "isEntityServerScript() -- limiting maxRetries to 1"; processLevelMaxRetries = 1; } - qCDebug(scriptengine) << getContext() << "processLevelMaxRetries =" << processLevelMaxRetries; + //qCDebug(scriptengine) << getContext() << "processLevelMaxRetries =" << processLevelMaxRetries << fileNameString; + + // this is where all unhandled exceptions end up getting logged + connect(this, &BaseScriptEngine::unhandledException, this, [this](const QScriptValue& err) { + auto output = err.engine() == this ? err : makeError(err); + if (!output.property("detail").isValid()) { + output.setProperty("detail", "UnhandledException"); + } + logException(output); + }); } QString ScriptEngine::getContext() const { @@ -223,13 +201,22 @@ QString ScriptEngine::getContext() const { } ScriptEngine::~ScriptEngine() { + // FIXME: are these scriptInfoMessage/scriptWarningMessage segfaulting anybody else at app shutdown? +#if !defined(Q_OS_LINUX) scriptInfoMessage("Script Engine shutting down:" + getFilename()); +#else + qCDebug(scriptengine) << "~ScriptEngine()" << this; +#endif auto scriptEngines = DependencyManager::get(); if (scriptEngines) { scriptEngines->removeScriptEngine(this); } else { +#if !defined(Q_OS_LINUX) scriptWarningMessage("Script destroyed after ScriptEngines!"); +#else + qCWarning(scriptengine) << ("Script destroyed after ScriptEngines!"); +#endif } } @@ -319,9 +306,12 @@ void ScriptEngine::runDebuggable() { } } _lastUpdate = now; - // Debug and clear exceptions - if (hasUncaughtException()) { - reportUncaughtException(); + + // only clear exceptions if we are not in the middle of evaluating + if (!isEvaluating() && hasUncaughtException()) { + qCWarning(scriptengine) << __FUNCTION__ << "---------- UNCAUGHT EXCEPTION --------"; + qCWarning(scriptengine) << "runDebuggable" << uncaughtException().toString(); + logException(__FUNCTION__); clearExceptions(); } }); @@ -356,10 +346,9 @@ void ScriptEngine::runInThread() { workerThread->start(); } -void ScriptEngine::executeOnScriptThread(std::function function, bool blocking ) { +void ScriptEngine::executeOnScriptThread(std::function function, const Qt::ConnectionType& type ) { if (QThread::currentThread() != thread()) { - QMetaObject::invokeMethod(this, "executeOnScriptThread", blocking ? Qt::BlockingQueuedConnection : Qt::QueuedConnection, - Q_ARG(std::function, function)); + QMetaObject::invokeMethod(this, "executeOnScriptThread", type, Q_ARG(std::function, function)); return; } @@ -558,6 +547,7 @@ void ScriptEngine::init() { qCWarning(scriptengine) << "deletingEntity while entity script is still running!" << entityID; } _entityScripts.remove(entityID); + emit entityScriptDetailsUpdated(); } }); @@ -589,8 +579,7 @@ void ScriptEngine::init() { QScriptValue webSocketConstructorValue = newFunction(WebSocketClass::constructor); globalObject().setProperty("WebSocket", webSocketConstructorValue); - QScriptValue printConstructorValue = newFunction(debugPrint); - globalObject().setProperty("print", printConstructorValue); + globalObject().setProperty("print", newFunction(debugPrint)); QScriptValue audioEffectOptionsConstructorValue = newFunction(AudioEffectOptions::constructor); globalObject().setProperty("AudioEffectOptions", audioEffectOptionsConstructorValue); @@ -604,6 +593,7 @@ void ScriptEngine::init() { qScriptRegisterMetaType(this, wscReadyStateToScriptValue, wscReadyStateFromScriptValue); registerGlobalObject("Script", this); + registerGlobalObject("Audio", &AudioScriptingInterface::getInstance()); registerGlobalObject("Entities", entityScriptingInterface.data()); registerGlobalObject("Quat", &_quatLibrary); @@ -870,7 +860,6 @@ void ScriptEngine::addEventHandler(const EntityItemID& entityID, const QString& handlersForEvent << handlerData; // Note that the same handler can be added many times. See removeEntityEventHandler(). } - QScriptValue ScriptEngine::evaluate(const QString& sourceCode, const QString& fileName, int lineNumber) { if (DependencyManager::get()->isStopped()) { return QScriptValue(); // bail early @@ -892,23 +881,28 @@ QScriptValue ScriptEngine::evaluate(const QString& sourceCode, const QString& fi // Check syntax auto syntaxError = lintScript(sourceCode, fileName); + if (syntaxError.isError()) { + if (isEvaluating()) { + currentContext()->throwValue(syntaxError); + } else { + syntaxError.setProperty("detail", "evaluate"); + emit unhandledException(syntaxError); + } + return syntaxError; + } QScriptProgram program { sourceCode, fileName, lineNumber }; - if (!syntaxError.isEmpty() || program.isNull()) { - scriptErrorMessage(qPrintable(syntaxError)); - return QScriptValue(); + if (program.isNull()) { + // can this happen? + auto err = makeError("could not create QScriptProgram for " + fileName); + emit unhandledException(err); + return err; } - ++_evaluatesPending; - auto result = BaseScriptEngine::evaluate(program); - --_evaluatesPending; - - if (hasUncaughtException()) { - result = uncaughtException(); - reportUncaughtException(program.fileName()); - emit evaluationFinished(result, true); - clearExceptions(); - } else { - emit evaluationFinished(result, false); + QScriptValue result; + { + // catch any exceptions throw by nested operations + ExceptionEmitter tryCatch(this, __FUNCTION__); + result = BaseScriptEngine::evaluate(program); } return result; } @@ -929,8 +923,11 @@ void ScriptEngine::run() { _isRunning = true; emit runningStateChanged(); - QScriptValue result = evaluate(_scriptContents, _fileNameString); - + { + // catch any exceptions throw by nested operations + ExceptionEmitter tryCatch(this, __FUNCTION__); + evaluate(_scriptContents, _fileNameString); + } #ifdef _WIN32 // VS13 does not sleep_until unless it uses the system_clock, see: // https://www.reddit.com/r/cpp_questions/comments/3o71ic/sleep_until_not_working_with_a_time_pointsteady/ @@ -1057,13 +1054,14 @@ void ScriptEngine::run() { } _lastUpdate = now; - // Debug and clear exceptions - if (hasUncaughtException()) { - reportUncaughtException(); + // only clear exceptions if we are not in the middle of evaluating + if (!isEvaluating() && hasUncaughtException()) { + qCWarning(scriptengine) << __FUNCTION__ << "---------- UNCAUGHT EXCEPTION --------"; + qCWarning(scriptengine) << "runInThread" << uncaughtException().toString(); + emit unhandledException(cloneUncaughtException(__FUNCTION__)); clearExceptions(); } } - scriptInfoMessage("Script Engine stopping:" + getFilename()); stopAllTimers(); // make sure all our timers are stopped if the script is ending @@ -1096,9 +1094,11 @@ void ScriptEngine::run() { // we want to only call it in our own run "shutdown" processing. void ScriptEngine::stopAllTimers() { QMutableHashIterator i(_timerFunctionMap); + int j {0}; while (i.hasNext()) { i.next(); QTimer* timer = i.key(); + qCDebug(scriptengine) << getFilename() << "stopAllTimers[" << j++ << "]"; stopTimer(timer); } } @@ -1185,6 +1185,7 @@ void ScriptEngine::timerFired() { _timerFunctionMap.remove(callingTimer); delete callingTimer; } + //qCWarning(scriptengine) << "timerFired" << timerData.function.toString(); // call the associated JS function, if it exists if (timerData.function.isValid()) { @@ -1193,11 +1194,11 @@ void ScriptEngine::timerFired() { auto postTimer = p_high_resolution_clock::now(); auto elapsed = (postTimer - preTimer); _totalTimerExecution += std::chrono::duration_cast(elapsed); - + } else { + qCWarning(scriptengine) << "timerFired -- invalid function" << timerData.function.toVariant().toString(); } } - QObject* ScriptEngine::setupTimerWithInterval(const QScriptValue& function, int intervalMS, bool isSingleShot) { // create the timer, add it to the map, and start it QTimer* newTimer = new QTimer(this); @@ -1214,7 +1215,7 @@ QObject* ScriptEngine::setupTimerWithInterval(const QScriptValue& function, int // make sure the timer stops when the script does connect(this, &ScriptEngine::scriptEnding, newTimer, &QTimer::stop); - CallbackData timerData = {function, currentEntityIdentifier, currentSandboxURL }; + CallbackData timerData = { function, currentEntityIdentifier, currentSandboxURL }; _timerFunctionMap.insert(newTimer, timerData); newTimer->start(intervalMS); @@ -1244,33 +1245,44 @@ void ScriptEngine::stopTimer(QTimer *timer) { timer->stop(); _timerFunctionMap.remove(timer); delete timer; + } else { + qCDebug(scriptengine) << "stopTimer -- not in _timerFunctionMap" << timer; } } QUrl ScriptEngine::resolvePath(const QString& include) const { QUrl url(include); // first lets check to see if it's already a full URL - if (!url.scheme().isEmpty()) { + if (include.startsWith("/") || url.scheme().length() == 1) { + url = QUrl::fromLocalFile(include); + } + if (!url.isRelative()) { return expandScriptUrl(url); } - QScriptContextInfo contextInfo { currentContext()->parentContext() }; - - // we apparently weren't a fully qualified url, so, let's assume we're relative - // to the original URL of our script - QUrl parentURL = contextInfo.fileName(); - if (parentURL.isEmpty()) { - if (_parentURL.isEmpty()) { - parentURL = QUrl(_fileNameString); - } else { - parentURL = QUrl(_parentURL); - } + // to the first absolute URL in the JS scope chain + QUrl parentURL; + auto ctx = currentContext(); + do { + QScriptContextInfo contextInfo { ctx }; + parentURL = QUrl(contextInfo.fileName()); + ctx = ctx->parentContext(); + } while (parentURL.isRelative() && ctx); + + if (parentURL.isRelative()) { + // fallback to the "include" parent (if defined, this will already be absolute) + parentURL = QUrl(_parentURL); } - // if the parent URL's scheme is empty, then this is probably a local file... - if (parentURL.scheme().isEmpty()) { - parentURL = QUrl::fromLocalFile(_fileNameString); + if (parentURL.isRelative()) { + // fallback to the original script engine URL + parentURL = QUrl(_fileNameString); + + // if still relative and path-like, then this is probably a local file... + if (parentURL.isRelative() && url.path().contains("/")) { + parentURL = QUrl::fromLocalFile(_fileNameString); + } } // at this point we should have a legitimate fully qualified URL for our parent @@ -1297,22 +1309,7 @@ void ScriptEngine::include(const QStringList& includeFiles, QScriptValue callbac return; // bail early } QList urls; - bool knowsSensitivity = false; - Qt::CaseSensitivity sensitivity { Qt::CaseSensitive }; - auto getSensitivity = [&]() { - if (!knowsSensitivity) { - QString path = currentSandboxURL.path(); - QFileInfo upperFI(path.toUpper()); - QFileInfo lowerFI(path.toLower()); - sensitivity = (upperFI == lowerFI) ? Qt::CaseInsensitive : Qt::CaseSensitive; - knowsSensitivity = true; - } - return sensitivity; - }; - // Guard against meaningless query and fragment parts. - // Do NOT use PreferLocalFile as its behavior is unpredictable (e.g., on defaultScriptsLocation()) - const auto strippingFlags = QUrl::RemoveFilename | QUrl::RemoveQuery | QUrl::RemoveFragment; for (QString includeFile : includeFiles) { QString file = ResourceManager::normalizeURL(includeFile); QUrl thisURL; @@ -1329,10 +1326,8 @@ void ScriptEngine::include(const QStringList& includeFiles, QScriptValue callbac thisURL = resolvePath(file); } - if (!isStandardLibrary && !currentSandboxURL.isEmpty() && (thisURL.scheme() == "file") && - (currentSandboxURL.scheme() != "file" || - !thisURL.toString(strippingFlags).startsWith(currentSandboxURL.toString(strippingFlags), getSensitivity()))) { - + bool disallowOutsideFiles = thisURL.isLocalFile() && !isStandardLibrary && !currentSandboxURL.isLocalFile(); + if (disallowOutsideFiles && !PathUtils::isDescendantOf(thisURL, currentSandboxURL)) { scriptWarningMessage("Script.include() ignoring file path" + thisURL.toString() + "outside of original entity script" + currentSandboxURL.toString()); } else { @@ -1368,7 +1363,17 @@ void ScriptEngine::include(const QStringList& includeFiles, QScriptValue callbac evaluate(contents, url.toString()); }; + ExceptionEmitter tryCatch(this, "include"); doWithEnvironment(capturedEntityIdentifier, capturedSandboxURL, operation); + if (tryCatch.hasPending()) { + // match previous include behavior where possible by logging, not propagating, exceptions. + // for nested evaluations, exceptions are now allowed to propagate + auto err = tryCatch.pending(); + emit unhandledException(err); + if (tryCatch.wouldEmit()) { + tryCatch.consume(); + } + } } else { scriptWarningMessage("Script.include() skipping evaluation of previously included url:" + url.toString()); } @@ -1470,21 +1475,6 @@ int ScriptEngine::getNumRunningEntityScripts() const { return sum; } -QString ScriptEngine::getEntityScriptStatus(const EntityItemID& entityID) { - if (_entityScripts.contains(entityID)) - return EntityScriptStatus_::valueToKey(_entityScripts[entityID].status).toLower(); - return QString(); -} - -bool ScriptEngine::getEntityScriptDetails(const EntityItemID& entityID, EntityScriptDetails &details) const { - auto it = _entityScripts.constFind(entityID); - if (it == _entityScripts.constEnd()) { - return false; - } - details = it.value(); - return true; -} - void ScriptEngine::setEntityScriptDetails(const EntityItemID& entityID, const EntityScriptDetails& details) { _entityScripts[entityID] = details; emit entityScriptDetailsUpdated(); @@ -1497,31 +1487,140 @@ void ScriptEngine::updateEntityScriptStatus(const EntityItemID& entityID, const emit entityScriptDetailsUpdated(); } -// since all of these operations can be asynch we will always do the actual work in the response handler -// for the download -void ScriptEngine::loadEntityScript(QWeakPointer theEngine, const EntityItemID& entityID, const QString& entityScript, bool forceRedownload) { - auto engine = theEngine.data(); - engine->executeOnScriptThread([=]{ - EntityScriptDetails details = engine->_entityScripts[entityID]; - if (details.status == EntityScriptStatus::PENDING || details.status == EntityScriptStatus::UNLOADED) { - engine->updateEntityScriptStatus(entityID, EntityScriptStatus::LOADING, QThread::currentThread()->objectName()); - } - }); +bool ScriptEngine::getEntityScriptDetails(const EntityItemID& entityID, EntityScriptDetails &details) const { + auto it = _entityScripts.constFind(entityID); + if (it == _entityScripts.constEnd()) { + return false; + } + details = it.value(); + return true; +} - // NOTE: If the script content is not currently in the cache, the LAMBDA here will be called on the Main Thread - // which means we're guaranteed that it's not the correct thread for the ScriptEngine. This means - // when we get into entityScriptContentAvailable() we will likely invokeMethod() to get it over - // to the "Entities" ScriptEngine thread. - DependencyManager::get()->getScriptContents(entityScript, [theEngine, entityID](const QString& scriptOrURL, const QString& contents, bool isURL, bool success, const QString &status) { - QSharedPointer strongEngine = theEngine.toStrongRef(); - if (strongEngine) { -#ifdef THREAD_DEBUGGING - qCDebug(scriptengine) << "ScriptEngine::entityScriptContentAvailable() IN LAMBDA contentAvailable on thread [" - << QThread::currentThread() << "] expected thread [" << strongEngine->thread() << "]"; -#endif - strongEngine->entityScriptContentAvailable(entityID, scriptOrURL, contents, isURL, success, status); +const auto RETRY_ATTEMPT_BATCH = 10; //glm::clamp(qgetenv("RETRY_ATTEMPT_BATCH").toInt(), 1, 50); +const auto RETRY_ATTEMPT_MSECS = 250; //glm::clamp(qgetenv("RETRY_ATTEMPT_MSECS").toInt(), 50, 1000); + +void ScriptEngine::deferLoadEntityScript(const EntityItemID& entityID, const QString& entityScript, bool forceRedownload) { + // forceRedownload doesn't make sense yet in this scenario (which only happens when another entity has taken lead on entityScript) + if (forceRedownload) { + qCDebug(scriptengine) << "deferLoadEntityScript -- TODO: ignoring forceRedownload =" << forceRedownload; + } + + const auto needTimer = _pendingLoadEntities.isEmpty(); + _pendingLoadEntities.push_back({ entityID, entityScript/*, forceRedownload*/ }); + + auto processDeferredEntities = [this](QScriptContext* ctx, QScriptEngine*) -> QScriptValue { + //qCDebug(scriptengine) << "deferLoadEntityScript.retry #" << _pendingLoadEntities.size() << " pending loads | " << QThread::currentThread(); + + for(int i=0; i < RETRY_ATTEMPT_BATCH && !_pendingLoadEntities.isEmpty(); i++) { + auto retry = _pendingLoadEntities.takeFirst(); + qCDebug(scriptengine) << "deferLoadEntityScript.retry[" << i << "]:" << retry.entityID << retry.entityScript; + if(!_entityScripts.contains(retry.entityID)) { + qCDebug(scriptengine) << "deferLoadEntityScript.retry -- entity details gone (entity deleted?)"; + } else { + auto details = _entityScripts[retry.entityID]; + if (details.status != EntityScriptStatus::PENDING) { + qCDebug(scriptengine) << "deferLoadEntityScript.retry -- entity status no longer PENDING; " << details.status; + } else { + loadEntityScript(retry.entityID, retry.entityScript, false); + } + } } - }, forceRedownload, processLevelMaxRetries); + if (_pendingLoadEntities.isEmpty()) { + QObject *interval = ctx->callee().property("interval").toQObject(); + // we're done processing so can kill the timer + qCDebug(scriptengine) << "loadEntityScript.retry queue processing complete -- exiting" << interval; + if (interval) { + clearInterval(interval); + } + } + return QScriptValue(); + }; + + if (needTimer) { + // we were the first to get queued -- so set up an interval timer for deferred processing + qCDebug(scriptengine) << "deferLoadEntityScript -- scheduling timer " << RETRY_ATTEMPT_MSECS; + + // processDeferredEntities gets wrapped as a "regular" JavaScript callback so that it can then + // be scheduled using setInterval per usual -- allowing the script engine to own its lifecycle. + // we stil need to call clearInterval manually when done, so its passed to calle() above as a property. + + QScriptValue function = newLambdaFunction(processDeferredEntities, "processDeferredEntities-loader"); + QObject *interval = setInterval( function, RETRY_ATTEMPT_MSECS ); + + // make the interval reachable from the handler + function.setProperty("interval", newQObject(interval)); + } +} + +void ScriptEngine::loadEntityScript(const EntityItemID& entityID, const QString& entityScript, bool forceRedownload) { + if (QThread::currentThread() != thread()) { + QMetaObject::invokeMethod(this, "loadEntityScript", + Q_ARG(const EntityItemID&, entityID), + Q_ARG(const QString&, entityScript), + Q_ARG(bool, forceRedownload) + ); + return; + } + PROFILE_RANGE(script, __FUNCTION__); + + if (isStopping() || DependencyManager::get()->isStopped()) { + qCDebug(scriptengine) << "loadEntityScript.start " << entityScript << entityID.toString() + << " but isStopping==" << isStopping() + << " || engines->isStopped==" << DependencyManager::get()->isStopped(); + return; + } + + if (!_entityScripts.contains(entityID)) { + // make sure EntityScriptDetails has an entry for this UUID right away + // (which allows bailing from the loading/provisioning process early if the Entity gets deleted mid-flight) + updateEntityScriptStatus(entityID, EntityScriptStatus::PENDING, "...pending..."); + } + + // This lock/defer approach allows multiple Entities to boot from the same script URL while still taking + // full advantage of cacheable require modules. This only affects Entities literally coming in back-to-back + // before the first one has time to finish loading. + auto &locker = _lockPerUniqueScriptURL[entityScript]; + if (!locker.tryLock()) { + qCDebug(scriptengine) << QString("loadEntityScript.deferring[%1] entity: %2 script: %3") + .arg( _pendingLoadEntities.size()).arg(entityID.toString()).arg(entityScript); + deferLoadEntityScript(entityID, entityScript, forceRedownload); + return; + } + +#ifdef DEBUG_ENTITY_STATES + auto previousStatus = _entityScripts.contains(entityID) ? _entityScripts[entityID].status : EntityScriptStatus::PENDING; + qCDebug(scriptengine) << "loadEntityScript.LOADING: " << entityScript << entityID.toString() + << "(previous: " << previousStatus << ")"; +#endif + + EntityScriptDetails newDetails; + newDetails.scriptText = entityScript; + newDetails.status = EntityScriptStatus::LOADING; + newDetails.definingSandboxURL = currentSandboxURL; + _entityScripts[entityID] = newDetails; + + auto scriptCache = DependencyManager::get(); + scriptCache->getScriptContents(entityScript, + [=, &locker](const QString& url, const QString& contents, bool isURL, bool success, const QString& status) { + if (isStopping()) { +#ifdef DEBUG_ENTITY_STATES + qCDebug(scriptengine) << "loadEntityScript.contentAvailable -- stopping"; +#endif + locker.unlock(); + return; + } + executeOnScriptThread([=, &locker]{ + //qCDebug(scriptengine) << "loadEntityScript.contentAvailable" << status << QUrl(url).fileName() << entityID.toString(); + if (!isStopping() && _entityScripts.contains(entityID)) { + entityScriptContentAvailable(entityID, url, contents, isURL, success, status); + } else { +#ifdef DEBUG_ENTITY_STATES + qCDebug(scriptengine) << "loadEntityScript.contentAvailable -- aborting"; +#endif + } + locker.unlock(); + }); + }, forceRedownload); } // since all of these operations can be asynch we will always do the actual work in the response handler @@ -1551,25 +1650,53 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co auto scriptCache = DependencyManager::get(); bool isFileUrl = isURL && scriptOrURL.startsWith("file://"); - auto fileName = isURL ? scriptOrURL : "EmbeddedEntityScript"; + auto fileName = isURL ? scriptOrURL : "about:EmbeddedEntityScript"; + const EntityScriptDetails &oldDetails = _entityScripts[entityID]; EntityScriptDetails newDetails; newDetails.scriptText = scriptOrURL; - if (!success) { - newDetails.status = EntityScriptStatus::ERROR_LOADING_SCRIPT; - newDetails.errorInfo = "Failed to load script (" + status + ")"; + // If an error happens below, we want to update newDetails with the new status info + // and also abort any pending Entity loads that are waiting on the exact same script URL. + auto setError = [&](const QString &errorInfo, const EntityScriptStatus& status) { + newDetails.errorInfo = errorInfo; + newDetails.status = status; setEntityScriptDetails(entityID, newDetails); + + QMutableListIterator i(_pendingLoadEntities); + // note: we want the *original* entityScript string (not the potentially normalized one from ScriptCache results) + const auto entityScript = oldDetails.scriptText; + while (i.hasNext()) { + auto retry = i.next(); + if (retry.entityScript == entityScript) { + qCDebug(scriptengine) << "... pending load of " << retry.entityID << " cancelled"; + i.remove(); + } + } + }; + + // NETWORK / FILESYSTEM ERRORS + if (!success) { + setError("Failed to load script (" + status + ")", EntityScriptStatus::ERROR_LOADING_SCRIPT); return; } + // SYNTAX ERRORS auto syntaxError = lintScript(contents, fileName); + if (syntaxError.isError()) { + auto message = syntaxError.property("formatted").toString(); + if (message.isEmpty()) { + message = syntaxError.toString(); + } + setError(QString("Bad syntax (%1)").arg(message), EntityScriptStatus::ERROR_RUNNING_SCRIPT); + syntaxError.setProperty("detail", entityID.toString()); + emit unhandledException(syntaxError); + return; + } QScriptProgram program { contents, fileName }; - if (!syntaxError.isNull() || program.isNull()) { - newDetails.status = EntityScriptStatus::ERROR_RUNNING_SCRIPT; - newDetails.errorInfo = QString("Bad syntax (%1)").arg(syntaxError); - setEntityScriptDetails(entityID, newDetails); - qCDebug(scriptengine) << newDetails.errorInfo << scriptOrURL; + if (program.isNull()) { + setError("Bad program (isNull)", EntityScriptStatus::ERROR_RUNNING_SCRIPT); + emit unhandledException(makeError("program.isNull")); return; // done processing script } @@ -1577,11 +1704,13 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co setParentURL(scriptOrURL); } + // SANITY/PERFORMANCE CHECK USING SANDBOX const int SANDBOX_TIMEOUT = 0.25 * MSECS_PER_SECOND; BaseScriptEngine sandbox; sandbox.setProcessEventsInterval(SANDBOX_TIMEOUT); - QScriptValue testConstructor; + QScriptValue testConstructor, exception; { + ExceptionEmitter tryCatch(&sandbox, QString("(preflight %1)").arg(entityID.toString())); QTimer timeout; timeout.setSingleShot(true); timeout.start(SANDBOX_TIMEOUT); @@ -1594,18 +1723,25 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co context->throwError(QString("Timed out (entity constructors are limited to %1ms)").arg(SANDBOX_TIMEOUT)); } }); + testConstructor = sandbox.evaluate(program); + + if (tryCatch.hasPending()) { + exception = tryCatch.consume(); + } else if (testConstructor.isError()) { + exception = testConstructor; + } } - QString exceptionMessage = sandbox.formatUncaughtException(program.fileName()); - if (!exceptionMessage.isNull()) { - newDetails.status = EntityScriptStatus::ERROR_RUNNING_SCRIPT; - newDetails.errorInfo = exceptionMessage; - setEntityScriptDetails(entityID, newDetails); - qCDebug(scriptengine) << "----- ScriptEngine::entityScriptContentAvailable -- hadUncaughtExceptions (" << scriptOrURL << ")"; + if (exception.isError()) { + // create a local copy using makeError to decouple from the sandbox engine + exception = makeError(exception); + setError(formatException(exception), EntityScriptStatus::ERROR_RUNNING_SCRIPT); + emit unhandledException(exception); return; } + // CONSTRUCTOR VIABILITY if (!testConstructor.isFunction()) { QString testConstructorType = QString(testConstructor.toVariant().typeName()); if (testConstructorType == "") { @@ -1616,32 +1752,49 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co if (testConstructorValue.size() > maxTestConstructorValueSize) { testConstructorValue = testConstructorValue.mid(0, maxTestConstructorValueSize) + "..."; } - scriptErrorMessage("Error -- ScriptEngine::loadEntityScript() entity:" + entityID.toString() - + "failed to load entity script -- expected a function, got " + testConstructorType - + "," + testConstructorValue - + "," + scriptOrURL); + auto message = QString("failed to load entity script -- expected a function, got %1, %2") + .arg(testConstructorType).arg(testConstructorValue); - newDetails.status = EntityScriptStatus::ERROR_RUNNING_SCRIPT; - newDetails.errorInfo = "Could not find constructor"; - setEntityScriptDetails(entityID, newDetails); + auto err = makeError(message); + err.setProperty("fileName", scriptOrURL); + err.setProperty("detail", "(constructor " + entityID.toString() + ")"); - qCDebug(scriptengine) << "----- ScriptEngine::entityScriptContentAvailable -- failed to run (" << scriptOrURL << ")"; + setError("Could not find constructor (" + testConstructorType + ")", EntityScriptStatus::ERROR_RUNNING_SCRIPT); + emit unhandledException(err); return; // done processing script } + // (this feeds into refreshFileScript) int64_t lastModified = 0; if (isFileUrl) { QString file = QUrl(scriptOrURL).toLocalFile(); lastModified = (quint64)QFileInfo(file).lastModified().toMSecsSinceEpoch(); } + + // THE ACTUAL EVALUATION AND CONSTRUCTION QScriptValue entityScriptConstructor, entityScriptObject; QUrl sandboxURL = currentSandboxURL.isEmpty() ? scriptOrURL : currentSandboxURL; auto initialization = [&]{ + ExceptionEmitter tryCatch(this, "(construct " + entityID.toString() + ")"); + entityScriptConstructor = evaluate(contents, fileName); entityScriptObject = entityScriptConstructor.construct(); + + if (tryCatch.hasPending()) { + entityScriptObject = tryCatch.consume(); + } }; + doWithEnvironment(entityID, sandboxURL, initialization); + if (entityScriptObject.isError()) { + auto exception = entityScriptObject; + setError(formatException(exception), EntityScriptStatus::ERROR_RUNNING_SCRIPT); + emit unhandledException(exception); + return; + } + + // ... AND WE HAVE LIFTOFF newDetails.status = EntityScriptStatus::RUNNING; newDetails.scriptObject = entityScriptObject; newDetails.lastModified = lastModified; @@ -1678,6 +1831,7 @@ void ScriptEngine::unloadEntityScript(const EntityItemID& entityID) { } EntityScriptDetails newDetails; newDetails.status = EntityScriptStatus::UNLOADED; + newDetails.lastModified = QDateTime::currentMSecsSinceEpoch(); setEntityScriptDetails(entityID, newDetails); stopAllTimersForEntityScript(entityID); } @@ -1700,15 +1854,14 @@ void ScriptEngine::unloadAllEntityScripts() { } _entityScripts.clear(); emit entityScriptDetailsUpdated(); + _lockPerUniqueScriptURL.clear(); #ifdef DEBUG_ENGINE_STATE - qCDebug(scriptengine) << "---- CURRENT STATE OF ENGINE: --------------------------"; - QScriptValueIterator it(globalObject()); - while (it.hasNext()) { - it.next(); - qCDebug(scriptengine) << it.name() << ":" << it.value().toString(); - } - qCDebug(scriptengine) << "--------------------------------------------------------"; + _debugDump( + "---- CURRENT STATE OF ENGINE: --------------------------", + globalObject(), + "--------------------------------------------------------" + ); #endif // DEBUG_ENGINE_STATE } @@ -1756,6 +1909,8 @@ void ScriptEngine::doWithEnvironment(const EntityItemID& entityID, const QUrl& s currentEntityIdentifier = entityID; currentSandboxURL = sandboxURL; + ExceptionEmitter tryCatcher(this, !entityID.isNull() ? entityID.toString() : __FUNCTION__); + #if DEBUG_CURRENT_ENTITY QScriptValue oldData = this->globalObject().property("debugEntityID"); this->globalObject().setProperty("debugEntityID", entityID.toScriptValue(this)); // Make the entityID available to javascript as a global. @@ -1764,14 +1919,10 @@ void ScriptEngine::doWithEnvironment(const EntityItemID& entityID, const QUrl& s #else operation(); #endif - if (hasUncaughtException()) { - reportUncaughtException(); - clearExceptions(); - } - currentEntityIdentifier = oldIdentifier; currentSandboxURL = oldSandboxURL; } + void ScriptEngine::callWithEnvironment(const EntityItemID& entityID, const QUrl& sandboxURL, QScriptValue function, QScriptValue thisObject, QScriptValueList args) { auto operation = [&]() { function.call(thisObject, args); @@ -1846,7 +1997,6 @@ void ScriptEngine::callEntityScriptMethod(const EntityItemID& entityID, const QS } } - void ScriptEngine::callEntityScriptMethod(const EntityItemID& entityID, const QString& methodName, const EntityItemID& otherID, const Collision& collision) { if (QThread::currentThread() != thread()) { #ifdef THREAD_DEBUGGING @@ -1881,3 +2031,4 @@ void ScriptEngine::callEntityScriptMethod(const EntityItemID& entityID, const QS } } } + diff --git a/libraries/script-engine/src/ScriptEngine.h b/libraries/script-engine/src/ScriptEngine.h index a382258973..7b2a5e8d8c 100644 --- a/libraries/script-engine/src/ScriptEngine.h +++ b/libraries/script-engine/src/ScriptEngine.h @@ -35,6 +35,7 @@ #include "ArrayBufferClass.h" #include "AssetScriptingInterface.h" #include "AudioScriptingInterface.h" +#include "BaseScriptEngine.h" #include "Quat.h" #include "Mat4.h" #include "ScriptCache.h" @@ -54,6 +55,13 @@ public: QUrl definingSandboxURL; }; +class DeferredLoadEntity { +public: + EntityItemID entityID; + QString entityScript; + //bool forceRedownload; +}; + typedef QList CallbackList; typedef QHash RegisteredEventHandlers; @@ -67,15 +75,7 @@ public: QString scriptText { "" }; QScriptValue scriptObject { QScriptValue() }; int64_t lastModified { 0 }; - QUrl definingSandboxURL { QUrl() }; -}; - -// common base class with just QScriptEngine-dependent helper methods -class BaseScriptEngine : public QScriptEngine { -public: - static const QString SCRIPT_EXCEPTION_FORMAT; - QString lintScript(const QString& sourceCode, const QString& fileName, const int lineNumber = 1); - QString formatUncaughtException(const QString& overrideFileName = QString()); + QUrl definingSandboxURL { QUrl("about:EntityScript") }; }; class ScriptEngine : public BaseScriptEngine, public EntitiesScriptEngineProvider { @@ -91,14 +91,13 @@ public: }; static int processLevelMaxRetries; - ScriptEngine(Context context, const QString& scriptContents = NO_SCRIPT, const QString& fileNameString = QString("")); + ScriptEngine(Context context, const QString& scriptContents = NO_SCRIPT, const QString& fileNameString = QString("about:ScriptEngine")); ~ScriptEngine(); /// run the script in a dedicated thread. This will have the side effect of evalulating /// the current script contents and calling run(). Callers will likely want to register the script with external /// services before calling this. void runInThread(); - Q_INVOKABLE void executeOnScriptThread(std::function function, bool blocking = false); void runDebuggable(); @@ -162,16 +161,17 @@ public: Q_INVOKABLE QObject* setTimeout(const QScriptValue& function, int timeoutMS); Q_INVOKABLE void clearInterval(QObject* timer) { stopTimer(reinterpret_cast(timer)); } Q_INVOKABLE void clearTimeout(QObject* timer) { stopTimer(reinterpret_cast(timer)); } + Q_INVOKABLE void print(const QString& message); Q_INVOKABLE QUrl resolvePath(const QString& path) const; Q_INVOKABLE QUrl resourcesPath() const; // Entity Script Related methods - Q_INVOKABLE QString getEntityScriptStatus(const EntityItemID& entityID); Q_INVOKABLE bool isEntityScriptRunning(const EntityItemID& entityID) { return _entityScripts.contains(entityID) && _entityScripts[entityID].status == EntityScriptStatus::RUNNING; } - static void loadEntityScript(QWeakPointer theEngine, const EntityItemID& entityID, const QString& entityScript, bool forceRedownload); + Q_INVOKABLE void deferLoadEntityScript(const EntityItemID& entityID, const QString& entityScript, bool forceRedownload); + Q_INVOKABLE void loadEntityScript(const EntityItemID& entityID, const QString& entityScript, bool forceRedownload); Q_INVOKABLE void unloadEntityScript(const EntityItemID& entityID); // will call unload method Q_INVOKABLE void unloadAllEntityScripts(); Q_INVOKABLE void callEntityScriptMethod(const EntityItemID& entityID, const QString& methodName, @@ -212,7 +212,6 @@ public: bool getEntityScriptDetails(const EntityItemID& entityID, EntityScriptDetails &details) const; public slots: - int evaluatePending() const { return _evaluatesPending; } void callAnimationStateHandler(QScriptValue callback, AnimVariantMap parameters, QStringList names, bool useNames, AnimVariantResultHandler resultHandler); void updateMemoryCost(const qint64&); @@ -228,7 +227,6 @@ signals: void warningMessage(const QString& message); void infoMessage(const QString& message); void runningStateChanged(); - void evaluationFinished(QScriptValue result, bool isException); void loadScript(const QString& scriptName, bool isUserLoaded); void reloadScript(const QString& scriptName, bool isUserLoaded); void doneRunning(); @@ -239,8 +237,9 @@ signals: protected: void init(); + Q_INVOKABLE void executeOnScriptThread(std::function function, const Qt::ConnectionType& type = Qt::QueuedConnection ); - QString reportUncaughtException(const QString& overrideFileName = QString()); + QString logException(const QScriptValue& exception); void timerFired(); void stopAllTimers(); void stopAllTimersForEntityScript(const EntityItemID& entityID); @@ -262,17 +261,18 @@ protected: void callWithEnvironment(const EntityItemID& entityID, const QUrl& sandboxURL, QScriptValue function, QScriptValue thisObject, QScriptValueList args); Context _context; - QString _scriptContents; QString _parentURL; std::atomic _isFinished { false }; std::atomic _isRunning { false }; std::atomic _isStopping { false }; - int _evaluatesPending { 0 }; bool _isInitialized { false }; QHash _timerFunctionMap; QSet _includedURLs; QHash _entityScripts; + std::map _lockPerUniqueScriptURL; + QList _pendingLoadEntities; + bool _isThreaded { false }; QScriptEngineDebugger* _debugger { nullptr }; bool _debuggable { false }; diff --git a/libraries/script-engine/src/ScriptEngines.cpp b/libraries/script-engine/src/ScriptEngines.cpp index b2ff337fb9..57887d2d96 100644 --- a/libraries/script-engine/src/ScriptEngines.cpp +++ b/libraries/script-engine/src/ScriptEngines.cpp @@ -364,25 +364,43 @@ QStringList ScriptEngines::getRunningScripts() { } void ScriptEngines::stopAllScripts(bool restart) { + QVector toReload; QReadLocker lock(&_scriptEnginesHashLock); for (QHash::const_iterator it = _scriptEnginesHash.constBegin(); it != _scriptEnginesHash.constEnd(); it++) { + ScriptEngine *scriptEngine = it.value(); // skip already stopped scripts - if (it.value()->isFinished() || it.value()->isStopping()) { + if (scriptEngine->isFinished() || scriptEngine->isStopping()) { continue; } // queue user scripts if restarting - if (restart && it.value()->isUserLoaded()) { - connect(it.value(), &ScriptEngine::finished, this, [this](QString scriptName, ScriptEngine* engine) { - reloadScript(scriptName); - }); + if (restart && scriptEngine->isUserLoaded()) { + toReload << it.key().toString(); } // stop all scripts - it.value()->stop(true); qCDebug(scriptengine) << "stopping script..." << it.key(); + scriptEngine->stop(); } + // wait for engines to stop (ie: providing time for .scriptEnding cleanup handlers to run) before + // triggering reload of any Client scripts / Entity scripts + QTimer::singleShot(500, this, [=]() { + for(const auto &scriptName : toReload) { + auto scriptEngine = getScriptEngine(scriptName); + if (scriptEngine && !scriptEngine->isFinished()) { + qCDebug(scriptengine) << "waiting on script:" << scriptName; + scriptEngine->waitTillDoneRunning(); + qCDebug(scriptengine) << "done waiting on script:" << scriptName; + } + qCDebug(scriptengine) << "reloading script..." << scriptName; + reloadScript(scriptName); + } + if (restart) { + qCDebug(scriptengine) << "stopAllScripts -- emitting scriptsReloading"; + emit scriptsReloading(); + } + }); } bool ScriptEngines::stopScript(const QString& rawScriptURL, bool restart) { @@ -421,9 +439,10 @@ void ScriptEngines::setScriptsLocation(const QString& scriptsLocation) { } void ScriptEngines::reloadAllScripts() { + qCDebug(scriptengine) << "reloadAllScripts -- clearing caches"; DependencyManager::get()->clearCache(); DependencyManager::get()->clearCache(); - emit scriptsReloading(); + qCDebug(scriptengine) << "reloadAllScripts -- stopping all scripts"; stopAllScripts(true); } @@ -456,7 +475,7 @@ ScriptEngine* ScriptEngines::loadScript(const QUrl& scriptFilename, bool isUserL return scriptEngine; } - scriptEngine = new ScriptEngine(_context, NO_SCRIPT, ""); + scriptEngine = new ScriptEngine(_context, NO_SCRIPT, "about:" + scriptFilename.fileName()); scriptEngine->setUserLoaded(isUserLoaded); connect(scriptEngine, &ScriptEngine::doneRunning, this, [scriptEngine] { scriptEngine->deleteLater(); diff --git a/libraries/shared/src/PathUtils.cpp b/libraries/shared/src/PathUtils.cpp index 016b9ccfd6..265eaaa5b6 100644 --- a/libraries/shared/src/PathUtils.cpp +++ b/libraries/shared/src/PathUtils.cpp @@ -18,7 +18,7 @@ #include #include "PathUtils.h" #include - +#include // std::once const QString& PathUtils::resourcesPath() { #ifdef Q_OS_MAC @@ -82,3 +82,28 @@ QUrl defaultScriptsLocation() { QFileInfo fileInfo(path); return QUrl::fromLocalFile(fileInfo.canonicalFilePath()); } + + +QString PathUtils::stripFilename(const QUrl& url) { + // Guard against meaningless query and fragment parts. + // Do NOT use PreferLocalFile as its behavior is unpredictable (e.g., on defaultScriptsLocation()) + return url.toString(QUrl::RemoveFilename | QUrl::RemoveQuery | QUrl::RemoveFragment); +} + +Qt::CaseSensitivity PathUtils::getFSCaseSensitivity() { + static Qt::CaseSensitivity sensitivity { Qt::CaseSensitive }; + static std::once_flag once; + std::call_once(once, [&] { + QString path = defaultScriptsLocation().toLocalFile(); + QFileInfo upperFI(path.toUpper()); + QFileInfo lowerFI(path.toLower()); + sensitivity = (upperFI == lowerFI) ? Qt::CaseInsensitive : Qt::CaseSensitive; + }); + return sensitivity; +} + +bool PathUtils::isDescendantOf(const QUrl& childURL, const QUrl& parentURL) { + QString child = stripFilename(childURL); + QString parent = stripFilename(parentURL); + return child.startsWith(parent, PathUtils::getFSCaseSensitivity()); +} diff --git a/libraries/shared/src/PathUtils.h b/libraries/shared/src/PathUtils.h index 546586fb64..1f7dcbe466 100644 --- a/libraries/shared/src/PathUtils.h +++ b/libraries/shared/src/PathUtils.h @@ -28,6 +28,11 @@ class PathUtils : public QObject, public Dependency { public: static const QString& resourcesPath(); static QString getRootDataDirectory(); + + static Qt::CaseSensitivity getFSCaseSensitivity(); + static QString stripFilename(const QUrl& url); + // note: this is FS-case-sensitive version of parentURL.isParentOf(childURL) + static bool isDescendantOf(const QUrl& childURL, const QUrl& parentURL); }; QString fileNameWithoutExtension(const QString& fileName, const QVector possibleExtensions); From 417587dcda6d6064f529a18d40917c597fc9d683 Mon Sep 17 00:00:00 2001 From: humbletim Date: Wed, 22 Feb 2017 15:22:56 -0500 Subject: [PATCH 02/17] * Update per CR feedback / code standards * Cull log spam * Add tryLock to deferred processor to preempt unnecessary loadEntityContent round-trips --- .../script-engine/src/BaseScriptEngine.cpp | 18 +++++------ .../script-engine/src/BaseScriptEngine.h | 6 ++-- libraries/script-engine/src/BatchLoader.cpp | 2 +- libraries/script-engine/src/ScriptCache.cpp | 2 ++ libraries/script-engine/src/ScriptEngine.cpp | 31 +++++++++++-------- 5 files changed, 32 insertions(+), 27 deletions(-) diff --git a/libraries/script-engine/src/BaseScriptEngine.cpp b/libraries/script-engine/src/BaseScriptEngine.cpp index 4342205414..fd4d829d54 100644 --- a/libraries/script-engine/src/BaseScriptEngine.cpp +++ b/libraries/script-engine/src/BaseScriptEngine.cpp @@ -118,14 +118,14 @@ QScriptValue BaseScriptEngine::cloneUncaughtException(const QString& extraDetail } if (fileName.isEmpty()) { // climb the stack frames looking for something useful to display - for(auto ctx = currentContext(); ctx && fileName.isEmpty(); ctx = ctx->parentContext()) { - QScriptContextInfo info { ctx }; + for (auto c = currentContext(); c && fileName.isEmpty(); c = c->parentContext()) { + QScriptContextInfo info { c }; if (!info.fileName().isEmpty()) { // take fileName:lineNumber as a pair fileName = info.fileName(); lineNumber = info.lineNumber(); if (backtrace.isEmpty()) { - backtrace = ctx->backtrace(); + backtrace = c->backtrace(); } break; } @@ -181,8 +181,6 @@ QScriptValue BaseScriptEngine::evaluateInClosure(const QScriptValue& closure, co return QScriptValue(); } - //_debugDump("evaluateInClosure.closure", closure); - const auto fileName = program.fileName(); const auto shortName = QUrl(fileName).fileName(); @@ -197,17 +195,17 @@ QScriptValue BaseScriptEngine::evaluateInClosure(const QScriptValue& closure, co setGlobalObject(global); } - auto ctx = pushContext(); + auto context = pushContext(); auto thiz = closure.property("this"); if (thiz.isObject()) { #ifdef DEBUG_JS qCDebug(scriptengine) << " setting this = closure.this" << shortName; #endif - ctx->setThisObject(thiz); + context->setThisObject(thiz); } - ctx->pushScope(closure); + context->pushScope(closure); #ifdef DEBUG_JS qCDebug(scriptengine) << QString("[%1] evaluateInClosure %2").arg(isEvaluating()).arg(shortName); #endif @@ -244,8 +242,8 @@ QScriptValue BaseScriptEngine::newLambdaFunction(std::functioncallee().prototype() === Lambda QObject - call.setData(data); // ctx->callee().data() will === data param + call.setPrototype(object); // context->callee().prototype() === Lambda QObject + call.setData(data); // context->callee().data() will === data param return call; } QString Lambda::toString() const { diff --git a/libraries/script-engine/src/BaseScriptEngine.h b/libraries/script-engine/src/BaseScriptEngine.h index 3ff4c22e4b..620c0915ea 100644 --- a/libraries/script-engine/src/BaseScriptEngine.h +++ b/libraries/script-engine/src/BaseScriptEngine.h @@ -39,7 +39,7 @@ signals: protected: void _emitUnhandledException(const QScriptValue& exception); - QScriptValue newLambdaFunction(std::function operation, const QScriptValue& data = QScriptValue(), const QScriptEngine::ValueOwnership& ownership = QScriptEngine::AutoOwnership); + QScriptValue newLambdaFunction(std::function operation, const QScriptValue& data = QScriptValue(), const QScriptEngine::ValueOwnership& ownership = QScriptEngine::AutoOwnership); static const QString _SETTINGS_ENABLE_EXTENDED_EXCEPTIONS; Setting::Handle _enableExtendedJSExceptions { _SETTINGS_ENABLE_EXTENDED_EXCEPTIONS, true }; @@ -72,14 +72,14 @@ protected: class Lambda : public QObject { Q_OBJECT public: - Lambda(QScriptEngine *engine, std::function operation, QScriptValue data); + Lambda(QScriptEngine *engine, std::function operation, QScriptValue data); ~Lambda(); public slots: QScriptValue call(); QString toString() const; private: QScriptEngine* engine; - std::function operation; + std::function operation; QScriptValue data; }; diff --git a/libraries/script-engine/src/BatchLoader.cpp b/libraries/script-engine/src/BatchLoader.cpp index eeaffff5cb..0c65d5c6f0 100644 --- a/libraries/script-engine/src/BatchLoader.cpp +++ b/libraries/script-engine/src/BatchLoader.cpp @@ -66,7 +66,7 @@ void BatchLoader::start(int maxRetries) { qCDebug(scriptengine) << "Loaded: " << url; } else { _data.insert(url, QString()); - qCDebug(scriptengine) << "Could not load: " << url; + qCDebug(scriptengine) << "Could not load: " << url << status; } if (!_finished && _urls.size() == _data.size()) { diff --git a/libraries/script-engine/src/ScriptCache.cpp b/libraries/script-engine/src/ScriptCache.cpp index 3bc780e28d..601ca6bc95 100644 --- a/libraries/script-engine/src/ScriptCache.cpp +++ b/libraries/script-engine/src/ScriptCache.cpp @@ -188,6 +188,8 @@ void ScriptCache::scriptContentAvailable(int maxRetries) { } } + } else { + qCWarning(scriptengine) << "Warning: scriptContentAvailable for inactive url: " << url; } } diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index 262823a85d..0a6c3536b5 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -172,7 +172,6 @@ ScriptEngine::ScriptEngine(Context context, const QString& scriptContents, const qCDebug(scriptengine) << "isEntityServerScript() -- limiting maxRetries to 1"; processLevelMaxRetries = 1; } - //qCDebug(scriptengine) << getContext() << "processLevelMaxRetries =" << processLevelMaxRetries << fileNameString; // this is where all unhandled exceptions end up getting logged connect(this, &BaseScriptEngine::unhandledException, this, [this](const QScriptValue& err) { @@ -1185,7 +1184,6 @@ void ScriptEngine::timerFired() { _timerFunctionMap.remove(callingTimer); delete callingTimer; } - //qCWarning(scriptengine) << "timerFired" << timerData.function.toString(); // call the associated JS function, if it exists if (timerData.function.isValid()) { @@ -1500,18 +1498,14 @@ const auto RETRY_ATTEMPT_BATCH = 10; //glm::clamp(qgetenv("RETRY_ATTEMPT_BATCH") const auto RETRY_ATTEMPT_MSECS = 250; //glm::clamp(qgetenv("RETRY_ATTEMPT_MSECS").toInt(), 50, 1000); void ScriptEngine::deferLoadEntityScript(const EntityItemID& entityID, const QString& entityScript, bool forceRedownload) { - // forceRedownload doesn't make sense yet in this scenario (which only happens when another entity has taken lead on entityScript) - if (forceRedownload) { - qCDebug(scriptengine) << "deferLoadEntityScript -- TODO: ignoring forceRedownload =" << forceRedownload; - } - const auto needTimer = _pendingLoadEntities.isEmpty(); + // NOTE: forceRedownload isn't forwarded here because deferLoadEntityScript() is only ever called when another entity has taken lead for the script _pendingLoadEntities.push_back({ entityID, entityScript/*, forceRedownload*/ }); - auto processDeferredEntities = [this](QScriptContext* ctx, QScriptEngine*) -> QScriptValue { - //qCDebug(scriptengine) << "deferLoadEntityScript.retry #" << _pendingLoadEntities.size() << " pending loads | " << QThread::currentThread(); + auto processDeferredEntities = [this](QScriptContext* context, QScriptEngine*) -> QScriptValue { + QList stillPending; - for(int i=0; i < RETRY_ATTEMPT_BATCH && !_pendingLoadEntities.isEmpty(); i++) { + for (int i=0; i < RETRY_ATTEMPT_BATCH && !_pendingLoadEntities.isEmpty(); i++) { auto retry = _pendingLoadEntities.takeFirst(); qCDebug(scriptengine) << "deferLoadEntityScript.retry[" << i << "]:" << retry.entityID << retry.entityScript; if(!_entityScripts.contains(retry.entityID)) { @@ -1521,12 +1515,21 @@ void ScriptEngine::deferLoadEntityScript(const EntityItemID& entityID, const QSt if (details.status != EntityScriptStatus::PENDING) { qCDebug(scriptengine) << "deferLoadEntityScript.retry -- entity status no longer PENDING; " << details.status; } else { - loadEntityScript(retry.entityID, retry.entityScript, false); + auto &locker = _lockPerUniqueScriptURL[retry.entityScript]; + if (locker.tryLock()) { + locker.unlock(); + loadEntityScript(retry.entityID, retry.entityScript, false); + } else { + stillPending << retry; + } } } } + foreach(const DeferredLoadEntity& retry, stillPending) { + _pendingLoadEntities.push_back(retry); + } if (_pendingLoadEntities.isEmpty()) { - QObject *interval = ctx->callee().property("interval").toQObject(); + QObject *interval = context->callee().property("interval").toQObject(); // we're done processing so can kill the timer qCDebug(scriptengine) << "loadEntityScript.retry queue processing complete -- exiting" << interval; if (interval) { @@ -1610,7 +1613,9 @@ void ScriptEngine::loadEntityScript(const EntityItemID& entityID, const QString& return; } executeOnScriptThread([=, &locker]{ - //qCDebug(scriptengine) << "loadEntityScript.contentAvailable" << status << QUrl(url).fileName() << entityID.toString(); +#ifdef DEBUG_ENTITY_STATES + qCDebug(scriptengine) << "loadEntityScript.contentAvailable" << status << QUrl(url).fileName() << entityID.toString(); +#endif if (!isStopping() && _entityScripts.contains(entityID)) { entityScriptContentAvailable(entityID, url, contents, isURL, success, status); } else { From 132a889f7474728dcfc5facd223f800854a378ff Mon Sep 17 00:00:00 2001 From: humbletim Date: Wed, 22 Feb 2017 20:36:49 -0500 Subject: [PATCH 03/17] * Add Qt::DirectConnection to signalHandlerException * CR feedback / coding standards --- libraries/script-engine/src/ScriptEngine.cpp | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index 0a6c3536b5..cee3f2344f 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -72,7 +72,7 @@ static const QScriptEngine::QObjectWrapOptions DEFAULT_QOBJECT_WRAP_OPTIONS = QScriptEngine::ExcludeDeleteLater | QScriptEngine::ExcludeChildObjects; static const QScriptValue::PropertyFlags READONLY_PROP_FLAGS { QScriptValue::ReadOnly | QScriptValue::Undeletable }; -static const QScriptValue::PropertyFlags HIDDEN_PROP_FLAGS { READONLY_PROP_FLAGS | QScriptValue::SkipInEnumeration }; +static const QScriptValue::PropertyFlags READONLY_HIDDEN_PROP_FLAGS { READONLY_PROP_FLAGS | QScriptValue::SkipInEnumeration }; @@ -165,7 +165,7 @@ ScriptEngine::ScriptEngine(Context context, const QString& scriptContents, const // ... but may not always be available -- so if needed we fallback to the passed exception emit unhandledException(exception); } - }); + }, Qt::DirectConnection); setProcessEventsInterval(MSECS_PER_SECOND); if (isEntityServerScript()) { @@ -1250,7 +1250,7 @@ void ScriptEngine::stopTimer(QTimer *timer) { QUrl ScriptEngine::resolvePath(const QString& include) const { QUrl url(include); - // first lets check to see if it's already a full URL + // first lets check to see if it's already a full URL -- or a Windows path like "c:/" if (include.startsWith("/") || url.scheme().length() == 1) { url = QUrl::fromLocalFile(include); } @@ -1261,12 +1261,12 @@ QUrl ScriptEngine::resolvePath(const QString& include) const { // we apparently weren't a fully qualified url, so, let's assume we're relative // to the first absolute URL in the JS scope chain QUrl parentURL; - auto ctx = currentContext(); + auto context = currentContext(); do { - QScriptContextInfo contextInfo { ctx }; + QScriptContextInfo contextInfo { context }; parentURL = QUrl(contextInfo.fileName()); - ctx = ctx->parentContext(); - } while (parentURL.isRelative() && ctx); + context = context->parentContext(); + } while (parentURL.isRelative() && context); if (parentURL.isRelative()) { // fallback to the "include" parent (if defined, this will already be absolute) From f82a0196a8a7e4edfa4c255fd790caafa7130c2a Mon Sep 17 00:00:00 2001 From: humbletim Date: Thu, 23 Feb 2017 18:12:12 -0500 Subject: [PATCH 04/17] Always consume exceptions thrown by include's --- libraries/script-engine/src/ScriptEngine.cpp | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index cee3f2344f..56ebe0d798 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -1365,12 +1365,12 @@ void ScriptEngine::include(const QStringList& includeFiles, QScriptValue callbac doWithEnvironment(capturedEntityIdentifier, capturedSandboxURL, operation); if (tryCatch.hasPending()) { // match previous include behavior where possible by logging, not propagating, exceptions. - // for nested evaluations, exceptions are now allowed to propagate auto err = tryCatch.pending(); emit unhandledException(err); - if (tryCatch.wouldEmit()) { - tryCatch.consume(); - } + // FIXME: to be revisited with next PR 21114-part3 for compat with require/module + //if (tryCatch.wouldEmit()) { + tryCatch.consume(); + //} } } else { scriptWarningMessage("Script.include() skipping evaluation of previously included url:" + url.toString()); From e794b64c31e748c5aaeff860b566a1d8ed2ee758 Mon Sep 17 00:00:00 2001 From: humbletim Date: Thu, 23 Feb 2017 18:13:24 -0500 Subject: [PATCH 05/17] Add resolvePath and include characterization/unit tests --- .../tests/unit_tests/scriptTests/error.js | 6 + .../unit_tests/scriptTests/nested-error.js | 10 ++ .../scriptTests/nested-syntax-error.js | 10 ++ .../unit_tests/scriptTests/nested/error.js | 5 + .../unit_tests/scriptTests/nested/lib.js | 5 + .../unit_tests/scriptTests/nested/sibling.js | 3 + .../scriptTests/nested/syntax-error.js | 3 + .../unit_tests/scriptTests/top-level-error.js | 11 ++ .../tests/unit_tests/scriptTests/top-level.js | 5 + .../tests/unit_tests/scriptUnitTests.js | 126 ++++++++++++++++++ 10 files changed, 184 insertions(+) create mode 100644 scripts/developer/tests/unit_tests/scriptTests/error.js create mode 100644 scripts/developer/tests/unit_tests/scriptTests/nested-error.js create mode 100644 scripts/developer/tests/unit_tests/scriptTests/nested-syntax-error.js create mode 100644 scripts/developer/tests/unit_tests/scriptTests/nested/error.js create mode 100644 scripts/developer/tests/unit_tests/scriptTests/nested/lib.js create mode 100644 scripts/developer/tests/unit_tests/scriptTests/nested/sibling.js create mode 100644 scripts/developer/tests/unit_tests/scriptTests/nested/syntax-error.js create mode 100644 scripts/developer/tests/unit_tests/scriptTests/top-level-error.js create mode 100644 scripts/developer/tests/unit_tests/scriptTests/top-level.js create mode 100644 scripts/developer/tests/unit_tests/scriptUnitTests.js diff --git a/scripts/developer/tests/unit_tests/scriptTests/error.js b/scripts/developer/tests/unit_tests/scriptTests/error.js new file mode 100644 index 0000000000..6b9a7c7445 --- /dev/null +++ b/scripts/developer/tests/unit_tests/scriptTests/error.js @@ -0,0 +1,6 @@ +afterError = false; +throw new Error('error.js'); +afterError = true; + +(1,eval)('this').$finishes.push(Script.resolvePath('')); + diff --git a/scripts/developer/tests/unit_tests/scriptTests/nested-error.js b/scripts/developer/tests/unit_tests/scriptTests/nested-error.js new file mode 100644 index 0000000000..3a190545ef --- /dev/null +++ b/scripts/developer/tests/unit_tests/scriptTests/nested-error.js @@ -0,0 +1,10 @@ +afterError = false; +outer = null; +Script.include('./nested/error.js?' + Settings.getValue('cache_buster')); +outer = { + inner: inner.lib, + sibling: sibling.lib, +}; +afterError = true; + +(1,eval)("this").$finishes.push(Script.resolvePath('')); diff --git a/scripts/developer/tests/unit_tests/scriptTests/nested-syntax-error.js b/scripts/developer/tests/unit_tests/scriptTests/nested-syntax-error.js new file mode 100644 index 0000000000..fb0e3679ff --- /dev/null +++ b/scripts/developer/tests/unit_tests/scriptTests/nested-syntax-error.js @@ -0,0 +1,10 @@ +afterError = false; +outer = null; +Script.include('./nested/syntax-error.js?' + Settings.getValue('cache_buster')); +outer = { + inner: inner.lib, + sibling: sibling.lib, +}; +afterError = true; + +(1,eval)("this").$finishes.push(Script.resolvePath('')); diff --git a/scripts/developer/tests/unit_tests/scriptTests/nested/error.js b/scripts/developer/tests/unit_tests/scriptTests/nested/error.js new file mode 100644 index 0000000000..aeb76eec01 --- /dev/null +++ b/scripts/developer/tests/unit_tests/scriptTests/nested/error.js @@ -0,0 +1,5 @@ +afterError = false; +throw new Error('nested/error.js'); +afterError = true; + +(1,eval)("this").$finishes.push(Script.resolvePath('')); diff --git a/scripts/developer/tests/unit_tests/scriptTests/nested/lib.js b/scripts/developer/tests/unit_tests/scriptTests/nested/lib.js new file mode 100644 index 0000000000..1c2cf3b885 --- /dev/null +++ b/scripts/developer/tests/unit_tests/scriptTests/nested/lib.js @@ -0,0 +1,5 @@ +Script.include('sibling.js'); +inner = { + lib: "nested/lib.js", +}; + diff --git a/scripts/developer/tests/unit_tests/scriptTests/nested/sibling.js b/scripts/developer/tests/unit_tests/scriptTests/nested/sibling.js new file mode 100644 index 0000000000..33fa068079 --- /dev/null +++ b/scripts/developer/tests/unit_tests/scriptTests/nested/sibling.js @@ -0,0 +1,3 @@ +sibling = { + lib: "nested/sibling", +}; diff --git a/scripts/developer/tests/unit_tests/scriptTests/nested/syntax-error.js b/scripts/developer/tests/unit_tests/scriptTests/nested/syntax-error.js new file mode 100644 index 0000000000..3b578c2674 --- /dev/null +++ b/scripts/developer/tests/unit_tests/scriptTests/nested/syntax-error.js @@ -0,0 +1,3 @@ +function() { + // intentional SyntaxError... + diff --git a/scripts/developer/tests/unit_tests/scriptTests/top-level-error.js b/scripts/developer/tests/unit_tests/scriptTests/top-level-error.js new file mode 100644 index 0000000000..4ef90ec238 --- /dev/null +++ b/scripts/developer/tests/unit_tests/scriptTests/top-level-error.js @@ -0,0 +1,11 @@ +afterError = false; +outer = null; +Script.include('./nested/lib.js'); +Undefined_symbol; +outer = { + inner: inner.lib, + sibling: sibling.lib, +}; +afterError = true; + +(1,eval)("this").$finishes.push(Script.resolvePath('')); diff --git a/scripts/developer/tests/unit_tests/scriptTests/top-level.js b/scripts/developer/tests/unit_tests/scriptTests/top-level.js new file mode 100644 index 0000000000..ab55007fe9 --- /dev/null +++ b/scripts/developer/tests/unit_tests/scriptTests/top-level.js @@ -0,0 +1,5 @@ +Script.include('./nested/lib.js'); +outer = { + inner: inner.lib, + sibling: sibling.lib, +}; diff --git a/scripts/developer/tests/unit_tests/scriptUnitTests.js b/scripts/developer/tests/unit_tests/scriptUnitTests.js new file mode 100644 index 0000000000..d464682ca9 --- /dev/null +++ b/scripts/developer/tests/unit_tests/scriptUnitTests.js @@ -0,0 +1,126 @@ +/* eslint-env jasmine */ + +instrument_testrunner(); + +describe('Script', function () { + // get the current filename without calling Script.resolvePath('') + try { + throw new Error('stack'); + } catch(e) { + var filename = e.fileName; + var dirname = filename.split('/').slice(0, -1).join('/') + '/'; + var parentdir = dirname.split('/').slice(0, -2).join('/') + '/'; + } + + // characterization tests + // initially these are just to capture how the app works currently + var testCases = { + '': filename, + '.': dirname, + '..': parentdir, + 'about:Entities 1': '', + 'Entities 1': dirname + 'Entities 1', + './file.js': dirname + 'file.js', + 'c:/temp/': 'file:///c:/temp/', + 'c:/temp': 'file:///c:/temp', + '/temp/': 'file:///temp/', + 'c:/': 'file:///c:/', + 'c:': 'file:///c:', + 'file:///~/libraries/a.js': 'file:///~/libraries/a.js', + '/temp/tested/../file.js': 'file:///temp/tested/../file.js', + '/~/libraries/utils.js': 'file:///~/libraries/utils.js', + '/temp/file.js': 'file:///temp/file.js', + '/~/': 'file:///~/', + }; + } + describe('resolvePath', function () { + Object.keys(testCases).forEach(function(input) { + it('(' + JSON.stringify(input) + ')', function () { + expect(Script.resolvePath(input)).toEqual(testCases[input]); + }); + }); + }); + + describe('include', function () { + var old_cache_buster; + var cache_buster = '#' + +new Date; + beforeAll(function() { + old_cache_buster = Settings.getValue('cache_buster'); + Settings.setValue('cache_buster', cache_buster); + }); + afterAll(function() { + Settings.setValue('cache_buster', old_cache_buster); + }); + beforeEach(function() { + vec3toStr = undefined; + }); + it('file:///~/system/libraries/utils.js' + cache_buster, function() { + Script.include('file:///~/system/libraries/utils.js' + cache_buster); + expect(vec3toStr).toEqual(jasmine.any(Function)); + }); + it('nested' + cache_buster, function() { + Script.include('./scriptTests/top-level.js' + cache_buster); + expect(outer).toEqual(jasmine.any(Object)); + expect(inner).toEqual(jasmine.any(Object)); + expect(sibling).toEqual(jasmine.any(Object)); + expect(outer.inner).toEqual(inner.lib); + expect(outer.sibling).toEqual(sibling.lib); + }); + describe('errors' + cache_buster, function() { + var finishes, oldFinishes; + beforeAll(function() { + oldFinishes = (1,eval)('this').$finishes; + }); + afterAll(function() { + (1,eval)('this').$finishes = oldFinishes; + }); + beforeEach(function() { + finishes = (1,eval)('this').$finishes = []; + }); + it('error', function() { + // a thrown Error in top-level include aborts that include, but does not throw the error back to JS + expect(function() { + Script.include('./scriptTests/error.js' + cache_buster); + }).not.toThrowError("error.js"); + expect(finishes.length).toBe(0); + }); + it('top-level-error', function() { + // an organice Error in a top-level include aborts that include, but does not throw the error + expect(function() { + Script.include('./scriptTests/top-level-error.js' + cache_buster); + }).not.toThrowError(/Undefined_symbol/); + expect(finishes.length).toBe(0); + }); + it('nested', function() { + // a thrown Error in a nested include aborts the nested include, but does not abort the top-level script + expect(function() { + Script.include('./scriptTests/nested-error.js' + cache_buster); + }).not.toThrowError("nested/error.js"); + expect(finishes.length).toBe(1); + }); + it('nested-syntax-error', function() { + // a SyntaxError in a nested include breaks only that include (the main script should finish unimpeded) + expect(function() { + Script.include('./scriptTests/nested-syntax-error.js' + cache_buster); + }).not.toThrowError(/SyntaxEror/); + expect(finishes.length).toBe(1); + }); + }); + }); +}); + +// enable scriptUnitTests to be loaded directly +function run() {} +function instrument_testrunner() { + if (typeof describe === 'undefined') { + print('instrumenting jasmine', Script.resolvePath('')); + Script.include('../../libraries/jasmine/jasmine.js'); + Script.include('../../libraries/jasmine/hifi-boot.js'); + jasmine.getEnv().addReporter({ jasmineDone: Script.stop }); + run = function() { + print('executing jasmine', Script.resolvePath('')); + jasmine.getEnv().execute(); + }; + } +} +run(); From 8ab7a8cad52e20ff48ccdb0c3765ab413a8ef5a0 Mon Sep 17 00:00:00 2001 From: humbletim Date: Thu, 23 Feb 2017 18:16:41 -0500 Subject: [PATCH 06/17] fix bracket --- scripts/developer/tests/unit_tests/scriptUnitTests.js | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/scripts/developer/tests/unit_tests/scriptUnitTests.js b/scripts/developer/tests/unit_tests/scriptUnitTests.js index d464682ca9..63b451e97f 100644 --- a/scripts/developer/tests/unit_tests/scriptUnitTests.js +++ b/scripts/developer/tests/unit_tests/scriptUnitTests.js @@ -31,8 +31,7 @@ describe('Script', function () { '/~/libraries/utils.js': 'file:///~/libraries/utils.js', '/temp/file.js': 'file:///temp/file.js', '/~/': 'file:///~/', - }; - } + }; describe('resolvePath', function () { Object.keys(testCases).forEach(function(input) { it('(' + JSON.stringify(input) + ')', function () { From 1eeb25a9ebc884549fe6b645fa4612117d9525ba Mon Sep 17 00:00:00 2001 From: humbletim Date: Thu, 23 Feb 2017 19:09:27 -0500 Subject: [PATCH 07/17] Increase deferred batch processing. --- libraries/script-engine/src/ScriptEngine.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index 56ebe0d798..ff0ddc2ce3 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -1494,7 +1494,7 @@ bool ScriptEngine::getEntityScriptDetails(const EntityItemID& entityID, EntitySc return true; } -const auto RETRY_ATTEMPT_BATCH = 10; //glm::clamp(qgetenv("RETRY_ATTEMPT_BATCH").toInt(), 1, 50); +const auto RETRY_ATTEMPT_BATCH = 100; //glm::clamp(qgetenv("RETRY_ATTEMPT_BATCH").toInt(), 1, 50); const auto RETRY_ATTEMPT_MSECS = 250; //glm::clamp(qgetenv("RETRY_ATTEMPT_MSECS").toInt(), 50, 1000); void ScriptEngine::deferLoadEntityScript(const EntityItemID& entityID, const QString& entityScript, bool forceRedownload) { From 0b73cef252f773e1e2a91a06ae301aa7d221cf83 Mon Sep 17 00:00:00 2001 From: humbletim Date: Thu, 23 Feb 2017 19:10:44 -0500 Subject: [PATCH 08/17] Add stampede test. --- .../tests/entityStampedeTest-entity-fail.js | 3 ++ .../tests/entityStampedeTest-entity.js | 12 +++++++ scripts/developer/tests/entityStampedeTest.js | 32 +++++++++++++++++++ 3 files changed, 47 insertions(+) create mode 100644 scripts/developer/tests/entityStampedeTest-entity-fail.js create mode 100644 scripts/developer/tests/entityStampedeTest-entity.js create mode 100644 scripts/developer/tests/entityStampedeTest.js diff --git a/scripts/developer/tests/entityStampedeTest-entity-fail.js b/scripts/developer/tests/entityStampedeTest-entity-fail.js new file mode 100644 index 0000000000..53c0469055 --- /dev/null +++ b/scripts/developer/tests/entityStampedeTest-entity-fail.js @@ -0,0 +1,3 @@ +(function() { + throw new Error(Script.resolvePath('')); +}) diff --git a/scripts/developer/tests/entityStampedeTest-entity.js b/scripts/developer/tests/entityStampedeTest-entity.js new file mode 100644 index 0000000000..1f1d6bcf76 --- /dev/null +++ b/scripts/developer/tests/entityStampedeTest-entity.js @@ -0,0 +1,12 @@ +(function() { + return { + preload: function(uuid) { + var shape = Entities.getEntityProperties(uuid).shape === 'Sphere' ? 'Cube' : 'Sphere'; + + Entities.editEntity(uuid, { + shape: shape, + color: { red: 0xff, green: 0xff, blue: 0xff }, + }); + } + }; +}) diff --git a/scripts/developer/tests/entityStampedeTest.js b/scripts/developer/tests/entityStampedeTest.js new file mode 100644 index 0000000000..c5040a9796 --- /dev/null +++ b/scripts/developer/tests/entityStampedeTest.js @@ -0,0 +1,32 @@ +var NUM_ENTITIES = 100; +var RADIUS = 2; +var DIV = NUM_ENTITIES / Math.PI / 2; +var PASS_SCRIPT_URL = Script.resolvePath('').replace('.js', '-entity.js'); +var FAIL_SCRIPT_URL = Script.resolvePath('').replace('.js', '-entity-fail.js'); + +var origin = Vec3.sum(MyAvatar.position, Vec3.multiply(5, Quat.getFront(MyAvatar.orientation))); +origin.y += HMD.eyeHeight; + +var uuids = []; + +Script.scriptEnding.connect(function() { + uuids.forEach(function(id) { + Entities.deleteEntity(id); + }); +}); + +for (var i=0; i < NUM_ENTITIES; i++) { + var failGroup = i % 2; + uuids.push(Entities.addEntity({ + type: 'Shape', + shape: failGroup ? 'Sphere' : 'Icosahedron', + name: 'entityStampedeTest-' + i, + lifetime: 120, + position: Vec3.sum(origin, Vec3.multiplyQbyV( + MyAvatar.orientation, { x: Math.sin(i / DIV) * RADIUS, y: Math.cos(i / DIV) * RADIUS, z: 0 } + )), + script: (failGroup ? FAIL_SCRIPT_URL : PASS_SCRIPT_URL) + Settings.getValue('cache_buster'), + dimensions: Vec3.HALF, + color: { red: 0, green: 0, blue: 0 }, + }, !Entities.serversExist())); +} From 3ad3fd472e5720f1a67d202657ababab98b88d51 Mon Sep 17 00:00:00 2001 From: humbletim Date: Thu, 23 Feb 2017 19:46:28 -0500 Subject: [PATCH 09/17] * Inline / duplicate exception checking per CR feedback * Coding standards --- .../script-engine/src/BaseScriptEngine.cpp | 36 +-------------- .../script-engine/src/BaseScriptEngine.h | 19 -------- libraries/script-engine/src/ScriptEngine.cpp | 45 +++++++++---------- 3 files changed, 24 insertions(+), 76 deletions(-) diff --git a/libraries/script-engine/src/BaseScriptEngine.cpp b/libraries/script-engine/src/BaseScriptEngine.cpp index fd4d829d54..16308c0650 100644 --- a/libraries/script-engine/src/BaseScriptEngine.cpp +++ b/libraries/script-engine/src/BaseScriptEngine.cpp @@ -210,10 +210,9 @@ QScriptValue BaseScriptEngine::evaluateInClosure(const QScriptValue& closure, co qCDebug(scriptengine) << QString("[%1] evaluateInClosure %2").arg(isEvaluating()).arg(shortName); #endif { - ExceptionEmitter tryCatch(this, __FUNCTION__); result = BaseScriptEngine::evaluate(program); - if (tryCatch.hasPending()) { - auto err = tryCatch.pending(); + if (hasUncaughtException()) { + auto err = cloneUncaughtException(__FUNCTION__); #ifdef DEBUG_JS_EXCEPTIONS qCWarning(scriptengine) << __FUNCTION__ << "---------- hasCaught:" << err.toString() << result.toString(); err.setProperty("_result", result); @@ -266,37 +265,6 @@ QScriptValue Lambda::call() { return operation(engine->currentContext(), engine); } -// BaseScriptEngine::ExceptionEmitter - -void BaseScriptEngine::_emitUnhandledException(const QScriptValue& exception) { - emit unhandledException(exception); -} -BaseScriptEngine::ExceptionEmitter::ExceptionEmitter(BaseScriptEngine* engine, const QString& debugName) - : _engine(engine), _debugName(debugName) { -} -bool BaseScriptEngine::ExceptionEmitter::hasPending() { - return _engine->hasUncaughtException(); -} -QScriptValue BaseScriptEngine::ExceptionEmitter::pending() { - return _engine->cloneUncaughtException(_debugName); -} -QScriptValue BaseScriptEngine::ExceptionEmitter::consume() { - if (hasPending()) { - _consumedException = pending(); - _engine->clearExceptions(); - } - return _consumedException; -} -bool BaseScriptEngine::ExceptionEmitter::wouldEmit() { - return !_engine->isEvaluating() && _engine->hasUncaughtException(); -} -BaseScriptEngine::ExceptionEmitter::~ExceptionEmitter() { - if (wouldEmit()) { - _engine->_emitUnhandledException(consume()); - } -} - - #ifdef DEBUG_JS void BaseScriptEngine::_debugDump(const QString& header, const QScriptValue& object, const QString& footer) { if (!header.isEmpty()) { diff --git a/libraries/script-engine/src/BaseScriptEngine.h b/libraries/script-engine/src/BaseScriptEngine.h index 620c0915ea..27a6eff33d 100644 --- a/libraries/script-engine/src/BaseScriptEngine.h +++ b/libraries/script-engine/src/BaseScriptEngine.h @@ -46,25 +46,6 @@ protected: #ifdef DEBUG_JS static void _debugDump(const QString& header, const QScriptValue& object, const QString& footer = QString()); #endif - - // ExceptionEmitter can be placed above calls that might throw JS exceptions and it'll - // automatically signal BaseScriptEngine when falling out of scope (recursion aware). - class ExceptionEmitter { - public: - ExceptionEmitter(BaseScriptEngine* engine, const QString& debugName = QString()); - // is there a pending exception? - bool hasPending(); - QScriptValue pending(); - // would it be emitted at scope's end? - bool wouldEmit(); - // consume and return the pending exception - QScriptValue consume(); - ~ExceptionEmitter(); - protected: - BaseScriptEngine* _engine; - QString _debugName; - QScriptValue _consumedException; - }; }; // Lambda helps create callable QScriptValues out of std::functions: diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index ff0ddc2ce3..06cbc8177a 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -899,9 +899,11 @@ QScriptValue ScriptEngine::evaluate(const QString& sourceCode, const QString& fi QScriptValue result; { - // catch any exceptions throw by nested operations - ExceptionEmitter tryCatch(this, __FUNCTION__); result = BaseScriptEngine::evaluate(program); + if (!isEvaluating() && hasUncaughtException()) { + emit unhandledException(cloneUncaughtException(__FUNCTION__)); + clearExceptions(); + } } return result; } @@ -923,9 +925,11 @@ void ScriptEngine::run() { emit runningStateChanged(); { - // catch any exceptions throw by nested operations - ExceptionEmitter tryCatch(this, __FUNCTION__); evaluate(_scriptContents, _fileNameString); + if (!isEvaluating() && hasUncaughtException()) { + emit unhandledException(cloneUncaughtException(__FUNCTION__)); + clearExceptions(); + } } #ifdef _WIN32 // VS13 does not sleep_until unless it uses the system_clock, see: @@ -1361,16 +1365,10 @@ void ScriptEngine::include(const QStringList& includeFiles, QScriptValue callbac evaluate(contents, url.toString()); }; - ExceptionEmitter tryCatch(this, "include"); doWithEnvironment(capturedEntityIdentifier, capturedSandboxURL, operation); - if (tryCatch.hasPending()) { - // match previous include behavior where possible by logging, not propagating, exceptions. - auto err = tryCatch.pending(); - emit unhandledException(err); - // FIXME: to be revisited with next PR 21114-part3 for compat with require/module - //if (tryCatch.wouldEmit()) { - tryCatch.consume(); - //} + if (hasUncaughtException()) { + emit unhandledException(cloneUncaughtException(__FUNCTION__)); + clearExceptions(); } } else { scriptWarningMessage("Script.include() skipping evaluation of previously included url:" + url.toString()); @@ -1508,7 +1506,7 @@ void ScriptEngine::deferLoadEntityScript(const EntityItemID& entityID, const QSt for (int i=0; i < RETRY_ATTEMPT_BATCH && !_pendingLoadEntities.isEmpty(); i++) { auto retry = _pendingLoadEntities.takeFirst(); qCDebug(scriptengine) << "deferLoadEntityScript.retry[" << i << "]:" << retry.entityID << retry.entityScript; - if(!_entityScripts.contains(retry.entityID)) { + if (!_entityScripts.contains(retry.entityID)) { qCDebug(scriptengine) << "deferLoadEntityScript.retry -- entity details gone (entity deleted?)"; } else { auto details = _entityScripts[retry.entityID]; @@ -1715,7 +1713,6 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co sandbox.setProcessEventsInterval(SANDBOX_TIMEOUT); QScriptValue testConstructor, exception; { - ExceptionEmitter tryCatch(&sandbox, QString("(preflight %1)").arg(entityID.toString())); QTimer timeout; timeout.setSingleShot(true); timeout.start(SANDBOX_TIMEOUT); @@ -1731,8 +1728,9 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co testConstructor = sandbox.evaluate(program); - if (tryCatch.hasPending()) { - exception = tryCatch.consume(); + if (sandbox.hasUncaughtException()) { + exception = sandbox.cloneUncaughtException(QString("(preflight %1)").arg(entityID.toString())); + sandbox.clearExceptions(); } else if (testConstructor.isError()) { exception = testConstructor; } @@ -1780,13 +1778,12 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co QScriptValue entityScriptConstructor, entityScriptObject; QUrl sandboxURL = currentSandboxURL.isEmpty() ? scriptOrURL : currentSandboxURL; auto initialization = [&]{ - ExceptionEmitter tryCatch(this, "(construct " + entityID.toString() + ")"); - entityScriptConstructor = evaluate(contents, fileName); entityScriptObject = entityScriptConstructor.construct(); - if (tryCatch.hasPending()) { - entityScriptObject = tryCatch.consume(); + if (hasUncaughtException()) { + entityScriptObject = cloneUncaughtException("(construct " + entityID.toString() + ")"); + clearExceptions(); } }; @@ -1914,8 +1911,6 @@ void ScriptEngine::doWithEnvironment(const EntityItemID& entityID, const QUrl& s currentEntityIdentifier = entityID; currentSandboxURL = sandboxURL; - ExceptionEmitter tryCatcher(this, !entityID.isNull() ? entityID.toString() : __FUNCTION__); - #if DEBUG_CURRENT_ENTITY QScriptValue oldData = this->globalObject().property("debugEntityID"); this->globalObject().setProperty("debugEntityID", entityID.toScriptValue(this)); // Make the entityID available to javascript as a global. @@ -1924,6 +1919,10 @@ void ScriptEngine::doWithEnvironment(const EntityItemID& entityID, const QUrl& s #else operation(); #endif + if (!isEvaluating() && hasUncaughtException()) { + emit unhandledException(cloneUncaughtException(!entityID.isNull() ? entityID.toString() : __FUNCTION__)); + clearExceptions(); + } currentEntityIdentifier = oldIdentifier; currentSandboxURL = oldSandboxURL; } From c89d203f94c0ffa9d18b2a515117c095828076da Mon Sep 17 00:00:00 2001 From: humbletim Date: Fri, 24 Feb 2017 12:27:33 -0500 Subject: [PATCH 10/17] Adapt from std::map locks to simple QHash for flagging busy scriptURLs --- libraries/script-engine/src/ScriptEngine.cpp | 69 ++++++++++++-------- libraries/script-engine/src/ScriptEngine.h | 2 +- 2 files changed, 44 insertions(+), 27 deletions(-) diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index 06cbc8177a..cb63628d1a 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -1494,6 +1494,7 @@ bool ScriptEngine::getEntityScriptDetails(const EntityItemID& entityID, EntitySc const auto RETRY_ATTEMPT_BATCH = 100; //glm::clamp(qgetenv("RETRY_ATTEMPT_BATCH").toInt(), 1, 50); const auto RETRY_ATTEMPT_MSECS = 250; //glm::clamp(qgetenv("RETRY_ATTEMPT_MSECS").toInt(), 50, 1000); +const static EntityItemID BAD_SCRIPT_UUID_PLACEHOLDER { "{20170224-dead-face-0000-cee000021114}" }; void ScriptEngine::deferLoadEntityScript(const EntityItemID& entityID, const QString& entityScript, bool forceRedownload) { const auto needTimer = _pendingLoadEntities.isEmpty(); @@ -1513,12 +1514,18 @@ void ScriptEngine::deferLoadEntityScript(const EntityItemID& entityID, const QSt if (details.status != EntityScriptStatus::PENDING) { qCDebug(scriptengine) << "deferLoadEntityScript.retry -- entity status no longer PENDING; " << details.status; } else { - auto &locker = _lockPerUniqueScriptURL[retry.entityScript]; - if (locker.tryLock()) { - locker.unlock(); + if (!_occupiedScriptURLs.contains(retry.entityScript)) { + // the URL is no longer busy with another Entity, so now it's our turn loadEntityScript(retry.entityID, retry.entityScript, false); } else { - stillPending << retry; + auto entityID = _occupiedScriptURLs[retry.entityScript]; + if (entityID == BAD_SCRIPT_UUID_PLACEHOLDER) { + // the URL was marked bad by an earlier load attempt, so abort the retry mission + qCDebug(scriptengine) << "... pending load of " << retry.entityID << " cancelled"; + } else { + // the URL is still occupied by another Entity, so add to next retry pass + stillPending << retry; + } } } } @@ -1543,7 +1550,7 @@ void ScriptEngine::deferLoadEntityScript(const EntityItemID& entityID, const QSt // processDeferredEntities gets wrapped as a "regular" JavaScript callback so that it can then // be scheduled using setInterval per usual -- allowing the script engine to own its lifecycle. - // we stil need to call clearInterval manually when done, so its passed to calle() above as a property. + // we stil need to call clearInterval manually when done, so its passed to callee() above as a property. QScriptValue function = newLambdaFunction(processDeferredEntities, "processDeferredEntities-loader"); QObject *interval = setInterval( function, RETRY_ATTEMPT_MSECS ); @@ -1577,14 +1584,28 @@ void ScriptEngine::loadEntityScript(const EntityItemID& entityID, const QString& updateEntityScriptStatus(entityID, EntityScriptStatus::PENDING, "...pending..."); } - // This lock/defer approach allows multiple Entities to boot from the same script URL while still taking + // This "occupied" approach allows multiple Entities to boot from the same script URL while still taking // full advantage of cacheable require modules. This only affects Entities literally coming in back-to-back // before the first one has time to finish loading. - auto &locker = _lockPerUniqueScriptURL[entityScript]; - if (!locker.tryLock()) { - qCDebug(scriptengine) << QString("loadEntityScript.deferring[%1] entity: %2 script: %3") - .arg( _pendingLoadEntities.size()).arg(entityID.toString()).arg(entityScript); - deferLoadEntityScript(entityID, entityScript, forceRedownload); + if (!_occupiedScriptURLs.contains(entityScript)) { + // the scriptURL is available -- flag as in-use and proceed + _occupiedScriptURLs[entityScript] = entityID; + } else { + // another Entity is either still booting from this script URL or has failed and marked it "out of order" + auto currentEntityID = _occupiedScriptURLs[entityScript]; + if (currentEntityID == BAD_SCRIPT_UUID_PLACEHOLDER && !forceRedownload) { + // since not force-reloading, assume that the exact same input would produce the exact same output again + // note: this state gets reset with "reload all scripts," leaving/returning to a Domain, clear cache, etc. + qCDebug(scriptengine) << QString("loadEntityScript.cancelled entity: %1 script: %2 (previous script failure)") + .arg(entityID.toString()).arg(entityScript); + updateEntityScriptStatus(entityID, EntityScriptStatus::ERROR_LOADING_SCRIPT, + "Cached Script was marked invalid by previous Entity load failure."); + } else { + // another entity is busy loading from this script URL so wait for them to finish + qCDebug(scriptengine) << QString("loadEntityScript.deferring[%0] entity: %1 script: %2") + .arg( _pendingLoadEntities.size()).arg(entityID.toString()).arg(entityScript); + deferLoadEntityScript(entityID, entityScript, forceRedownload); + } return; } @@ -1598,19 +1619,18 @@ void ScriptEngine::loadEntityScript(const EntityItemID& entityID, const QString& newDetails.scriptText = entityScript; newDetails.status = EntityScriptStatus::LOADING; newDetails.definingSandboxURL = currentSandboxURL; - _entityScripts[entityID] = newDetails; + setEntityScriptDetails(entityID, newDetails); auto scriptCache = DependencyManager::get(); scriptCache->getScriptContents(entityScript, - [=, &locker](const QString& url, const QString& contents, bool isURL, bool success, const QString& status) { + [this, entityScript, entityID](const QString& url, const QString& contents, bool isURL, bool success, const QString& status) { if (isStopping()) { #ifdef DEBUG_ENTITY_STATES qCDebug(scriptengine) << "loadEntityScript.contentAvailable -- stopping"; #endif - locker.unlock(); return; } - executeOnScriptThread([=, &locker]{ + executeOnScriptThread([=]{ #ifdef DEBUG_ENTITY_STATES qCDebug(scriptengine) << "loadEntityScript.contentAvailable" << status << QUrl(url).fileName() << entityID.toString(); #endif @@ -1621,7 +1641,10 @@ void ScriptEngine::loadEntityScript(const EntityItemID& entityID, const QString& qCDebug(scriptengine) << "loadEntityScript.contentAvailable -- aborting"; #endif } - locker.unlock(); + // recheck whether us since may have been set to BAD_SCRIPT_UUID_PLACEHOLDER in entityScriptContentAvailable + if (_occupiedScriptURLs[entityScript] == entityID) { + _occupiedScriptURLs.remove(entityScript); + } }); }, forceRedownload); } @@ -1666,16 +1689,10 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co newDetails.status = status; setEntityScriptDetails(entityID, newDetails); - QMutableListIterator i(_pendingLoadEntities); + qCDebug(scriptengine) << "entityScriptContentAvailable -- flagging " << oldDetails.scriptText << " as BAD_SCRIPT_UUID_PLACEHOLDER"; + // flag this scriptURL as unusuable // note: we want the *original* entityScript string (not the potentially normalized one from ScriptCache results) - const auto entityScript = oldDetails.scriptText; - while (i.hasNext()) { - auto retry = i.next(); - if (retry.entityScript == entityScript) { - qCDebug(scriptengine) << "... pending load of " << retry.entityID << " cancelled"; - i.remove(); - } - } + _occupiedScriptURLs[oldDetails.scriptText] = BAD_SCRIPT_UUID_PLACEHOLDER; }; // NETWORK / FILESYSTEM ERRORS @@ -1856,7 +1873,7 @@ void ScriptEngine::unloadAllEntityScripts() { } _entityScripts.clear(); emit entityScriptDetailsUpdated(); - _lockPerUniqueScriptURL.clear(); + _occupiedScriptURLs.clear(); #ifdef DEBUG_ENGINE_STATE _debugDump( diff --git a/libraries/script-engine/src/ScriptEngine.h b/libraries/script-engine/src/ScriptEngine.h index 7b2a5e8d8c..43cb3f897d 100644 --- a/libraries/script-engine/src/ScriptEngine.h +++ b/libraries/script-engine/src/ScriptEngine.h @@ -270,7 +270,7 @@ protected: QHash _timerFunctionMap; QSet _includedURLs; QHash _entityScripts; - std::map _lockPerUniqueScriptURL; + QHash _occupiedScriptURLs; QList _pendingLoadEntities; bool _isThreaded { false }; From 02827552aebe347d2d80307da1439db97be77f66 Mon Sep 17 00:00:00 2001 From: humbletim Date: Fri, 24 Feb 2017 12:31:18 -0500 Subject: [PATCH 11/17] Add EntityScriptServer version of the stampede test --- .../tests/entityServerStampedeTest.js | 33 +++++++++++++++++++ 1 file changed, 33 insertions(+) create mode 100644 scripts/developer/tests/entityServerStampedeTest.js diff --git a/scripts/developer/tests/entityServerStampedeTest.js b/scripts/developer/tests/entityServerStampedeTest.js new file mode 100644 index 0000000000..35ecd7eb11 --- /dev/null +++ b/scripts/developer/tests/entityServerStampedeTest.js @@ -0,0 +1,33 @@ +var NUM_ENTITIES = 100; +var RADIUS = 2; +var DIV = NUM_ENTITIES / Math.PI / 2; +var PASS_SCRIPT_URL = Script.resolvePath('entityStampedeTest-entity.js'); +var FAIL_SCRIPT_URL = Script.resolvePath('entityStampedeTest-entity-fail.js'); + +var origin = Vec3.sum(MyAvatar.position, Vec3.multiply(5, Quat.getFront(MyAvatar.orientation))); +origin.y += HMD.eyeHeight; + +var uuids = []; + +Script.scriptEnding.connect(function() { + uuids.forEach(function(id) { + Entities.deleteEntity(id); + }); +}); + +for (var i=0; i < NUM_ENTITIES; i++) { + var failGroup = i % 2; + uuids.push(Entities.addEntity({ + type: 'Shape', + shape: failGroup ? 'Sphere' : 'Icosahedron', + name: 'SERVER-entityStampedeTest-' + i, + lifetime: 120, + position: Vec3.sum(origin, Vec3.multiplyQbyV( + MyAvatar.orientation, { x: Math.sin(i / DIV) * RADIUS, y: Math.cos(i / DIV) * RADIUS, z: 0 } + )), + serverScripts: (failGroup ? FAIL_SCRIPT_URL : PASS_SCRIPT_URL) + Settings.getValue('cache_buster'), + dimensions: Vec3.HALF, + color: { red: 0, green: 0, blue: 0 }, + }, !Entities.serversExist())); +} + From 3ac116545e20fcf136f45a386a662c91fe4d3fd6 Mon Sep 17 00:00:00 2001 From: humbletim Date: Fri, 24 Feb 2017 16:05:11 -0500 Subject: [PATCH 12/17] * Switch trigger for deferred loads from timer to using leading entity completion * Bring back notion of tracking "bad scripts" to fail stampeding entities as a set * Update stampede JS tests to highlight/troubleshoot preexisting unload issue --- libraries/script-engine/src/ScriptEngine.cpp | 182 +++++++++--------- libraries/script-engine/src/ScriptEngine.h | 4 +- .../tests/entityServerStampedeTest-entity.js | 21 ++ .../tests/entityServerStampedeTest.js | 2 +- .../tests/entityStampedeTest-entity.js | 13 +- 5 files changed, 127 insertions(+), 95 deletions(-) create mode 100644 scripts/developer/tests/entityServerStampedeTest-entity.js diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index cb63628d1a..c0b2881b72 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -1496,67 +1496,58 @@ const auto RETRY_ATTEMPT_BATCH = 100; //glm::clamp(qgetenv("RETRY_ATTEMPT_BATCH" const auto RETRY_ATTEMPT_MSECS = 250; //glm::clamp(qgetenv("RETRY_ATTEMPT_MSECS").toInt(), 50, 1000); const static EntityItemID BAD_SCRIPT_UUID_PLACEHOLDER { "{20170224-dead-face-0000-cee000021114}" }; -void ScriptEngine::deferLoadEntityScript(const EntityItemID& entityID, const QString& entityScript, bool forceRedownload) { - const auto needTimer = _pendingLoadEntities.isEmpty(); - // NOTE: forceRedownload isn't forwarded here because deferLoadEntityScript() is only ever called when another entity has taken lead for the script - _pendingLoadEntities.push_back({ entityID, entityScript/*, forceRedownload*/ }); +void ScriptEngine::processDeferredEntityLoads(const QString& entityScript, const EntityItemID& leaderID) { + QList retryLoads; + QMutableListIterator i(_deferredEntityLoads); + while (i.hasNext()) { + auto retry = i.next(); + if (retry.entityScript == entityScript) { + retryLoads << retry; + i.remove(); + } + } + foreach(auto &retry, retryLoads) { + // check whether entity was since been deleted + if (!_entityScripts.contains(retry.entityID)) { + qCDebug(scriptengine) << "processDeferredEntityLoads -- entity details gone (entity deleted?)" + << retry.entityID; + continue; + } - auto processDeferredEntities = [this](QScriptContext* context, QScriptEngine*) -> QScriptValue { - QList stillPending; + // check whether entity has since been unloaded or otherwise errored-out + auto details = _entityScripts[retry.entityID]; + if (details.status != EntityScriptStatus::PENDING) { + qCDebug(scriptengine) << "processDeferredEntityLoads -- entity status no longer PENDING; " + << retry.entityID << details.status; + continue; + } - for (int i=0; i < RETRY_ATTEMPT_BATCH && !_pendingLoadEntities.isEmpty(); i++) { - auto retry = _pendingLoadEntities.takeFirst(); - qCDebug(scriptengine) << "deferLoadEntityScript.retry[" << i << "]:" << retry.entityID << retry.entityScript; - if (!_entityScripts.contains(retry.entityID)) { - qCDebug(scriptengine) << "deferLoadEntityScript.retry -- entity details gone (entity deleted?)"; + // propagate leader's failure reasons to the pending entity + const auto leaderDetails = _entityScripts[leaderID]; + if (leaderDetails.status != EntityScriptStatus::RUNNING) { + qCDebug(scriptengine) << QString("... pending load of %1 cancelled (leader: %2 status: %3)") + .arg(retry.entityID.toString()).arg(leaderID.toString()).arg(leaderDetails.status); + + auto extraDetail = "\n(propagated from " + leaderID.toString() + ")"; + if (leaderDetails.status == EntityScriptStatus::ERROR_LOADING_SCRIPT || + leaderDetails.status == EntityScriptStatus::ERROR_RUNNING_SCRIPT) { + // propagate same error so User doesn't have to hunt down stampede's leader + updateEntityScriptStatus(retry.entityID, leaderDetails.status, leaderDetails.errorInfo + extraDetail); } else { - auto details = _entityScripts[retry.entityID]; - if (details.status != EntityScriptStatus::PENDING) { - qCDebug(scriptengine) << "deferLoadEntityScript.retry -- entity status no longer PENDING; " << details.status; - } else { - if (!_occupiedScriptURLs.contains(retry.entityScript)) { - // the URL is no longer busy with another Entity, so now it's our turn - loadEntityScript(retry.entityID, retry.entityScript, false); - } else { - auto entityID = _occupiedScriptURLs[retry.entityScript]; - if (entityID == BAD_SCRIPT_UUID_PLACEHOLDER) { - // the URL was marked bad by an earlier load attempt, so abort the retry mission - qCDebug(scriptengine) << "... pending load of " << retry.entityID << " cancelled"; - } else { - // the URL is still occupied by another Entity, so add to next retry pass - stillPending << retry; - } - } - } + // the leader Entity somehow ended up in some other state (rapid-fire delete or unload could cause) + updateEntityScriptStatus(retry.entityID, EntityScriptStatus::ERROR_LOADING_SCRIPT, + "A previous Entity failed to load using this script URL; reload to try again." + extraDetail); } + continue; } - foreach(const DeferredLoadEntity& retry, stillPending) { - _pendingLoadEntities.push_back(retry); + + if (_occupiedScriptURLs.contains(retry.entityScript)) { + qCWarning(scriptengine) << "--- SHOULD NOT HAPPEN -- recursive call into processDeferredEntityLoads" << retry.entityScript; + continue; } - if (_pendingLoadEntities.isEmpty()) { - QObject *interval = context->callee().property("interval").toQObject(); - // we're done processing so can kill the timer - qCDebug(scriptengine) << "loadEntityScript.retry queue processing complete -- exiting" << interval; - if (interval) { - clearInterval(interval); - } - } - return QScriptValue(); - }; - if (needTimer) { - // we were the first to get queued -- so set up an interval timer for deferred processing - qCDebug(scriptengine) << "deferLoadEntityScript -- scheduling timer " << RETRY_ATTEMPT_MSECS; - - // processDeferredEntities gets wrapped as a "regular" JavaScript callback so that it can then - // be scheduled using setInterval per usual -- allowing the script engine to own its lifecycle. - // we stil need to call clearInterval manually when done, so its passed to callee() above as a property. - - QScriptValue function = newLambdaFunction(processDeferredEntities, "processDeferredEntities-loader"); - QObject *interval = setInterval( function, RETRY_ATTEMPT_MSECS ); - - // make the interval reachable from the handler - function.setProperty("interval", newQObject(interval)); + // if we made it here then the leading entity was successful so proceed with normal load + loadEntityScript(retry.entityID, retry.entityScript, false); } } @@ -1587,28 +1578,33 @@ void ScriptEngine::loadEntityScript(const EntityItemID& entityID, const QString& // This "occupied" approach allows multiple Entities to boot from the same script URL while still taking // full advantage of cacheable require modules. This only affects Entities literally coming in back-to-back // before the first one has time to finish loading. - if (!_occupiedScriptURLs.contains(entityScript)) { - // the scriptURL is available -- flag as in-use and proceed - _occupiedScriptURLs[entityScript] = entityID; - } else { - // another Entity is either still booting from this script URL or has failed and marked it "out of order" + if (_occupiedScriptURLs.contains(entityScript)) { auto currentEntityID = _occupiedScriptURLs[entityScript]; - if (currentEntityID == BAD_SCRIPT_UUID_PLACEHOLDER && !forceRedownload) { - // since not force-reloading, assume that the exact same input would produce the exact same output again - // note: this state gets reset with "reload all scripts," leaving/returning to a Domain, clear cache, etc. - qCDebug(scriptengine) << QString("loadEntityScript.cancelled entity: %1 script: %2 (previous script failure)") - .arg(entityID.toString()).arg(entityScript); - updateEntityScriptStatus(entityID, EntityScriptStatus::ERROR_LOADING_SCRIPT, - "Cached Script was marked invalid by previous Entity load failure."); + if (currentEntityID == BAD_SCRIPT_UUID_PLACEHOLDER) { + if (forceRedownload) { + // script was previously marked unusable, but we're reloading so reset it + _occupiedScriptURLs.remove(entityScript); + } else { + // since not reloading, assume that the exact same input would produce the exact same output again + // note: this state gets reset with "reload all scripts," leaving/returning to a Domain, clear cache, etc. + qCDebug(scriptengine) << QString("loadEntityScript.cancelled entity: %1 script: %2 (previous script failure)") + .arg(entityID.toString()).arg(entityScript); + updateEntityScriptStatus(entityID, EntityScriptStatus::ERROR_LOADING_SCRIPT, + "A previous Entity failed to load using this script URL; reload to try again."); + return; + } } else { // another entity is busy loading from this script URL so wait for them to finish - qCDebug(scriptengine) << QString("loadEntityScript.deferring[%0] entity: %1 script: %2") - .arg( _pendingLoadEntities.size()).arg(entityID.toString()).arg(entityScript); - deferLoadEntityScript(entityID, entityScript, forceRedownload); + qCDebug(scriptengine) << QString("loadEntityScript.deferring[%0] entity: %1 script: %2 (waiting on %3)") + .arg( _deferredEntityLoads.size()).arg(entityID.toString()).arg(entityScript).arg(currentEntityID.toString()); + _deferredEntityLoads.push_back({ entityID, entityScript }); + return; } - return; } + // the scriptURL slot is available; flag as in-use + _occupiedScriptURLs[entityScript] = entityID; + #ifdef DEBUG_ENTITY_STATES auto previousStatus = _entityScripts.contains(entityID) ? _entityScripts[entityID].status : EntityScriptStatus::PENDING; qCDebug(scriptengine) << "loadEntityScript.LOADING: " << entityScript << entityID.toString() @@ -1642,7 +1638,7 @@ void ScriptEngine::loadEntityScript(const EntityItemID& entityID, const QString& #endif } // recheck whether us since may have been set to BAD_SCRIPT_UUID_PLACEHOLDER in entityScriptContentAvailable - if (_occupiedScriptURLs[entityScript] == entityID) { + if (_occupiedScriptURLs.contains(entityScript) && _occupiedScriptURLs[entityScript] == entityID) { _occupiedScriptURLs.remove(entityScript); } }); @@ -1679,6 +1675,8 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co auto fileName = isURL ? scriptOrURL : "about:EmbeddedEntityScript"; const EntityScriptDetails &oldDetails = _entityScripts[entityID]; + const auto entityScript = oldDetails.scriptText; + EntityScriptDetails newDetails; newDetails.scriptText = scriptOrURL; @@ -1689,10 +1687,10 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co newDetails.status = status; setEntityScriptDetails(entityID, newDetails); - qCDebug(scriptengine) << "entityScriptContentAvailable -- flagging " << oldDetails.scriptText << " as BAD_SCRIPT_UUID_PLACEHOLDER"; - // flag this scriptURL as unusuable - // note: we want the *original* entityScript string (not the potentially normalized one from ScriptCache results) - _occupiedScriptURLs[oldDetails.scriptText] = BAD_SCRIPT_UUID_PLACEHOLDER; + qCDebug(scriptengine) << "entityScriptContentAvailable -- flagging " << entityScript << " as BAD_SCRIPT_UUID_PLACEHOLDER"; + // flag the original entityScript as unusuable + _occupiedScriptURLs[entityScript] = BAD_SCRIPT_UUID_PLACEHOLDER; + processDeferredEntityLoads(entityScript, entityID); }; // NETWORK / FILESYSTEM ERRORS @@ -1826,6 +1824,9 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co // if we got this far, then call the preload method callEntityScriptMethod(entityID, "preload"); + + _occupiedScriptURLs.remove(entityScript); + processDeferredEntityLoads(entityScript, entityID); } void ScriptEngine::unloadEntityScript(const EntityItemID& entityID) { @@ -1845,14 +1846,25 @@ void ScriptEngine::unloadEntityScript(const EntityItemID& entityID) { #endif if (_entityScripts.contains(entityID)) { + auto oldDetails = _entityScripts[entityID]; if (isEntityScriptRunning(entityID)) { callEntityScriptMethod(entityID, "unload"); + } else { + qCDebug(scriptengine) << "unload called while !running" << entityID << oldDetails.status; + } + if (oldDetails.status != EntityScriptStatus::UNLOADED) { + EntityScriptDetails newDetails; + newDetails.status = EntityScriptStatus::UNLOADED; + newDetails.lastModified = QDateTime::currentMSecsSinceEpoch(); + // keep scriptText populated for the current need to "debouce" duplicate calls to unloadEntityScript + newDetails.scriptText = oldDetails.scriptText; + setEntityScriptDetails(entityID, newDetails); } - EntityScriptDetails newDetails; - newDetails.status = EntityScriptStatus::UNLOADED; - newDetails.lastModified = QDateTime::currentMSecsSinceEpoch(); - setEntityScriptDetails(entityID, newDetails); stopAllTimersForEntityScript(entityID); + { + // FIXME: shouldn't have to do this here, but currently something seems to be firing unloads moments after firing initial load requests + processDeferredEntityLoads(oldDetails.scriptText, entityID); + } } } @@ -1902,17 +1914,7 @@ void ScriptEngine::refreshFileScript(const EntityItemID& entityID) { auto lastModified = QFileInfo(filePath).lastModified().toMSecsSinceEpoch(); if (lastModified > details.lastModified) { scriptInfoMessage("Reloading modified script " + details.scriptText); - - QFile file(filePath); - file.open(QIODevice::ReadOnly); - QString scriptContents = QTextStream(&file).readAll(); - this->unloadEntityScript(entityID); - this->entityScriptContentAvailable(entityID, details.scriptText, scriptContents, true, true, "Success"); - if (!isEntityScriptRunning(entityID)) { - scriptWarningMessage("Reload script " + details.scriptText + " failed"); - } else { - details = _entityScripts[entityID]; - } + loadEntityScript(entityID, details.scriptText, true); } } recurseGuard = false; diff --git a/libraries/script-engine/src/ScriptEngine.h b/libraries/script-engine/src/ScriptEngine.h index 43cb3f897d..7f533d2f40 100644 --- a/libraries/script-engine/src/ScriptEngine.h +++ b/libraries/script-engine/src/ScriptEngine.h @@ -170,7 +170,6 @@ public: Q_INVOKABLE bool isEntityScriptRunning(const EntityItemID& entityID) { return _entityScripts.contains(entityID) && _entityScripts[entityID].status == EntityScriptStatus::RUNNING; } - Q_INVOKABLE void deferLoadEntityScript(const EntityItemID& entityID, const QString& entityScript, bool forceRedownload); Q_INVOKABLE void loadEntityScript(const EntityItemID& entityID, const QString& entityScript, bool forceRedownload); Q_INVOKABLE void unloadEntityScript(const EntityItemID& entityID); // will call unload method Q_INVOKABLE void unloadAllEntityScripts(); @@ -247,6 +246,7 @@ protected: void updateEntityScriptStatus(const EntityItemID& entityID, const EntityScriptStatus& status, const QString& errorInfo = QString()); void setEntityScriptDetails(const EntityItemID& entityID, const EntityScriptDetails& details); void setParentURL(const QString& parentURL) { _parentURL = parentURL; } + void processDeferredEntityLoads(const QString& entityScript, const EntityItemID& leaderID); QObject* setupTimerWithInterval(const QScriptValue& function, int intervalMS, bool isSingleShot); void stopTimer(QTimer* timer); @@ -271,7 +271,7 @@ protected: QSet _includedURLs; QHash _entityScripts; QHash _occupiedScriptURLs; - QList _pendingLoadEntities; + QList _deferredEntityLoads; bool _isThreaded { false }; QScriptEngineDebugger* _debugger { nullptr }; diff --git a/scripts/developer/tests/entityServerStampedeTest-entity.js b/scripts/developer/tests/entityServerStampedeTest-entity.js new file mode 100644 index 0000000000..781753908c --- /dev/null +++ b/scripts/developer/tests/entityServerStampedeTest-entity.js @@ -0,0 +1,21 @@ +(function() { + return { + preload: function(uuid) { + var props = Entities.getEntityProperties(uuid); + var shape = props.shape === 'Sphere' ? 'Hexagon' : 'Sphere'; + + Entities.editEntity(uuid, { + shape: shape, + color: { red: 0xff, green: 0xff, blue: 0xff }, + }); + this.name = props.name; + print("preload", this.name); + }, + unload: function(uuid) { + print("unload", this.name); + Entities.editEntity(uuid, { + color: { red: 0x0f, green: 0x0f, blue: 0xff }, + }); + }, + }; +}) diff --git a/scripts/developer/tests/entityServerStampedeTest.js b/scripts/developer/tests/entityServerStampedeTest.js index 35ecd7eb11..3fcf01bb34 100644 --- a/scripts/developer/tests/entityServerStampedeTest.js +++ b/scripts/developer/tests/entityServerStampedeTest.js @@ -1,7 +1,7 @@ var NUM_ENTITIES = 100; var RADIUS = 2; var DIV = NUM_ENTITIES / Math.PI / 2; -var PASS_SCRIPT_URL = Script.resolvePath('entityStampedeTest-entity.js'); +var PASS_SCRIPT_URL = Script.resolvePath('entityServerStampedeTest-entity.js'); var FAIL_SCRIPT_URL = Script.resolvePath('entityStampedeTest-entity-fail.js'); var origin = Vec3.sum(MyAvatar.position, Vec3.multiply(5, Quat.getFront(MyAvatar.orientation))); diff --git a/scripts/developer/tests/entityStampedeTest-entity.js b/scripts/developer/tests/entityStampedeTest-entity.js index 1f1d6bcf76..bab4efa8eb 100644 --- a/scripts/developer/tests/entityStampedeTest-entity.js +++ b/scripts/developer/tests/entityStampedeTest-entity.js @@ -1,12 +1,21 @@ (function() { return { preload: function(uuid) { - var shape = Entities.getEntityProperties(uuid).shape === 'Sphere' ? 'Cube' : 'Sphere'; + var props = Entities.getEntityProperties(uuid); + var shape = props.shape === 'Sphere' ? 'Cube' : 'Sphere'; Entities.editEntity(uuid, { shape: shape, color: { red: 0xff, green: 0xff, blue: 0xff }, }); - } + this.name = props.name; + print("preload", this.name); + }, + unload: function(uuid) { + print("unload", this.name); + Entities.editEntity(uuid, { + color: { red: 0xff, green: 0x0f, blue: 0x0f }, + }); + }, }; }) From cdbb13ecff0e76a42249a6d30fd89256a0c9f7cd Mon Sep 17 00:00:00 2001 From: humbletim Date: Fri, 24 Feb 2017 17:40:06 -0500 Subject: [PATCH 13/17] Log cleanup --- libraries/script-engine/src/ScriptEngine.cpp | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index c0b2881b72..75dc83fe63 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -1587,16 +1587,20 @@ void ScriptEngine::loadEntityScript(const EntityItemID& entityID, const QString& } else { // since not reloading, assume that the exact same input would produce the exact same output again // note: this state gets reset with "reload all scripts," leaving/returning to a Domain, clear cache, etc. +#ifdef DEBUG_ENTITY_STATES qCDebug(scriptengine) << QString("loadEntityScript.cancelled entity: %1 script: %2 (previous script failure)") .arg(entityID.toString()).arg(entityScript); +#endif updateEntityScriptStatus(entityID, EntityScriptStatus::ERROR_LOADING_SCRIPT, "A previous Entity failed to load using this script URL; reload to try again."); return; } } else { // another entity is busy loading from this script URL so wait for them to finish +#ifdef DEBUG_ENTITY_STATES qCDebug(scriptengine) << QString("loadEntityScript.deferring[%0] entity: %1 script: %2 (waiting on %3)") .arg( _deferredEntityLoads.size()).arg(entityID.toString()).arg(entityScript).arg(currentEntityID.toString()); +#endif _deferredEntityLoads.push_back({ entityID, entityScript }); return; } @@ -1687,7 +1691,9 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co newDetails.status = status; setEntityScriptDetails(entityID, newDetails); +#ifdef DEBUG_ENTITY_STATES qCDebug(scriptengine) << "entityScriptContentAvailable -- flagging " << entityScript << " as BAD_SCRIPT_UUID_PLACEHOLDER"; +#endif // flag the original entityScript as unusuable _occupiedScriptURLs[entityScript] = BAD_SCRIPT_UUID_PLACEHOLDER; processDeferredEntityLoads(entityScript, entityID); From 731c01985bfafe6966eed5afd49c622d1a0c5087 Mon Sep 17 00:00:00 2001 From: humbletim Date: Fri, 24 Feb 2017 19:21:17 -0500 Subject: [PATCH 14/17] switch from autos --- libraries/script-engine/src/ScriptEngine.cpp | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index 75dc83fe63..99339834ce 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -1506,7 +1506,7 @@ void ScriptEngine::processDeferredEntityLoads(const QString& entityScript, const i.remove(); } } - foreach(auto &retry, retryLoads) { + foreach(DeferredLoadEntity retry, retryLoads) { // check whether entity was since been deleted if (!_entityScripts.contains(retry.entityID)) { qCDebug(scriptengine) << "processDeferredEntityLoads -- entity details gone (entity deleted?)" @@ -1528,7 +1528,7 @@ void ScriptEngine::processDeferredEntityLoads(const QString& entityScript, const qCDebug(scriptengine) << QString("... pending load of %1 cancelled (leader: %2 status: %3)") .arg(retry.entityID.toString()).arg(leaderID.toString()).arg(leaderDetails.status); - auto extraDetail = "\n(propagated from " + leaderID.toString() + ")"; + auto extraDetail = QString("\n(propagated from %1)").arg(leaderID.toString()); if (leaderDetails.status == EntityScriptStatus::ERROR_LOADING_SCRIPT || leaderDetails.status == EntityScriptStatus::ERROR_RUNNING_SCRIPT) { // propagate same error so User doesn't have to hunt down stampede's leader @@ -1599,7 +1599,7 @@ void ScriptEngine::loadEntityScript(const EntityItemID& entityID, const QString& // another entity is busy loading from this script URL so wait for them to finish #ifdef DEBUG_ENTITY_STATES qCDebug(scriptengine) << QString("loadEntityScript.deferring[%0] entity: %1 script: %2 (waiting on %3)") - .arg( _deferredEntityLoads.size()).arg(entityID.toString()).arg(entityScript).arg(currentEntityID.toString()); + .arg(_deferredEntityLoads.size()).arg(entityID.toString()).arg(entityScript).arg(currentEntityID.toString()); #endif _deferredEntityLoads.push_back({ entityID, entityScript }); return; @@ -1679,7 +1679,7 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co auto fileName = isURL ? scriptOrURL : "about:EmbeddedEntityScript"; const EntityScriptDetails &oldDetails = _entityScripts[entityID]; - const auto entityScript = oldDetails.scriptText; + const QString entityScript = oldDetails.scriptText; EntityScriptDetails newDetails; newDetails.scriptText = scriptOrURL; @@ -1852,7 +1852,7 @@ void ScriptEngine::unloadEntityScript(const EntityItemID& entityID) { #endif if (_entityScripts.contains(entityID)) { - auto oldDetails = _entityScripts[entityID]; + const EntityScriptDetails &oldDetails = _entityScripts[entityID]; if (isEntityScriptRunning(entityID)) { callEntityScriptMethod(entityID, "unload"); } else { From 5b11c0e00a92b55e12f4c433177d807b251b1a1c Mon Sep 17 00:00:00 2001 From: humbletim Date: Fri, 24 Feb 2017 20:45:12 -0500 Subject: [PATCH 15/17] remove unused consts --- libraries/script-engine/src/ScriptEngine.cpp | 2 -- 1 file changed, 2 deletions(-) diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index 99339834ce..d4b6d592c0 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -1492,8 +1492,6 @@ bool ScriptEngine::getEntityScriptDetails(const EntityItemID& entityID, EntitySc return true; } -const auto RETRY_ATTEMPT_BATCH = 100; //glm::clamp(qgetenv("RETRY_ATTEMPT_BATCH").toInt(), 1, 50); -const auto RETRY_ATTEMPT_MSECS = 250; //glm::clamp(qgetenv("RETRY_ATTEMPT_MSECS").toInt(), 50, 1000); const static EntityItemID BAD_SCRIPT_UUID_PLACEHOLDER { "{20170224-dead-face-0000-cee000021114}" }; void ScriptEngine::processDeferredEntityLoads(const QString& entityScript, const EntityItemID& leaderID) { From 654c72fb7e19c6ee6f5d46249220b5257c5bea9e Mon Sep 17 00:00:00 2001 From: humbletim Date: Mon, 27 Feb 2017 22:58:59 -0500 Subject: [PATCH 16/17] Add weakRef guard to detect ScriptEngine deletion during ScriptCache::getScriptContents --- libraries/script-engine/src/ScriptEngine.cpp | 8 +++++++- libraries/script-engine/src/ScriptEngine.h | 2 +- 2 files changed, 8 insertions(+), 2 deletions(-) diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index d4b6d592c0..bbe2d90ba4 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -1620,8 +1620,14 @@ void ScriptEngine::loadEntityScript(const EntityItemID& entityID, const QString& setEntityScriptDetails(entityID, newDetails); auto scriptCache = DependencyManager::get(); + // note: see EntityTreeRenderer.cpp for shared pointer lifecycle management + QWeakPointer weakRef(sharedFromThis()); scriptCache->getScriptContents(entityScript, - [this, entityScript, entityID](const QString& url, const QString& contents, bool isURL, bool success, const QString& status) { + [this, weakRef, entityScript, entityID](const QString& url, const QString& contents, bool isURL, bool success, const QString& status) { + if (!weakRef) { + qCWarning(scriptengine) << "loadEntityScript.contentAvailable -- ScriptEngine was deleted during getScriptContents!!"; + return; + } if (isStopping()) { #ifdef DEBUG_ENTITY_STATES qCDebug(scriptengine) << "loadEntityScript.contentAvailable -- stopping"; diff --git a/libraries/script-engine/src/ScriptEngine.h b/libraries/script-engine/src/ScriptEngine.h index 7f533d2f40..b988ccfe90 100644 --- a/libraries/script-engine/src/ScriptEngine.h +++ b/libraries/script-engine/src/ScriptEngine.h @@ -78,7 +78,7 @@ public: QUrl definingSandboxURL { QUrl("about:EntityScript") }; }; -class ScriptEngine : public BaseScriptEngine, public EntitiesScriptEngineProvider { +class ScriptEngine : public BaseScriptEngine, public EntitiesScriptEngineProvider, public QEnableSharedFromThis { Q_OBJECT Q_PROPERTY(QString context READ getContext) public: From 2505a89b5e6c3aac60420918164a070ca9bdc5fb Mon Sep 17 00:00:00 2001 From: humbletim Date: Tue, 28 Feb 2017 00:41:35 -0500 Subject: [PATCH 17/17] Per CR feedback bump to strong ref --- libraries/script-engine/src/ScriptEngine.cpp | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index bbe2d90ba4..621be00739 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -1624,7 +1624,8 @@ void ScriptEngine::loadEntityScript(const EntityItemID& entityID, const QString& QWeakPointer weakRef(sharedFromThis()); scriptCache->getScriptContents(entityScript, [this, weakRef, entityScript, entityID](const QString& url, const QString& contents, bool isURL, bool success, const QString& status) { - if (!weakRef) { + QSharedPointer strongRef(weakRef); + if (!strongRef) { qCWarning(scriptengine) << "loadEntityScript.contentAvailable -- ScriptEngine was deleted during getScriptContents!!"; return; }