From b15956278c680bf94c38dbd3b8a259f0fc431d4b Mon Sep 17 00:00:00 2001 From: humbletim Date: Thu, 16 Feb 2017 07:32:32 -0500 Subject: [PATCH] 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);