2 files changed, 115 insertions, 29 deletions

diff --git a/OpenSim/Region/ScriptEngine/XEngine/Tests/XEngineTest.cs b/OpenSim/Region/ScriptEngine/XEngine/Tests/XEngineTest.cs
index f331658..5abfe9a 100644
--- a/OpenSim/Region/ScriptEngine/XEngine/Tests/XEngineTest.cs
+++ b/OpenSim/Region/ScriptEngine/XEngine/Tests/XEngineTest.cs
@@ -44,7 +44,7 @@ namespace OpenSim.Region.ScriptEngine.XEngine.Tests
     /// XEngine tests.
     /// </summary>
     [TestFixture]
-    public class XEngineTest
+    public class XEngineTest : OpenSimTestCase
     {
         private TestScene m_scene;
         private XEngine m_xEngine;
diff --git a/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs b/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs
index 9f05666..05dd7ab 100644
--- a/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs
+++ b/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs
@@ -31,6 +31,7 @@ using System.Collections.Generic;
 using System.Diagnostics; //for [DebuggerNonUserCode]
 using System.Globalization;
 using System.IO;
+using System.Linq;
 using System.Reflection;
 using System.Security;
 using System.Security.Policy;
@@ -107,6 +108,24 @@ namespace OpenSim.Region.ScriptEngine.XEngine
         private IXmlRpcRouter m_XmlRpcRouter;
         private int m_EventLimit;
         private bool m_KillTimedOutScripts;
+
+        /// <summary>
+        /// Number of milliseconds we will wait for a script event to complete on script stop before we forcibly abort
+        /// its thread.
+        /// </summary>
+        /// <remarks>
+        /// It appears that if a script thread is aborted whilst it is holding ReaderWriterLockSlim (possibly the write
+        /// lock) then the lock is not properly released.  This causes mono 2.6, 2.10 and possibly
+        /// later to crash, sometimes with symptoms such as a leap to 100% script usage and a vm thead dump showing
+        /// all threads waiting on release of ReaderWriterLockSlim write thread which none of the threads listed 
+        /// actually hold.
+        /// 
+        /// Pausing for event completion reduces the risk of this happening.  However, it may be that aborting threads
+        /// is not a mono issue per se but rather a risky activity in itself in an AppDomain that is not immediately
+        /// shutting down.
+        /// </remarks>
+        private int m_WaitForEventCompletionOnScriptStop = 1000;
+
         private string m_ScriptEnginesPath = null;
 
         private ExpiringCache<UUID, bool> m_runFlags = new ExpiringCache<UUID, bool>();
@@ -316,6 +335,9 @@ namespace OpenSim.Region.ScriptEngine.XEngine
             m_EventLimit = m_ScriptConfig.GetInt("EventLimit", 30);
             m_KillTimedOutScripts = m_ScriptConfig.GetBoolean("KillTimedOutScripts", false);
             m_SaveTime = m_ScriptConfig.GetInt("SaveInterval", 120) * 1000;
+            m_WaitForEventCompletionOnScriptStop 
+                = m_ScriptConfig.GetInt("WaitForEventCompletionOnScriptStop", m_WaitForEventCompletionOnScriptStop);
+
             m_ScriptEnginesPath = m_ScriptConfig.GetString("ScriptEnginesPath", "ScriptEngines");
 
             m_Prio = ThreadPriority.BelowNormal;
@@ -371,7 +393,7 @@ namespace OpenSim.Region.ScriptEngine.XEngine
 
             MainConsole.Instance.Commands.AddCommand(
                 "Scripts", false, "scripts show", "scripts show [<script-item-uuid>]", "Show script information",
-                "Show information on all scripts known to the script engine."
+                "Show information on all scripts known to the script engine.\n"
                     + "If a <script-item-uuid> is given then only information on that script will be shown.",
                 HandleShowScripts);
 
@@ -390,22 +412,30 @@ namespace OpenSim.Region.ScriptEngine.XEngine
             MainConsole.Instance.Commands.AddCommand(
                 "Scripts", false, "scripts resume", "scripts resume [<script-item-uuid>]", "Resumes all suspended scripts",
                 "Resumes all currently suspended scripts.\n"
-                    + "Resumed scripts will process all events accumulated whilst suspended."
+                    + "Resumed scripts will process all events accumulated whilst suspended.\n"
                     + "If a <script-item-uuid> is given then only that script will be resumed.  Otherwise, all suitable scripts are resumed.",
                 (module, cmdparams) => HandleScriptsAction(cmdparams, HandleResumeScript));
 
             MainConsole.Instance.Commands.AddCommand(
                 "Scripts", false, "scripts stop", "scripts stop [<script-item-uuid>]", "Stops all running scripts",
-                "Stops all running scripts."
+                "Stops all running scripts.\n"
                     + "If a <script-item-uuid> is given then only that script will be stopped.  Otherwise, all suitable scripts are stopped.",
                 (module, cmdparams) => HandleScriptsAction(cmdparams, HandleStopScript));
 
             MainConsole.Instance.Commands.AddCommand(
                 "Scripts", false, "scripts start", "scripts start [<script-item-uuid>]", "Starts all stopped scripts",
-                "Starts all stopped scripts."
+                "Starts all stopped scripts.\n"
                     + "If a <script-item-uuid> is given then only that script will be started.  Otherwise, all suitable scripts are started.",
                 (module, cmdparams) => HandleScriptsAction(cmdparams, HandleStartScript));
 
+            MainConsole.Instance.Commands.AddCommand(
+                "Scripts", false, "debug script log", "debug scripts log <item-id> <log-level>", "Extra debug logging for a script",
+                "Activates or deactivates extra debug logging for the given script.\n"
+                    + "Level == 0, deactivate extra debug logging.\n"
+                    + "Level >= 1, log state changes.\n"
+                    + "Level >= 2, log event invocations.\n",
+                HandleDebugScriptLogCommand);
+
 //            MainConsole.Instance.Commands.AddCommand(
 //                "Debug", false, "debug xengine", "debug xengine [<level>]",
 //                "Turn on detailed xengine debugging.",
@@ -414,6 +444,41 @@ namespace OpenSim.Region.ScriptEngine.XEngine
 //                HandleDebugLevelCommand);
         }
 
