diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index 681d160821..ad869ddae3 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -193,8 +193,9 @@ static QTimer pingTimer; static const int MAX_CONCURRENT_RESOURCE_DOWNLOADS = 16; -// For processing on QThreadPool, target 2 less than the ideal number of threads, leaving -// 2 logical cores available for time sensitive tasks. +// For processing on QThreadPool, we target a number of threads after reserving some +// based on how many are being consumed by the application and the display plugin. However, +// we will never drop below the 'min' value static const int MIN_PROCESSING_THREAD_POOL_SIZE = 2; static const QString SNAPSHOT_EXTENSION = ".jpg"; @@ -3313,15 +3314,15 @@ 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()->getStat("Processing") }, - { "pending", DependencyManager::get()->getStat("PendingProcessing") } - }); + auto displayPlugin = getActiveDisplayPlugin(); + if (displayPlugin) { + PROFILE_COUNTER_IF_CHANGED(app, "present", float, displayPlugin->presentRate()); + } + PROFILE_COUNTER_IF_CHANGED(app, "fps", float, _frameCounter.rate()); + PROFILE_COUNTER_IF_CHANGED(app, "currentDownloads", int, ResourceCache::getLoadingRequests().length()); + PROFILE_COUNTER_IF_CHANGED(app, "pendingDownloads", int, ResourceCache::getPendingRequestCount()); + PROFILE_COUNTER_IF_CHANGED(app, "currentProcessing", int, DependencyManager::get()->getStat("Processing").toInt()); + PROFILE_COUNTER_IF_CHANGED(app, "pendingProcessing", int, DependencyManager::get()->getStat("PendingProcessing").toInt()); PROFILE_RANGE(app, __FUNCTION__); diff --git a/libraries/animation/src/Rig.cpp b/libraries/animation/src/Rig.cpp index 8d0c2567fe..fdeeb01739 100644 --- a/libraries/animation/src/Rig.cpp +++ b/libraries/animation/src/Rig.cpp @@ -902,7 +902,7 @@ void Rig::updateAnimationStateHandlers() { // called on avatar update thread (wh void Rig::updateAnimations(float deltaTime, glm::mat4 rootTransform) { - PROFILE_RANGE_EX(simulation_animation, __FUNCTION__, 0xffff00ff, 0); + PROFILE_RANGE_EX(simulation_animation_detail, __FUNCTION__, 0xffff00ff, 0); PerformanceTimer perfTimer("updateAnimations"); setModelOffset(rootTransform); diff --git a/libraries/display-plugins/src/display-plugins/OpenGLDisplayPlugin.cpp b/libraries/display-plugins/src/display-plugins/OpenGLDisplayPlugin.cpp index a6f7d3caf4..e57c2b1d52 100644 --- a/libraries/display-plugins/src/display-plugins/OpenGLDisplayPlugin.cpp +++ b/libraries/display-plugins/src/display-plugins/OpenGLDisplayPlugin.cpp @@ -561,22 +561,22 @@ void OpenGLDisplayPlugin::compositeLayers() { updateCompositeFramebuffer(); { - PROFILE_RANGE_EX(render, "compositeScene", 0xff0077ff, (uint64_t)presentCount()) + PROFILE_RANGE_EX(render_detail, "compositeScene", 0xff0077ff, (uint64_t)presentCount()) compositeScene(); } { - PROFILE_RANGE_EX(render, "compositeOverlay", 0xff0077ff, (uint64_t)presentCount()) + PROFILE_RANGE_EX(render_detail, "compositeOverlay", 0xff0077ff, (uint64_t)presentCount()) compositeOverlay(); } auto compositorHelper = DependencyManager::get(); if (compositorHelper->getReticleVisible()) { - PROFILE_RANGE_EX(render, "compositePointer", 0xff0077ff, (uint64_t)presentCount()) + PROFILE_RANGE_EX(render_detail, "compositePointer", 0xff0077ff, (uint64_t)presentCount()) compositePointer(); } { - PROFILE_RANGE_EX(render, "compositeExtra", 0xff0077ff, (uint64_t)presentCount()) + PROFILE_RANGE_EX(render_detail, "compositeExtra", 0xff0077ff, (uint64_t)presentCount()) compositeExtra(); } } diff --git a/libraries/entities-renderer/src/RenderableModelEntityItem.cpp b/libraries/entities-renderer/src/RenderableModelEntityItem.cpp index f0d39f7507..b901db38e7 100644 --- a/libraries/entities-renderer/src/RenderableModelEntityItem.cpp +++ b/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(render, "MetaModelRender"); + PROFILE_RANGE(render_detail, "MetaModelRender"); payload->entity->render(args); } } diff --git a/libraries/gpu-gl/src/gpu/gl/GLBackend.cpp b/libraries/gpu-gl/src/gpu/gl/GLBackend.cpp index 071bfef766..dbfe8fe730 100644 --- a/libraries/gpu-gl/src/gpu/gl/GLBackend.cpp +++ b/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(render_gpu_gl, "syncGPUBuffer"); + PROFILE_RANGE(render_gpu_gl_detail, "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(render_gpu_gl, "syncCPUTransform"); + PROFILE_RANGE(render_gpu_gl_detail, "syncCPUTransform"); _transform._cameras.clear(); _transform._cameraOffsets.clear(); @@ -242,7 +242,7 @@ void GLBackend::renderPassTransfer(const Batch& batch) { } { // Sync the transform buffers - PROFILE_RANGE(render_gpu_gl, "syncGPUTransform"); + PROFILE_RANGE(render_gpu_gl_detail, "syncGPUTransform"); transferTransformState(batch); } @@ -304,7 +304,7 @@ void GLBackend::render(const Batch& batch) { } { - PROFILE_RANGE(render_gpu_gl, "Transfer"); + PROFILE_RANGE(render_gpu_gl_detail, "Transfer"); renderPassTransfer(batch); } @@ -314,7 +314,7 @@ void GLBackend::render(const Batch& batch) { } #endif { - PROFILE_RANGE(render_gpu_gl, _stereo._enable ? "Render Stereo" : "Render"); + PROFILE_RANGE(render_gpu_gl_detail, _stereo._enable ? "Render Stereo" : "Render"); renderPassDraw(batch); } #ifdef GPU_STEREO_DRAWCALL_INSTANCED @@ -387,18 +387,22 @@ void GLBackend::resetStages() { void GLBackend::do_pushProfileRange(const Batch& batch, size_t paramOffset) { - auto name = batch._profileRanges.get(batch._params[paramOffset]._uint); - profileRanges.push_back(name); + if (trace_render_gpu_gl_detail().isDebugEnabled()) { + auto name = batch._profileRanges.get(batch._params[paramOffset]._uint); + profileRanges.push_back(name); #if defined(NSIGHT_FOUND) - nvtxRangePush(name.c_str()); + nvtxRangePush(name.c_str()); #endif + } } void GLBackend::do_popProfileRange(const Batch& batch, size_t paramOffset) { - profileRanges.pop_back(); + if (trace_render_gpu_gl_detail().isDebugEnabled()) { + profileRanges.pop_back(); #if defined(NSIGHT_FOUND) - nvtxRangePop(); + nvtxRangePop(); #endif + } } // TODO: As long as we have gl calls explicitely issued from interface diff --git a/libraries/gpu-gl/src/gpu/gl/GLBackendQuery.cpp b/libraries/gpu-gl/src/gpu/gl/GLBackendQuery.cpp index b4afd86abb..bdea67a99a 100644 --- a/libraries/gpu-gl/src/gpu/gl/GLBackendQuery.cpp +++ b/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(render_gpu_gl, glquery->_profileRangeId, query->getName().c_str(), 0xFFFF7F00); + PROFILE_RANGE_BEGIN(render_gpu_gl_detail, 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(render_gpu_gl, glquery->_profileRangeId); + PROFILE_RANGE_END(render_gpu_gl_detail, glquery->_profileRangeId); (void)CHECK_GL_ERROR(); } diff --git a/libraries/gpu-gl/src/gpu/gl/GLShared.cpp b/libraries/gpu-gl/src/gpu/gl/GLShared.cpp index 59ffc52e85..7acdc0ec79 100644 --- a/libraries/gpu-gl/src/gpu/gl/GLShared.cpp +++ b/libraries/gpu-gl/src/gpu/gl/GLShared.cpp @@ -17,6 +17,7 @@ Q_LOGGING_CATEGORY(gpugllogging, "hifi.gpu.gl") Q_LOGGING_CATEGORY(trace_render_gpu_gl, "trace.render.gpu.gl") +Q_LOGGING_CATEGORY(trace_render_gpu_gl_detail, "trace.render.gpu.gl.detail") namespace gpu { namespace gl { diff --git a/libraries/gpu-gl/src/gpu/gl/GLShared.h b/libraries/gpu-gl/src/gpu/gl/GLShared.h index 7c4d8106f9..b0eec23448 100644 --- a/libraries/gpu-gl/src/gpu/gl/GLShared.h +++ b/libraries/gpu-gl/src/gpu/gl/GLShared.h @@ -16,6 +16,7 @@ Q_DECLARE_LOGGING_CATEGORY(gpugllogging) Q_DECLARE_LOGGING_CATEGORY(trace_render_gpu_gl) +Q_DECLARE_LOGGING_CATEGORY(trace_render_gpu_gl_detail) namespace gpu { namespace gl { diff --git a/libraries/render-utils/src/Model.cpp b/libraries/render-utils/src/Model.cpp index ffbe1fb34c..32c42ca7c0 100644 --- a/libraries/render-utils/src/Model.cpp +++ b/libraries/render-utils/src/Model.cpp @@ -283,7 +283,7 @@ void Model::reset() { } bool Model::updateGeometry() { - PROFILE_RANGE(render, __FUNCTION__); + PROFILE_RANGE(render_detail, __FUNCTION__); PerformanceTimer perfTimer("Model::updateGeometry"); bool needFullUpdate = false; @@ -1114,7 +1114,7 @@ void Model::snapToRegistrationPoint() { } void Model::simulate(float deltaTime, bool fullUpdate) { - PROFILE_RANGE(simulation, __FUNCTION__); + PROFILE_RANGE(simulation_detail, __FUNCTION__); PerformanceTimer perfTimer("Model::simulate"); fullUpdate = updateGeometry() || fullUpdate || (_scaleToFit && !_scaledToFit) || (_snapModelToRegistrationPoint && !_snappedToRegistrationPoint); diff --git a/libraries/shared/src/Profile.cpp b/libraries/shared/src/Profile.cpp index 27ca303ccc..f23c17c6be 100644 --- a/libraries/shared/src/Profile.cpp +++ b/libraries/shared/src/Profile.cpp @@ -9,16 +9,21 @@ #include "Profile.h" Q_LOGGING_CATEGORY(trace_app, "trace.app") +Q_LOGGING_CATEGORY(trace_app_detail, "trace.app.detail") 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_detail, "trace.render.detail") 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_detail, "trace.simulation.detail") Q_LOGGING_CATEGORY(trace_simulation_animation, "trace.simulation.animation") +Q_LOGGING_CATEGORY(trace_simulation_animation_detail, "trace.simulation.animation.detail") Q_LOGGING_CATEGORY(trace_simulation_physics, "trace.simulation.physics") +Q_LOGGING_CATEGORY(trace_simulation_physics_detail, "trace.simulation.physics.detail") #if defined(NSIGHT_FOUND) #include "nvToolsExt.h" diff --git a/libraries/shared/src/Profile.h b/libraries/shared/src/Profile.h index 7472768ce1..da786526a7 100644 --- a/libraries/shared/src/Profile.h +++ b/libraries/shared/src/Profile.h @@ -13,16 +13,22 @@ #include "Trace.h" #include "SharedUtil.h" +// When profiling something that may happen many times per frame, use a xxx_detail category so that they may easily be filtered out of trace results Q_DECLARE_LOGGING_CATEGORY(trace_app) +Q_DECLARE_LOGGING_CATEGORY(trace_app_detail) Q_DECLARE_LOGGING_CATEGORY(trace_network) Q_DECLARE_LOGGING_CATEGORY(trace_render) +Q_DECLARE_LOGGING_CATEGORY(trace_render_detail) 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_detail) Q_DECLARE_LOGGING_CATEGORY(trace_simulation_animation) +Q_DECLARE_LOGGING_CATEGORY(trace_simulation_animation_detail) Q_DECLARE_LOGGING_CATEGORY(trace_simulation_physics) +Q_DECLARE_LOGGING_CATEGORY(trace_simulation_physics_detail) class Duration { public: @@ -69,6 +75,7 @@ inline void counter(const QLoggingCategory& category, const QString& name, const #define PROFILE_RANGE_END(category, rangeId) Duration::endRange(trace_##category(), rangeId) #define PROFILE_ASYNC_BEGIN(category, name, id, ...) asyncBegin(trace_##category(), name, id, ##__VA_ARGS__); #define PROFILE_ASYNC_END(category, name, id, ...) asyncEnd(trace_##category(), name, id, ##__VA_ARGS__); +#define PROFILE_COUNTER_IF_CHANGED(category, name, type, value) { static type lastValue = 0; type newValue = value; if (newValue != lastValue) { counter(trace_##category(), name, { { name, newValue }}); lastValue = newValue; } } #define PROFILE_COUNTER(category, name, ...) counter(trace_##category(), name, ##__VA_ARGS__); #define PROFILE_INSTANT(category, name, ...) instant(trace_##category(), name, ##__VA_ARGS__);