From 8ec20ef0423204f530f066cc8986d6c0a626ddab Mon Sep 17 00:00:00 2001 From: Brad Davis Date: Sun, 25 Jun 2017 20:04:49 -0700 Subject: [PATCH] Additional tracing of CPU cores --- interface/src/Application.cpp | 441 ++++++++++++++++++++++++---------- 1 file changed, 315 insertions(+), 126 deletions(-) diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index 75bcee0703..602495d165 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -25,6 +25,7 @@ #include #include #include +#include #include #include @@ -2154,48 +2155,74 @@ void Application::paintGL() { return; } - auto displayPlugin = getActiveDisplayPlugin(); - // FIXME not needed anymore? - _offscreenContext->makeCurrent(); + DisplayPluginPointer displayPlugin; + { + PROFILE_RANGE(render, "/getActiveDisplayPlugin"); + displayPlugin = getActiveDisplayPlugin(); + } - // If a display plugin loses it's underlying support, it - // needs to be able to signal us to not use it - if (!displayPlugin->beginFrameRender(_frameCount)) { - _inPaint = false; - updateDisplayMode(); - return; + { + PROFILE_RANGE(render, "/offscreenMakeCurrent"); + // FIXME not needed anymore? + _offscreenContext->makeCurrent(); + } + + { + PROFILE_RANGE(render, "/pluginBeginFrameRender"); + // If a display plugin loses it's underlying support, it + // needs to be able to signal us to not use it + if (!displayPlugin->beginFrameRender(_frameCount)) { + _inPaint = false; + updateDisplayMode(); + return; + } } // update the avatar with a fresh HMD pose - getMyAvatar()->updateFromHMDSensorMatrix(getHMDSensorPose()); + { + PROFILE_RANGE(render, "/updateAvatar"); + getMyAvatar()->updateFromHMDSensorMatrix(getHMDSensorPose()); + } auto lodManager = DependencyManager::get(); + RenderArgs renderArgs; { - QMutexLocker viewLocker(&_viewMutex); - _viewFrustum.calculate(); - } - RenderArgs renderArgs(_gpuContext, getEntities(), lodManager->getOctreeSizeScale(), - lodManager->getBoundaryLevelAdjust(), RenderArgs::DEFAULT_RENDER_MODE, - RenderArgs::MONO, RenderArgs::RENDER_DEBUG_NONE); - { - QMutexLocker viewLocker(&_viewMutex); - renderArgs.setViewFrustum(_viewFrustum); + PROFILE_RANGE(render, "/buildFrustrumAndArgs"); + { + QMutexLocker viewLocker(&_viewMutex); + _viewFrustum.calculate(); + } + renderArgs = RenderArgs(_gpuContext, getEntities(), lodManager->getOctreeSizeScale(), + lodManager->getBoundaryLevelAdjust(), RenderArgs::DEFAULT_RENDER_MODE, + RenderArgs::MONO, RenderArgs::RENDER_DEBUG_NONE); + { + QMutexLocker viewLocker(&_viewMutex); + renderArgs.setViewFrustum(_viewFrustum); + } } - PerformanceWarning::setSuppressShortTimings(Menu::getInstance()->isOptionChecked(MenuOption::SuppressShortTimings)); - bool showWarnings = Menu::getInstance()->isOptionChecked(MenuOption::PipelineWarnings); - PerformanceWarning warn(showWarnings, "Application::paintGL()"); - resizeGL(); - - _gpuContext->beginFrame(getHMDSensorPose()); - // Reset the gpu::Context Stages - // Back to the default framebuffer; - gpu::doInBatch(_gpuContext, [&](gpu::Batch& batch) { - batch.resetStages(); - }); + { + PROFILE_RANGE(render, "/resizeGL"); + PerformanceWarning::setSuppressShortTimings(Menu::getInstance()->isOptionChecked(MenuOption::SuppressShortTimings)); + bool showWarnings = Menu::getInstance()->isOptionChecked(MenuOption::PipelineWarnings); + PerformanceWarning warn(showWarnings, "Application::paintGL()"); + resizeGL(); + } { + PROFILE_RANGE(render, "/gpuContextReset"); + _gpuContext->beginFrame(getHMDSensorPose()); + // Reset the gpu::Context Stages + // Back to the default framebuffer; + gpu::doInBatch(_gpuContext, [&](gpu::Batch& batch) { + batch.resetStages(); + }); + } + + + { + PROFILE_RANGE(render, "/renderOverlay"); PerformanceTimer perfTimer("renderOverlay"); // NOTE: There is no batch associated with this renderArgs // the ApplicationOverlay class assumes it's viewport is setup to be the device size @@ -2206,114 +2233,127 @@ void Application::paintGL() { glm::vec3 boomOffset; { - PerformanceTimer perfTimer("CameraUpdates"); + PROFILE_RANGE(render, "/updateCamera"); + { + PerformanceTimer perfTimer("CameraUpdates"); - auto myAvatar = getMyAvatar(); - boomOffset = myAvatar->getScale() * myAvatar->getBoomLength() * -IDENTITY_FORWARD; + auto myAvatar = getMyAvatar(); + boomOffset = myAvatar->getScale() * myAvatar->getBoomLength() * -IDENTITY_FORWARD; - if (_myCamera.getMode() == CAMERA_MODE_FIRST_PERSON || _myCamera.getMode() == CAMERA_MODE_THIRD_PERSON) { - Menu::getInstance()->setIsOptionChecked(MenuOption::FirstPerson, myAvatar->getBoomLength() <= MyAvatar::ZOOM_MIN); - Menu::getInstance()->setIsOptionChecked(MenuOption::ThirdPerson, !(myAvatar->getBoomLength() <= MyAvatar::ZOOM_MIN)); - cameraMenuChanged(); - } - - // The render mode is default or mirror if the camera is in mirror mode, assigned further below - renderArgs._renderMode = RenderArgs::DEFAULT_RENDER_MODE; - - // Always use the default eye position, not the actual head eye position. - // Using the latter will cause the camera to wobble with idle animations, - // or with changes from the face tracker - if (_myCamera.getMode() == CAMERA_MODE_FIRST_PERSON) { - if (isHMDMode()) { - mat4 camMat = myAvatar->getSensorToWorldMatrix() * myAvatar->getHMDSensorMatrix(); - _myCamera.setPosition(extractTranslation(camMat)); - _myCamera.setOrientation(glm::quat_cast(camMat)); - } else { - _myCamera.setPosition(myAvatar->getDefaultEyePosition()); - _myCamera.setOrientation(myAvatar->getMyHead()->getHeadOrientation()); + if (_myCamera.getMode() == CAMERA_MODE_FIRST_PERSON || _myCamera.getMode() == CAMERA_MODE_THIRD_PERSON) { + Menu::getInstance()->setIsOptionChecked(MenuOption::FirstPerson, myAvatar->getBoomLength() <= MyAvatar::ZOOM_MIN); + Menu::getInstance()->setIsOptionChecked(MenuOption::ThirdPerson, !(myAvatar->getBoomLength() <= MyAvatar::ZOOM_MIN)); + cameraMenuChanged(); } - } else if (_myCamera.getMode() == CAMERA_MODE_THIRD_PERSON) { - if (isHMDMode()) { - auto hmdWorldMat = myAvatar->getSensorToWorldMatrix() * myAvatar->getHMDSensorMatrix(); - _myCamera.setOrientation(glm::normalize(glm::quat_cast(hmdWorldMat))); - _myCamera.setPosition(extractTranslation(hmdWorldMat) + - myAvatar->getOrientation() * boomOffset); - } else { - _myCamera.setOrientation(myAvatar->getHead()->getOrientation()); - if (Menu::getInstance()->isOptionChecked(MenuOption::CenterPlayerInView)) { - _myCamera.setPosition(myAvatar->getDefaultEyePosition() - + _myCamera.getOrientation() * boomOffset); - } else { - _myCamera.setPosition(myAvatar->getDefaultEyePosition() - + myAvatar->getOrientation() * boomOffset); - } - } - } else if (_myCamera.getMode() == CAMERA_MODE_MIRROR) { - if (isHMDMode()) { - auto mirrorBodyOrientation = myAvatar->getWorldAlignedOrientation() * glm::quat(glm::vec3(0.0f, PI + _rotateMirror, 0.0f)); - glm::quat hmdRotation = extractRotation(myAvatar->getHMDSensorMatrix()); - // Mirror HMD yaw and roll - glm::vec3 mirrorHmdEulers = glm::eulerAngles(hmdRotation); - mirrorHmdEulers.y = -mirrorHmdEulers.y; - mirrorHmdEulers.z = -mirrorHmdEulers.z; - glm::quat mirrorHmdRotation = glm::quat(mirrorHmdEulers); + // The render mode is default or mirror if the camera is in mirror mode, assigned further below + renderArgs._renderMode = RenderArgs::DEFAULT_RENDER_MODE; - glm::quat worldMirrorRotation = mirrorBodyOrientation * mirrorHmdRotation; - - _myCamera.setOrientation(worldMirrorRotation); - - glm::vec3 hmdOffset = extractTranslation(myAvatar->getHMDSensorMatrix()); - // Mirror HMD lateral offsets - hmdOffset.x = -hmdOffset.x; - - _myCamera.setPosition(myAvatar->getDefaultEyePosition() - + glm::vec3(0, _raiseMirror * myAvatar->getUniformScale(), 0) - + mirrorBodyOrientation * glm::vec3(0.0f, 0.0f, 1.0f) * MIRROR_FULLSCREEN_DISTANCE * _scaleMirror - + mirrorBodyOrientation * hmdOffset); - } else { - _myCamera.setOrientation(myAvatar->getWorldAlignedOrientation() - * glm::quat(glm::vec3(0.0f, PI + _rotateMirror, 0.0f))); - _myCamera.setPosition(myAvatar->getDefaultEyePosition() - + glm::vec3(0, _raiseMirror * myAvatar->getUniformScale(), 0) - + (myAvatar->getOrientation() * glm::quat(glm::vec3(0.0f, _rotateMirror, 0.0f))) * - glm::vec3(0.0f, 0.0f, -1.0f) * MIRROR_FULLSCREEN_DISTANCE * _scaleMirror); - } - renderArgs._renderMode = RenderArgs::MIRROR_RENDER_MODE; - } else if (_myCamera.getMode() == CAMERA_MODE_ENTITY) { - EntityItemPointer cameraEntity = _myCamera.getCameraEntityPointer(); - if (cameraEntity != nullptr) { + // Always use the default eye position, not the actual head eye position. + // Using the latter will cause the camera to wobble with idle animations, + // or with changes from the face tracker + if (_myCamera.getMode() == CAMERA_MODE_FIRST_PERSON) { if (isHMDMode()) { - glm::quat hmdRotation = extractRotation(myAvatar->getHMDSensorMatrix()); - _myCamera.setOrientation(cameraEntity->getRotation() * hmdRotation); - glm::vec3 hmdOffset = extractTranslation(myAvatar->getHMDSensorMatrix()); - _myCamera.setPosition(cameraEntity->getPosition() + (hmdRotation * hmdOffset)); + mat4 camMat = myAvatar->getSensorToWorldMatrix() * myAvatar->getHMDSensorMatrix(); + _myCamera.setPosition(extractTranslation(camMat)); + _myCamera.setOrientation(glm::quat_cast(camMat)); } else { - _myCamera.setOrientation(cameraEntity->getRotation()); - _myCamera.setPosition(cameraEntity->getPosition()); + _myCamera.setPosition(myAvatar->getDefaultEyePosition()); + _myCamera.setOrientation(myAvatar->getMyHead()->getHeadOrientation()); + } + } else if (_myCamera.getMode() == CAMERA_MODE_THIRD_PERSON) { + if (isHMDMode()) { + auto hmdWorldMat = myAvatar->getSensorToWorldMatrix() * myAvatar->getHMDSensorMatrix(); + _myCamera.setOrientation(glm::normalize(glm::quat_cast(hmdWorldMat))); + _myCamera.setPosition(extractTranslation(hmdWorldMat) + + myAvatar->getOrientation() * boomOffset); + } else { + _myCamera.setOrientation(myAvatar->getHead()->getOrientation()); + if (Menu::getInstance()->isOptionChecked(MenuOption::CenterPlayerInView)) { + _myCamera.setPosition(myAvatar->getDefaultEyePosition() + + _myCamera.getOrientation() * boomOffset); + } else { + _myCamera.setPosition(myAvatar->getDefaultEyePosition() + + myAvatar->getOrientation() * boomOffset); + } + } + } else if (_myCamera.getMode() == CAMERA_MODE_MIRROR) { + if (isHMDMode()) { + auto mirrorBodyOrientation = myAvatar->getWorldAlignedOrientation() * glm::quat(glm::vec3(0.0f, PI + _rotateMirror, 0.0f)); + + glm::quat hmdRotation = extractRotation(myAvatar->getHMDSensorMatrix()); + // Mirror HMD yaw and roll + glm::vec3 mirrorHmdEulers = glm::eulerAngles(hmdRotation); + mirrorHmdEulers.y = -mirrorHmdEulers.y; + mirrorHmdEulers.z = -mirrorHmdEulers.z; + glm::quat mirrorHmdRotation = glm::quat(mirrorHmdEulers); + + glm::quat worldMirrorRotation = mirrorBodyOrientation * mirrorHmdRotation; + + _myCamera.setOrientation(worldMirrorRotation); + + glm::vec3 hmdOffset = extractTranslation(myAvatar->getHMDSensorMatrix()); + // Mirror HMD lateral offsets + hmdOffset.x = -hmdOffset.x; + + _myCamera.setPosition(myAvatar->getDefaultEyePosition() + + glm::vec3(0, _raiseMirror * myAvatar->getUniformScale(), 0) + + mirrorBodyOrientation * glm::vec3(0.0f, 0.0f, 1.0f) * MIRROR_FULLSCREEN_DISTANCE * _scaleMirror + + mirrorBodyOrientation * hmdOffset); + } else { + _myCamera.setOrientation(myAvatar->getWorldAlignedOrientation() + * glm::quat(glm::vec3(0.0f, PI + _rotateMirror, 0.0f))); + _myCamera.setPosition(myAvatar->getDefaultEyePosition() + + glm::vec3(0, _raiseMirror * myAvatar->getUniformScale(), 0) + + (myAvatar->getOrientation() * glm::quat(glm::vec3(0.0f, _rotateMirror, 0.0f))) * + glm::vec3(0.0f, 0.0f, -1.0f) * MIRROR_FULLSCREEN_DISTANCE * _scaleMirror); + } + renderArgs._renderMode = RenderArgs::MIRROR_RENDER_MODE; + } else if (_myCamera.getMode() == CAMERA_MODE_ENTITY) { + EntityItemPointer cameraEntity = _myCamera.getCameraEntityPointer(); + if (cameraEntity != nullptr) { + if (isHMDMode()) { + glm::quat hmdRotation = extractRotation(myAvatar->getHMDSensorMatrix()); + _myCamera.setOrientation(cameraEntity->getRotation() * hmdRotation); + glm::vec3 hmdOffset = extractTranslation(myAvatar->getHMDSensorMatrix()); + _myCamera.setPosition(cameraEntity->getPosition() + (hmdRotation * hmdOffset)); + } else { + _myCamera.setOrientation(cameraEntity->getRotation()); + _myCamera.setPosition(cameraEntity->getPosition()); + } } } - } - // Update camera position - if (!isHMDMode()) { - _myCamera.update(1.0f / _frameCounter.rate()); + // Update camera position + if (!isHMDMode()) { + _myCamera.update(1.0f / _frameCounter.rate()); + } } } - getApplicationCompositor().setFrameInfo(_frameCount, _myCamera.getTransform()); + { + PROFILE_RANGE(render, "/updateCompositor"); + getApplicationCompositor().setFrameInfo(_frameCount, _myCamera.getTransform()); + } - // Primary rendering pass - auto framebufferCache = DependencyManager::get(); - const QSize size = framebufferCache->getFrameBufferSize(); - // Final framebuffer that will be handled to the display-plugin - auto finalFramebuffer = framebufferCache->getFramebuffer(); + gpu::FramebufferPointer finalFramebuffer; + QSize finalFramebufferSize; + { + PROFILE_RANGE(render, "/getOutputFramebuffer"); + // Primary rendering pass + auto framebufferCache = DependencyManager::get(); + finalFramebufferSize = framebufferCache->getFrameBufferSize(); + // Final framebuffer that will be handled to the display-plugin + finalFramebuffer = framebufferCache->getFramebuffer(); + } { PROFILE_RANGE(render, "/mainRender"); PerformanceTimer perfTimer("mainRender"); renderArgs._boomOffset = boomOffset; + // FIXME is this ever going to be different from the size previously set in the render args + // in the overlay render? // Viewport is assigned to the size of the framebuffer - renderArgs._viewport = ivec4(0, 0, size.width(), size.height()); + renderArgs._viewport = ivec4(0, 0, finalFramebufferSize.width(), finalFramebufferSize.height()); if (displayPlugin->isStereo()) { // Stereo modes will typically have a larger projection matrix overall, // so we ask for the 'mono' projection matrix, which for stereo and HMD @@ -3613,6 +3653,133 @@ bool Application::shouldPaint(float nsecsElapsed) { #include #include #pragma comment(lib, "pdh.lib") +#pragma comment(lib, "ntdll.lib") + +extern "C" { + enum SYSTEM_INFORMATION_CLASS { + SystemBasicInformation = 0, + SystemProcessorPerformanceInformation = 8, + }; + + struct SYSTEM_PROCESSOR_PERFORMANCE_INFORMATION { + LARGE_INTEGER IdleTime; + LARGE_INTEGER KernelTime; + LARGE_INTEGER UserTime; + LARGE_INTEGER DpcTime; + LARGE_INTEGER InterruptTime; + ULONG InterruptCount; + }; + + struct SYSTEM_BASIC_INFORMATION { + ULONG Reserved; + ULONG TimerResolution; + ULONG PageSize; + ULONG NumberOfPhysicalPages; + ULONG LowestPhysicalPageNumber; + ULONG HighestPhysicalPageNumber; + ULONG AllocationGranularity; + ULONG_PTR MinimumUserModeAddress; + ULONG_PTR MaximumUserModeAddress; + ULONG_PTR ActiveProcessorsAffinityMask; + CCHAR NumberOfProcessors; + }; + + NTSYSCALLAPI NTSTATUS NTAPI NtQuerySystemInformation( + _In_ SYSTEM_INFORMATION_CLASS SystemInformationClass, + _Out_writes_bytes_opt_(SystemInformationLength) PVOID SystemInformation, + _In_ ULONG SystemInformationLength, + _Out_opt_ PULONG ReturnLength + ); + +} +template +NTSTATUS NtQuerySystemInformation(SYSTEM_INFORMATION_CLASS SystemInformationClass, T& t) { + return NtQuerySystemInformation(SystemInformationClass, &t, (ULONG)sizeof(T), nullptr); +} + +template +NTSTATUS NtQuerySystemInformation(SYSTEM_INFORMATION_CLASS SystemInformationClass, std::vector& t) { + return NtQuerySystemInformation(SystemInformationClass, t.data(), (ULONG)(sizeof(T) * t.size()), nullptr); +} + + +template +void updateValueAndDelta(std::pair& pair, T newValue) { + auto& value = pair.first; + auto& delta = pair.second; + delta = (value != 0) ? newValue - value : 0; + value = newValue; +} + +struct MyCpuInfo { + using ValueAndDelta = std::pair; + std::string name; + ValueAndDelta kernel { 0, 0 }; + ValueAndDelta user { 0, 0 }; + ValueAndDelta idle { 0, 0 }; + float kernelUsage { 0.0f }; + float userUsage { 0.0f }; + + void update(const SYSTEM_PROCESSOR_PERFORMANCE_INFORMATION& cpuInfo) { + updateValueAndDelta(kernel, cpuInfo.KernelTime.QuadPart); + updateValueAndDelta(user, cpuInfo.UserTime.QuadPart); + updateValueAndDelta(idle, cpuInfo.IdleTime.QuadPart); + auto totalTime = kernel.second + user.second + idle.second; + if (totalTime != 0) { + kernelUsage = (FLOAT)kernel.second / totalTime; + userUsage = (FLOAT)user.second / totalTime; + } else { + kernelUsage = userUsage = 0.0f; + } + } +}; + +void updateCpuInformation() { + static std::once_flag once; + static SYSTEM_BASIC_INFORMATION systemInfo {}; + static SYSTEM_PROCESSOR_PERFORMANCE_INFORMATION cpuTotals; + static std::vector cpuInfos; + static std::vector myCpuInfos; + static MyCpuInfo myCpuTotals; + std::call_once(once, [&] { + NtQuerySystemInformation( SystemBasicInformation, systemInfo); + cpuInfos.resize(systemInfo.NumberOfProcessors); + myCpuInfos.resize(systemInfo.NumberOfProcessors); + for (size_t i = 0; i < systemInfo.NumberOfProcessors; ++i) { + myCpuInfos[i].name = "cpu." + std::to_string(i); + } + myCpuTotals.name = "cpu.total"; + }); + NtQuerySystemInformation(SystemProcessorPerformanceInformation, cpuInfos); + + // Zero the CPU totals. + memset(&cpuTotals, 0, sizeof(SYSTEM_PROCESSOR_PERFORMANCE_INFORMATION)); + for (size_t i = 0; i < systemInfo.NumberOfProcessors; ++i) { + auto& cpuInfo = cpuInfos[i]; + // KernelTime includes IdleTime. + cpuInfo.KernelTime.QuadPart -= cpuInfo.IdleTime.QuadPart; + + // Update totals + cpuTotals.IdleTime.QuadPart += cpuInfo.IdleTime.QuadPart; + cpuTotals.KernelTime.QuadPart += cpuInfo.KernelTime.QuadPart; + cpuTotals.UserTime.QuadPart += cpuInfo.UserTime.QuadPart; + + // Update friendly structure + auto& myCpuInfo = myCpuInfos[i]; + myCpuInfo.update(cpuInfo); + PROFILE_COUNTER(app, myCpuInfo.name.c_str(), { + { "kernel", myCpuInfo.kernelUsage }, + { "user", myCpuInfo.userUsage } + }); + } + + myCpuTotals.update(cpuTotals); + PROFILE_COUNTER(app, myCpuTotals.name.c_str(), { + { "kernel", myCpuTotals.kernelUsage }, + { "user", myCpuTotals.userUsage } + }); +} + static ULARGE_INTEGER lastCPU, lastSysCPU, lastUserCPU; static int numProcessors; @@ -3665,6 +3832,26 @@ void getCpuUsage(vec3& systemAndUser) { systemAndUser.z = (float)counterVal.doubleValue; } +void setupCpuMonitorThread() { + initCpuUsage(); + auto cpuMonitorThread = QThread::currentThread(); + + QTimer* timer = new QTimer(); + timer->setInterval(50); + QObject::connect(timer, &QTimer::timeout, [] { + updateCpuInformation(); + vec3 kernelUserAndSystem; + getCpuUsage(kernelUserAndSystem); + PROFILE_COUNTER(app, "cpuProcess", { { "system", kernelUserAndSystem.x }, { "user", kernelUserAndSystem.y } }); + PROFILE_COUNTER(app, "cpuSystem", { { "system", kernelUserAndSystem.z } }); + }); + QObject::connect(cpuMonitorThread, &QThread::finished, [=] { + timer->deleteLater(); + cpuMonitorThread->deleteLater(); + }); + timer->start(); +} + #endif @@ -3685,15 +3872,17 @@ void Application::idle(float nsecsElapsed) { } #ifdef Q_OS_WIN + // If tracing is enabled then monitor the CPU in a separate thread static std::once_flag once; - std::call_once(once, [] { - initCpuUsage(); + std::call_once(once, [&] { + if (trace_app().isDebugEnabled()) { + QThread* cpuMonitorThread = new QThread(qApp); + cpuMonitorThread->setObjectName("cpuMonitorThread"); + QObject::connect(cpuMonitorThread, &QThread::started, [this] { setupCpuMonitorThread(); }); + QObject::connect(qApp, &QCoreApplication::aboutToQuit, cpuMonitorThread, &QThread::quit); + cpuMonitorThread->start(); + } }); - - vec3 kernelUserAndSystem; - getCpuUsage(kernelUserAndSystem); - PROFILE_COUNTER(app, "cpuProcess", { { "system", kernelUserAndSystem.x }, { "user", kernelUserAndSystem.y } }); - PROFILE_COUNTER(app, "cpuSystem", { { "system", kernelUserAndSystem.z } }); #endif