+        private void HandleDebugScriptLogCommand(string module, string[] args)
+        {
+            if (!(MainConsole.Instance.ConsoleScene == null || MainConsole.Instance.ConsoleScene == m_Scene))
+                return;
+
+            if (args.Length != 5)
+            {
+                MainConsole.Instance.Output("Usage: debug script log <item-id> <log-level>");
+                return;
+            }
+
+            UUID itemId;
+
+            if (!ConsoleUtil.TryParseConsoleUuid(MainConsole.Instance, args[3], out itemId))
+                return;
+
+            int newLevel;
+
+            if (!ConsoleUtil.TryParseConsoleInt(MainConsole.Instance, args[4], out newLevel))
+                return;
+
+            IScriptInstance si;
+
+            lock (m_Scripts)
+            {
+                // XXX: We can't give the user feedback on a bad item id because this may apply to a different script
+                // engine
+                if (!m_Scripts.TryGetValue(itemId, out si))
+                    return;
+            }
+
+            si.DebugLevel = newLevel;
+            MainConsole.Instance.OutputFormat("Set debug level of {0} {1} to {2}", si.ScriptName, si.ItemID, newLevel);
+        }
+
         /// <summary>
         /// Change debug level
         /// </summary>
@@ -445,9 +510,21 @@ namespace OpenSim.Region.ScriptEngine.XEngine
         /// </summary>
         /// <param name="cmdparams"></param>
         /// <param name="instance"></param>
