* Update per CR feedback / code standards

* Cull log spam
* Add tryLock to deferred processor to preempt unnecessary loadEntityContent round-trips
This commit is contained in:
humbletim 2017-02-22 15:22:56 -05:00
parent b15956278c
commit 417587dcda
5 changed files with 32 additions and 27 deletions

View file

@ -118,14 +118,14 @@ QScriptValue BaseScriptEngine::cloneUncaughtException(const QString& extraDetail
} }
if (fileName.isEmpty()) { if (fileName.isEmpty()) {
// climb the stack frames looking for something useful to display // climb the stack frames looking for something useful to display
for(auto ctx = currentContext(); ctx && fileName.isEmpty(); ctx = ctx->parentContext()) { for (auto c = currentContext(); c && fileName.isEmpty(); c = c->parentContext()) {
QScriptContextInfo info { ctx }; QScriptContextInfo info { c };
if (!info.fileName().isEmpty()) { if (!info.fileName().isEmpty()) {
// take fileName:lineNumber as a pair // take fileName:lineNumber as a pair
fileName = info.fileName(); fileName = info.fileName();
lineNumber = info.lineNumber(); lineNumber = info.lineNumber();
if (backtrace.isEmpty()) { if (backtrace.isEmpty()) {
backtrace = ctx->backtrace(); backtrace = c->backtrace();
} }
break; break;
} }
@ -181,8 +181,6 @@ QScriptValue BaseScriptEngine::evaluateInClosure(const QScriptValue& closure, co
return QScriptValue(); return QScriptValue();
} }
//_debugDump("evaluateInClosure.closure", closure);
const auto fileName = program.fileName(); const auto fileName = program.fileName();
const auto shortName = QUrl(fileName).fileName(); const auto shortName = QUrl(fileName).fileName();
@ -197,17 +195,17 @@ QScriptValue BaseScriptEngine::evaluateInClosure(const QScriptValue& closure, co
setGlobalObject(global); setGlobalObject(global);
} }
auto ctx = pushContext(); auto context = pushContext();
auto thiz = closure.property("this"); auto thiz = closure.property("this");
if (thiz.isObject()) { if (thiz.isObject()) {
#ifdef DEBUG_JS #ifdef DEBUG_JS
qCDebug(scriptengine) << " setting this = closure.this" << shortName; qCDebug(scriptengine) << " setting this = closure.this" << shortName;
#endif #endif
ctx->setThisObject(thiz); context->setThisObject(thiz);
} }
ctx->pushScope(closure); context->pushScope(closure);
#ifdef DEBUG_JS #ifdef DEBUG_JS
qCDebug(scriptengine) << QString("[%1] evaluateInClosure %2").arg(isEvaluating()).arg(shortName); qCDebug(scriptengine) << QString("[%1] evaluateInClosure %2").arg(isEvaluating()).arg(shortName);
#endif #endif
@ -244,8 +242,8 @@ QScriptValue BaseScriptEngine::newLambdaFunction(std::function<QScriptValue(QScr
auto lambda = new Lambda(this, operation, data); auto lambda = new Lambda(this, operation, data);
auto object = newQObject(lambda, ownership); auto object = newQObject(lambda, ownership);
auto call = object.property("call"); auto call = object.property("call");
call.setPrototype(object); // ctx->callee().prototype() === Lambda QObject call.setPrototype(object); // context->callee().prototype() === Lambda QObject
call.setData(data); // ctx->callee().data() will === data param call.setData(data); // context->callee().data() will === data param
return call; return call;
} }
QString Lambda::toString() const { QString Lambda::toString() const {

View file

@ -39,7 +39,7 @@ signals:
protected: protected:
void _emitUnhandledException(const QScriptValue& exception); void _emitUnhandledException(const QScriptValue& exception);
QScriptValue newLambdaFunction(std::function<QScriptValue(QScriptContext *ctx, QScriptEngine* engine)> operation, const QScriptValue& data = QScriptValue(), const QScriptEngine::ValueOwnership& ownership = QScriptEngine::AutoOwnership); QScriptValue newLambdaFunction(std::function<QScriptValue(QScriptContext *context, QScriptEngine* engine)> operation, const QScriptValue& data = QScriptValue(), const QScriptEngine::ValueOwnership& ownership = QScriptEngine::AutoOwnership);
static const QString _SETTINGS_ENABLE_EXTENDED_EXCEPTIONS; static const QString _SETTINGS_ENABLE_EXTENDED_EXCEPTIONS;
Setting::Handle<bool> _enableExtendedJSExceptions { _SETTINGS_ENABLE_EXTENDED_EXCEPTIONS, true }; Setting::Handle<bool> _enableExtendedJSExceptions { _SETTINGS_ENABLE_EXTENDED_EXCEPTIONS, true };
@ -72,14 +72,14 @@ protected:
class Lambda : public QObject { class Lambda : public QObject {
Q_OBJECT Q_OBJECT
public: public:
Lambda(QScriptEngine *engine, std::function<QScriptValue(QScriptContext *ctx, QScriptEngine* engine)> operation, QScriptValue data); Lambda(QScriptEngine *engine, std::function<QScriptValue(QScriptContext *context, QScriptEngine* engine)> operation, QScriptValue data);
~Lambda(); ~Lambda();
public slots: public slots:
QScriptValue call(); QScriptValue call();
QString toString() const; QString toString() const;
private: private:
QScriptEngine* engine; QScriptEngine* engine;
std::function<QScriptValue(QScriptContext *ctx, QScriptEngine* engine)> operation; std::function<QScriptValue(QScriptContext *context, QScriptEngine* engine)> operation;
QScriptValue data; QScriptValue data;
}; };

View file

@ -66,7 +66,7 @@ void BatchLoader::start(int maxRetries) {
qCDebug(scriptengine) << "Loaded: " << url; qCDebug(scriptengine) << "Loaded: " << url;
} else { } else {
_data.insert(url, QString()); _data.insert(url, QString());
qCDebug(scriptengine) << "Could not load: " << url; qCDebug(scriptengine) << "Could not load: " << url << status;
} }
if (!_finished && _urls.size() == _data.size()) { if (!_finished && _urls.size() == _data.size()) {

View file

@ -188,6 +188,8 @@ void ScriptCache::scriptContentAvailable(int maxRetries) {
} }
} }
} else {
qCWarning(scriptengine) << "Warning: scriptContentAvailable for inactive url: " << url;
} }
} }

