From 7c7d239e00dfd8a9dc9c4e791cd0f49a1b9d7f4c Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Fri, 30 Dec 2016 09:13:21 -0800 Subject: [PATCH 1/6] first cut at using wait signals to improve RPC timing --- libraries/script-engine/src/ScriptEngine.cpp | 38 ++++++++++++++++++- libraries/script-engine/src/ScriptEngine.h | 3 ++ .../system/controllers/handControllerGrab.js | 1 + unpublishedScripts/marketplace/bow/bow.js | 1 + 4 files changed, 42 insertions(+), 1 deletion(-) diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index 03b01e1b9c..02f2efd063 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -573,6 +573,7 @@ void ScriptEngine::registerValue(const QString& valueName, QScriptValue value) { QMetaObject::invokeMethod(this, "registerValue", Q_ARG(const QString&, valueName), Q_ARG(QScriptValue, value)); + _hasInvokeMethod.wakeAll(); return; } @@ -603,6 +604,7 @@ void ScriptEngine::registerGlobalObject(const QString& name, QObject* object) { QMetaObject::invokeMethod(this, "registerGlobalObject", Q_ARG(const QString&, name), Q_ARG(QObject*, object)); + _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -628,6 +630,7 @@ void ScriptEngine::registerFunction(const QString& name, QScriptEngine::Function Q_ARG(const QString&, name), Q_ARG(QScriptEngine::FunctionSignature, functionSignature), Q_ARG(int, numArguments)); + _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -647,6 +650,7 @@ void ScriptEngine::registerFunction(const QString& parent, const QString& name, Q_ARG(const QString&, name), Q_ARG(QScriptEngine::FunctionSignature, functionSignature), Q_ARG(int, numArguments)); + _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -672,6 +676,7 @@ void ScriptEngine::registerGetterSetter(const QString& name, QScriptEngine::Func Q_ARG(QScriptEngine::FunctionSignature, getter), Q_ARG(QScriptEngine::FunctionSignature, setter), Q_ARG(const QString&, parent)); + _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -704,6 +709,7 @@ void ScriptEngine::removeEventHandler(const EntityItemID& entityID, const QStrin Q_ARG(const EntityItemID&, entityID), Q_ARG(const QString&, eventName), Q_ARG(QScriptValue, handler)); + _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -735,6 +741,7 @@ void ScriptEngine::addEventHandler(const EntityItemID& entityID, const QString& Q_ARG(const EntityItemID&, entityID), Q_ARG(const QString&, eventName), Q_ARG(QScriptValue, handler)); + _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -821,6 +828,7 @@ QScriptValue ScriptEngine::evaluate(const QString& sourceCode, const QString& fi Q_ARG(const QString&, sourceCode), Q_ARG(const QString&, fileName), Q_ARG(int, lineNumber)); + _hasInvokeMethod.wakeAll(); return result; } @@ -920,7 +928,25 @@ void ScriptEngine::run() { auto remainingSleepUntil = std::chrono::duration_cast(sleepUntil - clock::now()); auto closestUntil = std::min(remainingSleepUntil, untilTimer); auto thisSleepUntil = std::min(sleepUntil, clock::now() + closestUntil); - std::this_thread::sleep_until(thisSleepUntil); + + // if the sleep until is more than 1 ms away, then don't sleep, and instead use a wait condition + // for any possible invoke methods that might also be pending. + const std::chrono::microseconds MAX_USECS_TO_SLEEP(USECS_PER_MSEC); + if (closestUntil < MAX_USECS_TO_SLEEP) { + qDebug() << "about to sleep:" << closestUntil.count() << "usec"; + std::this_thread::sleep_until(thisSleepUntil); + } else { + // FIXME - we might want to make this 1 less ms to wait + unsigned long maxWait = closestUntil.count() / USECS_PER_MSEC; + qDebug() << "about to wait:" << maxWait << "ms --- closestUntil:" << closestUntil.count() << "usec"; + _waitingOnInvokeMethod.lock(); + bool signalled = _hasInvokeMethod.wait(&_waitingOnInvokeMethod, maxWait); + _waitingOnInvokeMethod.unlock(); + if (signalled) { + qDebug() << "SIGNALLED!! done waiting... now:" << usecTimestampNow(); + } + + } } #ifdef SCRIPT_DELAY_DEBUG @@ -1058,6 +1084,7 @@ void ScriptEngine::stop(bool marshal) { if (marshal) { QMetaObject::invokeMethod(this, "stop"); + _hasInvokeMethod.wakeAll(); return; } if (!_isFinished) { @@ -1078,6 +1105,7 @@ void ScriptEngine::callAnimationStateHandler(QScriptValue callback, AnimVariantM Q_ARG(QStringList, names), Q_ARG(bool, useNames), Q_ARG(AnimVariantResultHandler, resultHandler)); + _hasInvokeMethod.wakeAll(); return; } QScriptValue javascriptParameters = parameters.animVariantMapToScriptValue(this, names, useNames); @@ -1428,6 +1456,7 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co Q_ARG(const QString&, contents), Q_ARG(bool, isURL), Q_ARG(bool, success)); + _hasInvokeMethod.wakeAll(); return; } @@ -1526,6 +1555,7 @@ void ScriptEngine::unloadEntityScript(const EntityItemID& entityID) { QMetaObject::invokeMethod(this, "unloadEntityScript", Q_ARG(const EntityItemID&, entityID)); + _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -1547,6 +1577,7 @@ void ScriptEngine::unloadAllEntityScripts() { #endif QMetaObject::invokeMethod(this, "unloadAllEntityScripts"); + _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -1639,10 +1670,13 @@ void ScriptEngine::callEntityScriptMethod(const EntityItemID& entityID, const QS "entityID:" << entityID << "methodName:" << methodName; #endif + qDebug() << "about to invokeMethod callEntityScriptMethod() now:" << usecTimestampNow(); + QMetaObject::invokeMethod(this, "callEntityScriptMethod", Q_ARG(const EntityItemID&, entityID), Q_ARG(const QString&, methodName), Q_ARG(const QStringList&, params)); + _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -1675,6 +1709,7 @@ void ScriptEngine::callEntityScriptMethod(const EntityItemID& entityID, const QS Q_ARG(const EntityItemID&, entityID), Q_ARG(const QString&, methodName), Q_ARG(const PointerEvent&, event)); + _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -1708,6 +1743,7 @@ void ScriptEngine::callEntityScriptMethod(const EntityItemID& entityID, const QS Q_ARG(const QString&, methodName), Q_ARG(const EntityItemID&, otherID), Q_ARG(const Collision&, collision)); + _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING diff --git a/libraries/script-engine/src/ScriptEngine.h b/libraries/script-engine/src/ScriptEngine.h index 803aa7fa22..8e6184f62f 100644 --- a/libraries/script-engine/src/ScriptEngine.h +++ b/libraries/script-engine/src/ScriptEngine.h @@ -217,6 +217,9 @@ protected: void init(); + QWaitCondition _hasInvokeMethod; + QMutex _waitingOnInvokeMethod; + bool evaluatePending() const { return _evaluatesPending > 0; } quint64 getTimersRemainingTime(); void timerFired(); diff --git a/scripts/system/controllers/handControllerGrab.js b/scripts/system/controllers/handControllerGrab.js index 1f536b9567..23a98ccc1a 100644 --- a/scripts/system/controllers/handControllerGrab.js +++ b/scripts/system/controllers/handControllerGrab.js @@ -2141,6 +2141,7 @@ function MyController(hand) { }; this.nearGrabbing = function(deltaTime, timestamp) { + print("nearGrabbing() deltaTime:" + deltaTime); this.grabPointSphereOff(); diff --git a/unpublishedScripts/marketplace/bow/bow.js b/unpublishedScripts/marketplace/bow/bow.js index 818960e335..a735400a3c 100644 --- a/unpublishedScripts/marketplace/bow/bow.js +++ b/unpublishedScripts/marketplace/bow/bow.js @@ -154,6 +154,7 @@ }, continueEquip: function(entityID, args) { this.deltaTime = checkInterval(); + print("continueEquip delta:" + this.deltaTime); //debounce during debugging -- maybe we're updating too fast? if (USE_DEBOUNCE === true) { this.sinceLastUpdate = this.sinceLastUpdate + this.deltaTime; From 82ab8635d715165fef53342834b1a77b44ab541c Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Fri, 30 Dec 2016 12:02:48 -0800 Subject: [PATCH 2/6] debugging --- .../entities/src/EntityScriptingInterface.cpp | 2 ++ libraries/script-engine/src/ScriptEngine.cpp | 17 +++++++++++------ .../system/controllers/handControllerGrab.js | 13 +++++++++++-- 3 files changed, 24 insertions(+), 8 deletions(-) diff --git a/libraries/entities/src/EntityScriptingInterface.cpp b/libraries/entities/src/EntityScriptingInterface.cpp index 498e0959c6..55f640022a 100644 --- a/libraries/entities/src/EntityScriptingInterface.cpp +++ b/libraries/entities/src/EntityScriptingInterface.cpp @@ -526,6 +526,8 @@ void EntityScriptingInterface::setEntitiesScriptEngine(EntitiesScriptEngineProvi } void EntityScriptingInterface::callEntityMethod(QUuid id, const QString& method, const QStringList& params) { + qDebug() << __FUNCTION__ << "method:" << method << "now:" << usecTimestampNow(); + std::lock_guard lock(_entitiesScriptEngineLock); if (_entitiesScriptEngine) { EntityItemID entityID{ id }; diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index 02f2efd063..61b6b3c13b 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -928,22 +928,23 @@ void ScriptEngine::run() { auto remainingSleepUntil = std::chrono::duration_cast(sleepUntil - clock::now()); auto closestUntil = std::min(remainingSleepUntil, untilTimer); auto thisSleepUntil = std::min(sleepUntil, clock::now() + closestUntil); + auto untilThisSleepUntil = std::chrono::duration_cast(thisSleepUntil - clock::now()); // if the sleep until is more than 1 ms away, then don't sleep, and instead use a wait condition // for any possible invoke methods that might also be pending. const std::chrono::microseconds MAX_USECS_TO_SLEEP(USECS_PER_MSEC); - if (closestUntil < MAX_USECS_TO_SLEEP) { - qDebug() << "about to sleep:" << closestUntil.count() << "usec"; + if (untilThisSleepUntil < MAX_USECS_TO_SLEEP) { + qDebug() << "[" << getFilename() << "]" << "about to sleep untilThisSleepUntil:" << untilThisSleepUntil.count() << "usec -- averageTimerPerFrame:" << averageTimerPerFrame.count(); std::this_thread::sleep_until(thisSleepUntil); } else { // FIXME - we might want to make this 1 less ms to wait - unsigned long maxWait = closestUntil.count() / USECS_PER_MSEC; - qDebug() << "about to wait:" << maxWait << "ms --- closestUntil:" << closestUntil.count() << "usec"; + unsigned long maxWait = untilThisSleepUntil.count() / USECS_PER_MSEC; + qDebug() << "[" << getFilename() << "]" << "about to wait:" << maxWait << "ms --- untilThisSleepUntil:" << untilThisSleepUntil.count() << "usec -- averageTimerPerFrame:" << averageTimerPerFrame.count(); _waitingOnInvokeMethod.lock(); bool signalled = _hasInvokeMethod.wait(&_waitingOnInvokeMethod, maxWait); _waitingOnInvokeMethod.unlock(); if (signalled) { - qDebug() << "SIGNALLED!! done waiting... now:" << usecTimestampNow(); + qDebug() << "[" << getFilename() << "]" << "SIGNALLED!! done waiting... now:" << usecTimestampNow(); } } @@ -1664,13 +1665,15 @@ void ScriptEngine::callWithEnvironment(const EntityItemID& entityID, const QUrl& } void ScriptEngine::callEntityScriptMethod(const EntityItemID& entityID, const QString& methodName, const QStringList& params) { + qDebug() << "[" << getFilename() << "]" << __FUNCTION__ << "method:" << methodName << "now:" << usecTimestampNow(); + if (QThread::currentThread() != thread()) { #ifdef THREAD_DEBUGGING qCDebug(scriptengine) << "*** WARNING *** ScriptEngine::callEntityScriptMethod() called on wrong thread [" << QThread::currentThread() << "], invoking on correct thread [" << thread() << "] " "entityID:" << entityID << "methodName:" << methodName; #endif - qDebug() << "about to invokeMethod callEntityScriptMethod() now:" << usecTimestampNow(); + qDebug() << "[" << getFilename() << "]" << "about to invokeMethod callEntityScriptMethod() now:" << usecTimestampNow(); QMetaObject::invokeMethod(this, "callEntityScriptMethod", Q_ARG(const EntityItemID&, entityID), @@ -1692,6 +1695,8 @@ void ScriptEngine::callEntityScriptMethod(const EntityItemID& entityID, const QS QScriptValueList args; args << entityID.toScriptValue(this); args << qScriptValueFromSequence(this, params); + + qDebug() << "[" << getFilename() << "]" << __FUNCTION__ << "about to callWithEnvironment()... method:" << methodName << "now:" << usecTimestampNow(); callWithEnvironment(entityID, details.definingSandboxURL, entityScript.property(methodName), entityScript, args); } diff --git a/scripts/system/controllers/handControllerGrab.js b/scripts/system/controllers/handControllerGrab.js index 23a98ccc1a..84e3acf430 100644 --- a/scripts/system/controllers/handControllerGrab.js +++ b/scripts/system/controllers/handControllerGrab.js @@ -816,6 +816,7 @@ function MyController(hand) { }; this.update = function(deltaTime, timestamp) { + print("this.update() deltaTime:" + deltaTime + " timestamp:" + timestamp + " now:" + Date.now()); this.updateSmoothedTrigger(); @@ -844,6 +845,7 @@ function MyController(hand) { this.callEntityMethodOnGrabbed = function(entityMethodName) { var args = [this.hand === RIGHT_HAND ? "right" : "left", MyAvatar.sessionUUID]; + print("this.callEntityMethodOnGrabbed() entityMethodName:" + entityMethodName + " now:" + Date.now()); Entities.callEntityMethod(this.grabbedEntity, entityMethodName, args); }; @@ -2141,7 +2143,7 @@ function MyController(hand) { }; this.nearGrabbing = function(deltaTime, timestamp) { - print("nearGrabbing() deltaTime:" + deltaTime); + print("nearGrabbing() deltaTime:" + deltaTime + " now:" + Date.now()); this.grabPointSphereOff(); @@ -3068,8 +3070,15 @@ var handleHandMessages = function(channel, message, sender) { Messages.messageReceived.connect(handleHandMessages); var BASIC_TIMER_INTERVAL_MS = 20; // 20ms = 50hz good enough +var lastInterval = Date.now(); var updateIntervalTimer = Script.setInterval(function(){ - update(BASIC_TIMER_INTERVAL_MS / 1000); + var thisInterval = Date.now(); + var deltaTimeMsec = thisInterval - lastInterval; + var deltaTime = deltaTimeMsec / 1000; + lastInterval = thisInterval; + + print("setInterval function() deltaTimeMsec:" + deltaTimeMsec + " deltaTime:" + deltaTime + "(sec) now:" + Date.now()); + update(deltaTime); }, BASIC_TIMER_INTERVAL_MS); function cleanup() { From d440532cff46d4f5d2ffda360b90ca375adf223a Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Tue, 3 Jan 2017 11:10:07 -0800 Subject: [PATCH 3/6] make sure RPC is timely --- .../entities/src/EntityScriptingInterface.cpp | 2 - libraries/script-engine/src/ScriptEngine.cpp | 75 +----- libraries/script-engine/src/ScriptEngine.h | 3 - scripts/developer/tests/testInterval.js | 253 ++++++++++++++++++ .../tests/testIntervalRpcFunction.js | 77 ++++++ .../system/controllers/handControllerGrab.js | 58 +++- 6 files changed, 387 insertions(+), 81 deletions(-) create mode 100644 scripts/developer/tests/testInterval.js create mode 100644 scripts/developer/tests/testIntervalRpcFunction.js diff --git a/libraries/entities/src/EntityScriptingInterface.cpp b/libraries/entities/src/EntityScriptingInterface.cpp index 55f640022a..498e0959c6 100644 --- a/libraries/entities/src/EntityScriptingInterface.cpp +++ b/libraries/entities/src/EntityScriptingInterface.cpp @@ -526,8 +526,6 @@ void EntityScriptingInterface::setEntitiesScriptEngine(EntitiesScriptEngineProvi } void EntityScriptingInterface::callEntityMethod(QUuid id, const QString& method, const QStringList& params) { - qDebug() << __FUNCTION__ << "method:" << method << "now:" << usecTimestampNow(); - std::lock_guard lock(_entitiesScriptEngineLock); if (_entitiesScriptEngine) { EntityItemID entityID{ id }; diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index 61b6b3c13b..6bcf1b1c01 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -573,7 +573,6 @@ void ScriptEngine::registerValue(const QString& valueName, QScriptValue value) { QMetaObject::invokeMethod(this, "registerValue", Q_ARG(const QString&, valueName), Q_ARG(QScriptValue, value)); - _hasInvokeMethod.wakeAll(); return; } @@ -604,7 +603,6 @@ void ScriptEngine::registerGlobalObject(const QString& name, QObject* object) { QMetaObject::invokeMethod(this, "registerGlobalObject", Q_ARG(const QString&, name), Q_ARG(QObject*, object)); - _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -630,7 +628,6 @@ void ScriptEngine::registerFunction(const QString& name, QScriptEngine::Function Q_ARG(const QString&, name), Q_ARG(QScriptEngine::FunctionSignature, functionSignature), Q_ARG(int, numArguments)); - _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -650,7 +647,6 @@ void ScriptEngine::registerFunction(const QString& parent, const QString& name, Q_ARG(const QString&, name), Q_ARG(QScriptEngine::FunctionSignature, functionSignature), Q_ARG(int, numArguments)); - _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -676,7 +672,6 @@ void ScriptEngine::registerGetterSetter(const QString& name, QScriptEngine::Func Q_ARG(QScriptEngine::FunctionSignature, getter), Q_ARG(QScriptEngine::FunctionSignature, setter), Q_ARG(const QString&, parent)); - _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -709,7 +704,6 @@ void ScriptEngine::removeEventHandler(const EntityItemID& entityID, const QStrin Q_ARG(const EntityItemID&, entityID), Q_ARG(const QString&, eventName), Q_ARG(QScriptValue, handler)); - _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -741,7 +735,6 @@ void ScriptEngine::addEventHandler(const EntityItemID& entityID, const QString& Q_ARG(const EntityItemID&, entityID), Q_ARG(const QString&, eventName), Q_ARG(QScriptValue, handler)); - _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -828,7 +821,6 @@ QScriptValue ScriptEngine::evaluate(const QString& sourceCode, const QString& fi Q_ARG(const QString&, sourceCode), Q_ARG(const QString&, fileName), Q_ARG(int, lineNumber)); - _hasInvokeMethod.wakeAll(); return result; } @@ -916,38 +908,11 @@ void ScriptEngine::run() { break; } - // determine how long before the next timer should fire, we'd ideally like to sleep just - // that long, so the next processEvents() will allow the timers to fire on time. - const std::chrono::microseconds minTimerTimeRemaining(USECS_PER_MSEC * getTimersRemainingTime()); - - // However, if we haven't yet slept at least as long as our average timer per frame, then we will - // punish the timers to at least wait as long as the average run time of the timers. - auto untilTimer = std::max(minTimerTimeRemaining, averageTimerPerFrame); - - // choose the closest time point, our - auto remainingSleepUntil = std::chrono::duration_cast(sleepUntil - clock::now()); - auto closestUntil = std::min(remainingSleepUntil, untilTimer); - auto thisSleepUntil = std::min(sleepUntil, clock::now() + closestUntil); - auto untilThisSleepUntil = std::chrono::duration_cast(thisSleepUntil - clock::now()); - - // if the sleep until is more than 1 ms away, then don't sleep, and instead use a wait condition - // for any possible invoke methods that might also be pending. - const std::chrono::microseconds MAX_USECS_TO_SLEEP(USECS_PER_MSEC); - if (untilThisSleepUntil < MAX_USECS_TO_SLEEP) { - qDebug() << "[" << getFilename() << "]" << "about to sleep untilThisSleepUntil:" << untilThisSleepUntil.count() << "usec -- averageTimerPerFrame:" << averageTimerPerFrame.count(); - std::this_thread::sleep_until(thisSleepUntil); - } else { - // FIXME - we might want to make this 1 less ms to wait - unsigned long maxWait = untilThisSleepUntil.count() / USECS_PER_MSEC; - qDebug() << "[" << getFilename() << "]" << "about to wait:" << maxWait << "ms --- untilThisSleepUntil:" << untilThisSleepUntil.count() << "usec -- averageTimerPerFrame:" << averageTimerPerFrame.count(); - _waitingOnInvokeMethod.lock(); - bool signalled = _hasInvokeMethod.wait(&_waitingOnInvokeMethod, maxWait); - _waitingOnInvokeMethod.unlock(); - if (signalled) { - qDebug() << "[" << getFilename() << "]" << "SIGNALLED!! done waiting... now:" << usecTimestampNow(); - } - - } + // We only want to sleep a small amount so that any pending events (like timers or invokeMethod events) + // will be able to process quickly. + static const int SMALL_SLEEP_AMOUNT = 100; + auto smallSleepUntil = clock::now() + static_cast(SMALL_SLEEP_AMOUNT); + std::this_thread::sleep_until(smallSleepUntil); } #ifdef SCRIPT_DELAY_DEBUG @@ -1037,21 +1002,6 @@ void ScriptEngine::run() { emit doneRunning(); } -quint64 ScriptEngine::getTimersRemainingTime() { - quint64 minimumTime = USECS_PER_SECOND; // anything larger than this can be ignored - QMutableHashIterator i(_timerFunctionMap); - while (i.hasNext()) { - i.next(); - QTimer* timer = i.key(); - int remainingTime = timer->remainingTime(); - if (remainingTime >= 0) { - minimumTime = std::min((quint64)remainingTime, minimumTime); - } - } - return minimumTime; -} - - // NOTE: This is private because it must be called on the same thread that created the timers, which is why // we want to only call it in our own run "shutdown" processing. void ScriptEngine::stopAllTimers() { @@ -1062,6 +1012,7 @@ void ScriptEngine::stopAllTimers() { stopTimer(timer); } } + void ScriptEngine::stopAllTimersForEntityScript(const EntityItemID& entityID) { // We could maintain a separate map of entityID => QTimer, but someone will have to prove to me that it's worth the complexity. -HRS QVector toDelete; @@ -1085,7 +1036,6 @@ void ScriptEngine::stop(bool marshal) { if (marshal) { QMetaObject::invokeMethod(this, "stop"); - _hasInvokeMethod.wakeAll(); return; } if (!_isFinished) { @@ -1106,7 +1056,6 @@ void ScriptEngine::callAnimationStateHandler(QScriptValue callback, AnimVariantM Q_ARG(QStringList, names), Q_ARG(bool, useNames), Q_ARG(AnimVariantResultHandler, resultHandler)); - _hasInvokeMethod.wakeAll(); return; } QScriptValue javascriptParameters = parameters.animVariantMapToScriptValue(this, names, useNames); @@ -1457,7 +1406,6 @@ void ScriptEngine::entityScriptContentAvailable(const EntityItemID& entityID, co Q_ARG(const QString&, contents), Q_ARG(bool, isURL), Q_ARG(bool, success)); - _hasInvokeMethod.wakeAll(); return; } @@ -1556,7 +1504,6 @@ void ScriptEngine::unloadEntityScript(const EntityItemID& entityID) { QMetaObject::invokeMethod(this, "unloadEntityScript", Q_ARG(const EntityItemID&, entityID)); - _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -1578,7 +1525,6 @@ void ScriptEngine::unloadAllEntityScripts() { #endif QMetaObject::invokeMethod(this, "unloadAllEntityScripts"); - _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -1665,21 +1611,16 @@ void ScriptEngine::callWithEnvironment(const EntityItemID& entityID, const QUrl& } void ScriptEngine::callEntityScriptMethod(const EntityItemID& entityID, const QString& methodName, const QStringList& params) { - qDebug() << "[" << getFilename() << "]" << __FUNCTION__ << "method:" << methodName << "now:" << usecTimestampNow(); - if (QThread::currentThread() != thread()) { #ifdef THREAD_DEBUGGING qCDebug(scriptengine) << "*** WARNING *** ScriptEngine::callEntityScriptMethod() called on wrong thread [" << QThread::currentThread() << "], invoking on correct thread [" << thread() << "] " "entityID:" << entityID << "methodName:" << methodName; #endif - qDebug() << "[" << getFilename() << "]" << "about to invokeMethod callEntityScriptMethod() now:" << usecTimestampNow(); - QMetaObject::invokeMethod(this, "callEntityScriptMethod", Q_ARG(const EntityItemID&, entityID), Q_ARG(const QString&, methodName), Q_ARG(const QStringList&, params)); - _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -1695,8 +1636,6 @@ void ScriptEngine::callEntityScriptMethod(const EntityItemID& entityID, const QS QScriptValueList args; args << entityID.toScriptValue(this); args << qScriptValueFromSequence(this, params); - - qDebug() << "[" << getFilename() << "]" << __FUNCTION__ << "about to callWithEnvironment()... method:" << methodName << "now:" << usecTimestampNow(); callWithEnvironment(entityID, details.definingSandboxURL, entityScript.property(methodName), entityScript, args); } @@ -1714,7 +1653,6 @@ void ScriptEngine::callEntityScriptMethod(const EntityItemID& entityID, const QS Q_ARG(const EntityItemID&, entityID), Q_ARG(const QString&, methodName), Q_ARG(const PointerEvent&, event)); - _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING @@ -1748,7 +1686,6 @@ void ScriptEngine::callEntityScriptMethod(const EntityItemID& entityID, const QS Q_ARG(const QString&, methodName), Q_ARG(const EntityItemID&, otherID), Q_ARG(const Collision&, collision)); - _hasInvokeMethod.wakeAll(); return; } #ifdef THREAD_DEBUGGING diff --git a/libraries/script-engine/src/ScriptEngine.h b/libraries/script-engine/src/ScriptEngine.h index 8e6184f62f..803aa7fa22 100644 --- a/libraries/script-engine/src/ScriptEngine.h +++ b/libraries/script-engine/src/ScriptEngine.h @@ -217,9 +217,6 @@ protected: void init(); - QWaitCondition _hasInvokeMethod; - QMutex _waitingOnInvokeMethod; - bool evaluatePending() const { return _evaluatesPending > 0; } quint64 getTimersRemainingTime(); void timerFired(); diff --git a/scripts/developer/tests/testInterval.js b/scripts/developer/tests/testInterval.js new file mode 100644 index 0000000000..0b6b70686b --- /dev/null +++ b/scripts/developer/tests/testInterval.js @@ -0,0 +1,253 @@ + +// Tester, try testing these different settings. +// +// +-----------------+---------------------+----------------------+------------------------------------------------------------------------------------------------------------------ +// | TIMER_INTERVAL | TIMER_WORK_EFFORT | UPDATE_WORK_EFFORT | Expected result +// +-----------------+---------------------+----------------------+------------------------------------------------------------------------------------------------------------------ +// | 20 | < 1000 | < 1000 | timer 20ms/work 0ms, update 16.6ms/work 0ms +// | 5 | < 1000 | < 1000 | timer 5ms/work 0ms, update 16.6ms/work 0ms +// | 11 | < 1000 | < 1000 | timer 11ms/work 0ms, update 16.6ms/work 0ms +// | 11 | ~100000 | < 1000 | timer 11ms/work 3ms, update 16.6ms/work 0ms +// | 11 | ~500000 | < 1000 | timer 17.3ms/work 16.4ms, update 17.4ms/work 0ms, punishing the script, timer & update delayed +// | 40 | ~1000000 | < 1000 | timer 40ms/work 32ms, update 31ms/work 0ms, punishing the script, update delayed, timer on time +// | 10 | ~1000 | ~1000000 | timer 16ms/work 0ms, update 63ms/work 33ms, punishing the script, update delayed, timer slightly delayed +// | 10 | ~1000000 | ~1000000 | timer 90ms/work 33ms, update ~100-120ms/work 33ms, punishing the script, timer & update delayed +// +-----------------+---------------------+----------------------+------------------------------------------------------------------------------------------------------------------ + +var TIMER_HZ = 50; +var TIMER_INTERVAL = 1000 / TIMER_HZ; +var TIMER_WORK_EFFORT = 0; // 1000 is light work, 1000000 ~= 30ms +var UPDATE_WORK_EFFORT = 0; // 1000 is light work, 1000000 ~= 30ms + +var basePosition = Vec3.sum(Camera.getPosition(), Quat.getFront(Camera.getOrientation())); + +var timerBox = Entities.addEntity( + { type: "Box", + position: basePosition, + dimensions: { x: 0.1, y: 0.1, z: 0.1 }, + color: { red: 255, green: 0, blue: 255 }, + dynamic: false, + collisionless: true + }); + +var lastTick = Date.now(); +var deltaTick = 0; +var tickSamples = 0; +var totalVariance = 0; +var tickCount = 0; +var totalWork = 0; +var highVarianceCount = 0; +var varianceCount = 0; + +print("Set interval = " + TIMER_INTERVAL); + +var timerTime = 0.0; +var range = 0.5; +var rotationFactor = 0.5; // smaller == faster +var omega = 2.0 * Math.PI / rotationFactor; + +var ticker = Script.setInterval(function() { + + tickCount++; + var tickNow = Date.now(); + deltaTick = tickNow - lastTick; + + var variance = Math.abs(deltaTick - TIMER_INTERVAL); + totalVariance += variance; + + if (variance > 1) { + varianceCount++; + } + if (variance > 5) { + highVarianceCount++; + } + + var preWork = Date.now(); + var y = 2; + for (var x = 0; x < TIMER_WORK_EFFORT; x++) { + y = y * y; + } + var postWork = Date.now(); + deltaWork = postWork - preWork; + totalWork += deltaWork; + + // move a box + var deltaTime = deltaTick / 1000; + timerTime += deltaTime; + rotation = Quat.angleAxis(timerTime * omega / Math.PI * 180.0, { x: 0, y: 1, z: 0 }); + Entities.editEntity(timerBox, + { + position: { x: basePosition.x + Math.sin(timerTime * omega) / 2.0 * range, + y: basePosition.y, + z: basePosition.z }, + //rotation: rotation + }); + + tickSamples = tickSamples + deltaTick; + lastTick = tickNow; + + // report about every 5 seconds + if(tickCount == (TIMER_HZ * 5)) { + print("TIMER -- For " + tickCount + " samples average interval = " + tickSamples/tickCount + " ms" + + " average variance:" + totalVariance/tickCount + " ms" + + " min variance:" + varianceCount + " [" + (varianceCount/tickCount) * 100 + " %] " + + " high variance:" + highVarianceCount + " [" + (highVarianceCount/tickCount) * 100 + " %] " + + " average work:" + totalWork/tickCount + " ms"); + tickCount = 0; + tickSamples = 0; + totalWork = 0; + totalVariance = 0; + varianceCount = 0; + highVarianceCount = 0; + } +}, TIMER_INTERVAL); + +///////////////////////////////////////////////////////////////////////// + +var rpcPosition = Vec3.sum(basePosition, { x:0, y: 0.2, z: 0}); + +var theRpcFunctionInclude = Script.resolvePath("testIntervalRpcFunction.js"); + +print("theRpcFunctionInclude:" + theRpcFunctionInclude); + +var rpcBox = Entities.addEntity( + { type: "Box", + position: rpcPosition, + dimensions: { x: 0.1, y: 0.1, z: 0.1 }, + color: { red: 255, green: 255, blue: 0 }, + dynamic: false, + collisionless: true, + script: theRpcFunctionInclude + }); + +var rpcLastTick = Date.now(); +var rpcTotalTicks = 0; +var rpcCount = 0; +var rpcTotalVariance = 0; +var rpcTickCount = 0; +var rpcVarianceCount = 0; +var rpcHighVarianceCount = 0; + +var rpcTicker = Script.setInterval(function() { + + rpcTickCount++; + var tickNow = Date.now(); + var deltaTick = tickNow - rpcLastTick; + var variance = Math.abs(deltaTick - TIMER_INTERVAL); + rpcTotalVariance += variance; + + if (variance > 1) { + rpcVarianceCount++; + } + if (variance > 5) { + rpcHighVarianceCount++; + } + + rpcTotalTicks += deltaTick; + rpcLastTick = tickNow; + + var args = [range, rotationFactor, omega, TIMER_INTERVAL, TIMER_HZ]; + + Entities.callEntityMethod(rpcBox, "doRPC", args); + + // report about every 5 seconds + if(rpcTickCount == (TIMER_HZ * 5)) { + print("RPCTIMER- For " + rpcTickCount + " samples average interval = " + rpcTotalTicks/rpcTickCount + " ms" + + " average variance:" + rpcTotalVariance/rpcTickCount + " ms" + + " min variance:" + rpcVarianceCount + " [" + (rpcVarianceCount/rpcTickCount) * 100 + " %] " + + " high variance:" + rpcHighVarianceCount + " [" + (rpcHighVarianceCount/rpcTickCount) * 100 + " %] " + ); + rpcTickCount = 0; + rpcTotalTicks = 0; + rpcTotalVariance = 0; + rpcVarianceCount = 0; + rpcHighVarianceCount = 0; + } +}, TIMER_INTERVAL); + + +var updateCount = 0; +var updateTotalElapsed = 0; +var lastUpdate = Date.now(); +var updateTotalWork = 0; +var updateTotalVariance = 0; +var updateVarianceCount = 0; +var updateHighVarianceCount = 0; + +var updatePosition = Vec3.sum(basePosition, { x:0, y: -0.2, z: 0}); + +var updateBox = Entities.addEntity( + { type: "Box", + position: updatePosition, + dimensions: { x: 0.1, y: 0.1, z: 0.1 }, + color: { red: 0, green: 255, blue: 255 }, + dynamic: false, + collisionless: true + }); + + +var UPDATE_HZ = 60; // standard script update interval +var UPDATE_INTERVAL = 1000/UPDATE_HZ; // standard script update interval +var updateTime = 0; +var updateFunction = function(deltaTime){ + updateCount++; + var updateAt = Date.now(); + deltaUpdate = updateAt - lastUpdate; + updateTotalElapsed += deltaUpdate; + lastUpdate = updateAt; + + var variance = Math.abs(deltaUpdate - UPDATE_INTERVAL); + updateTotalVariance += variance; + + if (variance > 1) { + updateVarianceCount++; + } + + if (variance > 5) { + updateHighVarianceCount++; + } + + var preWork = Date.now(); + var y = 2; + for (var x = 0; x < UPDATE_WORK_EFFORT; x++) { + y = y * y; + } + var postWork = Date.now(); + deltaWork = postWork - preWork; + updateTotalWork += deltaWork; + + // move a box + + updateTime += deltaTime; + rotation = Quat.angleAxis(updateTime * omega / Math.PI * 180.0, { x: 0, y: 1, z: 0 }); + Entities.editEntity(updateBox, + { + position: { x: updatePosition.x + Math.sin(updateTime * omega) / 2.0 * range, + y: updatePosition.y, + z: updatePosition.z }, + }); + + + if(updateCount == (UPDATE_HZ * 5)) { + print("UPDATE -- For " + updateCount + " samples average update = " + updateTotalElapsed/updateCount + " ms" + + " average variance:" + updateTotalVariance/updateCount + " ms" + + " min variance:" + updateVarianceCount + " [" + (updateVarianceCount/updateCount) * 100 + " %] " + + " high variance:" + updateHighVarianceCount + " [" + (updateHighVarianceCount/updateCount) * 100 + " %] " + + " average work:" + updateTotalWork/updateCount + " ms"); + + updateCount = 0; + updateTotalElapsed = 0; + updateTotalWork = 0; + updateTotalVariance = 0; + updateVarianceCount = 0; + updateHighVarianceCount = 0; + } +}; + +Script.update.connect(updateFunction); + +Script.scriptEnding.connect(function(){ + Entities.deleteEntity(timerBox); + Entities.deleteEntity(rpcBox); + Entities.deleteEntity(updateBox); +}); diff --git a/scripts/developer/tests/testIntervalRpcFunction.js b/scripts/developer/tests/testIntervalRpcFunction.js new file mode 100644 index 0000000000..86caef3f61 --- /dev/null +++ b/scripts/developer/tests/testIntervalRpcFunction.js @@ -0,0 +1,77 @@ +(function() { + var x = false; + var y = false; + var z = false; + + var entityLastTick = Date.now(); + var entityTotalTicks = 0; + var entityCount = 0; + var entityTotalVariance = 0; + var entityTickCount = 0; + var entityVarianceCount = 0; + var entityHighVarianceCount = 0; + var _entityID; + var time = 0; + + function Foo() { return; }; + Foo.prototype = { + preload: function(entityID) { print('Foo preload'); _entityID = entityID; }, + doRPC: function(entityID, args) { + var range = args[0]; + var rotationFactor = args[1]; + var omega = args[2]; + var TIMER_INTERVAL = args[3]; + var TIMER_HZ = args[4]; + + // first time, set our x,y,z + if (x === false) { + var position = Entities.getEntityProperties(_entityID, "position").position; + x = position.x; + y = position.y; + z = position.z; + } + entityTickCount++; + var tickNow = Date.now(); + var deltaTick = tickNow - entityLastTick; + var variance = Math.abs(deltaTick - TIMER_INTERVAL); + entityTotalVariance += variance; + + if (variance > 1) { + entityVarianceCount++; + } + if (variance > 5) { + entityHighVarianceCount++; + } + + entityTotalTicks += deltaTick; + entityLastTick = tickNow; + + // move self!! + var deltaTime = deltaTick / 1000; + time += deltaTime; + rotation = Quat.angleAxis(time * omega / Math.PI * 180.0, { x: 0, y: 1, z: 0 }); + Entities.editEntity(_entityID, + { + position: { x: x + Math.sin(time * omega) / 2.0 * range, + y: y, + z: z }, + }); + + + if(entityTickCount == (TIMER_HZ * 5)) { + print("ENTITY -- For " + entityTickCount + " samples average interval = " + entityTotalTicks/entityTickCount + " ms" + + " average variance:" + entityTotalVariance/entityTickCount + " ms" + + " min variance:" + entityVarianceCount + " [" + (entityVarianceCount/entityTickCount) * 100 + " %] " + + " high variance:" + entityHighVarianceCount + " [" + (entityHighVarianceCount/entityTickCount) * 100 + " %] " + ); + entityTickCount = 0; + entityTotalTicks = 0; + entityTotalVariance = 0; + entityVarianceCount = 0; + entityHighVarianceCount = 0; + } + } + }; + + return new Foo(); +}); diff --git a/scripts/system/controllers/handControllerGrab.js b/scripts/system/controllers/handControllerGrab.js index 84e3acf430..513e70d18c 100644 --- a/scripts/system/controllers/handControllerGrab.js +++ b/scripts/system/controllers/handControllerGrab.js @@ -816,8 +816,6 @@ function MyController(hand) { }; this.update = function(deltaTime, timestamp) { - print("this.update() deltaTime:" + deltaTime + " timestamp:" + timestamp + " now:" + Date.now()); - this.updateSmoothedTrigger(); // If both trigger and grip buttons squeezed and nothing is held, rescale my avatar! @@ -845,7 +843,6 @@ function MyController(hand) { this.callEntityMethodOnGrabbed = function(entityMethodName) { var args = [this.hand === RIGHT_HAND ? "right" : "left", MyAvatar.sessionUUID]; - print("this.callEntityMethodOnGrabbed() entityMethodName:" + entityMethodName + " now:" + Date.now()); Entities.callEntityMethod(this.grabbedEntity, entityMethodName, args); }; @@ -2143,8 +2140,6 @@ function MyController(hand) { }; this.nearGrabbing = function(deltaTime, timestamp) { - print("nearGrabbing() deltaTime:" + deltaTime + " now:" + Date.now()); - this.grabPointSphereOff(); if (this.state == STATE_NEAR_GRABBING && (!this.triggerClicked && this.secondaryReleased())) { @@ -3069,16 +3064,65 @@ var handleHandMessages = function(channel, message, sender) { Messages.messageReceived.connect(handleHandMessages); -var BASIC_TIMER_INTERVAL_MS = 20; // 20ms = 50hz good enough +var TARGET_UPDATE_HZ = 50; // 50hz good enough (no change in logic) +var BASIC_TIMER_INTERVAL_MS = 1000 / TARGET_UPDATE_HZ; var lastInterval = Date.now(); + +var intervalCount = 0; +var totalDelta = 0; +var totalVariance = 0; +var highVarianceCount = 0; +var veryhighVarianceCount = 0; +var updateTotalWork = 0; + +var UPDATE_PERFORMANCE_DEBUGGING = false; + var updateIntervalTimer = Script.setInterval(function(){ + + intervalCount++; var thisInterval = Date.now(); var deltaTimeMsec = thisInterval - lastInterval; var deltaTime = deltaTimeMsec / 1000; lastInterval = thisInterval; - print("setInterval function() deltaTimeMsec:" + deltaTimeMsec + " deltaTime:" + deltaTime + "(sec) now:" + Date.now()); + totalDelta += deltaTimeMsec; + + var variance = Math.abs(deltaTimeMsec - BASIC_TIMER_INTERVAL_MS); + totalVariance += variance; + + if (variance > 1) { + highVarianceCount++; + } + + if (variance > 5) { + veryhighVarianceCount++; + } + + // will call update for both hands + var preWork = Date.now(); update(deltaTime); + var postWork = Date.now(); + var workDelta = postWork - preWork; + updateTotalWork += workDelta; + + if (intervalCount == 100) { + + if (UPDATE_PERFORMANCE_DEBUGGING) { + print("handControllerGrab.js -- For " + intervalCount + " samples average= " + totalDelta/intervalCount + " ms" + + " average variance:" + totalVariance/intervalCount + " ms" + + " high variance count:" + highVarianceCount + " [ " + (highVarianceCount/intervalCount) * 100 + "% ] " + + " VERY high variance count:" + veryhighVarianceCount + " [ " + (veryhighVarianceCount/intervalCount) * 100 + "% ] " + + " average work:" + updateTotalWork/intervalCount + " ms"); + } + + intervalCount = 0; + totalDelta = 0; + totalVariance = 0; + highVarianceCount = 0; + veryhighVarianceCount = 0; + updateTotalWork = 0; + } + }, BASIC_TIMER_INTERVAL_MS); function cleanup() { From ecaf3b7b3d5ba6c53cc54d6df87d51b2d3fe4eaf Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Tue, 3 Jan 2017 11:11:48 -0800 Subject: [PATCH 4/6] remove debugging --- unpublishedScripts/marketplace/bow/bow.js | 1 - 1 file changed, 1 deletion(-) diff --git a/unpublishedScripts/marketplace/bow/bow.js b/unpublishedScripts/marketplace/bow/bow.js index a735400a3c..818960e335 100644 --- a/unpublishedScripts/marketplace/bow/bow.js +++ b/unpublishedScripts/marketplace/bow/bow.js @@ -154,7 +154,6 @@ }, continueEquip: function(entityID, args) { this.deltaTime = checkInterval(); - print("continueEquip delta:" + this.deltaTime); //debounce during debugging -- maybe we're updating too fast? if (USE_DEBOUNCE === true) { this.sinceLastUpdate = this.sinceLastUpdate + this.deltaTime; From 4c1aaa376d47d6cd9daeb09b57afafcef061702d Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Tue, 3 Jan 2017 11:13:03 -0800 Subject: [PATCH 5/6] remove cruft --- libraries/script-engine/src/ScriptEngine.h | 1 - 1 file changed, 1 deletion(-) diff --git a/libraries/script-engine/src/ScriptEngine.h b/libraries/script-engine/src/ScriptEngine.h index 803aa7fa22..d9a1249b1c 100644 --- a/libraries/script-engine/src/ScriptEngine.h +++ b/libraries/script-engine/src/ScriptEngine.h @@ -218,7 +218,6 @@ protected: void init(); bool evaluatePending() const { return _evaluatesPending > 0; } - quint64 getTimersRemainingTime(); void timerFired(); void stopAllTimers(); void stopAllTimersForEntityScript(const EntityItemID& entityID); From 3c7fa41be9ff6043fc70d089166077798a73099c Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Tue, 3 Jan 2017 11:29:52 -0800 Subject: [PATCH 6/6] update test script --- scripts/developer/tests/testInterval.js | 23 +++++++---------------- 1 file changed, 7 insertions(+), 16 deletions(-) diff --git a/scripts/developer/tests/testInterval.js b/scripts/developer/tests/testInterval.js index 0b6b70686b..94a5fe1fa5 100644 --- a/scripts/developer/tests/testInterval.js +++ b/scripts/developer/tests/testInterval.js @@ -1,22 +1,15 @@ - // Tester, try testing these different settings. // -// +-----------------+---------------------+----------------------+------------------------------------------------------------------------------------------------------------------ -// | TIMER_INTERVAL | TIMER_WORK_EFFORT | UPDATE_WORK_EFFORT | Expected result -// +-----------------+---------------------+----------------------+------------------------------------------------------------------------------------------------------------------ -// | 20 | < 1000 | < 1000 | timer 20ms/work 0ms, update 16.6ms/work 0ms -// | 5 | < 1000 | < 1000 | timer 5ms/work 0ms, update 16.6ms/work 0ms -// | 11 | < 1000 | < 1000 | timer 11ms/work 0ms, update 16.6ms/work 0ms -// | 11 | ~100000 | < 1000 | timer 11ms/work 3ms, update 16.6ms/work 0ms -// | 11 | ~500000 | < 1000 | timer 17.3ms/work 16.4ms, update 17.4ms/work 0ms, punishing the script, timer & update delayed -// | 40 | ~1000000 | < 1000 | timer 40ms/work 32ms, update 31ms/work 0ms, punishing the script, update delayed, timer on time -// | 10 | ~1000 | ~1000000 | timer 16ms/work 0ms, update 63ms/work 33ms, punishing the script, update delayed, timer slightly delayed -// | 10 | ~1000000 | ~1000000 | timer 90ms/work 33ms, update ~100-120ms/work 33ms, punishing the script, timer & update delayed -// +-----------------+---------------------+----------------------+------------------------------------------------------------------------------------------------------------------ +// Changing the TIMER_HZ will show different performance results. It's expected that at 90hz you'll see a fair +// amount of variance, as Qt Timers simply aren't accurate enough. In general RPC peformance should match the timer +// without significant difference in variance. -var TIMER_HZ = 50; +var TIMER_HZ = 50; // Change this for different values var TIMER_INTERVAL = 1000 / TIMER_HZ; var TIMER_WORK_EFFORT = 0; // 1000 is light work, 1000000 ~= 30ms + +var UPDATE_HZ = 60; // standard script update rate +var UPDATE_INTERVAL = 1000/UPDATE_HZ; // standard script update interval var UPDATE_WORK_EFFORT = 0; // 1000 is light work, 1000000 ~= 30ms var basePosition = Vec3.sum(Camera.getPosition(), Quat.getFront(Camera.getOrientation())); @@ -186,8 +179,6 @@ var updateBox = Entities.addEntity( }); -var UPDATE_HZ = 60; // standard script update interval -var UPDATE_INTERVAL = 1000/UPDATE_HZ; // standard script update interval var updateTime = 0; var updateFunction = function(deltaTime){ updateCount++;