-        /// <returns>true if we're okay to proceed, false if not.</returns>
+        /// <param name="comparer">Basis on which to sort output.  Can be null if no sort needs to take place</param>
         private void HandleScriptsAction(string[] cmdparams, Action<IScriptInstance> action)
         {
+            HandleScriptsAction<object>(cmdparams, action, null);
+        }
+
+        /// <summary>
+        /// Parse the raw item id into a script instance from the command params if it's present.
+        /// </summary>
+        /// <param name="cmdparams"></param>
+        /// <param name="instance"></param>
+        /// <param name="keySelector">Basis on which to sort output.  Can be null if no sort needs to take place</param>
+        private void HandleScriptsAction<TKey>(
+            string[] cmdparams, Action<IScriptInstance> action, Func<IScriptInstance, TKey> keySelector)
+        {
             if (!(MainConsole.Instance.ConsoleScene == null || MainConsole.Instance.ConsoleScene == m_Scene))
                 return;
 
@@ -458,7 +535,12 @@ namespace OpenSim.Region.ScriptEngine.XEngine
     
                 if (cmdparams.Length == 2)
                 {
-                    foreach (IScriptInstance instance in m_Scripts.Values)
+                    IEnumerable<IScriptInstance> scripts = m_Scripts.Values;
+
+                    if (keySelector != null)
+                        scripts = scripts.OrderBy<IScriptInstance, TKey>(keySelector);
+
+                    foreach (IScriptInstance instance in scripts)
                         action(instance);
 
                     return;
@@ -468,7 +550,7 @@ namespace OpenSim.Region.ScriptEngine.XEngine
     
                 if (!UUID.TryParse(rawItemId, out itemId))
                 {
-                    MainConsole.Instance.OutputFormat("Error - {0} is not a valid UUID", rawItemId);
+                    MainConsole.Instance.OutputFormat("ERROR: {0} is not a valid UUID", rawItemId);
                     return;
                 }
     
@@ -505,9 +587,20 @@ namespace OpenSim.Region.ScriptEngine.XEngine
             StringBuilder sb = new StringBuilder();
             sb.AppendFormat("Status of XEngine instance for {0}\n", m_Scene.RegionInfo.RegionName);
 
+            long scriptsLoaded, eventsQueued = 0, eventsProcessed = 0;
+
             lock (m_Scripts)
-                sb.AppendFormat("Scripts loaded             : {0}\n", m_Scripts.Count);
+            {
+                scriptsLoaded = m_Scripts.Count;
+
+                foreach (IScriptInstance si in m_Scripts.Values)
+                {
+                    eventsQueued += si.EventsQueued;
+                    eventsProcessed += si.EventsProcessed;
+                }
+            }
 
+            sb.AppendFormat("Scripts loaded             : {0}\n", scriptsLoaded);
             sb.AppendFormat("Unique scripts             : {0}\n", m_uniqueScripts.Count);
             sb.AppendFormat("Scripts waiting for load   : {0}\n", m_CompileQueue.Count);
             sb.AppendFormat("Max threads                : {0}\n", m_ThreadPool.MaxThreads);
@@ -516,6 +609,8 @@ namespace OpenSim.Region.ScriptEngine.XEngine
             sb.AppendFormat("In use threads             : {0}\n", m_ThreadPool.InUseThreads);
             sb.AppendFormat("Work items waiting         : {0}\n", m_ThreadPool.WaitingCallbacks);
 //            sb.AppendFormat("Assemblies loaded          : {0}\n", m_Assemblies.Count);
+            sb.AppendFormat("Events queued              : {0}\n", eventsQueued);
+            sb.AppendFormat("Events processed           : {0}\n", eventsProcessed);
 
             SensorRepeat sr = AsyncCommandManager.GetSensorRepeatPlugin(this);
             sb.AppendFormat("Sensors                    : {0}\n", sr != null ? sr.SensorsCount : 0);
@@ -546,7 +641,7 @@ namespace OpenSim.Region.ScriptEngine.XEngine
                 }
             }
 
