Add experimental "slow frames" stat, available in "show stats" and via the monitoring module.

This increments a SlowFrames counter if a frame takes over 120% of maximum time.
This commit also introduces a generic OpenSim.Framework.Monitoring.Stat which is available to any code that wants to register a statistic.
This is more granualar than asking objects to create their own reports.
At some point this will supersede earlier IMonitor and IAlert facilities in MonitoringModule which are only available to scene code.

3 files changed, 158 insertions, 2 deletions

diff --git a/OpenSim/Framework/Monitoring/SimExtraStatsCollector.cs b/OpenSim/Framework/Monitoring/SimExtraStatsCollector.cs
index cdd7cc7..8ac9090 100644
--- a/OpenSim/Framework/Monitoring/SimExtraStatsCollector.cs
+++ b/OpenSim/Framework/Monitoring/SimExtraStatsCollector.cs
@@ -355,10 +355,19 @@ Asset service request failures: {3}" + Environment.NewLine,
             sb.Append(Environment.NewLine);
             sb.Append(
                 string.Format(
-                    "{0,6:0}  {1,6:0}  {2,6:0}  {3,6:0}  {4,6:0}  {5,6:0.0}  {6,6:0.0}  {7,6:0.0}  {8,6:0.0}  {9,6:0.0}  {10,6:0.0}",
+                    "{0,6:0}  {1,6:0}  {2,6:0}  {3,6:0}  {4,6:0}  {5,6:0.0}  {6,6:0.0}  {7,6:0.0}  {8,6:0.0}  {9,6:0.0}  {10,6:0.0}\n\n",
                     inPacketsPerSecond, outPacketsPerSecond, pendingDownloads, pendingUploads, unackedBytes, totalFrameTime,
                     netFrameTime, physicsFrameTime, otherFrameTime, agentFrameTime, imageFrameTime));
-            sb.Append(Environment.NewLine);
+
+            foreach (KeyValuePair<string, Stat> kvp in StatsManager.RegisteredStats)
+            {
+                Stat stat = kvp.Value;
+
+                if (stat.Category == "scene" && stat.Verbosity == StatVerbosity.Info)
+                {
+                    sb.AppendFormat("Slow frames ({0}): {1}\n", stat.Container, stat.Value);
+                }
+            }
 
             /*
             sb.Append(Environment.NewLine);
diff --git a/OpenSim/Framework/Monitoring/StatsManager.cs b/OpenSim/Framework/Monitoring/StatsManager.cs
index d78fa6a..02df0ac 100644
--- a/OpenSim/Framework/Monitoring/StatsManager.cs
+++ b/OpenSim/Framework/Monitoring/StatsManager.cs
@@ -25,6 +25,9 @@
  * SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
  */
 
+using System;
+using System.Collections.Generic;
+
 namespace OpenSim.Framework.Monitoring
 {
     /// <summary>
@@ -32,6 +35,14 @@ namespace OpenSim.Framework.Monitoring
     /// </summary>
     public class StatsManager
     {
+        /// <summary>
+        /// Registered stats.
+        /// </summary>
+        /// <remarks>
+        /// Do not add or remove from this dictionary.
+        /// </remarks>
+        public static Dictionary<string, Stat> RegisteredStats = new Dictionary<string, Stat>();
+
         private static AssetStatsCollector assetStats;
         private static UserStatsCollector userStats;
         private static SimExtraStatsCollector simExtraStats = new SimExtraStatsCollector();
@@ -61,5 +72,108 @@ namespace OpenSim.Framework.Monitoring
 
             return userStats;
         }
+
+        public static bool RegisterStat(Stat stat)
+        {
+            lock (RegisteredStats)
+            {
+                if (RegisteredStats.ContainsKey(stat.UniqueName))
+                {
+                    // XXX: For now just return false.  This is to avoid problems in regression tests where all tests
+                    // in a class are run in the same instance of the VM.
+                    return false;
+
+//                    throw new Exception(
+//                        "StatsManager already contains stat with ShortName {0} in Category {1}", stat.ShortName, stat.Category);
+                }
+
+                // We take a replace-on-write approach here so that we don't need to generate a new Dictionary
+                Dictionary<string, Stat> newRegisteredStats = new Dictionary<string, Stat>(RegisteredStats);
+                newRegisteredStats[stat.UniqueName] = stat;
+                RegisteredStats = newRegisteredStats;
+            }
+
+            return true;
+        }
+
+        public static bool DeregisterStat(Stat stat)
+        {
+            lock (RegisteredStats)
+            {
+                if (!RegisteredStats.ContainsKey(stat.UniqueName))
+                    return false;
+
+                Dictionary<string, Stat> newRegisteredStats = new Dictionary<string, Stat>(RegisteredStats);
+                newRegisteredStats.Remove(stat.UniqueName);
+                RegisteredStats = newRegisteredStats;
+
+                return true;
+            }
+        }
+    }
+
+    /// <summary>
+    /// Verbosity of stat.
+    /// </summary>
+    /// <remarks>
+    /// Info will always be displayed.
+    /// </remarks>
+    public enum StatVerbosity
+    {
+        Debug,
+        Info
+    }
+
+    /// <summary>
+    /// Holds individual static details
+    /// </summary>
+    public class Stat
+    {
+        /// <summary>
+        /// Unique stat name used for indexing.  Each ShortName in a Category must be unique.
+        /// </summary>
+        public string UniqueName { get; private set; }
+
+        /// <summary>
+        /// Category of this stat (e.g. cache, scene, etc).
+        /// </summary>
+        public string Category { get; private set; }
+
+        /// <summary>
+        /// Containing name for this stat.
+        /// FIXME: In the case of a scene, this is currently the scene name (though this leaves
+        /// us with a to-be-resolved problem of non-unique region names).
+        /// </summary>
+        /// <value>
+        /// The container.
+        /// </value>
+        public string Container { get; private set; }
+
+        public StatVerbosity Verbosity { get; private set; }
+        public string ShortName { get; private set; }
+        public string Name { get; private set; }
+        public string Description { get; private set; }
+        public string UnitName { get; private set; }
+
+        public double Value { get; set; }
+
+        public Stat(
+            string shortName, string name, string unitName, string category, string container, StatVerbosity verbosity, string description)
+        {
+            ShortName = shortName;
+            Name = name;
+            UnitName = unitName;
+            Category = category;
+            Container = container;
+            Verbosity = verbosity;
+            Description = description;
+
+            UniqueName = GenUniqueName(Container, Category, ShortName);
+        }
+
+        public static string GenUniqueName(string container, string category, string shortName)
+        {
+            return string.Format("{0}+{1}+{2}", container, category, shortName);
+        }
     }
 }
