diff --git a/OpenSim/Framework/MetricsCollector.cs b/OpenSim/Framework/MetricsCollector.cs
new file mode 100644
index 0000000000..c8f4a33260
--- /dev/null
+++ b/OpenSim/Framework/MetricsCollector.cs
@@ -0,0 +1,223 @@
+using System;
+using System.Diagnostics;
+
+namespace OpenSim.Framework
+{
+ ///
+ /// A MetricsCollector for 'long' values.
+ ///
+ public class MetricsCollectorLong : MetricsCollector
+ {
+ public MetricsCollectorLong(int windowSize, int numBuckets)
+ : base(windowSize, numBuckets)
+ {
+ }
+
+ protected override long GetZero() { return 0; }
+
+ protected override long Add(long a, long b) { return a + b; }
+ }
+
+
+ ///
+ /// A MetricsCollector for time spans.
+ ///
+ public class MetricsCollectorTime : MetricsCollectorLong
+ {
+ public MetricsCollectorTime(int windowSize, int numBuckets)
+ : base(windowSize, numBuckets)
+ {
+ }
+
+ public void AddSample(Stopwatch timer)
+ {
+ long ticks = timer.ElapsedTicks;
+ if (ticks > 0)
+ AddSample(ticks);
+ }
+
+ public TimeSpan GetSumTime()
+ {
+ return TimeSpan.FromMilliseconds((GetSum() * 1000) / Stopwatch.Frequency);
+ }
+ }
+
+
+ struct MetricsBucket
+ {
+ public T value;
+ public int count;
+ }
+
+
+ ///
+ /// Collects metrics in a sliding window.
+ ///
+ ///
+ /// MetricsCollector provides the current Sum of the metrics that it collects. It can easily be extended
+ /// to provide the Average, too. It uses a sliding window to keep these values current.
+ ///
+ /// This class is not thread-safe.
+ ///
+ /// Subclass MetricsCollector to have it use a concrete value type. Override the abstract methods.
+ ///
+ public abstract class MetricsCollector
+ {
+ private int bucketSize; // e.g. 3,000 ms
+
+ private MetricsBucket[] buckets;
+
+ private int NumBuckets { get { return buckets.Length; } }
+
+
+ // The number of the current bucket, if we had an infinite number of buckets and didn't have to wrap around
+ long curBucketGlobal;
+
+ // The total of all the buckets
+ T totalSum;
+ int totalCount;
+
+
+ ///
+ /// Returns the default (zero) value.
+ ///
+ ///
+ protected abstract T GetZero();
+
+ ///
+ /// Adds two values.
+ ///
+ protected abstract T Add(T a, T b);
+
+
+ ///
+ /// Creates a MetricsCollector.
+ ///
+ /// The period of time over which to collect the metrics, in ms. E.g.: 30,000.
+ /// The number of buckets to divide the samples into. E.g.: 10. Using more buckets
+ /// smooths the jarring that occurs whenever we drop an old bucket, but uses more memory.
+ public MetricsCollector(int windowSize, int numBuckets)
+ {
+ bucketSize = windowSize / numBuckets;
+ buckets = new MetricsBucket[numBuckets];
+ Reset();
+ }
+
+ public void Reset()
+ {
+ ZeroBuckets(0, NumBuckets);
+ curBucketGlobal = GetNow() / bucketSize;
+ totalSum = GetZero();
+ totalCount = 0;
+ }
+
+ public void AddSample(T sample)
+ {
+ MoveWindow();
+
+ int curBucket = (int)(curBucketGlobal % NumBuckets);
+ buckets[curBucket].value = Add(buckets[curBucket].value, sample);
+ buckets[curBucket].count++;
+
+ totalSum = Add(totalSum, sample);
+ totalCount++;
+ }
+
+ ///
+ /// Returns the total values in the collection window.
+ ///
+ public T GetSum()
+ {
+ // It might have been a while since we last added a sample, so we may need to adjust the window
+ MoveWindow();
+
+ return totalSum;
+ }
+
+ ///
+ /// Returns the current time in ms.
+ ///
+ private long GetNow()
+ {
+ return DateTime.Now.Ticks / TimeSpan.TicksPerMillisecond;
+ }
+
+ ///
+ /// Clears the values in buckets [offset, offset+num)
+ ///
+ private void ZeroBuckets(int offset, int num)
+ {
+ for (int i = 0; i < num; i++)
+ {
+ buckets[offset + i].value = GetZero();
+ buckets[offset + i].count = 0;
+ }
+ }
+
+ ///
+ /// Adjusts the buckets so that the "current bucket" corresponds to the current time.
+ /// This may require dropping old buckets.
+ ///
+ ///
+ /// This method allows for the possibility that we don't get new samples for each bucket, so the
+ /// new bucket may be some distance away from the last used bucket.
+ ///
+ private void MoveWindow()
+ {
+ long newBucketGlobal = GetNow() / bucketSize;
+ long bucketsDistance = newBucketGlobal - curBucketGlobal;
+
+ if (bucketsDistance == 0)
+ {
+ // We're still on the same bucket as before
+ return;
+ }
+
+ if (bucketsDistance >= NumBuckets)
+ {
+ // Discard everything
+ Reset();
+ return;
+ }
+
+ int curBucket = (int)(curBucketGlobal % NumBuckets);
+ int newBucket = (int)(newBucketGlobal % NumBuckets);
+
+
+ // Clear all the buckets in this range: (cur, new]
+ int numToClear = (int)bucketsDistance;
+
+ if (curBucket < NumBuckets - 1)
+ {
+ // Clear buckets at the end of the window
+ int num = Math.Min((int)bucketsDistance, NumBuckets - (curBucket + 1));
+ ZeroBuckets(curBucket + 1, num);
+ numToClear -= num;
+ }
+
+ if (numToClear > 0)
+ {
+ // Clear buckets at the beginning of the window
+ ZeroBuckets(0, numToClear);
+ }
+
+ // Move the "current bucket" pointer
+ curBucketGlobal = newBucketGlobal;
+
+ RecalcTotal();
+ }
+
+ private void RecalcTotal()
+ {
+ totalSum = GetZero();
+ totalCount = 0;
+
+ for (int i = 0; i < NumBuckets; i++)
+ {
+ totalSum = Add(totalSum, buckets[i].value);
+ totalCount += buckets[i].count;
+ }
+ }
+
+ }
+}
diff --git a/OpenSim/Region/ScriptEngine/Interfaces/IScriptInstance.cs b/OpenSim/Region/ScriptEngine/Interfaces/IScriptInstance.cs
index fa2ceef5a2..f695eba8a7 100644
--- a/OpenSim/Region/ScriptEngine/Interfaces/IScriptInstance.cs
+++ b/OpenSim/Region/ScriptEngine/Interfaces/IScriptInstance.cs
@@ -109,14 +109,9 @@ namespace OpenSim.Region.ScriptEngine.Interfaces
DateTime TimeStarted { get; }
///
- /// Tick the last measurement period was started.
+ /// Collects information about how long the script was executed.
///
- long MeasurementPeriodTickStart { get; }
-
- ///
- /// Ticks spent executing in the last measurement period.
- ///
- long MeasurementPeriodExecutionTime { get; }
+ MetricsCollectorTime ExecutionTime { get; }
///
/// Scene part in which this script instance is contained.
diff --git a/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs b/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs
index 05dea5da98..d8ad62c7d5 100644
--- a/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs
+++ b/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs
@@ -199,11 +199,9 @@ namespace OpenSim.Region.ScriptEngine.Shared.Instance
public DateTime TimeStarted { get; private set; }
- public long MeasurementPeriodTickStart { get; private set; }
+ public MetricsCollectorTime ExecutionTime { get; private set; }
- public long MeasurementPeriodExecutionTime { get; private set; }
-
- public static readonly int MaxMeasurementPeriod = 30 * 1000; // show the *recent* time used by the script, to find currently active scripts
+ private static readonly int MeasurementWindow = 30 * 1000; // show the *recent* time used by the script, to find currently active scripts
private bool m_coopTermination;
@@ -246,6 +244,8 @@ namespace OpenSim.Region.ScriptEngine.Shared.Instance
m_SaveState = StatePersistedHere;
+ ExecutionTime = new MetricsCollectorTime(MeasurementWindow, 10);
+
// m_log.DebugFormat(
// "[SCRIPT INSTANCE]: Instantiated script instance {0} (id {1}) in part {2} (id {3}) in object {4} attached avatar {5} in {6}",
// ScriptTask.Name, ScriptTask.ItemID, Part.Name, Part.UUID, Part.ParentGroup.Name, m_AttachedAvatar, Engine.World.Name);
@@ -505,8 +505,10 @@ namespace OpenSim.Region.ScriptEngine.Shared.Instance
Running = true;
TimeStarted = DateTime.Now;
- MeasurementPeriodTickStart = Util.EnvironmentTickCount();
- MeasurementPeriodExecutionTime = 0;
+
+ // Note: we don't reset ExecutionTime. The reason is that runaway scripts are stopped and restarted
+ // automatically, and we *do* want to show that they had high CPU in that case. If we had reset
+ // ExecutionTime here then runaway scripts, paradoxically, would never show up in the "Top Scripts" dialog.
if (EventQueue.Count > 0)
{
@@ -832,20 +834,13 @@ namespace OpenSim.Region.ScriptEngine.Shared.Instance
m_EventStart = DateTime.Now;
m_InEvent = true;
- // Reset the measurement period when we reach the end of the current one.
- if (Util.EnvironmentTickCountSubtract((int)MeasurementPeriodTickStart) > MaxMeasurementPeriod)
- {
- MeasurementPeriodTickStart = Util.EnvironmentTickCount();
- MeasurementPeriodExecutionTime = 0;
- }
+ Stopwatch timer = new Stopwatch();
+ timer.Start();
- Stopwatch executionTime = new Stopwatch();
- executionTime.Start();
-
m_Script.ExecuteEvent(State, data.EventName, data.Params);
- executionTime.Stop();
- MeasurementPeriodExecutionTime += executionTime.ElapsedMilliseconds;
+ timer.Stop();
+ ExecutionTime.AddSample(timer);
m_InEvent = false;
m_CurrentEvent = String.Empty;
diff --git a/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs b/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs
index ae028779ba..5071884ed0 100755
--- a/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs
+++ b/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs
@@ -2343,7 +2343,6 @@ namespace OpenSim.Region.ScriptEngine.XEngine
public Dictionary GetObjectScriptsExecutionTimes()
{
- long tickNow = Util.EnvironmentTickCount();
Dictionary topScripts = new Dictionary();
lock (m_Scripts)
@@ -2353,7 +2352,7 @@ namespace OpenSim.Region.ScriptEngine.XEngine
if (!topScripts.ContainsKey(si.LocalID))
topScripts[si.RootLocalID] = 0;
- topScripts[si.RootLocalID] += CalculateAdjustedExectionTime(si, tickNow);
+ topScripts[si.RootLocalID] += GetExectionTime(si);
}
}
@@ -2367,7 +2366,6 @@ namespace OpenSim.Region.ScriptEngine.XEngine
return 0.0f;
}
float time = 0.0f;
- long tickNow = Util.EnvironmentTickCount();
IScriptInstance si;
// Calculate the time for all scripts that this engine is executing
// Ignore any others
@@ -2376,36 +2374,15 @@ namespace OpenSim.Region.ScriptEngine.XEngine
si = GetInstance(id);
if (si != null && si.Running)
{
- time += CalculateAdjustedExectionTime(si, tickNow);
+ time += GetExectionTime(si);
}
}
return time;
}
- private float CalculateAdjustedExectionTime(IScriptInstance si, long tickNow)
+ private float GetExectionTime(IScriptInstance si)
{
- long ticksElapsed = Util.EnvironmentTickCountSubtract((int)tickNow, (int)si.MeasurementPeriodTickStart);
-
- // Avoid divide by zero
- if (ticksElapsed == 0)
- ticksElapsed = 1;
-
- // Scale execution time to the ideal 55 fps frame time for these reasons.
- //
- // 1) XEngine does not execute scripts per frame, unlike other script engines. Hence, there is no
- // 'script execution time per frame', which is the original purpose of this value.
- //
- // 2) Giving the raw execution times is misleading since scripts start at different times, making
- // it impossible to compare scripts.
- //
- // 3) Scaling the raw execution time to the time that the script has been running is better but
- // is still misleading since a script that has just been rezzed may appear to have been running
- // for much longer.
- //
- // 4) Hence, we scale execution time to an idealised frame time (55 fps). This is also not perfect
- // since the figure does not represent actual execution time and very hard running scripts will
- // never exceed 18ms (though this is a very high number for script execution so is a warning sign).
- return ((float)si.MeasurementPeriodExecutionTime / ticksElapsed) * 18.1818f;
+ return (float)si.ExecutionTime.GetSumTime().TotalMilliseconds;
}
public void SuspendScript(UUID itemID)