tracing polish

interface/src/Application.cpp

@@ -184,6 +184,8 @@ extern "C" {
 }
 #endif
 
+Q_LOGGING_CATEGORY(trace_app_input_mouse, "trace.app.input.mouse")
+
 using namespace std;
 
 static QTimer locationUpdateTimer;
@@ -2003,16 +2005,6 @@ void Application::initializeUi() {
 }
 
 void Application::paintGL() {
-    PROFILE_COUNTER(interfaceapp, "fps", { { "fps", _frameCounter.rate() } });
-    PROFILE_COUNTER(interfaceapp, "downloads", {
-        { "current", ResourceCache::getLoadingRequests().length() },
-        { "pending", ResourceCache::getPendingRequestCount() }
-    });
-    PROFILE_COUNTER(interfaceapp, "processing", {
-        { "current", DependencyManager::get<StatTracker>()->getStat("Processing") },
-        { "pending", DependencyManager::get<StatTracker>()->getStat("PendingProcessing") }
-    });
-
     // Some plugins process message events, allowing paintGL to be called reentrantly.
     if (_inPaint || _aboutToQuit) {
         return;
@@ -2024,7 +2016,7 @@ void Application::paintGL() {
     _frameCount++;
 
     auto lastPaintBegin = usecTimestampNow();
-    PROFILE_RANGE_EX(interfaceapp, __FUNCTION__, 0xff0000ff, (uint64_t)_frameCount);
+    PROFILE_RANGE_EX(render, __FUNCTION__, 0xff0000ff, (uint64_t)_frameCount);
     PerformanceTimer perfTimer("paintGL");
 
     if (nullptr == _displayPlugin) {
@@ -2201,7 +2193,7 @@ void Application::paintGL() {
     auto finalFramebuffer = framebufferCache->getFramebuffer();
 
     {
-        PROFILE_RANGE(interfaceapp, "/mainRender");
+        PROFILE_RANGE(render, "/mainRender");
         PerformanceTimer perfTimer("mainRender");
         renderArgs._boomOffset = boomOffset;
         // Viewport is assigned to the size of the framebuffer
@@ -2256,7 +2248,7 @@ void Application::paintGL() {
     frame->overlay = _applicationOverlay.getOverlayTexture();
     // deliver final scene rendering commands to the display plugin
     {
-        PROFILE_RANGE(interfaceapp, "/pluginOutput");
+        PROFILE_RANGE(render, "/pluginOutput");
         PerformanceTimer perfTimer("pluginOutput");
         _frameCounter.increment();
         displayPlugin->submitFrame(frame);
@@ -2344,7 +2336,7 @@ void Application::resizeEvent(QResizeEvent* event) {
 }
 
 void Application::resizeGL() {
-    PROFILE_RANGE(interfaceapp, __FUNCTION__);
+    PROFILE_RANGE(render, __FUNCTION__);
     if (nullptr == _displayPlugin) {
         return;
     }
@@ -3012,7 +3004,7 @@ void Application::maybeToggleMenuVisible(QMouseEvent* event) const {
 }
 
 void Application::mouseMoveEvent(QMouseEvent* event) {
-    PROFILE_RANGE(interfaceapp, __FUNCTION__);
+    PROFILE_RANGE(app_input_mouse, __FUNCTION__);
 
     if (_aboutToQuit) {
         return;
@@ -3322,6 +3314,18 @@ void Application::idle(float nsecsElapsed) {
         connect(offscreenUi.data(), &OffscreenUi::showDesktop, this, &Application::showDesktop);
     }
 
+    PROFILE_COUNTER(app, "fps", { { "fps", _frameCounter.rate() } });
+    PROFILE_COUNTER(app, "downloads", {
+        { "current", ResourceCache::getLoadingRequests().length() },
+        { "pending", ResourceCache::getPendingRequestCount() }
+    });
+    PROFILE_COUNTER(app, "processing", {
+        { "current", DependencyManager::get<StatTracker>()->getStat("Processing") },
+        { "pending", DependencyManager::get<StatTracker>()->getStat("PendingProcessing") }
+    });
+
+    PROFILE_RANGE(app, __FUNCTION__);
+
     if (auto steamClient = PluginManager::getInstance()->getSteamClientPlugin()) {
         steamClient->runCallbacks();
     }
@@ -4087,7 +4091,7 @@ static bool domainLoadingInProgress = false;
 
 void Application::update(float deltaTime) {
 
-    PROFILE_RANGE_EX(interfaceapp, __FUNCTION__, 0xffff0000, (uint64_t)_frameCount + 1);
+    PROFILE_RANGE_EX(app, __FUNCTION__, 0xffff0000, (uint64_t)_frameCount + 1);
 
     bool showWarnings = Menu::getInstance()->isOptionChecked(MenuOption::PipelineWarnings);
     PerformanceWarning warn(showWarnings, "Application::update()");
@@ -4096,7 +4100,7 @@ void Application::update(float deltaTime) {
 
     if (!_physicsEnabled) {
         if (!domainLoadingInProgress) {
-            PROFILE_ASYNC_BEGIN(interfaceapp, "Scene Loading", "");
+            PROFILE_ASYNC_BEGIN(app, "Scene Loading", "");
             domainLoadingInProgress = true;
         }
 
@@ -4131,7 +4135,7 @@ void Application::update(float deltaTime) {
         }
     } else if (domainLoadingInProgress) {
         domainLoadingInProgress = false;
-        PROFILE_ASYNC_END(interfaceapp, "Scene Loading", "");
+        PROFILE_ASYNC_END(app, "Scene Loading", "");
     }
 
     {
@@ -4225,12 +4229,12 @@ void Application::update(float deltaTime) {
     QSharedPointer<AvatarManager> avatarManager = DependencyManager::get<AvatarManager>();
 
     if (_physicsEnabled) {
-        PROFILE_RANGE_EX(interfaceapp, "Physics", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount());
+        PROFILE_RANGE_EX(simulation_physics, "Physics", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount());
 
         PerformanceTimer perfTimer("physics");
 
         {
-            PROFILE_RANGE_EX(interfaceapp, "UpdateStats", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount());
+            PROFILE_RANGE_EX(simulation_physics, "UpdateStats", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount());
 
             PerformanceTimer perfTimer("updateStates)");
             static VectorOfMotionStates motionStates;
@@ -4264,14 +4268,14 @@ void Application::update(float deltaTime) {
             });
         }
         {
-            PROFILE_RANGE_EX(interfaceapp, "StepSimulation", 0xffff8000, (uint64_t)getActiveDisplayPlugin()->presentCount());
+            PROFILE_RANGE_EX(simulation_physics, "StepSimulation", 0xffff8000, (uint64_t)getActiveDisplayPlugin()->presentCount());
             PerformanceTimer perfTimer("stepSimulation");
             getEntities()->getTree()->withWriteLock([&] {
                 _physicsEngine->stepSimulation();
             });
         }
         {
-            PROFILE_RANGE_EX(interfaceapp, "HarvestChanges", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount());
+            PROFILE_RANGE_EX(simulation_physics, "HarvestChanges", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount());
             PerformanceTimer perfTimer("harvestChanges");
             if (_physicsEngine->hasOutgoingChanges()) {
                 getEntities()->getTree()->withWriteLock([&] {
@@ -4313,20 +4317,20 @@ void Application::update(float deltaTime) {
         _avatarSimCounter.increment();
 
         {
-            PROFILE_RANGE_EX(interfaceapp, "OtherAvatars", 0xffff00ff, (uint64_t)getActiveDisplayPlugin()->presentCount());
+            PROFILE_RANGE_EX(simulation, "OtherAvatars", 0xffff00ff, (uint64_t)getActiveDisplayPlugin()->presentCount());
             avatarManager->updateOtherAvatars(deltaTime);
         }
 
         qApp->updateMyAvatarLookAtPosition();
 
         {
-            PROFILE_RANGE_EX(interfaceapp, "MyAvatar", 0xffff00ff, (uint64_t)getActiveDisplayPlugin()->presentCount());
+            PROFILE_RANGE_EX(simulation, "MyAvatar", 0xffff00ff, (uint64_t)getActiveDisplayPlugin()->presentCount());
             avatarManager->updateMyAvatar(deltaTime);
         }
     }
 
     {
-        PROFILE_RANGE_EX(interfaceapp, "Overlays", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount());
+        PROFILE_RANGE_EX(app, "Overlays", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount());
         PerformanceTimer perfTimer("overlays");
         _overlays.update(deltaTime);
     }
@@ -4346,7 +4350,7 @@ void Application::update(float deltaTime) {
 
     // Update my voxel servers with my current voxel query...
     {
-        PROFILE_RANGE_EX(interfaceapp, "QueryOctree", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount());
+        PROFILE_RANGE_EX(app, "QueryOctree", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount());
         QMutexLocker viewLocker(&_viewMutex);
         PerformanceTimer perfTimer("queryOctree");
         quint64 sinceLastQuery = now - _lastQueriedTime;
@@ -4386,7 +4390,7 @@ void Application::update(float deltaTime) {
     avatarManager->postUpdate(deltaTime);
 
     {
-        PROFILE_RANGE_EX(interfaceapp, "PreRenderLambdas", 0xffff0000, (uint64_t)0);
+        PROFILE_RANGE_EX(app, "PreRenderLambdas", 0xffff0000, (uint64_t)0);
 
         std::unique_lock<std::mutex> guard(_postUpdateLambdasLock);
         for (auto& iter : _postUpdateLambdas) {
@@ -4663,8 +4667,11 @@ QRect Application::getDesirableApplicationGeometry() const {
 //                 or the "myCamera".
 //
 void Application::loadViewFrustum(Camera& camera, ViewFrustum& viewFrustum) {
+<<<<<<< HEAD
     PROFILE_RANGE(interfaceapp, __FUNCTION__);
     PerformanceTimer perfTimer("loadViewFrustum");
+=======
+>>>>>>> tracing polish
     // We will use these below, from either the camera or head vectors calculated above
     viewFrustum.setProjection(camera.getProjection());
 
@@ -4840,7 +4847,7 @@ void Application::displaySide(RenderArgs* renderArgs, Camera& theCamera, bool se
     myAvatar->preDisplaySide(renderArgs);
 
     activeRenderingThread = QThread::currentThread();
-    PROFILE_RANGE(interfaceapp, __FUNCTION__);
+    PROFILE_RANGE(render, __FUNCTION__);
     PerformanceTimer perfTimer("display");
     PerformanceWarning warn(Menu::getInstance()->isOptionChecked(MenuOption::PipelineWarnings), "Application::displaySide()");
 

interface/src/ui/ApplicationOverlay.cpp

@@ -57,7 +57,7 @@ ApplicationOverlay::~ApplicationOverlay() {
 
 // Renders the overlays either to a texture or to the screen
 void ApplicationOverlay::renderOverlay(RenderArgs* renderArgs) {
-    PROFILE_RANGE(interfaceapp, __FUNCTION__);
+    PROFILE_RANGE(render, __FUNCTION__);
     PerformanceWarning warn(Menu::getInstance()->isOptionChecked(MenuOption::PipelineWarnings), "ApplicationOverlay::displayOverlay()");
 
     buildFramebufferObject();
@@ -96,7 +96,7 @@ void ApplicationOverlay::renderOverlay(RenderArgs* renderArgs) {
 }
 
 void ApplicationOverlay::renderQmlUi(RenderArgs* renderArgs) {
-    PROFILE_RANGE(interfaceapp, __FUNCTION__);
+    PROFILE_RANGE(app, __FUNCTION__);
 
     if (!_uiTexture) {
         _uiTexture = gpu::TexturePointer(gpu::Texture::createExternal2D(OffscreenQmlSurface::getDiscardLambda()));
@@ -124,7 +124,7 @@ void ApplicationOverlay::renderQmlUi(RenderArgs* renderArgs) {
 }
 
 void ApplicationOverlay::renderAudioScope(RenderArgs* renderArgs) {
-    PROFILE_RANGE(interfaceapp, __FUNCTION__);
+    PROFILE_RANGE(app, __FUNCTION__);
 
     gpu::Batch& batch = *renderArgs->_batch;
     auto geometryCache = DependencyManager::get<GeometryCache>();
@@ -143,7 +143,7 @@ void ApplicationOverlay::renderAudioScope(RenderArgs* renderArgs) {
 }
 
 void ApplicationOverlay::renderOverlays(RenderArgs* renderArgs) {
-    PROFILE_RANGE(interfaceapp, __FUNCTION__);
+    PROFILE_RANGE(app, __FUNCTION__);
 
     gpu::Batch& batch = *renderArgs->_batch;
     auto geometryCache = DependencyManager::get<GeometryCache>();
@@ -262,7 +262,7 @@ static const auto DEFAULT_SAMPLER = gpu::Sampler(gpu::Sampler::FILTER_MIN_MAG_LI
 static const auto DEPTH_FORMAT = gpu::Element(gpu::SCALAR, gpu::FLOAT, gpu::DEPTH);
 
 void ApplicationOverlay::buildFramebufferObject() {
-    PROFILE_RANGE(interfaceapp, __FUNCTION__);
+    PROFILE_RANGE(app, __FUNCTION__);
 
     auto uiSize = qApp->getUiSize();
     if (!_overlayFramebuffer || uiSize != _overlayFramebuffer->getSize()) {

interface/src/ui/overlays/Overlays.cpp

@@ -37,6 +37,7 @@
 #include "Web3DOverlay.h"
 #include <QtQuick/QQuickWindow>
 
+Q_LOGGING_CATEGORY(trace_render_overlays, "trace.render.overlays")
 
 Overlays::Overlays() :
     _nextOverlayID(1) {}
@@ -102,7 +103,7 @@ void Overlays::cleanupOverlaysToDelete() {
 }
 
 void Overlays::renderHUD(RenderArgs* renderArgs) {
-    PROFILE_RANGE(interfaceapp, __FUNCTION__);
+    PROFILE_RANGE(render_overlays, __FUNCTION__);
     QReadLocker lock(&_lock);
     gpu::Batch& batch = *renderArgs->_batch;
 

libraries/animation/src/AnimInverseKinematics.cpp

@@ -394,7 +394,7 @@ const AnimPoseVec& AnimInverseKinematics::overlay(const AnimVariantMap& animVars
         loadPoses(underPoses);
     } else {
 
-        PROFILE_RANGE_EX(animation, "ik/relax", 0xffff00ff, 0);
+        PROFILE_RANGE_EX(simulation_animation, "ik/relax", 0xffff00ff, 0);
 
         // relax toward underPoses
         // HACK: this relaxation needs to be constant per-frame rather than per-realtime
@@ -433,7 +433,7 @@ const AnimPoseVec& AnimInverseKinematics::overlay(const AnimVariantMap& animVars
         // build a list of targets from _targetVarVec
         std::vector<IKTarget> targets;
         {
-            PROFILE_RANGE_EX(animation, "ik/computeTargets", 0xffff00ff, 0);
+            PROFILE_RANGE_EX(simulation_animation, "ik/computeTargets", 0xffff00ff, 0);
             computeTargets(animVars, targets, underPoses);
         }
 
@@ -450,7 +450,7 @@ const AnimPoseVec& AnimInverseKinematics::overlay(const AnimVariantMap& animVars
         } else {
 
             {
-                PROFILE_RANGE_EX(animation, "ik/shiftHips", 0xffff00ff, 0);
+                PROFILE_RANGE_EX(simulation_animation, "ik/shiftHips", 0xffff00ff, 0);
 
                 // shift hips according to the _hipsOffset from the previous frame
                 float offsetLength = glm::length(_hipsOffset);
@@ -476,12 +476,12 @@ const AnimPoseVec& AnimInverseKinematics::overlay(const AnimVariantMap& animVars
             }
 
             {
-                PROFILE_RANGE_EX(animation, "ik/ccd", 0xffff00ff, 0);
+                PROFILE_RANGE_EX(simulation_animation, "ik/ccd", 0xffff00ff, 0);
                 solveWithCyclicCoordinateDescent(targets);
             }
 
             {
-                PROFILE_RANGE_EX(animation, "ik/measureHipsOffset", 0xffff00ff, 0);
+                PROFILE_RANGE_EX(simulation_animation, "ik/measureHipsOffset", 0xffff00ff, 0);
 
                 // measure new _hipsOffset for next frame
                 // by looking for discrepancies between where a targeted endEffector is

libraries/animation/src/AnimationCache.cpp

@@ -55,7 +55,7 @@ void AnimationReader::run() {
     DependencyManager::get<StatTracker>()->decrementStat("PendingProcessing");
     CounterStat counter("Processing");
 
-    PROFILE_RANGE_EX(animation, __FUNCTION__, 0xFF00FF00, 0, { { "url", _url.toString() } });
+    PROFILE_RANGE_EX(resource_parse, __FUNCTION__, 0xFF00FF00, 0, { { "url", _url.toString() } });
     auto originalPriority = QThread::currentThread()->priority();
     if (originalPriority == QThread::InheritPriority) {
         originalPriority = QThread::NormalPriority;

libraries/animation/src/Rig.cpp

@@ -883,7 +883,7 @@ void Rig::updateAnimationStateHandlers() { // called on avatar update thread (wh
 
 void Rig::updateAnimations(float deltaTime, glm::mat4 rootTransform) {
 
-    PROFILE_RANGE_EX(animation, __FUNCTION__, 0xffff00ff, 0);
+    PROFILE_RANGE_EX(simulation_animation, __FUNCTION__, 0xffff00ff, 0);
 
     setModelOffset(rootTransform);
 

libraries/display-plugins/src/display-plugins/OpenGLDisplayPlugin.cpp

@@ -129,7 +129,7 @@ public:
         _context->makeCurrent();
         while (!_shutdown) {
             if (_pendingMainThreadOperation) {
-                PROFILE_RANGE(displayPlugins, "MainThreadOp")
+                PROFILE_RANGE(render, "MainThreadOp")
                 {
                     Lock lock(_mutex);
                     _context->doneCurrent();
@@ -203,7 +203,7 @@ public:
             // Execute the frame and present it to the display device.
             _context->makeCurrent();
             {
-                PROFILE_RANGE(displayPlugins, "PluginPresent")
+                PROFILE_RANGE(render, "PluginPresent")
                 currentPlugin->present();
                 CHECK_GL_ERROR();
             }
@@ -560,22 +560,22 @@ void OpenGLDisplayPlugin::compositeLayers() {
     updateCompositeFramebuffer();
 
     {
-        PROFILE_RANGE_EX(displayPlugins, "compositeScene", 0xff0077ff, (uint64_t)presentCount())
+        PROFILE_RANGE_EX(render, "compositeScene", 0xff0077ff, (uint64_t)presentCount())
         compositeScene();
     }
 
     {
-        PROFILE_RANGE_EX(displayPlugins, "compositeOverlay", 0xff0077ff, (uint64_t)presentCount())
+        PROFILE_RANGE_EX(render, "compositeOverlay", 0xff0077ff, (uint64_t)presentCount())
         compositeOverlay();
     }
     auto compositorHelper = DependencyManager::get<CompositorHelper>();
     if (compositorHelper->getReticleVisible()) {
-        PROFILE_RANGE_EX(displayPlugins, "compositePointer", 0xff0077ff, (uint64_t)presentCount())
+        PROFILE_RANGE_EX(render, "compositePointer", 0xff0077ff, (uint64_t)presentCount())
         compositePointer();
     }
 
     {
-        PROFILE_RANGE_EX(displayPlugins, "compositeExtra", 0xff0077ff, (uint64_t)presentCount())
+        PROFILE_RANGE_EX(render, "compositeExtra", 0xff0077ff, (uint64_t)presentCount())
         compositeExtra();
     }
 }
@@ -595,12 +595,12 @@ void OpenGLDisplayPlugin::internalPresent() {
 }
 
 void OpenGLDisplayPlugin::present() {
-    PROFILE_RANGE_EX(displayPlugins, __FUNCTION__, 0xffffff00, (uint64_t)presentCount())
+    PROFILE_RANGE_EX(render, __FUNCTION__, 0xffffff00, (uint64_t)presentCount())
     updateFrameData();
     incrementPresentCount();
 
     {
-        PROFILE_RANGE_EX(displayPlugins, "recycle", 0xff00ff00, (uint64_t)presentCount())
+        PROFILE_RANGE_EX(render, "recycle", 0xff00ff00, (uint64_t)presentCount())
         _gpuContext->recycle();
     }
 
@@ -614,19 +614,19 @@ void OpenGLDisplayPlugin::present() {
                 _lastFrame = _currentFrame.get();
             });
             // Execute the frame rendering commands
-            PROFILE_RANGE_EX(displayPlugins, "execute", 0xff00ff00, (uint64_t)presentCount())
+            PROFILE_RANGE_EX(render, "execute", 0xff00ff00, (uint64_t)presentCount())
             _gpuContext->executeFrame(_currentFrame);
         }
 
         // Write all layers to a local framebuffer
         {
-            PROFILE_RANGE_EX(displayPlugins, "composite", 0xff00ffff, (uint64_t)presentCount())
+            PROFILE_RANGE_EX(render, "composite", 0xff00ffff, (uint64_t)presentCount())
             compositeLayers();
         }
 
         // Take the composite framebuffer and send it to the output device
         {
-            PROFILE_RANGE_EX(displayPlugins, "internalPresent", 0xff00ffff, (uint64_t)presentCount())
+            PROFILE_RANGE_EX(render, "internalPresent", 0xff00ffff, (uint64_t)presentCount())
             internalPresent();
         }
 

libraries/display-plugins/src/display-plugins/hmd/HmdDisplayPlugin.cpp

@@ -206,7 +206,7 @@ float HmdDisplayPlugin::getLeftCenterPixel() const {
 }
 
 void HmdDisplayPlugin::internalPresent() {
-    PROFILE_RANGE_EX(displayPlugins, __FUNCTION__, 0xff00ff00, (uint64_t)presentCount())
+    PROFILE_RANGE_EX(render, __FUNCTION__, 0xff00ff00, (uint64_t)presentCount())
 
     // Composite together the scene, overlay and mouse cursor
     hmdPresent();

libraries/entities-renderer/src/RenderableModelEntityItem.cpp

@@ -211,7 +211,7 @@ namespace render {
     template <> void payloadRender(const RenderableModelEntityItemMeta::Pointer& payload, RenderArgs* args) {
         if (args) {
             if (payload && payload->entity) {
-                PROFILE_RANGE(renderlogging, "MetaModelRender");
+                PROFILE_RANGE(render, "MetaModelRender");
                 payload->entity->render(args);
             }
         }

libraries/fbx/src/FBXReader_Node.cpp

@@ -321,7 +321,7 @@ FBXNode parseTextFBXNode(Tokenizer& tokenizer) {
 }
 
 FBXNode FBXReader::parseFBX(QIODevice* device) {
-    PROFILE_RANGE_EX(modelformat, __FUNCTION__, 0xff0000ff, device);
+    PROFILE_RANGE_EX(resource_parse, __FUNCTION__, 0xff0000ff, device);
     // verify the prolog
     const QByteArray BINARY_PROLOG = "Kaydara FBX Binary  ";
     if (device->peek(BINARY_PROLOG.size()) != BINARY_PROLOG) {

libraries/fbx/src/OBJReader.cpp

@@ -420,7 +420,7 @@ done:
 
 
 FBXGeometry* OBJReader::readOBJ(QByteArray& model, const QVariantHash& mapping, const QUrl& url) {
-    PROFILE_RANGE_EX(modelformat, __FUNCTION__, 0xffff0000, nullptr);
+    PROFILE_RANGE_EX(resource_parse, __FUNCTION__, 0xffff0000, nullptr);
     QBuffer buffer { &model };
     buffer.open(QIODevice::ReadOnly);
 

libraries/gl/src/gl/OffscreenQmlSurface.cpp

@@ -38,6 +38,9 @@
 #include "GLLogging.h"
 #include "Context.h"
 
+Q_LOGGING_CATEGORY(trace_render_qml, "trace.render.qml")
+Q_LOGGING_CATEGORY(trace_render_qml_gl, "trace.render.qml.gl")
+
 struct TextureSet {
     // The number of surfaces with this size
     size_t count { 0 };
@@ -276,6 +279,7 @@ void OffscreenQmlSurface::render() {
         return;
     }
 
+    PROFILE_RANGE(render_qml_gl, __FUNCTION__)
     _canvas->makeCurrent();
 
     _renderControl->sync();
@@ -284,7 +288,6 @@ void OffscreenQmlSurface::render() {
     GLuint texture = offscreenTextures.getNextTexture(_size);
     glBindFramebuffer(GL_DRAW_FRAMEBUFFER, _fbo);
     glFramebufferTexture(GL_DRAW_FRAMEBUFFER, GL_COLOR_ATTACHMENT0, texture, 0);
-    PROFILE_RANGE(glLogging, "qml_render->rendercontrol")
     _renderControl->render();
     glBindFramebuffer(GL_DRAW_FRAMEBUFFER, 0);
     glBindTexture(GL_TEXTURE_2D, texture);
@@ -617,12 +620,12 @@ void OffscreenQmlSurface::updateQuick() {
     }
 
     if (_polish) {
+        PROFILE_RANGE(render_qml, "OffscreenQML polish")
         _renderControl->polishItems();
         _polish = false;
     }
 
     if (_render) {
-        PROFILE_RANGE(glLogging, __FUNCTION__);
         render();
         _render = false;
     }

libraries/gpu-gl/src/gpu/gl/GLBackend.cpp

@@ -200,7 +200,7 @@ void GLBackend::renderPassTransfer(const Batch& batch) {
 
     _inRenderTransferPass = true;
     { // Sync all the buffers
-        PROFILE_RANGE(gpugllogging, "syncGPUBuffer");
+        PROFILE_RANGE(render_gpu_gl, "syncGPUBuffer");
 
         for (auto& cached : batch._buffers._items) {
             if (cached._data) {
@@ -210,7 +210,7 @@ void GLBackend::renderPassTransfer(const Batch& batch) {
     }
 
     { // Sync all the buffers
-        PROFILE_RANGE(gpugllogging, "syncCPUTransform");
+        PROFILE_RANGE(render_gpu_gl, "syncCPUTransform");
         _transform._cameras.clear();
         _transform._cameraOffsets.clear();
 
@@ -242,7 +242,7 @@ void GLBackend::renderPassTransfer(const Batch& batch) {
     }
 
     { // Sync the transform buffers
-        PROFILE_RANGE(gpugllogging, "syncGPUTransform");
+        PROFILE_RANGE(render_gpu_gl, "syncGPUTransform");
         transferTransformState(batch);
     }
 
@@ -304,7 +304,7 @@ void GLBackend::render(const Batch& batch) {
     }
     
     {
-        PROFILE_RANGE(gpugllogging, "Transfer");
+        PROFILE_RANGE(render_gpu_gl, "Transfer");
         renderPassTransfer(batch);
     }
 
@@ -314,7 +314,7 @@ void GLBackend::render(const Batch& batch) {
     }
 #endif
     {
-        PROFILE_RANGE(gpugllogging, _stereo._enable ? "Render Stereo" : "Render");
+        PROFILE_RANGE(render_gpu_gl, _stereo._enable ? "Render Stereo" : "Render");
         renderPassDraw(batch);
     }
 #ifdef GPU_STEREO_DRAWCALL_INSTANCED

libraries/gpu-gl/src/gpu/gl/GLBackendQuery.cpp

@@ -28,7 +28,7 @@ void GLBackend::do_beginQuery(const Batch& batch, size_t paramOffset) {
     auto query = batch._queries.get(batch._params[paramOffset]._uint);
     GLQuery* glquery = syncGPUObject(*query);
     if (glquery) {
-        PROFILE_RANGE_BEGIN(gpugllogging, glquery->_profileRangeId, query->getName().c_str(), 0xFFFF7F00);
+        PROFILE_RANGE_BEGIN(render_gpu_gl, glquery->_profileRangeId, query->getName().c_str(), 0xFFFF7F00);
 
         ++_queryStage._rangeQueryDepth;
         glGetInteger64v(GL_TIMESTAMP, (GLint64*)&glquery->_batchElapsedTime);
@@ -62,7 +62,7 @@ void GLBackend::do_endQuery(const Batch& batch, size_t paramOffset) {
         glGetInteger64v(GL_TIMESTAMP, &now);
         glquery->_batchElapsedTime = now - glquery->_batchElapsedTime;
 
-        PROFILE_RANGE_END(gpugllogging, glquery->_profileRangeId);
+        PROFILE_RANGE_END(render_gpu_gl, glquery->_profileRangeId);
 
         (void)CHECK_GL_ERROR();
     }

libraries/gpu-gl/src/gpu/gl/GLShared.cpp

@@ -16,6 +16,7 @@
 #include <fstream>
 
 Q_LOGGING_CATEGORY(gpugllogging, "hifi.gpu.gl")
+Q_LOGGING_CATEGORY(trace_render_gpu_gl, "trace.render.gpu.gl")
 
 namespace gpu { namespace gl {
 

libraries/gpu-gl/src/gpu/gl/GLShared.h

@@ -15,6 +15,7 @@
 #include <QLoggingCategory>
 
 Q_DECLARE_LOGGING_CATEGORY(gpugllogging)
+Q_DECLARE_LOGGING_CATEGORY(trace_render_gpu_gl)
 
 namespace gpu { namespace gl { 
 

libraries/gpu-gl/src/gpu/gl41/GL41BackendTexture.cpp

@@ -122,7 +122,7 @@ void GL41Texture::transferMip(uint16_t mipLevel, uint8_t face) const {
 }
 
 void GL41Texture::startTransfer() {
-    PROFILE_RANGE(gpugllogging, __FUNCTION__);
+    PROFILE_RANGE(render_gpu_gl, __FUNCTION__);
     Parent::startTransfer();
 
     glBindTexture(_target, _id);

libraries/gpu/src/gpu/Texture.cpp

@@ -759,7 +759,7 @@ bool sphericalHarmonicsFromTexture(const gpu::Texture& cubeTexture, std::vector<
         return false;
     }
 
-    PROFILE_RANGE(gpulogging, "sphericalHarmonicsFromTexture");
+    PROFILE_RANGE(render_gpu, "sphericalHarmonicsFromTexture");
 
     const uint sqOrder = order*order;
 
@@ -792,7 +792,7 @@ bool sphericalHarmonicsFromTexture(const gpu::Texture& cubeTexture, std::vector<
 
     // for each face of cube texture
     for(int face=0; face < gpu::Texture::NUM_CUBE_FACES; face++) {
-        PROFILE_RANGE(gpulogging, "ProcessFace");
+        PROFILE_RANGE(render_gpu, "ProcessFace");
 
         auto numComponents = cubeTexture.accessStoredMipFace(0,face)->getFormat().getScalarCount();
         auto data = cubeTexture.accessStoredMipFace(0,face)->readData();

libraries/model-networking/src/model-networking/ModelCache.cpp

@@ -24,6 +24,8 @@
 #include <Trace.h>
 #include <StatTracker.h>
 
+Q_LOGGING_CATEGORY(trace_resource_parse_geometry, "trace.resource.parse.geometry")
+
 class GeometryReader;
 
 class GeometryExtra {
@@ -54,7 +56,7 @@ private:
 };
 
 void GeometryMappingResource::downloadFinished(const QByteArray& data) {
-    PROFILE_ASYNC_BEGIN(modelnetworking, "GeometryMappingResource::downloadFinished", _url.toString(),
+    PROFILE_ASYNC_BEGIN(resource_parse_geometry, "GeometryMappingResource::downloadFinished", _url.toString(),
                          { { "url", _url.toString() } });
 
     auto mapping = FSTReader::readMapping(data);
@@ -120,7 +122,7 @@ void GeometryMappingResource::onGeometryMappingLoaded(bool success) {
         disconnect(_connection); // FIXME Should not have to do this
     }
 
-    PROFILE_ASYNC_END(modelnetworking, "GeometryMappingResource::downloadFinished", _url.toString());
+    PROFILE_ASYNC_END(resource_parse_geometry, "GeometryMappingResource::downloadFinished", _url.toString());
     finishedLoading(success);
 }
 
@@ -145,7 +147,7 @@ private:
 void GeometryReader::run() {
     DependencyManager::get<StatTracker>()->decrementStat("PendingProcessing");
     CounterStat counter("Processing");
-    PROFILE_RANGE_EX(modelnetworking, "GeometryReader::run", 0xFF00FF00, 0, { { "url", _url.toString() } });
+    PROFILE_RANGE_EX(resource_parse_geometry, "GeometryReader::run", 0xFF00FF00, 0, { { "url", _url.toString() } });
     auto originalPriority = QThread::currentThread()->priority();
     if (originalPriority == QThread::InheritPriority) {
         originalPriority = QThread::NormalPriority;

libraries/model-networking/src/model-networking/TextureCache.cpp

@@ -36,6 +36,8 @@
 #include <Trace.h>
 #include <StatTracker.h>
 
+Q_LOGGING_CATEGORY(trace_resource_parse_image, "trace.resource.parse.image")
+
 TextureCache::TextureCache() {
     setUnusedResourceCacheSize(0);
     setObjectName("TextureCache");
@@ -349,7 +351,7 @@ void ImageReader::run() {
 
     CounterStat counter("Processing");
 
-    PROFILE_RANGE_EX(modelnetworking, __FUNCTION__, 0xffff0000, 0, { { "url", _url.toString() } });
+    PROFILE_RANGE_EX(resource_parse_image, __FUNCTION__, 0xffff0000, 0, { { "url", _url.toString() } });
     auto originalPriority = QThread::currentThread()->priority();
     if (originalPriority == QThread::InheritPriority) {
         originalPriority = QThread::NormalPriority;
@@ -395,7 +397,7 @@ void ImageReader::run() {
 
         auto url = _url.toString().toStdString();
 
-        PROFILE_RANGE_EX(modelnetworking, __FUNCTION__, 0xffffff00, 0);
+        PROFILE_RANGE_EX(resource_parse_image, __FUNCTION__, 0xffffff00, 0);
         texture.reset(resource.dynamicCast<NetworkTexture>()->getTextureLoader()(image, url));
     }
 

libraries/model/src/model/TextureMap.cpp

@@ -746,7 +746,7 @@ const CubeLayout CubeLayout::CUBEMAP_LAYOUTS[] = {
 const int CubeLayout::NUM_CUBEMAP_LAYOUTS = sizeof(CubeLayout::CUBEMAP_LAYOUTS) / sizeof(CubeLayout);
 
 gpu::Texture* TextureUsage::processCubeTextureColorFromImage(const QImage& srcImage, const std::string& srcImageName, bool isLinear, bool doCompress, bool generateMips, bool generateIrradiance) {
-    PROFILE_RANGE(modelLog, "processCubeTextureColorFromImage");
+    PROFILE_RANGE(resource_parse, "processCubeTextureColorFromImage");
 
     gpu::Texture* theTexture = nullptr;
     if ((srcImage.width() > 0) && (srcImage.height() > 0)) {
@@ -805,13 +805,13 @@ gpu::Texture* TextureUsage::processCubeTextureColorFromImage(const QImage& srcIm
             }
 
             if (generateMips) {
-                PROFILE_RANGE(modelLog, "generateMips");
+                PROFILE_RANGE(resource_parse, "generateMips");
                 theTexture->autoGenerateMips(-1);
             }
 
             // Generate irradiance while we are at it
             if (generateIrradiance) {
-                PROFILE_RANGE(modelLog, "generateIrradiance");
+                PROFILE_RANGE(resource_parse, "generateIrradiance");
                 theTexture->generateIrradiance();
             }
         }

libraries/networking/src/ResourceCache.cpp

@@ -650,12 +650,12 @@ void Resource::reinsert() {
 
 void Resource::makeRequest() {
     if (_request) {
-        PROFILE_ASYNC_END(resourceLog, "Resource:" + getType(), QString::number(_requestID));
+        PROFILE_ASYNC_END(resource, "Resource:" + getType(), QString::number(_requestID));
         _request->disconnect();
         _request->deleteLater();
     }
 
-    PROFILE_ASYNC_BEGIN(resourceLog, "Resource:" + getType(), QString::number(_requestID), { { "url", _url.toString() }, { "activeURL", _activeUrl.toString() } });
+    PROFILE_ASYNC_BEGIN(resource, "Resource:" + getType(), QString::number(_requestID), { { "url", _url.toString() }, { "activeURL", _activeUrl.toString() } });
 
     _request = ResourceManager::createResourceRequest(this, _activeUrl);
 
@@ -663,7 +663,7 @@ void Resource::makeRequest() {
         qCDebug(networking).noquote() << "Failed to get request for" << _url.toDisplayString();
         ResourceCache::requestCompleted(_self);
         finishedLoading(false);
-        PROFILE_ASYNC_END(resourceLog, "Resource:" + getType(), QString::number(_requestID));
+        PROFILE_ASYNC_END(resource, "Resource:" + getType(), QString::number(_requestID));
         return;
     }
     
@@ -688,7 +688,7 @@ void Resource::handleDownloadProgress(uint64_t bytesReceived, uint64_t bytesTota
 void Resource::handleReplyFinished() {
     Q_ASSERT_X(_request, "Resource::handleReplyFinished", "Request should not be null while in handleReplyFinished");
 
-    PROFILE_ASYNC_END(resourceLog, "Resource:" + getType(), QString::number(_requestID), {
+    PROFILE_ASYNC_END(resource, "Resource:" + getType(), QString::number(_requestID), {
         { "from_cache", _request->loadedFromCache() },
         { "size_mb", _bytesTotal / 1000000.0 }
     });

libraries/networking/src/udt/SendQueue.cpp

@@ -86,7 +86,7 @@ SendQueue::SendQueue(Socket* socket, HifiSockAddr dest) :
     _socket(socket),
     _destination(dest)
 {
-    PROFILE_ASYNC_BEGIN(networking, "SendQueue", _destination.toString());
+    PROFILE_ASYNC_BEGIN(network, "SendQueue", _destination.toString());
 
     // setup psuedo-random number generation for all instances of SendQueue
     static std::random_device rd;
@@ -106,7 +106,7 @@ SendQueue::SendQueue(Socket* socket, HifiSockAddr dest) :
 }
 
 SendQueue::~SendQueue() {
-    PROFILE_ASYNC_END(networking, "SendQueue", _destination.toString());
+    PROFILE_ASYNC_END(network, "SendQueue", _destination.toString());
 }
 
 void SendQueue::queuePacket(std::unique_ptr<Packet> packet) {
@@ -227,7 +227,7 @@ void SendQueue::sendHandshake() {
     if (!_hasReceivedHandshakeACK) {
         // we haven't received a handshake ACK from the client, send another now
         auto handshakePacket = ControlPacket::create(ControlPacket::Handshake, sizeof(SequenceNumber));
-        PROFILE_ASYNC_BEGIN(networking, "SendQueue:Handshake", _destination.toString());
+        PROFILE_ASYNC_BEGIN(network, "SendQueue:Handshake", _destination.toString());
 
         handshakePacket->writePrimitive(_initialSequenceNumber);
         _socket->writeBasePacket(*handshakePacket, _destination);
@@ -244,7 +244,7 @@ void SendQueue::handshakeACK(SequenceNumber initialSequenceNumber) {
             std::lock_guard<std::mutex> locker { _handshakeMutex };
             _hasReceivedHandshakeACK = true;
         }
-        PROFILE_ASYNC_END(networking, "SendQueue:Handshake", _destination.toString());
+        PROFILE_ASYNC_END(network, "SendQueue:Handshake", _destination.toString());
 
         // Notify on the handshake ACK condition
         _handshakeACKCondition.notify_one();

libraries/octree/src/OctreeElement.cpp

@@ -392,7 +392,6 @@ OctreeElementPointer OctreeElement::addChildAtIndex(int childIndex) {
 
         _isDirty = true;
         markWithChangedTime();
-        PROFILE_INSTANT(octree, "EntityAdd", "g");
     }
     return childAt;
 }

libraries/render-utils/src/DeferredLightingEffect.cpp

@@ -793,7 +793,7 @@ void RenderDeferred::configure(const Config& config) {
 }
 
 void RenderDeferred::run(const SceneContextPointer& sceneContext, const RenderContextPointer& renderContext, const Inputs& inputs) {
-    PROFILE_RANGE(renderlogging, "DeferredLighting");
+    PROFILE_RANGE(render, "DeferredLighting");
 
     auto deferredTransform = inputs.get0();
     auto deferredFramebuffer = inputs.get1();

libraries/render-utils/src/Model.cpp

@@ -281,7 +281,7 @@ void Model::reset() {
 }
 
 bool Model::updateGeometry() {
-    PROFILE_RANGE(renderutils, __FUNCTION__);
+    PROFILE_RANGE(render, __FUNCTION__);
     PerformanceTimer perfTimer("Model::updateGeometry");
     bool needFullUpdate = false;
 
@@ -476,7 +476,7 @@ bool Model::convexHullContains(glm::vec3 point) {
 // entity-scripts to call.  I think it would be best to do the picking once-per-frame (in cpu, or gpu if possible)
 // and then the calls use the most recent such result.
 void Model::recalculateMeshBoxes(bool pickAgainstTriangles) {
-    PROFILE_RANGE(renderutils, __FUNCTION__);
+    PROFILE_RANGE(render, __FUNCTION__);
     bool calculatedMeshTrianglesNeeded = pickAgainstTriangles && !_calculatedMeshTrianglesValid;
 
     if (!_calculatedMeshBoxesValid || calculatedMeshTrianglesNeeded || (!_calculatedMeshPartBoxesValid && pickAgainstTriangles) ) {
@@ -969,7 +969,7 @@ Blender::Blender(ModelPointer model, int blendNumber, const Geometry::WeakPointe
 }
 
 void Blender::run() {
-    PROFILE_RANGE_EX(renderutils, __FUNCTION__, 0xFFFF0000, 0, { { "url", _model->getURL().toString() } });
+    PROFILE_RANGE_EX(simulation_animation, __FUNCTION__, 0xFFFF0000, 0, { { "url", _model->getURL().toString() } });
     QVector<glm::vec3> vertices, normals;
     if (_model) {
         int offset = 0;
@@ -1090,7 +1090,7 @@ void Model::snapToRegistrationPoint() {
 }
 
 void Model::simulate(float deltaTime, bool fullUpdate) {
-    PROFILE_RANGE(renderutils, __FUNCTION__);
+    PROFILE_RANGE(simulation, __FUNCTION__);
     PerformanceTimer perfTimer("Model::simulate");
     fullUpdate = updateGeometry() || fullUpdate || (_scaleToFit && !_scaledToFit)
                     || (_snapModelToRegistrationPoint && !_snappedToRegistrationPoint);

libraries/render/src/render/Scene.cpp

@@ -78,13 +78,16 @@ void consolidateChangeQueue(PendingChangesQueue& queue, PendingChanges& singleBa
 }
  
 void Scene::processPendingChangesQueue() {
-    PROFILE_RANGE(renderlogging, __FUNCTION__);
+    PROFILE_RANGE(render, __FUNCTION__);
-    _changeQueueMutex.lock();
     PendingChanges consolidatedPendingChanges;
-    consolidateChangeQueue(_changeQueue, consolidatedPendingChanges);
-    _changeQueueMutex.unlock();
 
-    _itemsMutex.lock();
+    {
+        std::unique_lock<std::mutex> lock(_changeQueueMutex);
+        consolidateChangeQueue(_changeQueue, consolidatedPendingChanges);
+    }
+    
+    {
+        std::unique_lock<std::mutex> lock(_itemsMutex);
         // Here we should be able to check the value of last ItemID allocated 
         // and allocate new items accordingly
         ItemID maxID = _IDAllocator.load();
@@ -108,9 +111,7 @@ void Scene::processPendingChangesQueue() {
 
         // Update the numItemsAtomic counter AFTER the pending changes went through
         _numAllocatedItems.exchange(maxID);
-
+    }
-     // ready to go back to rendering activities
-    _itemsMutex.unlock();
 }
 
 void Scene::resetItems(const ItemIDs& ids, Payloads& payloads) {

libraries/render/src/render/Task.h

@@ -572,7 +572,7 @@ public:
 
     void run(const SceneContextPointer& sceneContext, const RenderContextPointer& renderContext) {
         PerformanceTimer perfTimer(_name.c_str());
-        PROFILE_RANGE(renderlogging, _name.c_str());
+        PROFILE_RANGE(render, _name.c_str());
         auto start = usecTimestampNow();
 
         _concept->run(sceneContext, renderContext);

libraries/shared/src/Profile.cpp

@@ -8,6 +8,21 @@
 
 #include "Profile.h"
 
+Q_LOGGING_CATEGORY(trace_app, "trace.app")
+Q_LOGGING_CATEGORY(trace_network, "trace.network")
+Q_LOGGING_CATEGORY(trace_parse, "trace.parse")
+Q_LOGGING_CATEGORY(trace_render, "trace.render")
+Q_LOGGING_CATEGORY(trace_render_gpu, "trace.render.gpu")
+Q_LOGGING_CATEGORY(trace_resource, "trace.resource")
+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_physics, "trace.simulation.physics")
+
+void foo() {
+    randFloat();
+}
 
 #if defined(NSIGHT_FOUND)
 #include "nvToolsExt.h"

libraries/shared/src/Profile.h

@@ -11,6 +11,18 @@
 #define HIFI_PROFILE_
 
 #include "Trace.h"
+#include "SharedUtil.h"
+
+Q_DECLARE_LOGGING_CATEGORY(trace_app)
+Q_DECLARE_LOGGING_CATEGORY(trace_network)
+Q_DECLARE_LOGGING_CATEGORY(trace_render)
+Q_DECLARE_LOGGING_CATEGORY(trace_render_gpu)
+Q_DECLARE_LOGGING_CATEGORY(trace_resource)
+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_physics)
 
 class Duration {
 public:
@@ -51,13 +63,18 @@ inline void counter(const QLoggingCategory& category, const QString& name, const
     }
 }
 
-#define PROFILE_RANGE(category, name) Duration profileRangeThis(category(), name);
+#define PROFILE_RANGE(category, name) Duration profileRangeThis(trace_##category(), name);
-#define PROFILE_RANGE_EX(category, name, argbColor, payload, ...) Duration profileRangeThis(category(), name, argbColor, (uint64_t)payload, ##__VA_ARGS__);
+#define PROFILE_RANGE_EX(category, name, argbColor, payload, ...) Duration profileRangeThis(trace_##category(), name, argbColor, (uint64_t)payload, ##__VA_ARGS__);
-#define PROFILE_RANGE_BEGIN(category, rangeId, name, argbColor) rangeId = Duration::beginRange(category(), name, argbColor)
+#define PROFILE_RANGE_BEGIN(category, rangeId, name, argbColor) rangeId = Duration::beginRange(trace_##category(), name, argbColor)
-#define PROFILE_RANGE_END(category, rangeId) Duration::endRange(category(), rangeId)
+#define PROFILE_RANGE_END(category, rangeId) Duration::endRange(trace_##category(), rangeId)
-#define PROFILE_ASYNC_BEGIN(category, name, id, ...) asyncBegin(category(), name, id, ##__VA_ARGS__);
+#define PROFILE_ASYNC_BEGIN(category, name, id, ...) asyncBegin(trace_##category(), name, id, ##__VA_ARGS__);
-#define PROFILE_ASYNC_END(category, name, id, ...) asyncEnd(category(), name, id, ##__VA_ARGS__);
+#define PROFILE_ASYNC_END(category, name, id, ...) asyncEnd(trace_##category(), name, id, ##__VA_ARGS__);
-#define PROFILE_COUNTER(category, name, ...) counter(category(), name, ##__VA_ARGS__);
+#define PROFILE_COUNTER(category, name, ...) counter(trace_##category(), name, ##__VA_ARGS__);
-#define PROFILE_INSTANT(category, name, ...) instant(category(), name, ##__VA_ARGS__);
+#define PROFILE_INSTANT(category, name, ...) instant(trace_##category(), name, ##__VA_ARGS__);
+
+#define SAMPLE_PROFILE_RANGE(chance, category, name, ...) if (randFloat() <= chance) { PROFILE_RANGE(category, name); }
+#define SAMPLE_PROFILE_RANGE_EX(chance, category, name, ...) if (randFloat() <= chance) { PROFILE_RANGE_EX(category, name, argbColor, payload, ##__VA_ARGS__); }
+#define SAMPLE_PROFILE_COUNTER(chance, category, name, ...) if (randFloat() <= chance) { PROFILE_COUNTER(category, name, ##__VA_ARGS__); }
+#define SAMPLE_PROFILE_INSTANT(chance, category, name, ...) if (randFloat() <= chance) { PROFILE_INSTANT(category, name, ##__VA_ARGS__); }
 
 #endif

libraries/shared/src/Trace.cpp

@@ -13,6 +13,9 @@
 #include <QtCore/QDebug>
 #include <QtCore/QCoreApplication>
 #include <QtCore/QThread>
+#include <QtCore/QFileInfo>
+#include <QtCore/QDir>
+#include <QtCore/QStandardPaths>
 
 #include <QtCore/QFile>
 #include <QtCore/QFileInfo>
@@ -100,7 +103,24 @@ void TraceEvent::writeJson(QTextStream& out) const {
 #endif
 }
 
-void Tracer::serialize(const QString& path) {
+void Tracer::serialize(const QString& originalPath) {
+
+    QString path = originalPath;
+
+    // If the filename is relative, turn it into an absolute path relative to the document directory.
+    QFileInfo originalFileInfo(path);
+    if (originalFileInfo.isRelative()) {
+        QString docsLocation = QStandardPaths::writableLocation(QStandardPaths::DocumentsLocation);
+        path = docsLocation + "/" + path;
+        QFileInfo info(path);
+        if (!info.absoluteDir().exists()) {
+            QString originalRelativePath = originalFileInfo.path();
+            QDir(docsLocation).mkpath(originalRelativePath);
+        }
+    }
+
+
+
     std::list<TraceEvent> currentEvents;
     {
         std::lock_guard<std::mutex> guard(_eventsMutex);

libraries/shared/src/Trace.h

@@ -21,8 +21,6 @@
 
 #include "DependencyManager.h"
 
-#define TRACE_ENABLED
-
 namespace tracing {
 
 bool enabled();

plugins/oculus/src/OculusDisplayPlugin.cpp

@@ -110,7 +110,7 @@ void OculusDisplayPlugin::hmdPresent() {
         return;
     }
 
-    PROFILE_RANGE_EX(displayplugins, __FUNCTION__, 0xff00ff00, (uint64_t)_currentFrame->frameIndex)
+    PROFILE_RANGE_EX(render, __FUNCTION__, 0xff00ff00, (uint64_t)_currentFrame->frameIndex)
 
     int curIndex;
     ovr_GetTextureSwapChainCurrentIndex(_session, _textureSwapChain, &curIndex);

plugins/openvr/src/OpenVrDisplayPlugin.cpp

@@ -529,7 +529,7 @@ static bool isBadPose(vr::HmdMatrix34_t* mat) {
 }
 
 bool OpenVrDisplayPlugin::beginFrameRender(uint32_t frameIndex) {
-    PROFILE_RANGE_EX(displayplugins, __FUNCTION__, 0xff7fff00, frameIndex)
+    PROFILE_RANGE_EX(render, __FUNCTION__, 0xff7fff00, frameIndex)
     handleOpenVrEvents();
     if (openVrQuitRequested()) {
         QMetaObject::invokeMethod(qApp, "quit");
@@ -633,7 +633,7 @@ void OpenVrDisplayPlugin::compositeLayers() {
 }
 
 void OpenVrDisplayPlugin::hmdPresent() {
-    PROFILE_RANGE_EX(displayplugins, __FUNCTION__, 0xff00ff00, (uint64_t)_currentFrame->frameIndex)
+    PROFILE_RANGE_EX(render, __FUNCTION__, 0xff00ff00, (uint64_t)_currentFrame->frameIndex)
 
     if (_threadedSubmit) {
         _submitThread->waitForPresent();
@@ -654,7 +654,7 @@ void OpenVrDisplayPlugin::hmdPresent() {
 }
 
 void OpenVrDisplayPlugin::postPreview() {
-    PROFILE_RANGE_EX(displayplugins, __FUNCTION__, 0xff00ff00, (uint64_t)_currentFrame->frameIndex)
+    PROFILE_RANGE_EX(render, __FUNCTION__, 0xff00ff00, (uint64_t)_currentFrame->frameIndex)
     PoseData nextRender, nextSim;
     nextRender.frameIndex = presentCount();
 

tests/render-perf/src/main.cpp

@@ -900,7 +900,7 @@ private:
         gpu::doInBatch(gpuContext, [&](gpu::Batch& batch) {
             batch.resetStages();
         });
-        PROFILE_RANGE(renderperflogging, __FUNCTION__);
+        PROFILE_RANGE(render, __FUNCTION__);
         PerformanceTimer perfTimer("draw");
         // The pending changes collecting the changes here
         render::PendingChanges pendingChanges;

tests/shared/src/TraceTests.cpp

@@ -9,33 +9,35 @@
 #include "TraceTests.h"
 
 #include <QtTest/QtTest>
-#include <Trace.h>
+#include <QtGui/QDesktopServices>
+
+#include <Profile.h>
 
-#include <SharedUtil.h>
 #include <NumericalConstants.h>
 #include <../QTestExtensions.h>
 
 QTEST_MAIN(TraceTests)
-Q_LOGGING_CATEGORY(tracertestlogging, "hifi.tracer.test")
+Q_LOGGING_CATEGORY(trace_test, "trace.test")
+
+const QString OUTPUT_FILE = "traces/testTrace.json.gz";
 
 void TraceTests::testTraceSerialization() {
     auto tracer = DependencyManager::set<tracing::Tracer>();
     tracer->startTracing();
-    tracer->traceEvent(tracertestlogging(), "TestEvent", tracing::DurationBegin);
     {
         auto start = usecTimestampNow();
+        PROFILE_RANGE(test, "TestEvent")
         for (size_t i = 0; i < 10000; ++i) {
-            tracer->traceEvent(tracertestlogging(), "TestCounter", tracing::Counter, "", { { "i", i } });
+            SAMPLE_PROFILE_COUNTER(0.1f, test, "TestCounter", { { "i", i } })
         }
         auto duration = usecTimestampNow() - start;
         duration /= USECS_PER_MSEC;
         qDebug() << "Recording took " << duration << "ms";
     }
-    tracer->traceEvent(tracertestlogging(), "TestEvent", tracing::DurationEnd);
     tracer->stopTracing();
     {
         auto start = usecTimestampNow();
-        tracer->serialize("testTrace.json.gz");
+        tracer->serialize(OUTPUT_FILE);
         auto duration = usecTimestampNow() - start;
         duration /= USECS_PER_MSEC;
         qDebug() << "Serialization took " << duration << "ms";