\ No newline at end of file
diff --git a/OpenSim/Region/Framework/Scenes/SimStatsReporter.cs b/OpenSim/Region/Framework/Scenes/SimStatsReporter.cs
index 96317c3..b7b5ea2 100644
--- a/OpenSim/Region/Framework/Scenes/SimStatsReporter.cs
+++ b/OpenSim/Region/Framework/Scenes/SimStatsReporter.cs
@@ -47,6 +47,7 @@ namespace OpenSim.Region.Framework.Scenes
             = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);
 
         public const string LastReportedObjectUpdateStatName = "LastReportedObjectUpdates";
+        public const string SlowFramesStatName = "SlowFrames";
 
         public delegate void SendStatResult(SimStats stats);
 
@@ -129,6 +130,16 @@ namespace OpenSim.Region.Framework.Scenes
         }
 
         /// <summary>
+        /// Number of frames that have taken longer to process than Scene.MIN_FRAME_TIME
+        /// </summary>
+        public Stat SlowFramesStat { get; private set; }
+
+        /// <summary>
+        /// The threshold at which we log a slow frame.
+        /// </summary>
+        public int SlowFramesStatReportThreshold { get; private set; }
+
+        /// <summary>
         /// Extra sim statistics that are used by monitors but not sent to the client.
         /// </summary>
         /// <value>
@@ -225,6 +236,22 @@ namespace OpenSim.Region.Framework.Scenes
 
             if (StatsManager.SimExtraStats != null)
                 OnSendStatsResult += StatsManager.SimExtraStats.ReceiveClassicSimStatsPacket;
+
+            /// At the moment, we'll only report if a frame is over 120% of target, since commonly frames are a bit
+            /// longer than ideal (which in itself is a concern).
+            SlowFramesStatReportThreshold = (int)Math.Ceiling(m_scene.MinFrameTime * 1000 * 1.2);
+
+            SlowFramesStat
+                = new Stat(
+                    "SlowFrames",
+                    "Slow Frames",
+                    "frames",
+                    "scene",
+                    m_scene.Name,
+                    StatVerbosity.Info,
+                    "Number of frames where frame time has been significantly longer than the desired frame time.");
+
+            StatsManager.RegisterStat(SlowFramesStat);
         }
 
         public void Close()
@@ -418,6 +445,7 @@ namespace OpenSim.Region.Framework.Scenes
                 lock (m_lastReportedExtraSimStats)
                 {
                     m_lastReportedExtraSimStats[LastReportedObjectUpdateStatName] = m_objectUpdates / m_statsUpdateFactor;
+                    m_lastReportedExtraSimStats[SlowFramesStat.ShortName] = (float)SlowFramesStat.Value;
 
                     Dictionary<string, float> physicsStats = m_scene.PhysicsScene.GetStats();
     
@@ -535,6 +563,11 @@ namespace OpenSim.Region.Framework.Scenes
         public void addFrameMS(int ms)
         {
             m_frameMS += ms;
+
+            // At the moment, we'll only report if a frame is over 120% of target, since commonly frames are a bit
+            // longer than ideal due to the inaccuracy of the Sleep in Scene.Update() (which in itself is a concern).
+            if (ms > SlowFramesStatReportThreshold)
+                SlowFramesStat.Value++;
         }
 
         public void AddSpareMS(int ms)