View file

@ -172,7 +172,6 @@ ScriptEngine::ScriptEngine(Context context, const QString& scriptContents, const
qCDebug(scriptengine) << "isEntityServerScript() -- limiting maxRetries to 1"; qCDebug(scriptengine) << "isEntityServerScript() -- limiting maxRetries to 1";
processLevelMaxRetries = 1; processLevelMaxRetries = 1;
} }
//qCDebug(scriptengine) << getContext() << "processLevelMaxRetries =" << processLevelMaxRetries << fileNameString;
// this is where all unhandled exceptions end up getting logged // this is where all unhandled exceptions end up getting logged
connect(this, &BaseScriptEngine::unhandledException, this, [this](const QScriptValue& err) { connect(this, &BaseScriptEngine::unhandledException, this, [this](const QScriptValue& err) {
@ -1185,7 +1184,6 @@ void ScriptEngine::timerFired() {
_timerFunctionMap.remove(callingTimer); _timerFunctionMap.remove(callingTimer);
delete callingTimer; delete callingTimer;
} }
//qCWarning(scriptengine) << "timerFired" << timerData.function.toString();
// call the associated JS function, if it exists // call the associated JS function, if it exists
if (timerData.function.isValid()) { if (timerData.function.isValid()) {
@ -1500,18 +1498,14 @@ const auto RETRY_ATTEMPT_BATCH = 10; //glm::clamp(qgetenv("RETRY_ATTEMPT_BATCH")
const auto RETRY_ATTEMPT_MSECS = 250; //glm::clamp(qgetenv("RETRY_ATTEMPT_MSECS").toInt(), 50, 1000); 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) { 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(); const auto needTimer = _pendingLoadEntities.isEmpty();
// NOTE: forceRedownload isn't forwarded here because deferLoadEntityScript() is only ever called when another entity has taken lead for the script
_pendingLoadEntities.push_back({ entityID, entityScript/*, forceRedownload*/ }); _pendingLoadEntities.push_back({ entityID, entityScript/*, forceRedownload*/ });
auto processDeferredEntities = [this](QScriptContext* ctx, QScriptEngine*) -> QScriptValue { auto processDeferredEntities = [this](QScriptContext* context, QScriptEngine*) -> QScriptValue {
//qCDebug(scriptengine) << "deferLoadEntityScript.retry #" << _pendingLoadEntities.size() << " pending loads | " << QThread::currentThread(); QList<DeferredLoadEntity> stillPending;
for(int i=0; i < RETRY_ATTEMPT_BATCH && !_pendingLoadEntities.isEmpty(); i++) { for (int i=0; i < RETRY_ATTEMPT_BATCH && !_pendingLoadEntities.isEmpty(); i++) {
auto retry = _pendingLoadEntities.takeFirst(); auto retry = _pendingLoadEntities.takeFirst();
qCDebug(scriptengine) << "deferLoadEntityScript.retry[" << i << "]:" << retry.entityID << retry.entityScript; qCDebug(scriptengine) << "deferLoadEntityScript.retry[" << i << "]:" << retry.entityID << retry.entityScript;
if(!_entityScripts.contains(retry.entityID)) { if(!_entityScripts.contains(retry.entityID)) {
@ -1521,12 +1515,21 @@ void ScriptEngine::deferLoadEntityScript(const EntityItemID& entityID, const QSt
if (details.status != EntityScriptStatus::PENDING) { if (details.status != EntityScriptStatus::PENDING) {
qCDebug(scriptengine) << "deferLoadEntityScript.retry -- entity status no longer PENDING; " << details.status; qCDebug(scriptengine) << "deferLoadEntityScript.retry -- entity status no longer PENDING; " << details.status;
} else { } else {
loadEntityScript(retry.entityID, retry.entityScript, false); auto &locker = _lockPerUniqueScriptURL[retry.entityScript];
if (locker.tryLock()) {
locker.unlock();
loadEntityScript(retry.entityID, retry.entityScript, false);
} else {
stillPending << retry;
}
} }
} }
} }
foreach(const DeferredLoadEntity& retry, stillPending) {
_pendingLoadEntities.push_back(retry);
}
if (_pendingLoadEntities.isEmpty()) { if (_pendingLoadEntities.isEmpty()) {
QObject *interval = ctx->callee().property("interval").toQObject(); QObject *interval = context->callee().property("interval").toQObject();
// we're done processing so can kill the timer // we're done processing so can kill the timer
qCDebug(scriptengine) << "loadEntityScript.retry queue processing complete -- exiting" << interval; qCDebug(scriptengine) << "loadEntityScript.retry queue processing complete -- exiting" << interval;
if (interval) { if (interval) {
@ -1610,7 +1613,9 @@ void ScriptEngine::loadEntityScript(const EntityItemID& entityID, const QString&
return; return;
} }
executeOnScriptThread([=, &locker]{ executeOnScriptThread([=, &locker]{
//qCDebug(scriptengine) << "loadEntityScript.contentAvailable" << status << QUrl(url).fileName() << entityID.toString(); #ifdef DEBUG_ENTITY_STATES
qCDebug(scriptengine) << "loadEntityScript.contentAvailable" << status << QUrl(url).fileName() << entityID.toString();
#endif
if (!isStopping() && _entityScripts.contains(entityID)) { if (!isStopping() && _entityScripts.contains(entityID)) {
entityScriptContentAvailable(entityID, url, contents, isURL, success, status); entityScriptContentAvailable(entityID, url, contents, isURL, success, status);
} else { } else {