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.

2 files changed, 124 insertions, 78 deletions

diff --git a/OpenSim/Region/Framework/Scenes/Scene.cs b/OpenSim/Region/Framework/Scenes/Scene.cs
index 702e322..ae35cb9 100644
--- a/OpenSim/Region/Framework/Scenes/Scene.cs
+++ b/OpenSim/Region/Framework/Scenes/Scene.cs
@@ -219,6 +219,7 @@ namespace OpenSim.Region.Framework.Scenes
         private int backupMS;
         private int terrainMS;
         private int landMS;
+        private int spareMS;
 
         /// <summary>
         /// Tick at which the last frame was processed.
@@ -1360,43 +1361,41 @@ 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
                 {
                     // Apply taints in terrain module to terrain in physics scene
                     if (Frame % m_update_terrain == 0)
                     {
-                        terMS = Util.EnvironmentTickCount();
+                        tmpMS = Util.EnvironmentTickCount();
                         UpdateTerrain();
-                        terrainMS = Util.EnvironmentTickCountSubtract(terMS);
+                        terrainMS = Util.EnvironmentTickCountSubtract(tmpMS);
                     }
 
-                    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)
@@ -1405,9 +1404,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();
@@ -1422,29 +1421,29 @@ 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_land == 0)
@@ -1453,24 +1452,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)
                     {
@@ -1521,13 +1502,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 11c321b..88e0b05 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;
 
+        /// <summary>
+        /// These are the IDs of stats sent in the StatsPacket to the viewer.
+        /// </summary>
+        /// <remarks>
+        /// 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).
+        /// </remarks>
         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
         }
 
         /// <summary>
@@ -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;
 
         /// <summary>
         /// 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;
 
         /// <summary>
         /// Number of agent updates requested in this stats cycle
         /// </summary>
-        private int m_agentUpdates = 0;
+        private int m_agentUpdates;
 
         /// <summary>
         /// Number of object updates requested in this stats cycle
         /// </summary>
         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;