Additional work on tracing
Showing the changes to interface/src/Application.cpp (1 of 38 files). Show all
Unified · Split
| @@ -179,6 +179,8 @@ extern "C" { · 178 unmodified lines | |||
| 179 | } | 179 | } |
| 180 | #endif | 180 | #endif |
| 181 | 181 | ||
| 182 | Q_LOGGING_CATEGORY(trace_app_input_mouse, "trace.app.input.mouse") | ||
| 183 | |||
| 182 | using namespace std; | 184 | using namespace std; |
| 183 | 185 | ||
| 184 | static QTimer locationUpdateTimer; | 186 | static QTimer locationUpdateTimer; |
| @@ -1960,16 +1962,6 @@ void Application::initializeUi() { · 1775 unmodified lines | |||
| 1960 | } | 1962 | } |
| 1961 | 1963 | ||
| 1962 | void Application::paintGL() { | 1964 | void Application::paintGL() { |
| 1963 | PROFILE_COUNTER(interfaceapp, "fps", { { "fps", _frameCounter.rate() } }); | ||
| 1964 | PROFILE_COUNTER(interfaceapp, "downloads", { | ||
| 1965 | { "current", ResourceCache::getLoadingRequests().length() }, | ||
| 1966 | { "pending", ResourceCache::getPendingRequestCount() } | ||
| 1967 | }); | ||
| 1968 | PROFILE_COUNTER(interfaceapp, "processing", { | ||
| 1969 | { "current", DependencyManager::get<StatTracker>()->getStat("Processing") }, | ||
| 1970 | { "pending", DependencyManager::get<StatTracker>()->getStat("PendingProcessing") } | ||
| 1971 | }); | ||
| 1972 | |||
| 1973 | // Some plugins process message events, allowing paintGL to be called reentrantly. | 1965 | // Some plugins process message events, allowing paintGL to be called reentrantly. |
| 1974 | if (_inPaint || _aboutToQuit) { | 1966 | if (_inPaint || _aboutToQuit) { |
| 1975 | return; | 1967 | return; |
| @@ -1981,7 +1973,7 @@ void Application::paintGL() { · 5 unmodified lines | |||
| 1981 | _frameCount++; | 1973 | _frameCount++; |
| 1982 | 1974 | ||
| 1983 | auto lastPaintBegin = usecTimestampNow(); | 1975 | auto lastPaintBegin = usecTimestampNow(); |
| 1984 | PROFILE_RANGE_EX(interfaceapp, __FUNCTION__, 0xff0000ff, (uint64_t)_frameCount); | 1976 | PROFILE_RANGE_EX(render, __FUNCTION__, 0xff0000ff, (uint64_t)_frameCount); |
| 1985 | PerformanceTimer perfTimer("paintGL"); | 1977 | PerformanceTimer perfTimer("paintGL"); |
| 1986 | 1978 | ||
| 1987 | if (nullptr == _displayPlugin) { | 1979 | if (nullptr == _displayPlugin) { |
| @@ -2158,7 +2150,7 @@ void Application::paintGL() { · 170 unmodified lines | |||
| 2158 | auto finalFramebuffer = framebufferCache->getFramebuffer(); | 2150 | auto finalFramebuffer = framebufferCache->getFramebuffer(); |
| 2159 | 2151 | ||
| 2160 | { | 2152 | { |
| 2161 | PROFILE_RANGE(interfaceapp, "/mainRender"); | 2153 | PROFILE_RANGE(render, "/mainRender"); |
| 2162 | PerformanceTimer perfTimer("mainRender"); | 2154 | PerformanceTimer perfTimer("mainRender"); |
| 2163 | renderArgs._boomOffset = boomOffset; | 2155 | renderArgs._boomOffset = boomOffset; |
| 2164 | // Viewport is assigned to the size of the framebuffer | 2156 | // Viewport is assigned to the size of the framebuffer |
| @@ -2213,7 +2205,7 @@ void Application::paintGL() { · 48 unmodified lines | |||
| 2213 | frame->overlay = _applicationOverlay.getOverlayTexture(); | 2205 | frame->overlay = _applicationOverlay.getOverlayTexture(); |
| 2214 | // deliver final scene rendering commands to the display plugin | 2206 | // deliver final scene rendering commands to the display plugin |
| 2215 | { | 2207 | { |
| 2216 | PROFILE_RANGE(interfaceapp, "/pluginOutput"); | 2208 | PROFILE_RANGE(render, "/pluginOutput"); |
| 2217 | PerformanceTimer perfTimer("pluginOutput"); | 2209 | PerformanceTimer perfTimer("pluginOutput"); |
| 2218 | _frameCounter.increment(); | 2210 | _frameCounter.increment(); |
| 2219 | displayPlugin->submitFrame(frame); | 2211 | displayPlugin->submitFrame(frame); |
| @@ -2301,7 +2293,7 @@ void Application::resizeEvent(QResizeEvent* event) { · 81 unmodified lines | |||
| 2301 | } | 2293 | } |
| 2302 | 2294 | ||
| 2303 | void Application::resizeGL() { | 2295 | void Application::resizeGL() { |
| 2304 | PROFILE_RANGE(interfaceapp, __FUNCTION__); | 2296 | PROFILE_RANGE(render, __FUNCTION__); |
| 2305 | if (nullptr == _displayPlugin) { | 2297 | if (nullptr == _displayPlugin) { |
| 2306 | return; | 2298 | return; |
| 2307 | } | 2299 | } |
| @@ -2946,7 +2938,7 @@ void Application::maybeToggleMenuVisible(QMouseEvent* event) const { · 638 unmodified lines | |||
| 2946 | } | 2938 | } |
| 2947 | 2939 | ||
| 2948 | void Application::mouseMoveEvent(QMouseEvent* event) { | 2940 | void Application::mouseMoveEvent(QMouseEvent* event) { |
| 2949 | PROFILE_RANGE(interfaceapp, __FUNCTION__); | 2941 | PROFILE_RANGE(app_input_mouse, __FUNCTION__); |
| 2950 | 2942 | ||
| 2951 | if (_aboutToQuit) { | 2943 | if (_aboutToQuit) { |
| 2952 | return; | 2944 | return; |
| @@ -3240,7 +3232,6 @@ bool Application::shouldPaint(float nsecsElapsed) { · 287 unmodified lines | |||
| 3240 | } | 3232 | } |
| 3241 | 3233 | ||
| 3242 | void Application::idle(float nsecsElapsed) { | 3234 | void Application::idle(float nsecsElapsed) { |
| 3243 | PROFILE_RANGE(interfaceapp, __FUNCTION__); | ||
| 3244 | PerformanceTimer perfTimer("idle"); | 3235 | PerformanceTimer perfTimer("idle"); |
| 3245 | 3236 | ||
| 3246 | // Update the deadlock watchdog | 3237 | // Update the deadlock watchdog |
| @@ -3256,6 +3247,18 @@ void Application::idle(float nsecsElapsed) { · 9 unmodified lines | |||
| 3256 | connect(offscreenUi.data(), &OffscreenUi::showDesktop, this, &Application::showDesktop); | 3247 | connect(offscreenUi.data(), &OffscreenUi::showDesktop, this, &Application::showDesktop); |
| 3257 | } | 3248 | } |
| 3258 | 3249 | ||
| 3250 | PROFILE_COUNTER(app, "fps", { { "fps", _frameCounter.rate() } }); | ||
| 3251 | PROFILE_COUNTER(app, "downloads", { | ||
| 3252 | { "current", ResourceCache::getLoadingRequests().length() }, | ||
| 3253 | { "pending", ResourceCache::getPendingRequestCount() } | ||
| 3254 | }); | ||
| 3255 | PROFILE_COUNTER(app, "processing", { | ||
| 3256 | { "current", DependencyManager::get<StatTracker>()->getStat("Processing") }, | ||
| 3257 | { "pending", DependencyManager::get<StatTracker>()->getStat("PendingProcessing") } | ||
| 3258 | }); | ||
| 3259 | |||
| 3260 | PROFILE_RANGE(app, __FUNCTION__); | ||
| 3261 | |||
| 3259 | if (auto steamClient = PluginManager::getInstance()->getSteamClientPlugin()) { | 3262 | if (auto steamClient = PluginManager::getInstance()->getSteamClientPlugin()) { |
| 3260 | steamClient->runCallbacks(); | 3263 | steamClient->runCallbacks(); |
| 3261 | } | 3264 | } |
| @@ -3973,7 +3976,7 @@ static bool domainLoadingInProgress = false; · 711 unmodified lines | |||
| 3973 | 3976 | ||
| 3974 | void Application::update(float deltaTime) { | 3977 | void Application::update(float deltaTime) { |
| 3975 | 3978 | ||
| 3976 | PROFILE_RANGE_EX(interfaceapp, __FUNCTION__, 0xffff0000, (uint64_t)_frameCount + 1); | 3979 | PROFILE_RANGE_EX(app, __FUNCTION__, 0xffff0000, (uint64_t)_frameCount + 1); |
| 3977 | 3980 | ||
| 3978 | bool showWarnings = Menu::getInstance()->isOptionChecked(MenuOption::PipelineWarnings); | 3981 | bool showWarnings = Menu::getInstance()->isOptionChecked(MenuOption::PipelineWarnings); |
| 3979 | PerformanceWarning warn(showWarnings, "Application::update()"); | 3982 | PerformanceWarning warn(showWarnings, "Application::update()"); |
| @@ -3982,7 +3985,7 @@ void Application::update(float deltaTime) { · 2 unmodified lines | |||
| 3982 | 3985 | ||
| 3983 | if (!_physicsEnabled) { | 3986 | if (!_physicsEnabled) { |
| 3984 | if (!domainLoadingInProgress) { | 3987 | if (!domainLoadingInProgress) { |
| 3985 | PROFILE_ASYNC_BEGIN(interfaceapp, "Scene Loading", ""); | 3988 | PROFILE_ASYNC_BEGIN(app, "Scene Loading", ""); |
| 3986 | domainLoadingInProgress = true; | 3989 | domainLoadingInProgress = true; |
| 3987 | } | 3990 | } |
| 3988 | 3991 | ||
| @@ -4017,7 +4020,7 @@ void Application::update(float deltaTime) { · 28 unmodified lines | |||
| 4017 | } | 4020 | } |
| 4018 | } else if (domainLoadingInProgress) { | 4021 | } else if (domainLoadingInProgress) { |
| 4019 | domainLoadingInProgress = false; | 4022 | domainLoadingInProgress = false; |
| 4020 | PROFILE_ASYNC_END(interfaceapp, "Scene Loading", ""); | 4023 | PROFILE_ASYNC_END(app, "Scene Loading", ""); |
| 4021 | } | 4024 | } |
| 4022 | 4025 | ||
| 4023 | { | 4026 | { |
| @@ -4111,12 +4114,12 @@ void Application::update(float deltaTime) { · 87 unmodified lines | |||
| 4111 | QSharedPointer<AvatarManager> avatarManager = DependencyManager::get<AvatarManager>(); | 4114 | QSharedPointer<AvatarManager> avatarManager = DependencyManager::get<AvatarManager>(); |
| 4112 | 4115 | ||
| 4113 | if (_physicsEnabled) { | 4116 | if (_physicsEnabled) { |
| 4114 | PROFILE_RANGE_EX(interfaceapp, "Physics", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount()); | 4117 | PROFILE_RANGE_EX(simulation_physics, "Physics", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount()); |
| 4115 | 4118 | ||
| 4116 | PerformanceTimer perfTimer("physics"); | 4119 | PerformanceTimer perfTimer("physics"); |
| 4117 | 4120 | ||
| 4118 | { | 4121 | { |
| 4119 | PROFILE_RANGE_EX(interfaceapp, "UpdateStats", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount()); | 4122 | PROFILE_RANGE_EX(simulation_physics, "UpdateStats", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount()); |
| 4120 | 4123 | ||
| 4121 | PerformanceTimer perfTimer("updateStates)"); | 4124 | PerformanceTimer perfTimer("updateStates)"); |
| 4122 | static VectorOfMotionStates motionStates; | 4125 | static VectorOfMotionStates motionStates; |
| @@ -4150,14 +4153,14 @@ void Application::update(float deltaTime) { · 27 unmodified lines | |||
| 4150 | }); | 4153 | }); |
| 4151 | } | 4154 | } |
| 4152 | { | 4155 | { |
| 4153 | PROFILE_RANGE_EX(interfaceapp, "StepSimulation", 0xffff8000, (uint64_t)getActiveDisplayPlugin()->presentCount()); | 4156 | PROFILE_RANGE_EX(simulation_physics, "StepSimulation", 0xffff8000, (uint64_t)getActiveDisplayPlugin()->presentCount()); |
| 4154 | PerformanceTimer perfTimer("stepSimulation"); | 4157 | PerformanceTimer perfTimer("stepSimulation"); |
| 4155 | getEntities()->getTree()->withWriteLock([&] { | 4158 | getEntities()->getTree()->withWriteLock([&] { |
| 4156 | _physicsEngine->stepSimulation(); | 4159 | _physicsEngine->stepSimulation(); |
| 4157 | }); | 4160 | }); |
| 4158 | } | 4161 | } |
| 4159 | { | 4162 | { |
| 4160 | PROFILE_RANGE_EX(interfaceapp, "HarvestChanges", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount()); | 4163 | PROFILE_RANGE_EX(simulation_physics, "HarvestChanges", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount()); |
| 4161 | PerformanceTimer perfTimer("harvestChanges"); | 4164 | PerformanceTimer perfTimer("harvestChanges"); |
| 4162 | if (_physicsEngine->hasOutgoingChanges()) { | 4165 | if (_physicsEngine->hasOutgoingChanges()) { |
| 4163 | getEntities()->getTree()->withWriteLock([&] { | 4166 | getEntities()->getTree()->withWriteLock([&] { |
| @@ -4199,20 +4202,20 @@ void Application::update(float deltaTime) { · 35 unmodified lines | |||
| 4199 | _avatarSimCounter.increment(); | 4202 | _avatarSimCounter.increment(); |
| 4200 | 4203 | ||
| 4201 | { | 4204 | { |
| 4202 | PROFILE_RANGE_EX(interfaceapp, "OtherAvatars", 0xffff00ff, (uint64_t)getActiveDisplayPlugin()->presentCount()); | 4205 | PROFILE_RANGE_EX(simulation, "OtherAvatars", 0xffff00ff, (uint64_t)getActiveDisplayPlugin()->presentCount()); |
| 4203 | avatarManager->updateOtherAvatars(deltaTime); | 4206 | avatarManager->updateOtherAvatars(deltaTime); |
| 4204 | } | 4207 | } |
| 4205 | 4208 | ||
| 4206 | qApp->updateMyAvatarLookAtPosition(); | 4209 | qApp->updateMyAvatarLookAtPosition(); |
| 4207 | 4210 | ||
| 4208 | { | 4211 | { |
| 4209 | PROFILE_RANGE_EX(interfaceapp, "MyAvatar", 0xffff00ff, (uint64_t)getActiveDisplayPlugin()->presentCount()); | 4212 | PROFILE_RANGE_EX(simulation, "MyAvatar", 0xffff00ff, (uint64_t)getActiveDisplayPlugin()->presentCount()); |
| 4210 | avatarManager->updateMyAvatar(deltaTime); | 4213 | avatarManager->updateMyAvatar(deltaTime); |
| 4211 | } | 4214 | } |
| 4212 | } | 4215 | } |
| 4213 | 4216 | ||
| 4214 | { | 4217 | { |
| 4215 | PROFILE_RANGE_EX(interfaceapp, "Overlays", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount()); | 4218 | PROFILE_RANGE_EX(app, "Overlays", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount()); |
| 4216 | PerformanceTimer perfTimer("overlays"); | 4219 | PerformanceTimer perfTimer("overlays"); |
| 4217 | _overlays.update(deltaTime); | 4220 | _overlays.update(deltaTime); |
| 4218 | } | 4221 | } |
| @@ -4232,7 +4235,7 @@ void Application::update(float deltaTime) { · 13 unmodified lines | |||
| 4232 | 4235 | ||
| 4233 | // Update my voxel servers with my current voxel query... | 4236 | // Update my voxel servers with my current voxel query... |
| 4234 | { | 4237 | { |
| 4235 | PROFILE_RANGE_EX(interfaceapp, "QueryOctree", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount()); | 4238 | PROFILE_RANGE_EX(app, "QueryOctree", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount()); |
| 4236 | QMutexLocker viewLocker(&_viewMutex); | 4239 | QMutexLocker viewLocker(&_viewMutex); |
| 4237 | PerformanceTimer perfTimer("queryOctree"); | 4240 | PerformanceTimer perfTimer("queryOctree"); |
| 4238 | quint64 sinceLastQuery = now - _lastQueriedTime; | 4241 | quint64 sinceLastQuery = now - _lastQueriedTime; |
| @@ -4272,7 +4275,7 @@ void Application::update(float deltaTime) { · 33 unmodified lines | |||
| 4272 | avatarManager->postUpdate(deltaTime); | 4275 | avatarManager->postUpdate(deltaTime); |
| 4273 | 4276 | ||
| 4274 | { | 4277 | { |
| 4275 | PROFILE_RANGE_EX(interfaceapp, "PreRenderLambdas", 0xffff0000, (uint64_t)0); | 4278 | PROFILE_RANGE_EX(app, "PreRenderLambdas", 0xffff0000, (uint64_t)0); |
| 4276 | 4279 | ||
| 4277 | std::unique_lock<std::mutex> guard(_postUpdateLambdasLock); | 4280 | std::unique_lock<std::mutex> guard(_postUpdateLambdasLock); |
| 4278 | for (auto& iter : _postUpdateLambdas) { | 4281 | for (auto& iter : _postUpdateLambdas) { |
| @@ -4549,8 +4552,6 @@ QRect Application::getDesirableApplicationGeometry() const { · 270 unmodified lines | |||
| 4549 | // or the "myCamera". | 4552 | // or the "myCamera". |
| 4550 | // | 4553 | // |
| 4551 | void Application::loadViewFrustum(Camera& camera, ViewFrustum& viewFrustum) { | 4554 | void Application::loadViewFrustum(Camera& camera, ViewFrustum& viewFrustum) { |
| 4552 | PROFILE_RANGE(interfaceapp, __FUNCTION__); | ||
| 4553 | PerformanceTimer perfTimer("loadViewFrustum"); | ||
| 4554 | // We will use these below, from either the camera or head vectors calculated above | 4555 | // We will use these below, from either the camera or head vectors calculated above |
| 4555 | viewFrustum.setProjection(camera.getProjection()); | 4556 | viewFrustum.setProjection(camera.getProjection()); |
| 4556 | 4557 | ||
| @@ -4726,7 +4727,7 @@ void Application::displaySide(RenderArgs* renderArgs, Camera& theCamera, bool se · 169 unmodified lines | |||
| 4726 | myAvatar->preDisplaySide(renderArgs); | 4727 | myAvatar->preDisplaySide(renderArgs); |
| 4727 | 4728 | ||
| 4728 | activeRenderingThread = QThread::currentThread(); | 4729 | activeRenderingThread = QThread::currentThread(); |
| 4729 | PROFILE_RANGE(interfaceapp, __FUNCTION__); | 4730 | PROFILE_RANGE(render, __FUNCTION__); |
| 4730 | PerformanceTimer perfTimer("display"); | 4731 | PerformanceTimer perfTimer("display"); |
| 4731 | PerformanceWarning warn(Menu::getInstance()->isOptionChecked(MenuOption::PipelineWarnings), "Application::displaySide()"); | 4732 | PerformanceWarning warn(Menu::getInstance()->isOptionChecked(MenuOption::PipelineWarnings), "Application::displaySide()"); |
| 4732 | 4733 | ||