From 280d005d55ba31a634144fae00ae4db2eb2609ae Mon Sep 17 00:00:00 2001 From: "Justin Clark-Casey (justincc)" Date: Tue, 5 Jun 2012 00:17:55 +0100 Subject: [PATCH] Start sending spare frame time MS viewer stat. Make frame time correctly display total frame time, not just non-spare time. This makes it easier to see when components of frame time exceed normal permitted frame time. Currently reflect scene frame times. --- OpenSim/Region/Framework/Scenes/Scene.cs | 91 +++++++------- .../Framework/Scenes/SimStatsReporter.cs | 112 ++++++++++++------ 2 files changed, 125 insertions(+), 78 deletions(-) diff --git a/OpenSim/Region/Framework/Scenes/Scene.cs b/OpenSim/Region/Framework/Scenes/Scene.cs index e7f79b537f..ff08303ae8 100644 --- a/OpenSim/Region/Framework/Scenes/Scene.cs +++ b/OpenSim/Region/Framework/Scenes/Scene.cs @@ -218,6 +218,7 @@ namespace OpenSim.Region.Framework.Scenes private int backupMS; private int terrainMS; private int landMS; + private int spareMS; /// /// Tick at which the last frame was processed. @@ -1341,35 +1342,34 @@ namespace OpenSim.Region.Framework.Scenes endFrame = Frame + frames; float physicsFPS = 0f; - int tmpPhysicsMS, tmpPhysicsMS2, tmpAgentMS, tmpTempOnRezMS, evMS, backMS, terMS; - int previousFrameTick; - int maintc; + int previousFrameTick, tmpMS; + int maintc = Util.EnvironmentTickCount(); while (!m_shuttingDown && (endFrame == null || Frame < endFrame)) { - maintc = Util.EnvironmentTickCount(); ++Frame; // m_log.DebugFormat("[SCENE]: Processing frame {0} in {1}", Frame, RegionInfo.RegionName); - agentMS = tempOnRezMS = eventMS = backupMS = terrainMS = landMS = 0; + agentMS = tempOnRezMS = eventMS = backupMS = terrainMS = landMS = spareMS = 0; try { - tmpPhysicsMS2 = Util.EnvironmentTickCount(); + tmpMS = Util.EnvironmentTickCount(); + if ((Frame % m_update_physics == 0) && m_physics_enabled) m_sceneGraph.UpdatePreparePhysics(); - physicsMS2 = Util.EnvironmentTickCountSubtract(tmpPhysicsMS2); + physicsMS2 = Util.EnvironmentTickCountSubtract(tmpMS); // Apply any pending avatar force input to the avatar's velocity - tmpAgentMS = Util.EnvironmentTickCount(); + tmpMS = Util.EnvironmentTickCount(); if (Frame % m_update_entitymovement == 0) m_sceneGraph.UpdateScenePresenceMovement(); - agentMS = Util.EnvironmentTickCountSubtract(tmpAgentMS); + agentMS = Util.EnvironmentTickCountSubtract(tmpMS); // Perform the main physics update. This will do the actual work of moving objects and avatars according to their // velocity - tmpPhysicsMS = Util.EnvironmentTickCount(); + tmpMS = Util.EnvironmentTickCount(); if (Frame % m_update_physics == 0) { if (m_physics_enabled) @@ -1378,9 +1378,9 @@ namespace OpenSim.Region.Framework.Scenes if (SynchronizeScene != null) SynchronizeScene(this); } - physicsMS = Util.EnvironmentTickCountSubtract(tmpPhysicsMS); + physicsMS = Util.EnvironmentTickCountSubtract(tmpMS); - tmpAgentMS = Util.EnvironmentTickCount(); + tmpMS = Util.EnvironmentTickCount(); // Check if any objects have reached their targets CheckAtTargets(); @@ -1395,36 +1395,36 @@ namespace OpenSim.Region.Framework.Scenes if (Frame % m_update_presences == 0) m_sceneGraph.UpdatePresences(); - agentMS += Util.EnvironmentTickCountSubtract(tmpAgentMS); + agentMS += Util.EnvironmentTickCountSubtract(tmpMS); // Delete temp-on-rez stuff if (Frame % m_update_temp_cleaning == 0 && !m_cleaningTemps) { - tmpTempOnRezMS = Util.EnvironmentTickCount(); + tmpMS = Util.EnvironmentTickCount(); m_cleaningTemps = true; Util.FireAndForget(delegate { CleanTempObjects(); m_cleaningTemps = false; }); - tempOnRezMS = Util.EnvironmentTickCountSubtract(tmpTempOnRezMS); + tempOnRezMS = Util.EnvironmentTickCountSubtract(tmpMS); } if (Frame % m_update_events == 0) { - evMS = Util.EnvironmentTickCount(); + tmpMS = Util.EnvironmentTickCount(); UpdateEvents(); - eventMS = Util.EnvironmentTickCountSubtract(evMS); + eventMS = Util.EnvironmentTickCountSubtract(tmpMS); } if (Frame % m_update_backup == 0) { - backMS = Util.EnvironmentTickCount(); + tmpMS = Util.EnvironmentTickCount(); UpdateStorageBackup(); - backupMS = Util.EnvironmentTickCountSubtract(backMS); + backupMS = Util.EnvironmentTickCountSubtract(tmpMS); } if (Frame % m_update_terrain == 0) { - terMS = Util.EnvironmentTickCount(); + tmpMS = Util.EnvironmentTickCount(); UpdateTerrain(); - terrainMS = Util.EnvironmentTickCountSubtract(terMS); + terrainMS = Util.EnvironmentTickCountSubtract(tmpMS); } //if (Frame % m_update_land == 0) @@ -1433,24 +1433,6 @@ namespace OpenSim.Region.Framework.Scenes // UpdateLand(); // landMS = Util.EnvironmentTickCountSubtract(ldMS); //} - - frameMS = Util.EnvironmentTickCountSubtract(maintc); - otherMS = tempOnRezMS + eventMS + backupMS + terrainMS + landMS; - - // if (Frame%m_update_avatars == 0) - // UpdateInWorldTime(); - StatsReporter.AddPhysicsFPS(physicsFPS); - StatsReporter.AddTimeDilation(TimeDilation); - StatsReporter.AddFPS(1); - - // frameMS currently records work frame times, not total frame times (work + any required sleep to - // reach min frame time. - StatsReporter.addFrameMS(frameMS); - - StatsReporter.addAgentMS(agentMS); - StatsReporter.addPhysicsMS(physicsMS + physicsMS2); - StatsReporter.addOtherMS(otherMS); - StatsReporter.addScriptLines(m_sceneGraph.GetScriptLPS()); if (LoginsDisabled && Frame == 20) { @@ -1501,13 +1483,34 @@ namespace OpenSim.Region.Framework.Scenes previousFrameTick = m_lastFrameTick; m_lastFrameTick = Util.EnvironmentTickCount(); - maintc = Util.EnvironmentTickCountSubtract(m_lastFrameTick, maintc); - maintc = (int)(MinFrameTime * 1000) - maintc; + tmpMS = Util.EnvironmentTickCountSubtract(m_lastFrameTick, maintc); + tmpMS = (int)(MinFrameTime * 1000) - tmpMS; - if (maintc > 0) - Thread.Sleep(maintc); + if (tmpMS > 0) + { + Thread.Sleep(tmpMS); + spareMS += tmpMS; + } - // Optionally warn if a frame takes double the amount of time that it should. + frameMS = Util.EnvironmentTickCountSubtract(maintc); + maintc = Util.EnvironmentTickCount(); + + otherMS = tempOnRezMS + eventMS + backupMS + terrainMS + landMS; + + // if (Frame%m_update_avatars == 0) + // UpdateInWorldTime(); + StatsReporter.AddPhysicsFPS(physicsFPS); + StatsReporter.AddTimeDilation(TimeDilation); + StatsReporter.AddFPS(1); + + StatsReporter.addFrameMS(frameMS); + StatsReporter.addAgentMS(agentMS); + StatsReporter.addPhysicsMS(physicsMS + physicsMS2); + StatsReporter.addOtherMS(otherMS); + StatsReporter.AddSpareMS(spareMS); + StatsReporter.addScriptLines(m_sceneGraph.GetScriptLPS()); + + // Optionally warn if a frame takes double the amount of time that it should. if (DebugUpdates && Util.EnvironmentTickCountSubtract( m_lastFrameTick, previousFrameTick) > (int)(MinFrameTime * 1000 * 2)) diff --git a/OpenSim/Region/Framework/Scenes/SimStatsReporter.cs b/OpenSim/Region/Framework/Scenes/SimStatsReporter.cs index 11c321bec0..88e0b05369 100644 --- a/OpenSim/Region/Framework/Scenes/SimStatsReporter.cs +++ b/OpenSim/Region/Framework/Scenes/SimStatsReporter.cs @@ -56,10 +56,17 @@ namespace OpenSim.Region.Framework.Scenes public event YourStatsAreWrong OnStatsIncorrect; - private SendStatResult handlerSendStatResult = null; + private SendStatResult handlerSendStatResult; - private YourStatsAreWrong handlerStatsIncorrect = null; + private YourStatsAreWrong handlerStatsIncorrect; + /// + /// These are the IDs of stats sent in the StatsPacket to the viewer. + /// + /// + /// Some of these are not relevant to OpenSimulator since it is architected differently to other simulators + /// (e.g. script instructions aren't executed as part of the frame loop so 'script time' is tricky). + /// public enum Stats : uint { TimeDilation = 0, @@ -83,7 +90,20 @@ namespace OpenSim.Region.Framework.Scenes OutPacketsPerSecond = 18, PendingDownloads = 19, PendingUploads = 20, + VirtualSizeKb = 21, + ResidentSizeKb = 22, + PendingLocalUploads = 23, UnAckedBytes = 24, + PhysicsPinnedTasks = 25, + PhysicsLodTasks = 26, + SimPhysicsStepMs = 27, + SimPhysicsShapeMs = 28, + SimPhysicsOtherMs = 29, + SimPhysicsMemory = 30, + ScriptEps = 31, + SimSpareMs = 32, + SimSleepMs = 33, + SimIoPumpTime = 34 } /// @@ -118,9 +138,9 @@ namespace OpenSim.Region.Framework.Scenes // Sending a stats update every 3 seconds- private int m_statsUpdatesEveryMS = 3000; - private float m_statsUpdateFactor = 0; - private float m_timeDilation = 0; - private int m_fps = 0; + private float m_statsUpdateFactor; + private float m_timeDilation; + private int m_fps; /// /// Number of the last frame on which we processed a stats udpate. @@ -143,41 +163,42 @@ namespace OpenSim.Region.Framework.Scenes private float m_reportedFpsCorrectionFactor = 5; // saved last reported value so there is something available for llGetRegionFPS - private float lastReportedSimFPS = 0; - private float[] lastReportedSimStats = new float[21]; - private float m_pfps = 0; + private float lastReportedSimFPS; + private float[] lastReportedSimStats = new float[22]; + private float m_pfps; /// /// Number of agent updates requested in this stats cycle /// - private int m_agentUpdates = 0; + private int m_agentUpdates; /// /// Number of object updates requested in this stats cycle /// private int m_objectUpdates; - private int m_frameMS = 0; - private int m_netMS = 0; - private int m_agentMS = 0; - private int m_physicsMS = 0; - private int m_imageMS = 0; - private int m_otherMS = 0; + private int m_frameMS; + private int m_spareMS; + private int m_netMS; + private int m_agentMS; + private int m_physicsMS; + private int m_imageMS; + private int m_otherMS; //Ckrinke: (3-21-08) Comment out to remove a compiler warning. Bring back into play when needed. //Ckrinke private int m_scriptMS = 0; - private int m_rootAgents = 0; - private int m_childAgents = 0; - private int m_numPrim = 0; - private int m_inPacketsPerSecond = 0; - private int m_outPacketsPerSecond = 0; - private int m_activePrim = 0; - private int m_unAckedBytes = 0; - private int m_pendingDownloads = 0; - private int m_pendingUploads = 0; - private int m_activeScripts = 0; - private int m_scriptLinesPerSecond = 0; + private int m_rootAgents; + private int m_childAgents; + private int m_numPrim; + private int m_inPacketsPerSecond; + private int m_outPacketsPerSecond; + private int m_activePrim; + private int m_unAckedBytes; + private int m_pendingDownloads; + private int m_pendingUploads = 0; // FIXME: Not currently filled in + private int m_activeScripts; + private int m_scriptLinesPerSecond; private int m_objectCapacity = 45000; @@ -199,7 +220,7 @@ namespace OpenSim.Region.Framework.Scenes m_objectCapacity = scene.RegionInfo.ObjectCapacity; m_report.AutoReset = true; m_report.Interval = m_statsUpdatesEveryMS; - m_report.Elapsed += statsHeartBeat; + m_report.Elapsed += TriggerStatsHeartbeat; m_report.Enabled = true; if (StatsManager.SimExtraStats != null) @@ -208,7 +229,7 @@ namespace OpenSim.Region.Framework.Scenes public void Close() { - m_report.Elapsed -= statsHeartBeat; + m_report.Elapsed -= TriggerStatsHeartbeat; m_report.Close(); } @@ -223,9 +244,23 @@ namespace OpenSim.Region.Framework.Scenes m_report.Interval = m_statsUpdatesEveryMS; } + private void TriggerStatsHeartbeat(object sender, EventArgs args) + { + try + { + statsHeartBeat(sender, args); + } + catch (Exception e) + { + m_log.Warn(string.Format( + "[SIM STATS REPORTER] Update for {0} failed with exception ", + m_scene.RegionInfo.RegionName), e); + } + } + private void statsHeartBeat(object sender, EventArgs e) { - SimStatsPacket.StatBlock[] sb = new SimStatsPacket.StatBlock[21]; + SimStatsPacket.StatBlock[] sb = new SimStatsPacket.StatBlock[22]; SimStatsPacket.RegionBlock rb = new SimStatsPacket.RegionBlock(); // Know what's not thread safe in Mono... modifying timers. @@ -292,7 +327,7 @@ namespace OpenSim.Region.Framework.Scenes if (framesUpdated == 0) framesUpdated = 1; - for (int i = 0; i < 21; i++) + for (int i = 0; i < 22; i++) { sb[i] = new SimStatsPacket.StatBlock(); } @@ -359,8 +394,11 @@ namespace OpenSim.Region.Framework.Scenes sb[20].StatID = (uint)Stats.ScriptLinesPerSecond; sb[20].StatValue = m_scriptLinesPerSecond / m_statsUpdateFactor; - - for (int i = 0; i < 21; i++) + + sb[21].StatID = (uint)Stats.SimSpareMs; + sb[21].StatValue = m_spareMS / framesUpdated; + + for (int i = 0; i < 22; i++) { lastReportedSimStats[i] = sb[i].StatValue; } @@ -398,11 +436,11 @@ namespace OpenSim.Region.Framework.Scenes } } - resetvalues(); + ResetValues(); } } - private void resetvalues() + private void ResetValues() { m_timeDilation = 0; m_fps = 0; @@ -420,6 +458,7 @@ namespace OpenSim.Region.Framework.Scenes m_physicsMS = 0; m_imageMS = 0; m_otherMS = 0; + m_spareMS = 0; //Ckrinke This variable is not used, so comment to remove compiler warning until it is used. //Ckrinke m_scriptMS = 0; @@ -498,6 +537,11 @@ namespace OpenSim.Region.Framework.Scenes m_frameMS += ms; } + public void AddSpareMS(int ms) + { + m_spareMS += ms; + } + public void addNetMS(int ms) { m_netMS += ms;