-            HandleScriptsAction(cmdparams, HandleShowScript);
+            HandleScriptsAction<long>(cmdparams, HandleShowScript, si => si.EventsProcessed);
         }
 
         private void HandleShowScript(IScriptInstance instance)
@@ -576,11 +671,10 @@ namespace OpenSim.Region.ScriptEngine.XEngine
 
             sb.AppendFormat("Script name         : {0}\n", instance.ScriptName);
             sb.AppendFormat("Status              : {0}\n", status);
-
-            lock (eq)
-                sb.AppendFormat("Queued events       : {0}\n", eq.Count);
-
+            sb.AppendFormat("Queued events       : {0}\n", instance.EventsQueued);
+            sb.AppendFormat("Processed events    : {0}\n", instance.EventsProcessed);
             sb.AppendFormat("Item UUID           : {0}\n", instance.ItemID);
+            sb.AppendFormat("Asset UUID          : {0}\n", instance.AssetID);
             sb.AppendFormat("Containing part name: {0}\n", instance.PrimName);
             sb.AppendFormat("Containing part UUID: {0}\n", instance.ObjectID);
             sb.AppendFormat("Position            : {0}\n", sop.AbsolutePosition);
@@ -1089,8 +1183,7 @@ namespace OpenSim.Region.ScriptEngine.XEngine
 
             string assembly = "";
 
-            CultureInfo USCulture = new CultureInfo("en-US");
-            Thread.CurrentThread.CurrentCulture = USCulture;
+            Culture.SetCurrentCulture();
 
             Dictionary<KeyValuePair<int, int>, KeyValuePair<int, int>> linemap;
 
@@ -1347,9 +1440,7 @@ namespace OpenSim.Region.ScriptEngine.XEngine
             lockScriptsForWrite(false);
             instance.ClearQueue();
 
-            // Give the script some time to finish processing its last event.  Simply aborting the script thread can
-            // cause issues on mono 2.6, 2.10 and possibly later where locks are not released properly on abort.
-            instance.Stop(1000);
+            instance.Stop(m_WaitForEventCompletionOnScriptStop);
 
 //                bool objectRemoved = false;
 
@@ -1485,6 +1576,7 @@ namespace OpenSim.Region.ScriptEngine.XEngine
             startInfo.StartSuspended = true;
 
             m_ThreadPool = new SmartThreadPool(startInfo);
+            m_ThreadPool.Name = "XEngine";
         }
 
         //
@@ -1504,8 +1596,7 @@ namespace OpenSim.Region.ScriptEngine.XEngine
         /// <returns></returns>
         private object ProcessEventHandler(object parms)
         {
-            CultureInfo USCulture = new CultureInfo("en-US");
-            Thread.CurrentThread.CurrentCulture = USCulture;
+            Culture.SetCurrentCulture();
 
             IScriptInstance instance = (ScriptInstance) parms;
             
@@ -1693,7 +1784,7 @@ namespace OpenSim.Region.ScriptEngine.XEngine
         {
             IScriptInstance instance = GetInstance(itemID);
             if (instance != null)
-                instance.ResetScript();
+                instance.ResetScript(m_WaitForEventCompletionOnScriptStop);
         }
 
         public void StartScript(UUID itemID)
@@ -1708,16 +1799,11 @@ namespace OpenSim.Region.ScriptEngine.XEngine
         public void StopScript(UUID itemID)
         {
             IScriptInstance instance = GetInstance(itemID);
+
             if (instance != null)
-            {
-                // Give the script some time to finish processing its last event.  Simply aborting the script thread can
-                // cause issues on mono 2.6, 2.10 and possibly later where locks are not released properly on abort.
-                instance.Stop(1000);
-            }
+                instance.Stop(m_WaitForEventCompletionOnScriptStop);
             else
-            {
                 m_runFlags.AddOrUpdate(itemID, false, 240);
-            }
         }
 
         public DetectParams GetDetectParams(UUID itemID, int idx)