Merge pull request #9212 from AndrewMeadows/benji-001

add profile stats relating to avatar CPU costs

interface/src/Application.cpp

@@ -3225,6 +3225,8 @@ bool Application::shouldPaint(float nsecsElapsed) {
 }
 
 void Application::idle(float nsecsElapsed) {
+    PROFILE_RANGE(interfaceapp, __FUNCTION__);
+    PerformanceTimer perfTimer("idle");
 
     // Update the deadlock watchdog
     updateHeartbeat();
@@ -3239,8 +3241,6 @@ void Application::idle(float nsecsElapsed) {
         connect(offscreenUi.data(), &OffscreenUi::showDesktop, this, &Application::showDesktop);
     }
 
-    PROFILE_RANGE(interfaceapp, __FUNCTION__);
-
     if (auto steamClient = PluginManager::getInstance()->getSteamClientPlugin()) {
         steamClient->runCallbacks();
     }
@@ -3261,8 +3261,6 @@ void Application::idle(float nsecsElapsed) {
 
     _simCounter.increment();
 
-    PerformanceTimer perfTimer("idle");
-
     // Normally we check PipelineWarnings, but since idle will often take more than 10ms we only show these idle timing
     // details if we're in ExtraDebugging mode. However, the ::update() and its subcomponents will show their timing
     // details normally.
@@ -4536,8 +4534,8 @@ QRect Application::getDesirableApplicationGeometry() const {
 //                 or the "myCamera".
 //
 void Application::loadViewFrustum(Camera& camera, ViewFrustum& viewFrustum) {
-    PerformanceTimer perfTimer("loadViewFrustum");
     PROFILE_RANGE(interfaceapp, __FUNCTION__);
+    PerformanceTimer perfTimer("loadViewFrustum");
     // We will use these below, from either the camera or head vectors calculated above
     viewFrustum.setProjection(camera.getProjection());
 

interface/src/avatar/Avatar.cpp

@@ -184,6 +184,7 @@ void Avatar::animateScaleChanges(float deltaTime) {
 }
 
 void Avatar::updateAvatarEntities() {
+    PerformanceTimer perfTimer("attachments");
     // - if queueEditEntityMessage sees clientOnly flag it does _myAvatar->updateAvatarEntity()
     // - updateAvatarEntity saves the bytes and sets _avatarEntityDataLocallyEdited
     // - MyAvatar::update notices _avatarEntityDataLocallyEdited and calls sendIdentityPacket
@@ -285,28 +286,38 @@ void Avatar::simulate(float deltaTime) {
     }
     animateScaleChanges(deltaTime);
 
-    // update the shouldAnimate flag to match whether or not we will render the avatar.
-    const float MINIMUM_VISIBILITY_FOR_ON = 0.4f;
-    const float MAXIMUM_VISIBILITY_FOR_OFF = 0.6f;
-    ViewFrustum viewFrustum;
-    qApp->copyViewFrustum(viewFrustum);
-    float visibility = calculateRenderAccuracy(viewFrustum.getPosition(),
-            getBounds(), DependencyManager::get<LODManager>()->getOctreeSizeScale());
-    if (!_shouldAnimate) {
-        if (visibility > MINIMUM_VISIBILITY_FOR_ON) {
-            _shouldAnimate = true;
-            qCDebug(interfaceapp) << "Restoring" << (isMyAvatar() ? "myself" : getSessionUUID()) << "for visibility" << visibility;
+    bool avatarPositionInView = false;
+    bool avatarMeshInView = false;
+    { // update the shouldAnimate flag to match whether or not we will render the avatar.
+        PerformanceTimer perfTimer("cull");
+        ViewFrustum viewFrustum;
+        {
+            PerformanceTimer perfTimer("LOD");
+            const float MINIMUM_VISIBILITY_FOR_ON = 0.4f;
+            const float MAXIMUM_VISIBILITY_FOR_OFF = 0.6f;
+            qApp->copyViewFrustum(viewFrustum);
+            float visibility = calculateRenderAccuracy(viewFrustum.getPosition(),
+                    getBounds(), DependencyManager::get<LODManager>()->getOctreeSizeScale());
+            if (!_shouldAnimate) {
+                if (visibility > MINIMUM_VISIBILITY_FOR_ON) {
+                    _shouldAnimate = true;
+                    qCDebug(interfaceapp) << "Restoring" << (isMyAvatar() ? "myself" : getSessionUUID()) << "for visibility" << visibility;
+                }
+            } else if (visibility < MAXIMUM_VISIBILITY_FOR_OFF) {
+                _shouldAnimate = false;
+                qCDebug(interfaceapp) << "Optimizing" << (isMyAvatar() ? "myself" : getSessionUUID()) << "for visibility" << visibility;
+            }
         }
-    } else if (visibility < MAXIMUM_VISIBILITY_FOR_OFF) {
-        _shouldAnimate = false;
-        qCDebug(interfaceapp) << "Optimizing" << (isMyAvatar() ? "myself" : getSessionUUID()) << "for visibility" << visibility;
-    }
 
-    // simple frustum check
-    float boundingRadius = getBoundingRadius();
-    qApp->copyDisplayViewFrustum(viewFrustum);
-    bool avatarPositionInView = viewFrustum.sphereIntersectsFrustum(getPosition(), boundingRadius);
-    bool avatarMeshInView = viewFrustum.boxIntersectsFrustum(_skeletonModel->getRenderableMeshBound());
+        {
+            PerformanceTimer perfTimer("inView");
+            // simple frustum check
+            float boundingRadius = getBoundingRadius();
+            qApp->copyDisplayViewFrustum(viewFrustum);
+            avatarPositionInView = viewFrustum.sphereIntersectsFrustum(getPosition(), boundingRadius);
+            avatarMeshInView = viewFrustum.boxIntersectsFrustum(_skeletonModel->getRenderableMeshBound());
+        }
+    }
 
     if (_shouldAnimate && !_shouldSkipRender && (avatarPositionInView || avatarMeshInView)) {
         {
@@ -331,6 +342,7 @@ void Avatar::simulate(float deltaTime) {
     } else {
         // a non-full update is still required so that the position, rotation, scale and bounds of the skeletonModel are updated.
         getHead()->setPosition(getPosition());
+        PerformanceTimer perfTimer("skeleton");
         _skeletonModel->simulate(deltaTime, false);
     }
 
@@ -379,6 +391,7 @@ void Avatar::applyPositionDelta(const glm::vec3& delta) {
 }
 
 void Avatar::measureMotionDerivatives(float deltaTime) {
+    PerformanceTimer perfTimer("derivatives");
     // linear
     float invDeltaTime = 1.0f / deltaTime;
     // Floating point error prevents us from computing velocity in a naive way
@@ -645,6 +658,7 @@ bool Avatar::shouldRenderHead(const RenderArgs* renderArgs) const {
 
 // virtual
 void Avatar::simulateAttachments(float deltaTime) {
+    PerformanceTimer perfTimer("attachments");
     for (int i = 0; i < (int)_attachmentModels.size(); i++) {
         const AttachmentData& attachment = _attachmentData.at(i);
         auto& model = _attachmentModels.at(i);
@@ -1039,6 +1053,7 @@ void Avatar::setAttachmentData(const QVector<AttachmentData>& attachmentData) {
 
 
 int Avatar::parseDataFromBuffer(const QByteArray& buffer) {
+    PerformanceTimer perfTimer("unpack");
     if (!_initialized) {
         // now that we have data for this Avatar we are go for init
         init();
@@ -1258,6 +1273,7 @@ void Avatar::setOrientation(const glm::quat& orientation) {
 }
 
 void Avatar::updatePalms() {
+    PerformanceTimer perfTimer("palms");
     // update thread-safe caches
     _leftPalmRotationCache.set(getUncachedLeftPalmRotation());
     _rightPalmRotationCache.set(getUncachedRightPalmRotation());

libraries/animation/src/Rig.cpp

@@ -20,6 +20,7 @@
 #include <GeometryUtil.h>
 #include <NumericalConstants.h>
 #include <DebugDraw.h>
+#include <PerfStat.h>
 #include <ScriptValueUtils.h>
 #include <shared/NsightHelpers.h>
 
@@ -1249,6 +1250,7 @@ void Rig::copyJointsIntoJointData(QVector<JointData>& jointDataVec) const {
 }
 
 void Rig::copyJointsFromJointData(const QVector<JointData>& jointDataVec) {
+    PerformanceTimer perfTimer("copyJoints");
     if (_animSkeleton && jointDataVec.size() == (int)_internalPoseSet._overrideFlags.size()) {
 
         // transform all the default poses into rig space.

libraries/avatars/src/AvatarHashMap.cpp

@@ -13,6 +13,7 @@
 
 #include <NodeList.h>
 #include <udt/PacketHeaders.h>
+#include <PerfStat.h>
 #include <SharedUtil.h>
 
 #include "AvatarLogging.h"
@@ -98,6 +99,7 @@ AvatarSharedPointer AvatarHashMap::findAvatar(const QUuid& sessionUUID) {
 }
 
 void AvatarHashMap::processAvatarDataPacket(QSharedPointer<ReceivedMessage> message, SharedNodePointer sendingNode) {
+    PerformanceTimer perfTimer("receiveAvatar");
     // enumerate over all of the avatars in this packet
     // only add them if mixerWeakPointer points to something (meaning that mixer is still around)
     while (message->getBytesLeftToRead()) {

libraries/entities-renderer/src/RenderableModelEntityItem.cpp

@@ -1169,6 +1169,7 @@ void RenderableModelEntityItem::setJointTranslationsSet(const QVector<bool>& tra
 
 
 void RenderableModelEntityItem::locationChanged(bool tellPhysics) {
+    PerformanceTimer pertTimer("locationChanged");
     EntityItem::locationChanged(tellPhysics);
     if (_model && _model->isActive()) {
         _model->setRotation(getRotation());

libraries/render-utils/src/Model.cpp

@@ -282,6 +282,7 @@ void Model::reset() {
 
 bool Model::updateGeometry() {
     PROFILE_RANGE(renderutils, __FUNCTION__);
+    PerformanceTimer perfTimer("Model::updateGeometry");
     bool needFullUpdate = false;
 
     if (!isLoaded()) {
@@ -1090,6 +1091,7 @@ void Model::snapToRegistrationPoint() {
 
 void Model::simulate(float deltaTime, bool fullUpdate) {
     PROFILE_RANGE(renderutils, __FUNCTION__);
+    PerformanceTimer perfTimer("Model::simulate");
     fullUpdate = updateGeometry() || fullUpdate || (_scaleToFit && !_scaledToFit)
                     || (_snapModelToRegistrationPoint && !_snappedToRegistrationPoint);