History

separate out supporting changes into 21114-part2 branch

humbletim committed 9 years ago

Commit b1595621 parent 9b0bee910 files · +833 −223Browse files

Showing the changes to libraries/script-engine/src/ScriptEngine.cpp (1 of 10 files). Show all

Unified · Split

libraries/script-engine/src/ScriptEngine.cpp+342−191
@@ -49,6 +49,7 @@ · 48 unmodified lines
4949
5050 #include "ArrayBufferViewClass.h"
5151 #include "BatchLoader.h"
52+#include "BaseScriptEngine.h"
5253 #include "DataViewClass.h"
5354 #include "EventTypes.h"
5455 #include "FileScriptingInterface.h" // unzip project
@@ -68,9 +69,12 @@ · 13 unmodified lines
6869
6970 #include "MIDIEvent.h"
7071
71−const QString BaseScriptEngine::SCRIPT_EXCEPTION_FORMAT { "[UncaughtException] %1 in %2:%3" };
7272 static const QScriptEngine::QObjectWrapOptions DEFAULT_QOBJECT_WRAP_OPTIONS =
7373 QScriptEngine::ExcludeDeleteLater | QScriptEngine::ExcludeChildObjects;
74+static const QScriptValue::PropertyFlags READONLY_PROP_FLAGS { QScriptValue::ReadOnly | QScriptValue::Undeletable };
75+static const QScriptValue::PropertyFlags HIDDEN_PROP_FLAGS { READONLY_PROP_FLAGS | QScriptValue::SkipInEnumeration };
76+
77+
7478
7579 static const bool HIFI_AUTOREFRESH_FILE_SCRIPTS { true };
7680
@@ -89,13 +93,9 @@ static QScriptValue debugPrint(QScriptContext* context, QScriptEngine* engine){ · 12 unmodified lines
8993 }
9094 qCDebug(scriptengineScript).noquote() << "script:print()<<" << message; // noquote() so that \n is treated as newline
9195
92− message = message.replace("\\", "\\\\")
93− .replace("\n", "\\n")
94− .replace("\r", "\\r")
95− .replace("'", "\\'");
96−
97− // FIXME - this approach neeeds revisiting. print() comes here, which ends up doing an evaluate?
98− engine->evaluate("Script.print('" + message + "')");
96+ // FIXME - this approach neeeds revisiting. print() comes here, which ends up calling Script.print?
97+ engine->globalObject().property("Script").property("print")
98+ .call(engine->nullValue(), QScriptValueList({ message }));
9999
100100 return QScriptValue();
101101 }
@@ -139,52 +139,15 @@ QString encodeEntityIdIntoEntityUrl(const QString& url, const QString& entityID) · 37 unmodified lines
139139 return url + " [EntityID:" + entityID + "]";
140140 }
141141
142−QString BaseScriptEngine::lintScript(const QString& sourceCode, const QString& fileName, const int lineNumber) {
143− const auto syntaxCheck = checkSyntax(sourceCode);
144− if (syntaxCheck.state() != syntaxCheck.Valid) {
145− const auto error = syntaxCheck.errorMessage();
146− const auto line = QString::number(syntaxCheck.errorLineNumber());
147− const auto column = QString::number(syntaxCheck.errorColumnNumber());
148− const auto message = QString("[SyntaxError] %1 in %2:%3(%4)").arg(error, fileName, line, column);
149− return message;
150− }
151− return QString();
152−}
153−
154−QString BaseScriptEngine::formatUncaughtException(const QString& overrideFileName) {
155− QString message;
156− if (hasUncaughtException()) {
157− const auto error = uncaughtException();
158− const auto backtrace = uncaughtExceptionBacktrace();
159− const auto exception = error.toString();
160− auto filename = overrideFileName;
161− if (filename.isEmpty()) {
162− QScriptContextInfo ctx { currentContext() };
163− filename = ctx.fileName();
164− }
165− const auto line = QString::number(uncaughtExceptionLineNumber());
166−
167− message = QString(SCRIPT_EXCEPTION_FORMAT).arg(exception, overrideFileName, line);
168− if (!backtrace.empty()) {
169− static const auto lineSeparator = "\n ";
170− message += QString("\n[Backtrace]%1%2").arg(lineSeparator, backtrace.join(lineSeparator));
171− }
172− }
173− return message;
174−}
175−
176−QString ScriptEngine::reportUncaughtException(const QString& overrideFileName) {
177− QString message;
178− if (!hasUncaughtException()) {
179− return message;
180− }
181− message = formatUncaughtException(overrideFileName.isEmpty() ? _fileNameString : overrideFileName);
142+QString ScriptEngine::logException(const QScriptValue& exception) {
143+ auto message = formatException(exception);
182144 scriptErrorMessage(qPrintable(message));
183145 return message;
184146 }
185147
186148 int ScriptEngine::processLevelMaxRetries { ScriptRequest::MAX_RETRIES };
187149 ScriptEngine::ScriptEngine(Context context, const QString& scriptContents, const QString& fileNameString) :
150+ BaseScriptEngine(),
188151 _context(context),
189152 _scriptContents(scriptContents),
190153 _timerFunctionMap(),
@@ -194,8 +157,14 @@ ScriptEngine::ScriptEngine(Context context, const QString& scriptContents, const · 3 unmodified lines
194157 DependencyManager::get<ScriptEngines>()->addScriptEngine(this);
195158
196159 connect(this, &QScriptEngine::signalHandlerException, this, [this](const QScriptValue& exception) {
197− reportUncaughtException();
198− clearExceptions();
160+ if (hasUncaughtException()) {
161+ // the engine's uncaughtException() seems to produce much better stack traces here
162+ emit unhandledException(cloneUncaughtException("signalHandlerException"));
163+ clearExceptions();
164+ } else {
165+ // ... but may not always be available -- so if needed we fallback to the passed exception
166+ emit unhandledException(exception);
167+ }
199168 });
200169
201170 setProcessEventsInterval(MSECS_PER_SECOND);
@@ -203,7 +172,16 @@ ScriptEngine::ScriptEngine(Context context, const QString& scriptContents, const · 1 unmodified line
203172 qCDebug(scriptengine) << "isEntityServerScript() -- limiting maxRetries to 1";
204173 processLevelMaxRetries = 1;
205174 }
206− qCDebug(scriptengine) << getContext() << "processLevelMaxRetries =" << processLevelMaxRetries;
175+ //qCDebug(scriptengine) << getContext() << "processLevelMaxRetries =" << processLevelMaxRetries << fileNameString;
176+
177+ // this is where all unhandled exceptions end up getting logged
178+ connect(this, &BaseScriptEngine::unhandledException, this, [this](const QScriptValue& err) {
179+ auto output = err.engine() == this ? err : makeError(err);
180+ if (!output.property("detail").isValid()) {
181+ output.setProperty("detail", "UnhandledException");
182+ }
183+ logException(output);
184+ });
207185 }
208186
209187 QString ScriptEngine::getContext() const {
@@ -223,13 +201,22 @@ QString ScriptEngine::getContext() const { · 13 unmodified lines
223201 }
224202
225203 ScriptEngine::~ScriptEngine() {
204+ // FIXME: are these scriptInfoMessage/scriptWarningMessage segfaulting anybody else at app shutdown?
205+#if !defined(Q_OS_LINUX)
226206 scriptInfoMessage("Script Engine shutting down:" + getFilename());
207+#else
208+ qCDebug(scriptengine) << "~ScriptEngine()" << this;
209+#endif
227210
228211 auto scriptEngines = DependencyManager::get<ScriptEngines>();
229212 if (scriptEngines) {
230213 scriptEngines->removeScriptEngine(this);
231214 } else {
215+#if !defined(Q_OS_LINUX)
232216 scriptWarningMessage("Script destroyed after ScriptEngines!");
217+#else
218+ qCWarning(scriptengine) << ("Script destroyed after ScriptEngines!");
219+#endif
233220 }
234221 }
235222
@@ -319,9 +306,12 @@ void ScriptEngine::runDebuggable() { · 83 unmodified lines
319306 }
320307 }
321308 _lastUpdate = now;
322− // Debug and clear exceptions
323− if (hasUncaughtException()) {
324− reportUncaughtException();
309+
310+ // only clear exceptions if we are not in the middle of evaluating
311+ if (!isEvaluating() && hasUncaughtException()) {
312+ qCWarning(scriptengine) << __FUNCTION__ << "---------- UNCAUGHT EXCEPTION --------";
313+ qCWarning(scriptengine) << "runDebuggable" << uncaughtException().toString();
314+ logException(__FUNCTION__);
325315 clearExceptions();
326316 }
327317 });
@@ -356,10 +346,9 @@ void ScriptEngine::runInThread() { · 28 unmodified lines
356346 workerThread->start();
357347 }
358348
359−void ScriptEngine::executeOnScriptThread(std::function<void()> function, bool blocking ) {
349+void ScriptEngine::executeOnScriptThread(std::function<void()> function, const Qt::ConnectionType& type ) {
360350 if (QThread::currentThread() != thread()) {
361− QMetaObject::invokeMethod(this, "executeOnScriptThread", blocking ? Qt::BlockingQueuedConnection : Qt::QueuedConnection,
362− Q_ARG(std::function<void()>, function));
351+ QMetaObject::invokeMethod(this, "executeOnScriptThread", type, Q_ARG(std::function<void()>, function));
363352 return;
364353 }
365354
@@ -558,6 +547,7 @@ void ScriptEngine::init() { · 192 unmodified lines
558547 qCWarning(scriptengine) << "deletingEntity while entity script is still running!" << entityID;
559548 }
560549 _entityScripts.remove(entityID);
550+ emit entityScriptDetailsUpdated();
561551 }
562552 });
563553
@@ -589,8 +579,7 @@ void ScriptEngine::init() { · 25 unmodified lines
589579 QScriptValue webSocketConstructorValue = newFunction(WebSocketClass::constructor);
590580 globalObject().setProperty("WebSocket", webSocketConstructorValue);
591581
592− QScriptValue printConstructorValue = newFunction(debugPrint);
593− globalObject().setProperty("print", printConstructorValue);
582+ globalObject().setProperty("print", newFunction(debugPrint));
594583
595584 QScriptValue audioEffectOptionsConstructorValue = newFunction(AudioEffectOptions::constructor);
596585 globalObject().setProperty("AudioEffectOptions", audioEffectOptionsConstructorValue);
@@ -604,6 +593,7 @@ void ScriptEngine::init() { · 7 unmodified lines
604593 qScriptRegisterMetaType(this, wscReadyStateToScriptValue, wscReadyStateFromScriptValue);
605594
606595 registerGlobalObject("Script", this);
596+
607597 registerGlobalObject("Audio", &AudioScriptingInterface::getInstance());
608598 registerGlobalObject("Entities", entityScriptingInterface.data());
609599 registerGlobalObject("Quat", &_quatLibrary);
@@ -870,7 +860,6 @@ void ScriptEngine::addEventHandler(const EntityItemID& entityID, const QString& · 260 unmodified lines
870860 handlersForEvent << handlerData; // Note that the same handler can be added many times. See removeEntityEventHandler().
871861 }
872862
873−
874863 QScriptValue ScriptEngine::evaluate(const QString& sourceCode, const QString& fileName, int lineNumber) {
875864 if (DependencyManager::get<ScriptEngines>()->isStopped()) {
876865 return QScriptValue(); // bail early
@@ -892,23 +881,28 @@ QScriptValue ScriptEngine::evaluate(const QString& sourceCode, const QString& fi · 15 unmodified lines
892881
893882 // Check syntax
894883 auto syntaxError = lintScript(sourceCode, fileName);
884+ if (syntaxError.isError()) {
885+ if (isEvaluating()) {
886+ currentContext()->throwValue(syntaxError);
887+ } else {
888+ syntaxError.setProperty("detail", "evaluate");
889+ emit unhandledException(syntaxError);
890+ }
891+ return syntaxError;
892+ }
895893 QScriptProgram program { sourceCode, fileName, lineNumber };
896− if (!syntaxError.isEmpty() || program.isNull()) {
897− scriptErrorMessage(qPrintable(syntaxError));
898− return QScriptValue();
894+ if (program.isNull()) {
895+ // can this happen?
896+ auto err = makeError("could not create QScriptProgram for " + fileName);
897+ emit unhandledException(err);
898+ return err;
899899 }
900900
901− ++_evaluatesPending;
902− auto result = BaseScriptEngine::evaluate(program);
903− --_evaluatesPending;
904−
905− if (hasUncaughtException()) {
906− result = uncaughtException();
907− reportUncaughtException(program.fileName());
908− emit evaluationFinished(result, true);
909− clearExceptions();
910− } else {
911− emit evaluationFinished(result, false);
901+ QScriptValue result;
902+ {
903+ // catch any exceptions throw by nested operations
904+ ExceptionEmitter tryCatch(this, __FUNCTION__);
905+ result = BaseScriptEngine::evaluate(program);
912906 }
913907 return result;
914908 }
@@ -929,8 +923,11 @@ void ScriptEngine::run() { · 14 unmodified lines
929923 _isRunning = true;
930924 emit runningStateChanged();
931925
932− QScriptValue result = evaluate(_scriptContents, _fileNameString);
933−
926+ {
927+ // catch any exceptions throw by nested operations
928+ ExceptionEmitter tryCatch(this, __FUNCTION__);
929+ evaluate(_scriptContents, _fileNameString);
930+ }
934931 #ifdef _WIN32
935932 // VS13 does not sleep_until unless it uses the system_clock, see:
936933 // https://www.reddit.com/r/cpp_questions/comments/3o71ic/sleep_until_not_working_with_a_time_pointsteady/
@@ -1057,13 +1054,14 @@ void ScriptEngine::run() { · 120 unmodified lines
10571054 }
10581055 _lastUpdate = now;
10591056
1060− // Debug and clear exceptions
1061− if (hasUncaughtException()) {
1062− reportUncaughtException();
1057+ // only clear exceptions if we are not in the middle of evaluating
1058+ if (!isEvaluating() && hasUncaughtException()) {
1059+ qCWarning(scriptengine) << __FUNCTION__ << "---------- UNCAUGHT EXCEPTION --------";
1060+ qCWarning(scriptengine) << "runInThread" << uncaughtException().toString();
1061+ emit unhandledException(cloneUncaughtException(__FUNCTION__));
10631062 clearExceptions();
10641063 }
10651064 }
1066−
10671065 scriptInfoMessage("Script Engine stopping:" + getFilename());
10681066
10691067 stopAllTimers(); // make sure all our timers are stopped if the script is ending
@@ -1096,9 +1094,11 @@ void ScriptEngine::run() { · 26 unmodified lines
10961094 // we want to only call it in our own run "shutdown" processing.
10971095 void ScriptEngine::stopAllTimers() {
10981096 QMutableHashIterator<QTimer*, CallbackData> i(_timerFunctionMap);
1097+ int j {0};
10991098 while (i.hasNext()) {
11001099 i.next();
11011100 QTimer* timer = i.key();
1101+ qCDebug(scriptengine) << getFilename() << "stopAllTimers[" << j++ << "]";
11021102 stopTimer(timer);
11031103 }
11041104 }
@@ -1185,6 +1185,7 @@ void ScriptEngine::timerFired() { · 80 unmodified lines
11851185 _timerFunctionMap.remove(callingTimer);
11861186 delete callingTimer;
11871187 }
1188+ //qCWarning(scriptengine) << "timerFired" << timerData.function.toString();
11881189
11891190 // call the associated JS function, if it exists
11901191 if (timerData.function.isValid()) {
@@ -1193,11 +1194,11 @@ void ScriptEngine::timerFired() { · 2 unmodified lines
11931194 auto postTimer = p_high_resolution_clock::now();
11941195 auto elapsed = (postTimer - preTimer);
11951196 _totalTimerExecution += std::chrono::duration_cast<std::chrono::microseconds>(elapsed);
1196−
1197+ } else {
1198+ qCWarning(scriptengine) << "timerFired -- invalid function" << timerData.function.toVariant().toString();
11971199 }
11981200 }
11991201
1200−
12011202 QObject* ScriptEngine::setupTimerWithInterval(const QScriptValue& function, int intervalMS, bool isSingleShot) {
12021203 // create the timer, add it to the map, and start it
12031204 QTimer* newTimer = new QTimer(this);
@@ -1214,7 +1215,7 @@ QObject* ScriptEngine::setupTimerWithInterval(const QScriptValue& function, int · 10 unmodified lines
12141215 // make sure the timer stops when the script does
12151216 connect(this, &ScriptEngine::scriptEnding, newTimer, &QTimer::stop);
12161217
1217− CallbackData timerData = {function, currentEntityIdentifier, currentSandboxURL };
1218+ CallbackData timerData = { function, currentEntityIdentifier, currentSandboxURL };
12181219 _timerFunctionMap.insert(newTimer, timerData);
12191220
12201221 newTimer->start(intervalMS);
@@ -1244,35 +1245,46 @@ void ScriptEngine::stopTimer(QTimer *timer) { · 23 unmodified lines
12441245 timer->stop();
12451246 _timerFunctionMap.remove(timer);
12461247 delete timer;
1248+ } else {
1249+ qCDebug(scriptengine) << "stopTimer -- not in _timerFunctionMap" << timer;
12471250 }
12481251 }
12491252
12501253 QUrl ScriptEngine::resolvePath(const QString& include) const {
12511254 QUrl url(include);
12521255 // first lets check to see if it's already a full URL
1253− if (!url.scheme().isEmpty()) {
1256+ if (include.startsWith("/") || url.scheme().length() == 1) {
1257+ url = QUrl::fromLocalFile(include);
1258+ }
1259+ if (!url.isRelative()) {
12541260 return expandScriptUrl(url);
12551261 }
12561262
1257− QScriptContextInfo contextInfo { currentContext()->parentContext() };
1258−
1259−
12601263 // we apparently weren't a fully qualified url, so, let's assume we're relative
1261− // to the original URL of our script
1262− QUrl parentURL = contextInfo.fileName();
1263− if (parentURL.isEmpty()) {
1264− if (_parentURL.isEmpty()) {
1265− parentURL = QUrl(_fileNameString);
1266− } else {
1267− parentURL = QUrl(_parentURL);
1264+ // to the first absolute URL in the JS scope chain
1265+ QUrl parentURL;
1266+ auto ctx = currentContext();
1267+ do {
1268+ QScriptContextInfo contextInfo { ctx };
1269+ parentURL = QUrl(contextInfo.fileName());
1270+ ctx = ctx->parentContext();
1271+ } while (parentURL.isRelative() && ctx);
1272+
1273+ if (parentURL.isRelative()) {
1274+ // fallback to the "include" parent (if defined, this will already be absolute)
1275+ parentURL = QUrl(_parentURL);
1276+ }
1277+
1278+ if (parentURL.isRelative()) {
1279+ // fallback to the original script engine URL
1280+ parentURL = QUrl(_fileNameString);
1281+
1282+ // if still relative and path-like, then this is probably a local file...
1283+ if (parentURL.isRelative() && url.path().contains("/")) {
1284+ parentURL = QUrl::fromLocalFile(_fileNameString);
12681285 }
12691286 }
12701287
1271− // if the parent URL's scheme is empty, then this is probably a local file...
1272− if (parentURL.scheme().isEmpty()) {
1273− parentURL = QUrl::fromLocalFile(_fileNameString);
1274− }
1275−
12761288 // at this point we should have a legitimate fully qualified URL for our parent
12771289 url = expandScriptUrl(parentURL.resolved(url));
12781290 return url;
@@ -1297,22 +1309,7 @@ void ScriptEngine::include(const QStringList& includeFiles, QScriptValue callbac · 18 unmodified lines
12971309 return; // bail early
12981310 }
12991311 QList<QUrl> urls;
1300− bool knowsSensitivity = false;
1301− Qt::CaseSensitivity sensitivity { Qt::CaseSensitive };
1302− auto getSensitivity = [&]() {
1303− if (!knowsSensitivity) {
1304− QString path = currentSandboxURL.path();
1305− QFileInfo upperFI(path.toUpper());
1306− QFileInfo lowerFI(path.toLower());
1307− sensitivity = (upperFI == lowerFI) ? Qt::CaseInsensitive : Qt::CaseSensitive;
1308− knowsSensitivity = true;
1309− }
1310− return sensitivity;
1311− };
13121312
1313− // Guard against meaningless query and fragment parts.
1314− // Do NOT use PreferLocalFile as its behavior is unpredictable (e.g., on defaultScriptsLocation())
1315− const auto strippingFlags = QUrl::RemoveFilename | QUrl::RemoveQuery | QUrl::RemoveFragment;
13161313 for (QString includeFile : includeFiles) {
13171314 QString file = ResourceManager::normalizeURL(includeFile);
13181315 QUrl thisURL;
@@ -1329,10 +1326,8 @@ void ScriptEngine::include(const QStringList& includeFiles, QScriptValue callbac · 10 unmodified lines
13291326 thisURL = resolvePath(file);
13301327 }
13311328
1332− if (!isStandardLibrary && !currentSandboxURL.isEmpty() && (thisURL.scheme() == "file") &&
1333− (currentSandboxURL.scheme() != "file" ||
1334− !thisURL.toString(strippingFlags).startsWith(currentSandboxURL.toString(strippingFlags), getSensitivity()))) {
1335−
1329+ bool disallowOutsideFiles = thisURL.isLocalFile() && !isStandardLibrary && !currentSandboxURL.isLocalFile();
1330+ if (disallowOutsideFiles && !PathUtils::isDescendantOf(thisURL, currentSandboxURL)) {
13361331 scriptWarningMessage("Script.include() ignoring file path" + thisURL.toString()
13371332 + "outside of original entity script" + currentSandboxURL.toString());
13381333 } else {
@@ -1368,7 +1363,17 @@ void ScriptEngine::include(const QStringList& includeFiles, QScriptValue callbac · 29 unmodified lines
13681363 evaluate(contents, url.toString());
13691364 };
13701365
1366+ ExceptionEmitter tryCatch(this, "include");
13711367 doWithEnvironment(capturedEntityIdentifier, capturedSandboxURL, operation);
1368+ if (tryCatch.hasPending()) {
1369+ // match previous include behavior where possible by logging, not propagating, exceptions.
1370+ // for nested evaluations, exceptions are now allowed to propagate
1371+ auto err = tryCatch.pending();
1372+ emit unhandledException(err);
1373+ if (tryCatch.wouldEmit()) {
1374+ tryCatch.consume();
1375+ }
1376+ }
13721377 } else {
13731378 scriptWarningMessage("Script.include() skipping evaluation of previously included url:" + url.toString());
13741379 }
@@ -1470,10 +1475,16 @@ int ScriptEngine::getNumRunningEntityScripts() const { · 95 unmodified lines
14701475 return sum;
14711476 }
14721477
1473−QString ScriptEngine::getEntityScriptStatus(const EntityItemID& entityID) {
1474− if (_entityScripts.contains(entityID))
1475− return EntityScriptStatus_::valueToKey(_entityScripts[entityID].status).toLower();
1476− return QString();
1478+void ScriptEngine::setEntityScriptDetails(const EntityItemID& entityID, const EntityScriptDetails& details) {
1479+ _entityScripts[entityID] = details;
1480+ emit entityScriptDetailsUpdated();
1481+}
1482+
1483+void ScriptEngine::updateEntityScriptStatus(const EntityItemID& entityID, const EntityScriptStatus &status, const QString& errorInfo) {
1484+ EntityScriptDetails &details = _entityScripts[entityID];
1485+ details.status = status;
1486+ details.errorInfo = errorInfo;
1487+ emit entityScriptDetailsUpdated();
14771488 }
14781489
14791490 bool ScriptEngine::getEntityScriptDetails(const EntityItemID& entityID, EntityScriptDetails &details) const {
@@ -1485,43 +1496,131 @@ bool ScriptEngine::getEntityScriptDetails(const EntityItemID& entityID, EntitySc · 5 unmodified lines
14851496 return true;
14861497 }
14871498
1488−void ScriptEngine::setEntityScriptDetails(const EntityItemID& entityID, const EntityScriptDetails& details) {
1489− _entityScripts[entityID] = details;
1490− emit entityScriptDetailsUpdated();
1491−}
1499+const auto RETRY_ATTEMPT_BATCH = 10; //glm::clamp(qgetenv("RETRY_ATTEMPT_BATCH").toInt(), 1, 50);
1500+const auto RETRY_ATTEMPT_MSECS = 250; //glm::clamp(qgetenv("RETRY_ATTEMPT_MSECS").toInt(), 50, 1000);
14921501
1493−void ScriptEngine::updateEntityScriptStatus(const EntityItemID& entityID, const EntityScriptStatus &status, const QString& errorInfo) {
1494− EntityScriptDetails &details = _entityScripts[entityID];
1495− details.status = status;
1496− details.errorInfo = errorInfo;
1497− emit entityScriptDetailsUpdated();
1498−}
1502+void ScriptEngine::deferLoadEntityScript(const EntityItemID& entityID, const QString& entityScript, bool forceRedownload) {
1503+ // forceRedownload doesn't make sense yet in this scenario (which only happens when another entity has taken lead on entityScript)
1504+ if (forceRedownload) {
1505+ qCDebug(scriptengine) << "deferLoadEntityScript -- TODO: ignoring forceRedownload =" << forceRedownload;
1506+ }
14991507
1500−// since all of these operations can be asynch we will always do the actual work in the response handler
1501−// for the download
1502−void ScriptEngine::loadEntityScript(QWeakPointer<ScriptEngine> theEngine, const EntityItemID& entityID, const QString& entityScript, bool forceRedownload) {
1503− auto engine = theEngine.data();
1504− engine->executeOnScriptThread([=]{
1505− EntityScriptDetails details = engine->_entityScripts[entityID];
1506− if (details.status == EntityScriptStatus::PENDING || details.status == EntityScriptStatus::UNLOADED) {
1507− engine->updateEntityScriptStatus(entityID, EntityScriptStatus::LOADING, QThread::currentThread()->objectName());
1508+ const auto needTimer = _pendingLoadEntities.isEmpty();
1509+ _pendingLoadEntities.push_back({ entityID, entityScript/*, forceRedownload*/ });
1510+
1511+ auto processDeferredEntities = [this](QScriptContext* ctx, QScriptEngine*) -> QScriptValue {
1512+ //qCDebug(scriptengine) << "deferLoadEntityScript.retry #" << _pendingLoadEntities.size() << " pending loads | " << QThread::currentThread();
1513+
1514+ for(int i=0; i < RETRY_ATTEMPT_BATCH && !_pendingLoadEntities.isEmpty(); i++) {
1515+ auto retry = _pendingLoadEntities.takeFirst();
1516+ qCDebug(scriptengine) << "deferLoadEntityScript.retry[" << i << "]:" << retry.entityID << retry.entityScript;
1517+ if(!_entityScripts.contains(retry.entityID)) {
1518+ qCDebug(scriptengine) << "deferLoadEntityScript.retry -- entity details gone (entity deleted?)";
1519+ } else {
1520+ auto details = _entityScripts[retry.entityID];
1521+ if (details.status != EntityScriptStatus::PENDING) {
1522+ qCDebug(scriptengine) << "deferLoadEntityScript.retry -- entity status no longer PENDING; " << details.status;
1523+ } else {
1524+ loadEntityScript(retry.entityID, retry.entityScript, false);
1525+ }
1526+ }
15081527 }
1509− });
1528+ if (_pendingLoadEntities.isEmpty()) {
1529+ QObject *interval = ctx->callee().property("interval").toQObject();
1530+ // we're done processing so can kill the timer
1531+ qCDebug(scriptengine) << "loadEntityScript.retry queue processing complete -- exiting" << interval;
1532+ if (interval) {
1533+ clearInterval(interval);
1534+ }
1535+ }
1536+ return QScriptValue();
1537+ };
15101538
1511− // NOTE: If the script content is not currently in the cache, the LAMBDA here will be called on the Main Thread
1512− // which means we're guaranteed that it's not the correct thread for the ScriptEngine. This means
1513− // when we get into entityScriptContentAvailable() we will likely invokeMethod() to get it over
1514− // to the "Entities" ScriptEngine thread.
1515− DependencyManager::get<ScriptCache>()->getScriptContents(entityScript, [theEngine, entityID](const QString& scriptOrURL, const QString& contents, bool isURL, bool success, const QString &status) {
1516− QSharedPointer<ScriptEngine> strongEngine = theEngine.toStrongRef();
1517− if (strongEngine) {
1518−#ifdef THREAD_DEBUGGING
1519− qCDebug(scriptengine) << "ScriptEngine::entityScriptContentAvailable() IN LAMBDA contentAvailable on thread ["
1520− << QThread::currentThread() << "] expected thread [" << strongEngine->thread() << "]";
1539+ if (needTimer) {
1540+ // we were the first to get queued -- so set up an interval timer for deferred processing
1541+ qCDebug(scriptengine) << "deferLoadEntityScript -- scheduling timer " << RETRY_ATTEMPT_MSECS;
1542+
1543+ // processDeferredEntities gets wrapped as a "regular" JavaScript callback so that it can then
1544+ // be scheduled using setInterval per usual -- allowing the script engine to own its lifecycle.
1545+ // we stil need to call clearInterval manually when done, so its passed to calle() above as a property.
1546+
1547+ QScriptValue function = newLambdaFunction(processDeferredEntities, "processDeferredEntities-loader");
1548+ QObject *interval = setInterval( function, RETRY_ATTEMPT_MSECS );
1549+
1550+ // make the interval reachable from the handler
1551+ function.setProperty("interval", newQObject(interval));
1552+ }
1553+}
1554+
1555+void ScriptEngine::loadEntityScript(const EntityItemID& entityID, const QString& entityScript, bool forceRedownload) {
1556+ if (QThread::currentThread() != thread()) {
1557+ QMetaObject::invokeMethod(this, "loadEntityScript",
1558+ Q_ARG(const EntityItemID&, entityID),
1559+ Q_ARG(const QString&, entityScript),
1560+ Q_ARG(bool, forceRedownload)
1561+ );
1562+ return;
1563+ }
1564+ PROFILE_RANGE(script, __FUNCTION__);
1565+
1566+ if (isStopping() || DependencyManager::get<ScriptEngines>()->isStopped()) {
1567+ qCDebug(scriptengine) << "loadEntityScript.start " << entityScript << entityID.toString()
1568+ << " but isStopping==" << isStopping()
1569+ << " || engines->isStopped==" << DependencyManager::get<ScriptEngines>()->isStopped();
1570+ return;
1571+ }
1572+
1573+ if (!_entityScripts.contains(entityID)) {
1574+ // make sure EntityScriptDetails has an entry for this UUID right away
1575+ // (which allows bailing from the loading/provisioning process early if the Entity gets deleted mid-flight)
1576+ updateEntityScriptStatus(entityID, EntityScriptStatus::PENDING, "...pending...");
1577+ }
1578+
1579+ // This lock/defer approach allows multiple Entities to boot from the same script URL while still taking
1580+ // full advantage of cacheable require modules. This only affects Entities literally coming in back-to-back
1581+ // before the first one has time to finish loading.
1582+ auto &locker = _lockPerUniqueScriptURL[entityScript];
1583+ if (!locker.tryLock()) {
1584+ qCDebug(scriptengine) << QString("loadEntityScript.deferring[%1] entity: %2 script: %3")
1585+ .arg( _pendingLoadEntities.size()).arg(entityID.toString()).arg(entityScript);
1586+ deferLoadEntityScript(entityID, entityScript, forceRedownload);
1587+ return;
1588+ }
1589+
1590+#ifdef DEBUG_ENTITY_STATES
1591+ auto previousStatus = _entityScripts.contains(entityID) ? _entityScripts[entityID].status : EntityScriptStatus::PENDING;
1592+ qCDebug(scriptengine) << "loadEntityScript.LOADING: " << entityScript << entityID.toString()
1593+ << "(previous: " << previousStatus << ")";
15211594 #endif
1522− strongEngine->entityScriptContentAvailable(entityID, scriptOrURL, contents, isURL, success, status);
1523− }
1524− }, forceRedownload, processLevelMaxRetries);
1595+
1596+ EntityScriptDetails newDetails;
1597+ newDetails.scriptText = entityScript;
1598+ newDetails.status = EntityScriptStatus::LOADING;
1599+ newDetails.definingSandboxURL = currentSandboxURL;
1600+ _entityScripts[entityID] = newDetails;
1601+
1602+ auto scriptCache = DependencyManager::get<ScriptCache>();
1603+ scriptCache->getScriptContents(entityScript,
1604+ [=, &locker](const QString& url, const QString& contents, bool isURL, bool success, const QString& status) {
1605+ if (isStopping()) {
1606+#ifdef DEBUG_ENTITY_STATES
1607+ qCDebug(scriptengine) << "loadEntityScript.contentAvailable -- stopping";
1608+#endif
1609+ locker.unlock();
1610+ return;
1611+ }
1612+ executeOnScriptThread([=, &locker]{
1613+ //qCDebug(scriptengine) << "loadEntityScript.contentAvailable" << status << QUrl(url).fileName() << entityID.toString();
1614+ if (!isStopping() && _entityScripts.contains(entityID)) {
1615+ entityScriptContentAvailable(entityID, url, contents, isURL, success, status);
1616+ } else {
1617+#ifdef DEBUG_ENTITY_STATES
1618+ qCDebug(scriptengine) << "loadEntityScript.contentAvailable -- aborting";
1619+#endif
1620+ }
1621+ locker.unlock();
1622+ });
1623+ }, forceRedownload);
15251624 }
15261625
15271626 // 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 · 23 unmodified lines
15511650
15521651 auto scriptCache = DependencyManager::get<ScriptCache>();
15531652 bool isFileUrl = isURL && scriptOrURL.startsWith("file://");
1554− auto fileName = isURL ? scriptOrURL : "EmbeddedEntityScript";
1653+ auto fileName = isURL ? scriptOrURL : "about:EmbeddedEntityScript";
15551654
1655+ const EntityScriptDetails &oldDetails = _entityScripts[entityID];
15561656 EntityScriptDetails newDetails;
15571657 newDetails.scriptText = scriptOrURL;
15581658
1559− if (!success) {
1560− newDetails.status = EntityScriptStatus::ERROR_LOADING_SCRIPT;
1561− newDetails.errorInfo = "Failed to load script (" + status + ")";
1659+ // If an error happens below, we want to update newDetails with the new status info
1660+ // and also abort any pending Entity loads that are waiting on the exact same script URL.
1661+ auto setError = [&](const QString &errorInfo, const EntityScriptStatus& status) {
1662+ newDetails.errorInfo = errorInfo;
1663+ newDetails.status = status;
15621664 setEntityScriptDetails(entityID, newDetails);
1665+
1666+ QMutableListIterator<DeferredLoadEntity> i(_pendingLoadEntities);
1667+ // note: we want the *original* entityScript string (not the potentially normalized one from ScriptCache results)
1668+ const auto entityScript = oldDetails.scriptText;
1669+ while (i.hasNext()) {
1670+ auto retry = i.next();
1671+ if (retry.entityScript == entityScript) {
1672+ qCDebug(scriptengine) << "... pending load of " << retry.entityID << " cancelled";
1673+ i.remove();
1674+ }
1675+ }
1676+ };
1677+
1678+ // NETWORK / FILESYSTEM ERRORS
1679+ if (!success) {
1680+ setError("Failed to load script (" + status + ")", EntityScriptStatus::ERROR_LOADING_SCRIPT);
15631681 return;
15641682 }
15651683
1684+ // SYNTAX ERRORS
15661685 auto syntaxError = lintScript(contents, fileName);
1686+ if (syntaxError.isError()) {
1687+ auto message = syntaxError.property("formatted").toString();
1688+ if (message.isEmpty()) {
1689+ message = syntaxError.toString();
1690+ }
1691+ setError(QString("Bad syntax (%1)").arg(message), EntityScriptStatus::ERROR_RUNNING_SCRIPT);
1692+ syntaxError.setProperty("detail", entityID.toString());
1693+ emit unhandledException(syntaxError);
1694+ return;
1695+ }
15671696 QScriptProgram program { contents, fileName };
1568− if (!syntaxError.isNull() || program.isNull()) {
1569− newDetails.status = EntityScriptStatus::ERROR_RUNNING_SCRIPT;
1570− newDetails.errorInfo = QString("Bad syntax (%1)").arg(syntaxError);
1571− setEntityScriptDetails(entityID, newDetails);
1572− qCDebug(scriptengine) << newDetails.errorInfo << scriptOrURL;
1697+ if (program.isNull()) {
1698+ setError("Bad program (isNull)", EntityScriptStatus::ERROR_RUNNING_SCRIPT);
1699+ emit unhandledException(makeError("program.isNull"));
15731700 return; // done processing script
15741701 }
15751702
@@ -1577,11 +1704,13 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co · 1 unmodified line
15771704 setParentURL(scriptOrURL);
15781705 }
15791706
1707+ // SANITY/PERFORMANCE CHECK USING SANDBOX
15801708 const int SANDBOX_TIMEOUT = 0.25 * MSECS_PER_SECOND;
15811709 BaseScriptEngine sandbox;
15821710 sandbox.setProcessEventsInterval(SANDBOX_TIMEOUT);
1583− QScriptValue testConstructor;
1711+ QScriptValue testConstructor, exception;
15841712 {
1713+ ExceptionEmitter tryCatch(&sandbox, QString("(preflight %1)").arg(entityID.toString()));
15851714 QTimer timeout;
15861715 timeout.setSingleShot(true);
15871716 timeout.start(SANDBOX_TIMEOUT);
@@ -1594,18 +1723,25 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co · 6 unmodified lines
15941723 context->throwError(QString("Timed out (entity constructors are limited to %1ms)").arg(SANDBOX_TIMEOUT));
15951724 }
15961725 });
1726+
15971727 testConstructor = sandbox.evaluate(program);
1728+
1729+ if (tryCatch.hasPending()) {
1730+ exception = tryCatch.consume();
1731+ } else if (testConstructor.isError()) {
1732+ exception = testConstructor;
1733+ }
15981734 }
15991735
1600− QString exceptionMessage = sandbox.formatUncaughtException(program.fileName());
1601− if (!exceptionMessage.isNull()) {
1602− newDetails.status = EntityScriptStatus::ERROR_RUNNING_SCRIPT;
1603− newDetails.errorInfo = exceptionMessage;
1604− setEntityScriptDetails(entityID, newDetails);
1605− qCDebug(scriptengine) << "----- ScriptEngine::entityScriptContentAvailable -- hadUncaughtExceptions (" << scriptOrURL << ")";
1736+ if (exception.isError()) {
1737+ // create a local copy using makeError to decouple from the sandbox engine
1738+ exception = makeError(exception);
1739+ setError(formatException(exception), EntityScriptStatus::ERROR_RUNNING_SCRIPT);
1740+ emit unhandledException(exception);
16061741 return;
16071742 }
16081743
1744+ // CONSTRUCTOR VIABILITY
16091745 if (!testConstructor.isFunction()) {
16101746 QString testConstructorType = QString(testConstructor.toVariant().typeName());
16111747 if (testConstructorType == "") {
@@ -1616,32 +1752,49 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co · 4 unmodified lines
16161752 if (testConstructorValue.size() > maxTestConstructorValueSize) {
16171753 testConstructorValue = testConstructorValue.mid(0, maxTestConstructorValueSize) + "...";
16181754 }
1619− scriptErrorMessage("Error -- ScriptEngine::loadEntityScript() entity:" + entityID.toString()
1620− + "failed to load entity script -- expected a function, got " + testConstructorType
1621− + "," + testConstructorValue
1622− + "," + scriptOrURL);
1755+ auto message = QString("failed to load entity script -- expected a function, got %1, %2")
1756+ .arg(testConstructorType).arg(testConstructorValue);
16231757
1624− newDetails.status = EntityScriptStatus::ERROR_RUNNING_SCRIPT;
1625− newDetails.errorInfo = "Could not find constructor";
1626− setEntityScriptDetails(entityID, newDetails);
1758+ auto err = makeError(message);
1759+ err.setProperty("fileName", scriptOrURL);
1760+ err.setProperty("detail", "(constructor " + entityID.toString() + ")");
16271761
1628− qCDebug(scriptengine) << "----- ScriptEngine::entityScriptContentAvailable -- failed to run (" << scriptOrURL << ")";
1762+ setError("Could not find constructor (" + testConstructorType + ")", EntityScriptStatus::ERROR_RUNNING_SCRIPT);
1763+ emit unhandledException(err);
16291764 return; // done processing script
16301765 }
16311766
1767+ // (this feeds into refreshFileScript)
16321768 int64_t lastModified = 0;
16331769 if (isFileUrl) {
16341770 QString file = QUrl(scriptOrURL).toLocalFile();
16351771 lastModified = (quint64)QFileInfo(file).lastModified().toMSecsSinceEpoch();
16361772 }
1773+
1774+ // THE ACTUAL EVALUATION AND CONSTRUCTION
16371775 QScriptValue entityScriptConstructor, entityScriptObject;
16381776 QUrl sandboxURL = currentSandboxURL.isEmpty() ? scriptOrURL : currentSandboxURL;
16391777 auto initialization = [&]{
1778+ ExceptionEmitter tryCatch(this, "(construct " + entityID.toString() + ")");
1779+
16401780 entityScriptConstructor = evaluate(contents, fileName);
16411781 entityScriptObject = entityScriptConstructor.construct();
1782+
1783+ if (tryCatch.hasPending()) {
1784+ entityScriptObject = tryCatch.consume();
1785+ }
16421786 };
1787+
16431788 doWithEnvironment(entityID, sandboxURL, initialization);
16441789
1790+ if (entityScriptObject.isError()) {
1791+ auto exception = entityScriptObject;
1792+ setError(formatException(exception), EntityScriptStatus::ERROR_RUNNING_SCRIPT);
1793+ emit unhandledException(exception);
1794+ return;
1795+ }
1796+
1797+ // ... AND WE HAVE LIFTOFF
16451798 newDetails.status = EntityScriptStatus::RUNNING;
16461799 newDetails.scriptObject = entityScriptObject;
16471800 newDetails.lastModified = lastModified;
@@ -1678,6 +1831,7 @@ void ScriptEngine::unloadEntityScript(const EntityItemID& entityID) { · 30 unmodified lines
16781831 }
16791832 EntityScriptDetails newDetails;
16801833 newDetails.status = EntityScriptStatus::UNLOADED;
1834+ newDetails.lastModified = QDateTime::currentMSecsSinceEpoch();
16811835 setEntityScriptDetails(entityID, newDetails);
16821836 stopAllTimersForEntityScript(entityID);
16831837 }
@@ -1700,15 +1854,14 @@ void ScriptEngine::unloadAllEntityScripts() { · 16 unmodified lines
17001854 }
17011855 _entityScripts.clear();
17021856 emit entityScriptDetailsUpdated();
1857+ _lockPerUniqueScriptURL.clear();
17031858
17041859 #ifdef DEBUG_ENGINE_STATE
1705− qCDebug(scriptengine) << "---- CURRENT STATE OF ENGINE: --------------------------";
1706− QScriptValueIterator it(globalObject());
1707− while (it.hasNext()) {
1708− it.next();
1709− qCDebug(scriptengine) << it.name() << ":" << it.value().toString();
1710− }
1711− qCDebug(scriptengine) << "--------------------------------------------------------";
1860+ _debugDump(
1861+ "---- CURRENT STATE OF ENGINE: --------------------------",
1862+ globalObject(),
1863+ "--------------------------------------------------------"
1864+ );
17121865 #endif // DEBUG_ENGINE_STATE
17131866 }
17141867
@@ -1756,6 +1909,8 @@ void ScriptEngine::doWithEnvironment(const EntityItemID& entityID, const QUrl& s · 41 unmodified lines
17561909 currentEntityIdentifier = entityID;
17571910 currentSandboxURL = sandboxURL;
17581911
1912+ ExceptionEmitter tryCatcher(this, !entityID.isNull() ? entityID.toString() : __FUNCTION__);
1913+
17591914 #if DEBUG_CURRENT_ENTITY
17601915 QScriptValue oldData = this->globalObject().property("debugEntityID");
17611916 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 · 2 unmodified lines
17641919 #else
17651920 operation();
17661921 #endif
1767− if (hasUncaughtException()) {
1768− reportUncaughtException();
1769− clearExceptions();
1770− }
1771−
17721922 currentEntityIdentifier = oldIdentifier;
17731923 currentSandboxURL = oldSandboxURL;
17741924 }
1925+
17751926 void ScriptEngine::callWithEnvironment(const EntityItemID& entityID, const QUrl& sandboxURL, QScriptValue function, QScriptValue thisObject, QScriptValueList args) {
17761927 auto operation = [&]() {
17771928 function.call(thisObject, args);
@@ -1846,7 +1997,6 @@ void ScriptEngine::callEntityScriptMethod(const EntityItemID& entityID, const QS · 68 unmodified lines
18461997 }
18471998 }
18481999
1849−
18502000 void ScriptEngine::callEntityScriptMethod(const EntityItemID& entityID, const QString& methodName, const EntityItemID& otherID, const Collision& collision) {
18512001 if (QThread::currentThread() != thread()) {
18522002 #ifdef THREAD_DEBUGGING
@@ -1881,3 +2031,4 @@ void ScriptEngine::callEntityScriptMethod(const EntityItemID& entityID, const QS · 28 unmodified lines
18812031 }
18822032 }
18832033 }
2034+