From 03114fa6106e807a8e4732e9c0b07b3fcb4d3cdc Mon Sep 17 00:00:00 2001 From: Andrew Meadows Date: Tue, 20 Dec 2016 11:42:37 -0800 Subject: [PATCH] add AvatarsPerSec trace stats --- interface/src/Application.cpp | 20 +++++++++++++++----- interface/src/avatar/Avatar.cpp | 20 +++++++++++++++++++- interface/src/avatar/Avatar.h | 2 ++ interface/src/avatar/AvatarManager.cpp | 8 +++++++- libraries/shared/src/Profile.cpp | 1 + libraries/shared/src/Profile.h | 1 + 6 files changed, 45 insertions(+), 7 deletions(-) diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index 691c5051b1..5ca2e1bc7f 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -570,16 +570,26 @@ Application::Application(int& argc, char** argv, QElapsedTimer& startupTimer, bo const QString TEST_SCRIPT = "--testScript"; const QString TRACE_FILE = "--traceFile"; const QStringList args = arguments(); - for (int i = 0; i < args.size() - 1; ++i) { + std::cout << "adebug args.size() = " << args.size() << std::endl; // adebug + for (int i = 0; i < args.size(); ++i) { + std::cout << i << " adebug '" << args.at(i).toStdString() << std::endl; // adebug if (args.at(i) == TEST_SCRIPT) { QString testScriptPath = args.at(i + 1); + std::cout << "adebug given test script '" << testScriptPath.toStdString() << "'" << std::endl; // adebug if (QFileInfo(testScriptPath).exists()) { setProperty(hifi::properties::TEST, QUrl::fromLocalFile(testScriptPath)); + std::cout << "adebug found test script '" << testScriptPath.toStdString() << "'" << std::endl; // adebug + ++i; + } else { + std::cout << "adebug did NOT find test script '" << testScriptPath.toStdString() << "'" << std::endl; // adebug + } + } else { + std::cout << "adebug test script not specified'" << std::endl; // adebug + if (args.at(i) == TRACE_FILE) { + QString traceFilePath = args.at(i + 1); + setProperty(hifi::properties::TRACING, traceFilePath); + DependencyManager::get()->startTracing(); } - } else if (args.at(i) == TRACE_FILE) { - QString traceFilePath = args.at(i + 1); - setProperty(hifi::properties::TRACING, traceFilePath); - DependencyManager::get()->startTracing(); } } } diff --git a/interface/src/avatar/Avatar.cpp b/interface/src/avatar/Avatar.cpp index e83df85ff0..37840436fb 100644 --- a/interface/src/avatar/Avatar.cpp +++ b/interface/src/avatar/Avatar.cpp @@ -75,6 +75,19 @@ namespace render { } } +static uint64_t timeProcessingJoints = 0; +static int32_t numJointsProcessed = 0; + +float Avatar::getNumJointsProcessedPerSecond() { + float rate = 0.0f; + if (timeProcessingJoints > 0) { + rate = (float)(numJointsProcessed * USECS_PER_SECOND) / (float)timeProcessingJoints; + } + timeProcessingJoints = 0; + numJointsProcessed = 0; + return rate; +} + Avatar::Avatar(RigPointer rig) : AvatarData(), _skeletonOffset(0.0f), @@ -281,7 +294,7 @@ void Avatar::updateAvatarEntities() { void Avatar::simulate(float deltaTime) { PerformanceTimer perfTimer("simulate"); - if (!isDead() && !_motionState) { + if (!_motionState && !isDead()) { DependencyManager::get()->addAvatarToSimulation(this); } animateScaleChanges(deltaTime); @@ -319,6 +332,7 @@ void Avatar::simulate(float deltaTime) { } } + uint64_t start = usecTimestampNow(); if (_shouldAnimate && !_shouldSkipRender && (avatarPositionInView || avatarMeshInView)) { { PerformanceTimer perfTimer("skeleton"); @@ -345,6 +359,8 @@ void Avatar::simulate(float deltaTime) { PerformanceTimer perfTimer("skeleton"); _skeletonModel->simulate(deltaTime, false); } + timeProcessingJoints += usecTimestampNow() - start; + numJointsProcessed += _jointData.size(); // update animation for display name fade in/out if ( _displayNameTargetAlpha != _displayNameAlpha) { @@ -627,6 +643,7 @@ glm::quat Avatar::computeRotationFromBodyToWorldUp(float proportion) const { } void Avatar::fixupModelsInScene() { +#ifdef FOO // adebug _attachmentsToDelete.clear(); // check to see if when we added our models to the scene they were ready, if they were not ready, then @@ -650,6 +667,7 @@ void Avatar::fixupModelsInScene() { _attachmentsToDelete.insert(_attachmentsToDelete.end(), _attachmentsToRemove.begin(), _attachmentsToRemove.end()); _attachmentsToRemove.clear(); scene->enqueuePendingChanges(pendingChanges); +#endif // adebug } bool Avatar::shouldRenderHead(const RenderArgs* renderArgs) const { diff --git a/interface/src/avatar/Avatar.h b/interface/src/avatar/Avatar.h index dd0a9b2ab1..784f380028 100644 --- a/interface/src/avatar/Avatar.h +++ b/interface/src/avatar/Avatar.h @@ -57,6 +57,8 @@ class Avatar : public AvatarData { Q_PROPERTY(glm::vec3 skeletonOffset READ getSkeletonOffset WRITE setSkeletonOffset) public: + static float getNumJointsProcessedPerSecond(); + explicit Avatar(RigPointer rig = nullptr); ~Avatar(); diff --git a/interface/src/avatar/AvatarManager.cpp b/interface/src/avatar/AvatarManager.cpp index e2058ae1cf..fa695d9287 100644 --- a/interface/src/avatar/AvatarManager.cpp +++ b/interface/src/avatar/AvatarManager.cpp @@ -25,13 +25,13 @@ #endif +#include #include #include #include #include #include #include -#include #include "Application.h" #include "Avatar.h" @@ -129,6 +129,8 @@ void AvatarManager::updateOtherAvatars(float deltaTime) { QReadLocker lock(&_hashLock); if (_avatarHash.size() < 2 && _avatarFades.isEmpty()) { + PROFILE_COUNTER(simulation_avatar, "AvatarsPerSec", { { "aps", 0.0f } }); + PROFILE_COUNTER(simulation_avatar, "JointsPerSec", { { "jps", 0.0f } }); return; } @@ -143,6 +145,7 @@ void AvatarManager::updateOtherAvatars(float deltaTime) { // simulate avatars auto hashCopy = getHashCopy(); + uint64_t start = usecTimestampNow(); AvatarHash::iterator avatarIterator = hashCopy.begin(); while (avatarIterator != hashCopy.end()) { auto avatar = std::static_pointer_cast(avatarIterator.value()); @@ -165,6 +168,9 @@ void AvatarManager::updateOtherAvatars(float deltaTime) { // simulate avatar fades simulateAvatarFades(deltaTime); + float avatarsPerSecond = (float)(size() * USECS_PER_SECOND) / (float)(usecTimestampNow() - start); + PROFILE_COUNTER(simulation_avatar, "AvatarsPerSec", { { "aps", avatarsPerSecond } }); + PROFILE_COUNTER(simulation_avatar, "JointsPerSec", { { "jps", Avatar::getNumJointsProcessedPerSecond() } }); } void AvatarManager::postUpdate(float deltaTime) { diff --git a/libraries/shared/src/Profile.cpp b/libraries/shared/src/Profile.cpp index 4c5882348e..33c5c15862 100644 --- a/libraries/shared/src/Profile.cpp +++ b/libraries/shared/src/Profile.cpp @@ -18,6 +18,7 @@ Q_LOGGING_CATEGORY(trace_resource_network, "trace.resource.network") Q_LOGGING_CATEGORY(trace_resource_parse, "trace.resource.parse") Q_LOGGING_CATEGORY(trace_simulation, "trace.simulation") Q_LOGGING_CATEGORY(trace_simulation_animation, "trace.simulation.animation") +Q_LOGGING_CATEGORY(trace_simulation_avatar, "trace.simulation.avatar") Q_LOGGING_CATEGORY(trace_simulation_physics, "trace.simulation.physics") #if defined(NSIGHT_FOUND) diff --git a/libraries/shared/src/Profile.h b/libraries/shared/src/Profile.h index 6d02a0939f..57a98deb73 100644 --- a/libraries/shared/src/Profile.h +++ b/libraries/shared/src/Profile.h @@ -22,6 +22,7 @@ Q_DECLARE_LOGGING_CATEGORY(trace_resource_parse) Q_DECLARE_LOGGING_CATEGORY(trace_resource_network) Q_DECLARE_LOGGING_CATEGORY(trace_simulation) Q_DECLARE_LOGGING_CATEGORY(trace_simulation_animation) +Q_DECLARE_LOGGING_CATEGORY(trace_simulation_avatar) Q_DECLARE_LOGGING_CATEGORY(trace_simulation_physics) class Duration {