Merge pull request #11504 from AndrewMeadows/main-loop-stats-audit

Tweak debug stats for more clarity
This commit is contained in:
Sam Gateau 2017-10-03 11:23:16 -07:00 committed by GitHub
commit ab8757eeb2
12 changed files with 325 additions and 292 deletions

View file

@ -55,7 +55,11 @@ Item {
text: "Avatars: " + root.avatarCount
}
StatText {
text: "Frame Rate: " + root.framerate.toFixed(2);
text: "Game Rate: " + root.gameLoopRate
}
StatText {
visible: root.expanded
text: root.gameUpdateStats
}
StatText {
text: "Render Rate: " + root.renderrate.toFixed(2);
@ -64,21 +68,17 @@ Item {
text: "Present Rate: " + root.presentrate.toFixed(2);
}
StatText {
text: "Present New Rate: " + root.presentnewrate.toFixed(2);
visible: root.expanded
text: " Present New Rate: " + root.presentnewrate.toFixed(2);
}
StatText {
text: "Present Drop Rate: " + root.presentdroprate.toFixed(2);
visible: root.expanded
text: " Present Drop Rate: " + root.presentdroprate.toFixed(2);
}
StatText {
text: "Stutter Rate: " + root.stutterrate.toFixed(3);
visible: root.stutterrate != -1;
}
StatText {
text: "Simrate: " + root.simrate
}
StatText {
text: "Avatar Simrate: " + root.avatarSimrate
}
StatText {
text: "Missed Frame Count: " + root.appdropped;
visible: root.appdropped > 0;
@ -261,9 +261,6 @@ Item {
StatText {
text: "GPU: " + root.gpuFrameTime.toFixed(1) + " ms"
}
StatText {
text: "Avatar: " + root.avatarSimulationTime.toFixed(1) + " ms"
}
StatText {
text: "Triangles: " + root.triangles +
" / Material Switches: " + root.materialSwitches

View file

@ -1545,15 +1545,13 @@ Application::Application(int& argc, char** argv, QElapsedTimer& startupTimer, bo
auto displayPlugin = qApp->getActiveDisplayPlugin();
properties["fps"] = _frameCounter.rate();
properties["target_frame_rate"] = getTargetFrameRate();
properties["render_rate"] = displayPlugin->renderRate();
properties["render_rate"] = _renderLoopCounter.rate();
properties["target_render_rate"] = getTargetRenderFrameRate();
properties["present_rate"] = displayPlugin->presentRate();
properties["new_frame_present_rate"] = displayPlugin->newFramePresentRate();
properties["dropped_frame_rate"] = displayPlugin->droppedFrameRate();
properties["stutter_rate"] = displayPlugin->stutterRate();
properties["sim_rate"] = getAverageSimsPerSecond();
properties["avatar_sim_rate"] = getAvatarSimrate();
properties["game_rate"] = getGameLoopRate();
properties["has_async_reprojection"] = displayPlugin->hasAsyncReprojection();
properties["hardware_stats"] = displayPlugin->getHardwareStats();
@ -2388,11 +2386,11 @@ void Application::paintGL() {
return;
}
_frameCount++;
_renderFrameCount++;
_lastTimeRendered.start();
auto lastPaintBegin = usecTimestampNow();
PROFILE_RANGE_EX(render, __FUNCTION__, 0xff0000ff, (uint64_t)_frameCount);
PROFILE_RANGE_EX(render, __FUNCTION__, 0xff0000ff, (uint64_t)_renderFrameCount);
PerformanceTimer perfTimer("paintGL");
if (nullptr == _displayPlugin) {
@ -2409,7 +2407,7 @@ void Application::paintGL() {
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)) {
if (!displayPlugin->beginFrameRender(_renderFrameCount)) {
updateDisplayMode();
return;
}
@ -2564,14 +2562,14 @@ void Application::paintGL() {
}
// Update camera position
if (!isHMDMode()) {
_myCamera.update(1.0f / _frameCounter.rate());
_myCamera.update();
}
}
}
{
PROFILE_RANGE(render, "/updateCompositor");
getApplicationCompositor().setFrameInfo(_frameCount, _myCamera.getTransform(), getMyAvatar()->getSensorToWorldMatrix());
getApplicationCompositor().setFrameInfo(_renderFrameCount, _myCamera.getTransform(), getMyAvatar()->getSensorToWorldMatrix());
}
gpu::FramebufferPointer finalFramebuffer;
@ -2652,7 +2650,7 @@ void Application::paintGL() {
}
auto frame = _gpuContext->endFrame();
frame->frameIndex = _frameCount;
frame->frameIndex = _renderFrameCount;
frame->framebuffer = finalFramebuffer;
frame->framebufferRecycler = [](const gpu::FramebufferPointer& framebuffer){
DependencyManager::get<FramebufferCache>()->releaseFramebuffer(framebuffer);
@ -2663,7 +2661,7 @@ void Application::paintGL() {
{
PROFILE_RANGE(render, "/pluginOutput");
PerformanceTimer perfTimer("pluginOutput");
_frameCounter.increment();
_renderLoopCounter.increment();
displayPlugin->submitFrame(frame);
}
@ -4041,7 +4039,7 @@ void Application::idle() {
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, "renderLoopRate", float, _renderLoopCounter.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<StatTracker>()->getStat("Processing").toInt());
@ -4077,8 +4075,6 @@ void Application::idle() {
Stats::getInstance()->updateStats();
_simCounter.increment();
// Normally we check PipelineWarnings, but since idle will often take more than 10ms we only show these idle timing
// details if we're in ExtraDebugging mode. However, the ::update() and its subcomponents will show their timing
// details normally.
@ -4158,6 +4154,7 @@ void Application::idle() {
Menu::getInstance()->setIsOptionChecked(MenuOption::ThirdPerson, !(myAvatar->getBoomLength() <= MyAvatar::ZOOM_MIN));
cameraMenuChanged();
}
_gameLoopCounter.increment();
}
ivec2 Application::getMouse() const {
@ -4844,12 +4841,7 @@ static bool domainLoadingInProgress = false;
void Application::update(float deltaTime) {
PROFILE_RANGE_EX(app, __FUNCTION__, 0xffff0000, (uint64_t)_frameCount + 1);
bool showWarnings = Menu::getInstance()->isOptionChecked(MenuOption::PipelineWarnings);
PerformanceWarning warn(showWarnings, "Application::update()");
updateLOD(deltaTime);
PROFILE_RANGE_EX(app, __FUNCTION__, 0xffff0000, (uint64_t)_renderFrameCount + 1);
if (!_physicsEnabled) {
if (!domainLoadingInProgress) {
@ -4880,6 +4872,7 @@ void Application::update(float deltaTime) {
PROFILE_ASYNC_END(app, "Scene Loading", "");
}
auto myAvatar = getMyAvatar();
{
PerformanceTimer perfTimer("devices");
@ -4913,129 +4906,127 @@ void Application::update(float deltaTime) {
_lastFaceTrackerUpdate = 0;
}
}
auto userInputMapper = DependencyManager::get<UserInputMapper>();
auto myAvatar = getMyAvatar();
auto userInputMapper = DependencyManager::get<UserInputMapper>();
controller::InputCalibrationData calibrationData = {
myAvatar->getSensorToWorldMatrix(),
createMatFromQuatAndPos(myAvatar->getOrientation(), myAvatar->getPosition()),
myAvatar->getHMDSensorMatrix(),
myAvatar->getCenterEyeCalibrationMat(),
myAvatar->getHeadCalibrationMat(),
myAvatar->getSpine2CalibrationMat(),
myAvatar->getHipsCalibrationMat(),
myAvatar->getLeftFootCalibrationMat(),
myAvatar->getRightFootCalibrationMat(),
myAvatar->getRightArmCalibrationMat(),
myAvatar->getLeftArmCalibrationMat(),
myAvatar->getRightHandCalibrationMat(),
myAvatar->getLeftHandCalibrationMat()
};
controller::InputCalibrationData calibrationData = {
myAvatar->getSensorToWorldMatrix(),
createMatFromQuatAndPos(myAvatar->getOrientation(), myAvatar->getPosition()),
myAvatar->getHMDSensorMatrix(),
myAvatar->getCenterEyeCalibrationMat(),
myAvatar->getHeadCalibrationMat(),
myAvatar->getSpine2CalibrationMat(),
myAvatar->getHipsCalibrationMat(),
myAvatar->getLeftFootCalibrationMat(),
myAvatar->getRightFootCalibrationMat(),
myAvatar->getRightArmCalibrationMat(),
myAvatar->getLeftArmCalibrationMat(),
myAvatar->getRightHandCalibrationMat(),
myAvatar->getLeftHandCalibrationMat()
};
InputPluginPointer keyboardMousePlugin;
for (auto inputPlugin : PluginManager::getInstance()->getInputPlugins()) {
if (inputPlugin->getName() == KeyboardMouseDevice::NAME) {
keyboardMousePlugin = inputPlugin;
} else if (inputPlugin->isActive()) {
inputPlugin->pluginUpdate(deltaTime, calibrationData);
}
}
userInputMapper->setInputCalibrationData(calibrationData);
userInputMapper->update(deltaTime);
if (keyboardMousePlugin && keyboardMousePlugin->isActive()) {
keyboardMousePlugin->pluginUpdate(deltaTime, calibrationData);
}
// Transfer the user inputs to the driveKeys
// FIXME can we drop drive keys and just have the avatar read the action states directly?
myAvatar->clearDriveKeys();
if (_myCamera.getMode() != CAMERA_MODE_INDEPENDENT) {
if (!_controllerScriptingInterface->areActionsCaptured()) {
myAvatar->setDriveKey(MyAvatar::TRANSLATE_Z, -1.0f * userInputMapper->getActionState(controller::Action::TRANSLATE_Z));
myAvatar->setDriveKey(MyAvatar::TRANSLATE_Y, userInputMapper->getActionState(controller::Action::TRANSLATE_Y));
myAvatar->setDriveKey(MyAvatar::TRANSLATE_X, userInputMapper->getActionState(controller::Action::TRANSLATE_X));
if (deltaTime > FLT_EPSILON) {
myAvatar->setDriveKey(MyAvatar::PITCH, -1.0f * userInputMapper->getActionState(controller::Action::PITCH));
myAvatar->setDriveKey(MyAvatar::YAW, -1.0f * userInputMapper->getActionState(controller::Action::YAW));
myAvatar->setDriveKey(MyAvatar::STEP_YAW, -1.0f * userInputMapper->getActionState(controller::Action::STEP_YAW));
InputPluginPointer keyboardMousePlugin;
for (auto inputPlugin : PluginManager::getInstance()->getInputPlugins()) {
if (inputPlugin->getName() == KeyboardMouseDevice::NAME) {
keyboardMousePlugin = inputPlugin;
} else if (inputPlugin->isActive()) {
inputPlugin->pluginUpdate(deltaTime, calibrationData);
}
}
myAvatar->setDriveKey(MyAvatar::ZOOM, userInputMapper->getActionState(controller::Action::TRANSLATE_CAMERA_Z));
}
static const std::vector<controller::Action> avatarControllerActions = {
controller::Action::LEFT_HAND,
controller::Action::RIGHT_HAND,
controller::Action::LEFT_FOOT,
controller::Action::RIGHT_FOOT,
controller::Action::HIPS,
controller::Action::SPINE2,
controller::Action::HEAD,
controller::Action::LEFT_HAND_THUMB1,
controller::Action::LEFT_HAND_THUMB2,
controller::Action::LEFT_HAND_THUMB3,
controller::Action::LEFT_HAND_THUMB4,
controller::Action::LEFT_HAND_INDEX1,
controller::Action::LEFT_HAND_INDEX2,
controller::Action::LEFT_HAND_INDEX3,
controller::Action::LEFT_HAND_INDEX4,
controller::Action::LEFT_HAND_MIDDLE1,
controller::Action::LEFT_HAND_MIDDLE2,
controller::Action::LEFT_HAND_MIDDLE3,
controller::Action::LEFT_HAND_MIDDLE4,
controller::Action::LEFT_HAND_RING1,
controller::Action::LEFT_HAND_RING2,
controller::Action::LEFT_HAND_RING3,
controller::Action::LEFT_HAND_RING4,
controller::Action::LEFT_HAND_PINKY1,
controller::Action::LEFT_HAND_PINKY2,
controller::Action::LEFT_HAND_PINKY3,
controller::Action::LEFT_HAND_PINKY4,
controller::Action::RIGHT_HAND_THUMB1,
controller::Action::RIGHT_HAND_THUMB2,
controller::Action::RIGHT_HAND_THUMB3,
controller::Action::RIGHT_HAND_THUMB4,
controller::Action::RIGHT_HAND_INDEX1,
controller::Action::RIGHT_HAND_INDEX2,
controller::Action::RIGHT_HAND_INDEX3,
controller::Action::RIGHT_HAND_INDEX4,
controller::Action::RIGHT_HAND_MIDDLE1,
controller::Action::RIGHT_HAND_MIDDLE2,
controller::Action::RIGHT_HAND_MIDDLE3,
controller::Action::RIGHT_HAND_MIDDLE4,
controller::Action::RIGHT_HAND_RING1,
controller::Action::RIGHT_HAND_RING2,
controller::Action::RIGHT_HAND_RING3,
controller::Action::RIGHT_HAND_RING4,
controller::Action::RIGHT_HAND_PINKY1,
controller::Action::RIGHT_HAND_PINKY2,
controller::Action::RIGHT_HAND_PINKY3,
controller::Action::RIGHT_HAND_PINKY4,
controller::Action::LEFT_ARM,
controller::Action::RIGHT_ARM,
controller::Action::LEFT_SHOULDER,
controller::Action::RIGHT_SHOULDER,
controller::Action::LEFT_FORE_ARM,
controller::Action::RIGHT_FORE_ARM,
controller::Action::LEFT_LEG,
controller::Action::RIGHT_LEG,
controller::Action::LEFT_UP_LEG,
controller::Action::RIGHT_UP_LEG,
controller::Action::LEFT_TOE_BASE,
controller::Action::RIGHT_TOE_BASE
};
userInputMapper->setInputCalibrationData(calibrationData);
userInputMapper->update(deltaTime);
// copy controller poses from userInputMapper to myAvatar.
glm::mat4 myAvatarMatrix = createMatFromQuatAndPos(myAvatar->getOrientation(), myAvatar->getPosition());
glm::mat4 worldToSensorMatrix = glm::inverse(myAvatar->getSensorToWorldMatrix());
glm::mat4 avatarToSensorMatrix = worldToSensorMatrix * myAvatarMatrix;
for (auto& action : avatarControllerActions) {
controller::Pose pose = userInputMapper->getPoseState(action);
myAvatar->setControllerPoseInSensorFrame(action, pose.transform(avatarToSensorMatrix));
if (keyboardMousePlugin && keyboardMousePlugin->isActive()) {
keyboardMousePlugin->pluginUpdate(deltaTime, calibrationData);
}
// Transfer the user inputs to the driveKeys
// FIXME can we drop drive keys and just have the avatar read the action states directly?
myAvatar->clearDriveKeys();
if (_myCamera.getMode() != CAMERA_MODE_INDEPENDENT) {
if (!_controllerScriptingInterface->areActionsCaptured()) {
myAvatar->setDriveKey(MyAvatar::TRANSLATE_Z, -1.0f * userInputMapper->getActionState(controller::Action::TRANSLATE_Z));
myAvatar->setDriveKey(MyAvatar::TRANSLATE_Y, userInputMapper->getActionState(controller::Action::TRANSLATE_Y));
myAvatar->setDriveKey(MyAvatar::TRANSLATE_X, userInputMapper->getActionState(controller::Action::TRANSLATE_X));
if (deltaTime > FLT_EPSILON) {
myAvatar->setDriveKey(MyAvatar::PITCH, -1.0f * userInputMapper->getActionState(controller::Action::PITCH));
myAvatar->setDriveKey(MyAvatar::YAW, -1.0f * userInputMapper->getActionState(controller::Action::YAW));
myAvatar->setDriveKey(MyAvatar::STEP_YAW, -1.0f * userInputMapper->getActionState(controller::Action::STEP_YAW));
}
}
myAvatar->setDriveKey(MyAvatar::ZOOM, userInputMapper->getActionState(controller::Action::TRANSLATE_CAMERA_Z));
}
static const std::vector<controller::Action> avatarControllerActions = {
controller::Action::LEFT_HAND,
controller::Action::RIGHT_HAND,
controller::Action::LEFT_FOOT,
controller::Action::RIGHT_FOOT,
controller::Action::HIPS,
controller::Action::SPINE2,
controller::Action::HEAD,
controller::Action::LEFT_HAND_THUMB1,
controller::Action::LEFT_HAND_THUMB2,
controller::Action::LEFT_HAND_THUMB3,
controller::Action::LEFT_HAND_THUMB4,
controller::Action::LEFT_HAND_INDEX1,
controller::Action::LEFT_HAND_INDEX2,
controller::Action::LEFT_HAND_INDEX3,
controller::Action::LEFT_HAND_INDEX4,
controller::Action::LEFT_HAND_MIDDLE1,
controller::Action::LEFT_HAND_MIDDLE2,
controller::Action::LEFT_HAND_MIDDLE3,
controller::Action::LEFT_HAND_MIDDLE4,
controller::Action::LEFT_HAND_RING1,
controller::Action::LEFT_HAND_RING2,
controller::Action::LEFT_HAND_RING3,
controller::Action::LEFT_HAND_RING4,
controller::Action::LEFT_HAND_PINKY1,
controller::Action::LEFT_HAND_PINKY2,
controller::Action::LEFT_HAND_PINKY3,
controller::Action::LEFT_HAND_PINKY4,
controller::Action::RIGHT_HAND_THUMB1,
controller::Action::RIGHT_HAND_THUMB2,
controller::Action::RIGHT_HAND_THUMB3,
controller::Action::RIGHT_HAND_THUMB4,
controller::Action::RIGHT_HAND_INDEX1,
controller::Action::RIGHT_HAND_INDEX2,
controller::Action::RIGHT_HAND_INDEX3,
controller::Action::RIGHT_HAND_INDEX4,
controller::Action::RIGHT_HAND_MIDDLE1,
controller::Action::RIGHT_HAND_MIDDLE2,
controller::Action::RIGHT_HAND_MIDDLE3,
controller::Action::RIGHT_HAND_MIDDLE4,
controller::Action::RIGHT_HAND_RING1,
controller::Action::RIGHT_HAND_RING2,
controller::Action::RIGHT_HAND_RING3,
controller::Action::RIGHT_HAND_RING4,
controller::Action::RIGHT_HAND_PINKY1,
controller::Action::RIGHT_HAND_PINKY2,
controller::Action::RIGHT_HAND_PINKY3,
controller::Action::RIGHT_HAND_PINKY4,
controller::Action::LEFT_ARM,
controller::Action::RIGHT_ARM,
controller::Action::LEFT_SHOULDER,
controller::Action::RIGHT_SHOULDER,
controller::Action::LEFT_FORE_ARM,
controller::Action::RIGHT_FORE_ARM,
controller::Action::LEFT_LEG,
controller::Action::RIGHT_LEG,
controller::Action::LEFT_UP_LEG,
controller::Action::RIGHT_UP_LEG,
controller::Action::LEFT_TOE_BASE,
controller::Action::RIGHT_TOE_BASE
};
// copy controller poses from userInputMapper to myAvatar.
glm::mat4 myAvatarMatrix = createMatFromQuatAndPos(myAvatar->getOrientation(), myAvatar->getPosition());
glm::mat4 worldToSensorMatrix = glm::inverse(myAvatar->getSensorToWorldMatrix());
glm::mat4 avatarToSensorMatrix = worldToSensorMatrix * myAvatarMatrix;
for (auto& action : avatarControllerActions) {
controller::Pose pose = userInputMapper->getPoseState(action);
myAvatar->setControllerPoseInSensorFrame(action, pose.transform(avatarToSensorMatrix));
}
}
updateThreads(deltaTime); // If running non-threaded, then give the threads some time to process...
@ -5043,117 +5034,123 @@ void Application::update(float deltaTime) {
QSharedPointer<AvatarManager> avatarManager = DependencyManager::get<AvatarManager>();
if (_physicsEnabled) {
{
PROFILE_RANGE_EX(simulation_physics, "Physics", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount());
PerformanceTimer perfTimer("physics");
if (_physicsEnabled) {
{
PROFILE_RANGE_EX(simulation_physics, "UpdateStates", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount());
{
PROFILE_RANGE_EX(simulation_physics, "UpdateStates", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount());
PerformanceTimer perfTimer("updateStates)");
static VectorOfMotionStates motionStates;
_entitySimulation->getObjectsToRemoveFromPhysics(motionStates);
_physicsEngine->removeObjects(motionStates);
_entitySimulation->deleteObjectsRemovedFromPhysics();
PerformanceTimer perfTimer("updateStates)");
static VectorOfMotionStates motionStates;
_entitySimulation->getObjectsToRemoveFromPhysics(motionStates);
_physicsEngine->removeObjects(motionStates);
_entitySimulation->deleteObjectsRemovedFromPhysics();
getEntities()->getTree()->withReadLock([&] {
_entitySimulation->getObjectsToAddToPhysics(motionStates);
_physicsEngine->addObjects(motionStates);
getEntities()->getTree()->withReadLock([&] {
_entitySimulation->getObjectsToAddToPhysics(motionStates);
_physicsEngine->addObjects(motionStates);
});
getEntities()->getTree()->withReadLock([&] {
_entitySimulation->getObjectsToChange(motionStates);
VectorOfMotionStates stillNeedChange = _physicsEngine->changeObjects(motionStates);
_entitySimulation->setObjectsToChange(stillNeedChange);
});
_entitySimulation->applyDynamicChanges();
avatarManager->getObjectsToRemoveFromPhysics(motionStates);
_physicsEngine->removeObjects(motionStates);
avatarManager->getObjectsToAddToPhysics(motionStates);
_physicsEngine->addObjects(motionStates);
avatarManager->getObjectsToChange(motionStates);
_physicsEngine->changeObjects(motionStates);
myAvatar->prepareForPhysicsSimulation();
_physicsEngine->forEachDynamic([&](EntityDynamicPointer dynamic) {
dynamic->prepareForPhysicsSimulation();
});
}
{
PROFILE_RANGE_EX(simulation_physics, "StepSimulation", 0xffff8000, (uint64_t)getActiveDisplayPlugin()->presentCount());
PerformanceTimer perfTimer("stepSimulation");
getEntities()->getTree()->withWriteLock([&] {
_physicsEngine->stepSimulation();
});
}
{
PROFILE_RANGE_EX(simulation_physics, "HarvestChanges", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount());
PerformanceTimer perfTimer("harvestChanges");
if (_physicsEngine->hasOutgoingChanges()) {
// grab the collision events BEFORE handleOutgoingChanges() because at this point
// we have a better idea of which objects we own or should own.
auto& collisionEvents = _physicsEngine->getCollisionEvents();
getEntities()->getTree()->withWriteLock([&] {
PerformanceTimer perfTimer("handleOutgoingChanges");
const VectorOfMotionStates& outgoingChanges = _physicsEngine->getChangedMotionStates();
_entitySimulation->handleChangedMotionStates(outgoingChanges);
avatarManager->handleChangedMotionStates(outgoingChanges);
const VectorOfMotionStates& deactivations = _physicsEngine->getDeactivatedMotionStates();
_entitySimulation->handleDeactivatedMotionStates(deactivations);
});
getEntities()->getTree()->withReadLock([&] {
_entitySimulation->getObjectsToChange(motionStates);
VectorOfMotionStates stillNeedChange = _physicsEngine->changeObjects(motionStates);
_entitySimulation->setObjectsToChange(stillNeedChange);
});
if (!_aboutToQuit) {
// handleCollisionEvents() AFTER handleOutgoinChanges()
PerformanceTimer perfTimer("entities");
avatarManager->handleCollisionEvents(collisionEvents);
// Collision events (and their scripts) must not be handled when we're locked, above. (That would risk
// deadlock.)
_entitySimulation->handleCollisionEvents(collisionEvents);
_entitySimulation->applyDynamicChanges();
// NOTE: the getEntities()->update() call below will wait for lock
// and will simulate entity motion (the EntityTree has been given an EntitySimulation).
getEntities()->update(true); // update the models...
}
avatarManager->getObjectsToRemoveFromPhysics(motionStates);
_physicsEngine->removeObjects(motionStates);
avatarManager->getObjectsToAddToPhysics(motionStates);
_physicsEngine->addObjects(motionStates);
avatarManager->getObjectsToChange(motionStates);
_physicsEngine->changeObjects(motionStates);
myAvatar->harvestResultsFromPhysicsSimulation(deltaTime);
if (Menu::getInstance()->isOptionChecked(MenuOption::DisplayDebugTimingDetails) &&
Menu::getInstance()->isOptionChecked(MenuOption::ExpandPhysicsSimulationTiming)) {
_physicsEngine->harvestPerformanceStats();
}
// NOTE: the PhysicsEngine stats are written to stdout NOT to Qt log framework
_physicsEngine->dumpStatsIfNecessary();
myAvatar->prepareForPhysicsSimulation();
_physicsEngine->forEachDynamic([&](EntityDynamicPointer dynamic) {
dynamic->prepareForPhysicsSimulation();
});
}
{
PROFILE_RANGE_EX(simulation_physics, "StepSimulation", 0xffff8000, (uint64_t)getActiveDisplayPlugin()->presentCount());
PerformanceTimer perfTimer("stepSimulation");
getEntities()->getTree()->withWriteLock([&] {
_physicsEngine->stepSimulation();
});
}
{
PROFILE_RANGE_EX(simulation_physics, "HarvestChanges", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount());
PerformanceTimer perfTimer("harvestChanges");
if (_physicsEngine->hasOutgoingChanges()) {
// grab the collision events BEFORE handleOutgoingChanges() because at this point
// we have a better idea of which objects we own or should own.
auto& collisionEvents = _physicsEngine->getCollisionEvents();
getEntities()->getTree()->withWriteLock([&] {
PerformanceTimer perfTimer("handleOutgoingChanges");
const VectorOfMotionStates& outgoingChanges = _physicsEngine->getChangedMotionStates();
_entitySimulation->handleChangedMotionStates(outgoingChanges);
avatarManager->handleChangedMotionStates(outgoingChanges);
const VectorOfMotionStates& deactivations = _physicsEngine->getDeactivatedMotionStates();
_entitySimulation->handleDeactivatedMotionStates(deactivations);
});
if (!_aboutToQuit) {
// handleCollisionEvents() AFTER handleOutgoinChanges()
PerformanceTimer perfTimer("entities");
avatarManager->handleCollisionEvents(collisionEvents);
// Collision events (and their scripts) must not be handled when we're locked, above. (That would risk
// deadlock.)
_entitySimulation->handleCollisionEvents(collisionEvents);
// NOTE: the getEntities()->update() call below will wait for lock
// and will simulate entity motion (the EntityTree has been given an EntitySimulation).
getEntities()->update(true); // update the models...
}
myAvatar->harvestResultsFromPhysicsSimulation(deltaTime);
if (Menu::getInstance()->isOptionChecked(MenuOption::DisplayDebugTimingDetails) &&
Menu::getInstance()->isOptionChecked(MenuOption::ExpandPhysicsSimulationTiming)) {
_physicsEngine->harvestPerformanceStats();
}
// NOTE: the PhysicsEngine stats are written to stdout NOT to Qt log framework
_physicsEngine->dumpStatsIfNecessary();
}
}
} else {
// update the rendering without any simulation
getEntities()->update(false);
}
} else {
// update the rendering without any simulation
getEntities()->update(false);
}
// AvatarManager update
{
PerformanceTimer perfTimer("AvatarManager");
_avatarSimCounter.increment();
{
PerformanceTimer perfTimer("otherAvatars");
PROFILE_RANGE_EX(simulation, "OtherAvatars", 0xffff00ff, (uint64_t)getActiveDisplayPlugin()->presentCount());
avatarManager->updateOtherAvatars(deltaTime);
}
qApp->updateMyAvatarLookAtPosition();
{
PROFILE_RANGE_EX(simulation, "MyAvatar", 0xffff00ff, (uint64_t)getActiveDisplayPlugin()->presentCount());
PerformanceTimer perfTimer("MyAvatar");
qApp->updateMyAvatarLookAtPosition();
avatarManager->updateMyAvatar(deltaTime);
}
}
PerformanceTimer perfTimer("misc");
bool showWarnings = Menu::getInstance()->isOptionChecked(MenuOption::PipelineWarnings);
PerformanceWarning warn(showWarnings, "Application::update()");
updateLOD(deltaTime);
// TODO: break these out into distinct perfTimers when they prove interesting
{
PROFILE_RANGE(app, "RayPickManager");
_rayPickManager.update();
@ -5471,7 +5468,7 @@ bool Application::isHMDMode() const {
return getActiveDisplayPlugin()->isHmd();
}
float Application::getTargetFrameRate() const { return getActiveDisplayPlugin()->getTargetFrameRate(); }
float Application::getTargetRenderFrameRate() const { return getActiveDisplayPlugin()->getTargetFrameRate(); }
QRect Application::getDesirableApplicationGeometry() const {
QRect applicationGeometry = getWindow()->geometry();

View file

@ -192,10 +192,9 @@ public:
Overlays& getOverlays() { return _overlays; }
size_t getFrameCount() const { return _frameCount; }
float getFps() const { return _frameCounter.rate(); }
float getTargetFrameRate() const; // frames/second
size_t getRenderFrameCount() const { return _renderFrameCount; }
float getRenderLoopRate() const { return _renderLoopCounter.rate(); }
float getTargetRenderFrameRate() const; // frames/second
float getFieldOfView() { return _fieldOfView.get(); }
void setFieldOfView(float fov);
@ -266,8 +265,7 @@ public:
void updateMyAvatarLookAtPosition();
float getAvatarSimrate() const { return _avatarSimCounter.rate(); }
float getAverageSimsPerSecond() const { return _simCounter.rate(); }
float getGameLoopRate() const { return _gameLoopCounter.rate(); }
void takeSnapshot(bool notify, bool includeAnimated = false, float aspectRatio = 0.0f);
void takeSecondaryCameraSnapshot();
@ -531,12 +529,11 @@ private:
QUndoStack _undoStack;
UndoStackScriptingInterface _undoStackScriptingInterface;
uint32_t _frameCount { 0 };
uint32_t _renderFrameCount { 0 };
// Frame Rate Measurement
RateCounter<> _frameCounter;
RateCounter<> _avatarSimCounter;
RateCounter<> _simCounter;
RateCounter<500> _renderLoopCounter;
RateCounter<500> _gameLoopCounter;
QTimer _minimizedWindowTimer;
QElapsedTimer _timerStart;

View file

@ -252,11 +252,12 @@ void AvatarManager::updateOtherAvatars(float deltaTime) {
qApp->getMain3DScene()->enqueueTransaction(transaction);
}
_avatarSimulationTime = (float)(usecTimestampNow() - startTime) / (float)USECS_PER_MSEC;
_numAvatarsUpdated = numAvatarsUpdated;
_numAvatarsNotUpdated = numAVatarsNotUpdated;
simulateAvatarFades(deltaTime);
_avatarSimulationTime = (float)(usecTimestampNow() - startTime) / (float)USECS_PER_MSEC;
}
void AvatarManager::postUpdate(float deltaTime, const render::ScenePointer& scene) {

View file

@ -22,16 +22,14 @@ class RatesScriptingInterface : public QObject {
Q_PROPERTY(float newFrame READ getNewFrameRate)
Q_PROPERTY(float dropped READ getDropRate)
Q_PROPERTY(float simulation READ getSimulationRate)
Q_PROPERTY(float avatar READ getAvatarRate)
public:
RatesScriptingInterface(QObject* parent) : QObject(parent) {}
float getRenderRate() { return qApp->getFps(); }
float getRenderRate() { return qApp->getRenderLoopRate(); }
float getPresentRate() { return qApp->getActiveDisplayPlugin()->presentRate(); }
float getNewFrameRate() { return qApp->getActiveDisplayPlugin()->newFramePresentRate(); }
float getDropRate() { return qApp->getActiveDisplayPlugin()->droppedFrameRate(); }
float getSimulationRate() { return qApp->getAverageSimsPerSecond(); }
float getAvatarRate() { return qApp->getAvatarSimrate(); }
float getSimulationRate() { return qApp->getGameLoopRate(); }
};
#endif // HIFI_INTERFACE_RATES_SCRIPTING_INTERFACE_H

View file

@ -8,6 +8,7 @@
#include "Stats.h"
#include <queue>
#include <sstream>
#include <QFontDatabase>
@ -116,12 +117,6 @@ void Stats::updateStats(bool force) {
}
}
bool shouldDisplayTimingDetail = Menu::getInstance()->isOptionChecked(MenuOption::DisplayDebugTimingDetails) &&
Menu::getInstance()->isOptionChecked(MenuOption::Stats) && isExpanded();
if (shouldDisplayTimingDetail != PerformanceTimer::isActive()) {
PerformanceTimer::setActive(shouldDisplayTimingDetail);
}
auto nodeList = DependencyManager::get<NodeList>();
auto avatarManager = DependencyManager::get<AvatarManager>();
// we need to take one avatar out so we don't include ourselves
@ -129,7 +124,7 @@ void Stats::updateStats(bool force) {
STAT_UPDATE(updatedAvatarCount, avatarManager->getNumAvatarsUpdated());
STAT_UPDATE(notUpdatedAvatarCount, avatarManager->getNumAvatarsNotUpdated());
STAT_UPDATE(serverCount, (int)nodeList->size());
STAT_UPDATE_FLOAT(framerate, qApp->getFps(), 0.1f);
STAT_UPDATE_FLOAT(renderrate, qApp->getRenderLoopRate(), 0.1f);
if (qApp->getActiveDisplayPlugin()) {
auto displayPlugin = qApp->getActiveDisplayPlugin();
auto stats = displayPlugin->getHardwareStats();
@ -137,7 +132,6 @@ void Stats::updateStats(bool force) {
STAT_UPDATE(longrenders, stats["long_render_count"].toInt());
STAT_UPDATE(longsubmits, stats["long_submit_count"].toInt());
STAT_UPDATE(longframes, stats["long_frame_count"].toInt());
STAT_UPDATE_FLOAT(renderrate, displayPlugin->renderRate(), 0.1f);
STAT_UPDATE_FLOAT(presentrate, displayPlugin->presentRate(), 0.1f);
STAT_UPDATE_FLOAT(presentnewrate, displayPlugin->newFramePresentRate(), 0.1f);
STAT_UPDATE_FLOAT(presentdroprate, displayPlugin->droppedFrameRate(), 0.1f);
@ -150,8 +144,7 @@ void Stats::updateStats(bool force) {
STAT_UPDATE(presentnewrate, -1);
STAT_UPDATE(presentdroprate, -1);
}
STAT_UPDATE(simrate, (int)qApp->getAverageSimsPerSecond());
STAT_UPDATE(avatarSimrate, (int)qApp->getAvatarSimrate());
STAT_UPDATE(gameLoopRate, (int)qApp->getGameLoopRate());
auto bandwidthRecorder = DependencyManager::get<BandwidthRecorder>();
STAT_UPDATE(packetInCount, (int)bandwidthRecorder->getCachedTotalAverageInputPacketsPerSecond());
@ -406,14 +399,21 @@ void Stats::updateStats(bool force) {
STAT_UPDATE(lodStatus, "You can see " + DependencyManager::get<LODManager>()->getLODFeedbackText());
}
bool performanceTimerIsActive = PerformanceTimer::isActive();
bool displayPerf = _expanded && Menu::getInstance()->isOptionChecked(MenuOption::DisplayDebugTimingDetails);
if (displayPerf && performanceTimerIsActive) {
if (!_timingExpanded) {
_timingExpanded = true;
bool performanceTimerShouldBeActive = Menu::getInstance()->isOptionChecked(MenuOption::Stats) && _expanded;
if (performanceTimerShouldBeActive != PerformanceTimer::isActive()) {
PerformanceTimer::setActive(performanceTimerShouldBeActive);
}
if (performanceTimerShouldBeActive) {
PerformanceTimer::tallyAllTimerRecords(); // do this even if we're not displaying them, so they don't stack up
}
if (performanceTimerShouldBeActive &&
Menu::getInstance()->isOptionChecked(MenuOption::DisplayDebugTimingDetails)) {
if (!_showTimingDetails) {
_showTimingDetails = true;
emit timingExpandedChanged();
}
PerformanceTimer::tallyAllTimerRecords(); // do this even if we're not displaying them, so they don't stack up
// we will also include room for 1 line per timing record and a header of 4 lines
// Timing details...
@ -453,10 +453,55 @@ void Stats::updateStats(bool force) {
}
_timingStats = perfLines;
emit timingStatsChanged();
} else if (_timingExpanded) {
_timingExpanded = false;
} else if (_showTimingDetails) {
_showTimingDetails = false;
emit timingExpandedChanged();
}
if (_expanded && performanceTimerShouldBeActive) {
if (!_showGameUpdateStats) {
_showGameUpdateStats = true;
}
class SortableStat {
public:
SortableStat(QString a, float p) : message(a), priority(p) {}
QString message;
float priority;
bool operator<(const SortableStat& other) const { return priority < other.priority; }
};
const QMap<QString, PerformanceTimerRecord>& allRecords = PerformanceTimer::getAllTimerRecords();
std::priority_queue<SortableStat> idleUpdateStats;
auto itr = allRecords.find("/idle/update");
if (itr != allRecords.end()) {
float dt = (float)itr.value().getMovingAverage() / (float)USECS_PER_MSEC;
_gameUpdateStats = QString("/idle/update = %1 ms").arg(dt);
QVector<QString> categories = { "devices", "physics", "otherAvatars", "MyAvatar", "misc" };
for (int32_t j = 0; j < categories.size(); ++j) {
QString recordKey = "/idle/update/" + categories[j];
itr = allRecords.find(recordKey);
if (itr != allRecords.end()) {
float dt = (float)itr.value().getMovingAverage() / (float)USECS_PER_MSEC;
QString message = QString("\n %1 = %2").arg(categories[j]).arg(dt);
idleUpdateStats.push(SortableStat(message, dt));
}
}
while (!idleUpdateStats.empty()) {
SortableStat stat = idleUpdateStats.top();
_gameUpdateStats += stat.message;
idleUpdateStats.pop();
}
emit gameUpdateStatsChanged();
} else if (_gameUpdateStats != "") {
_gameUpdateStats = "";
emit gameUpdateStatsChanged();
}
} else if (_showGameUpdateStats) {
_showGameUpdateStats = false;
_gameUpdateStats = "";
emit gameUpdateStatsChanged();
}
}
void Stats::setRenderDetails(const render::RenderDetails& details) {

View file

@ -32,8 +32,6 @@ class Stats : public QQuickItem {
STATS_PROPERTY(int, serverCount, 0)
// How often the app is creating new gpu::Frames
STATS_PROPERTY(float, framerate, 0)
// How often the display plugin is executing a given frame
STATS_PROPERTY(float, renderrate, 0)
// How often the display plugin is presenting to the device
STATS_PROPERTY(float, presentrate, 0)
@ -47,8 +45,7 @@ class Stats : public QQuickItem {
STATS_PROPERTY(float, presentnewrate, 0)
STATS_PROPERTY(float, presentdroprate, 0)
STATS_PROPERTY(int, simrate, 0)
STATS_PROPERTY(int, avatarSimrate, 0)
STATS_PROPERTY(int, gameLoopRate, 0)
STATS_PROPERTY(int, avatarCount, 0)
STATS_PROPERTY(int, updatedAvatarCount, 0)
STATS_PROPERTY(int, notUpdatedAvatarCount, 0)
@ -108,6 +105,7 @@ class Stats : public QQuickItem {
STATS_PROPERTY(QString, packetStats, QString())
STATS_PROPERTY(QString, lodStatus, QString())
STATS_PROPERTY(QString, timingStats, QString())
STATS_PROPERTY(QString, gameUpdateStats, QString())
STATS_PROPERTY(int, serverElements, 0)
STATS_PROPERTY(int, serverInternal, 0)
STATS_PROPERTY(int, serverLeaves, 0)
@ -148,7 +146,7 @@ public:
void updateStats(bool force = false);
bool isExpanded() { return _expanded; }
bool isTimingExpanded() { return _timingExpanded; }
bool isTimingExpanded() { return _showTimingDetails; }
void setExpanded(bool expanded) {
if (_expanded != expanded) {
@ -167,7 +165,6 @@ signals:
void longrendersChanged();
void longframesChanged();
void appdroppedChanged();
void framerateChanged();
void expandedChanged();
void timingExpandedChanged();
void serverCountChanged();
@ -176,8 +173,7 @@ signals:
void presentnewrateChanged();
void presentdroprateChanged();
void stutterrateChanged();
void simrateChanged();
void avatarSimrateChanged();
void gameLoopRateChanged();
void avatarCountChanged();
void updatedAvatarCountChanged();
void notUpdatedAvatarCountChanged();
@ -242,6 +238,7 @@ signals:
void localInternalChanged();
void localLeavesChanged();
void timingStatsChanged();
void gameUpdateStatsChanged();
void glContextSwapchainMemoryChanged();
void qmlTextureMemoryChanged();
void texturePendingTransfersChanged();
@ -267,7 +264,8 @@ private:
int _recentMaxPackets{ 0 } ; // recent max incoming voxel packets to process
bool _resetRecentMaxPacketsSoon{ true };
bool _expanded{ false };
bool _timingExpanded{ false };
bool _showTimingDetails{ false };
bool _showGameUpdateStats{ false };
QString _monospaceFont;
const AudioIOStats* _audioStats;
QStringList _downloadUrls = QStringList();

View file

@ -129,10 +129,10 @@ protected:
bool _vsyncEnabled { true };
QThread* _presentThread{ nullptr };
std::queue<gpu::FramePointer> _newFrameQueue;
RateCounter<100> _droppedFrameRate;
RateCounter<100> _newFrameRate;
RateCounter<100> _presentRate;
RateCounter<100> _renderRate;
RateCounter<200> _droppedFrameRate;
RateCounter<200> _newFrameRate;
RateCounter<200> _presentRate;
RateCounter<200> _renderRate;
gpu::FramePointer _currentFrame;
gpu::Frame* _lastFrame { nullptr };

View file

@ -151,7 +151,7 @@ void DrawSceneOctree::run(const RenderContextPointer& renderContext, const ItemS
float angle = glm::degrees(getAccuracyAngle(args->_sizeScale, args->_boundaryLevelAdjust));
Transform crosshairModel;
crosshairModel.setTranslation(glm::vec3(0.0, 0.0, -1000.0));
crosshairModel.setScale(1000.0 * tan(glm::radians(angle))); // Scaling at the actual tan of the lod angle => Multiplied by TWO
crosshairModel.setScale(1000.0f * tanf(glm::radians(angle))); // Scaling at the actual tan of the lod angle => Multiplied by TWO
batch.resetViewTransform();
batch.setModelTransform(crosshairModel);
batch.setPipeline(getDrawLODReticlePipeline());

View file

@ -45,7 +45,7 @@ Camera::Camera() :
{
}
void Camera::update(float deltaTime) {
void Camera::update() {
if (_isKeepLookingAt) {
lookAt(_lookingAt);
}

View file

@ -53,7 +53,7 @@ public:
void initialize(); // instantly put the camera at the ideal position and orientation.
void update( float deltaTime );
void update();
CameraMode getMode() const { return _mode; }
void setMode(CameraMode m);

View file

@ -35,19 +35,19 @@ public:
uint32_t interval() const { return INTERVAL; }
private:
mutable uint64_t _start { usecTimestampNow() };
mutable uint64_t _expiry { usecTimestampNow() + INTERVAL * USECS_PER_MSEC};
mutable size_t _count { 0 };
const float _scale { powf(10, PRECISION) };
mutable std::atomic<float> _rate;
void checkRate() const {
auto now = usecTimestampNow();
float currentIntervalMs = (now - _start) / (float)USECS_PER_MSEC;
if (currentIntervalMs > (float)INTERVAL) {
float currentCount = _count;
float intervalSeconds = currentIntervalMs / (float)MSECS_PER_SECOND;
_rate = roundf(currentCount / intervalSeconds * _scale) / _scale;
_start = now;
if (now > _expiry) {
float MSECS_PER_USEC = 0.001f;
float SECS_PER_MSEC = 0.001f;
float intervalSeconds = ((float)INTERVAL + (float)(now - _expiry) * MSECS_PER_USEC) * SECS_PER_MSEC;
_rate = roundf((float)_count / intervalSeconds * _scale) / _scale;
_expiry = now + INTERVAL * USECS_PER_MSEC;
_count = 0;
};
}