From 418c0cb01d72a48bb1cd708d25a3e9159e711661 Mon Sep 17 00:00:00 2001 From: Justin Clark-Casey (justincc) Date: Wed, 12 Dec 2012 22:06:09 +0000 Subject: Add asset id to "show script" and "show scripts" command output to make it easier to extract and inspect the script's asset via "dump asset" --- OpenSim/Region/ScriptEngine/XEngine/XEngine.cs | 1 + 1 file changed, 1 insertion(+) (limited to 'OpenSim/Region/ScriptEngine') diff --git a/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs b/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs index 965101a..986f658 100644 --- a/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs +++ b/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs @@ -542,6 +542,7 @@ namespace OpenSim.Region.ScriptEngine.XEngine 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); -- cgit v1.1 From 047270bdc83d029486215a418fada27b225dbab0 Mon Sep 17 00:00:00 2001 From: Justin Clark-Casey (justincc) Date: Wed, 12 Dec 2012 23:13:34 +0000 Subject: Add "debug script log" command to allow setting a numeric debug level on individual IScriptInstances for debugging purposes. Current, state changes and event fires can be logged for individual scripts. See command help for more details. --- .../ScriptEngine/Interfaces/IScriptInstance.cs | 12 +++++ .../ScriptEngine/Shared/Instance/ScriptInstance.cs | 37 +++++++++++---- OpenSim/Region/ScriptEngine/XEngine/XEngine.cs | 53 ++++++++++++++++++++-- 3 files changed, 89 insertions(+), 13 deletions(-) (limited to 'OpenSim/Region/ScriptEngine') diff --git a/OpenSim/Region/ScriptEngine/Interfaces/IScriptInstance.cs b/OpenSim/Region/ScriptEngine/Interfaces/IScriptInstance.cs index 0cef550..00a99c3 100644 --- a/OpenSim/Region/ScriptEngine/Interfaces/IScriptInstance.cs +++ b/OpenSim/Region/ScriptEngine/Interfaces/IScriptInstance.cs @@ -59,6 +59,18 @@ namespace OpenSim.Region.ScriptEngine.Interfaces public interface IScriptInstance { /// + /// Debug level for this script instance. + /// + /// + /// Level == 0, no extra data is logged. + /// Level >= 1, state changes are logged. + /// Level >= 2, event firing is logged. + /// + /// The debug level. + /// + int DebugLevel { get; set; } + + /// /// Is the script currently running? /// bool Running { get; set; } diff --git a/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs b/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs index 5ad6eeb..435e9dc 100644 --- a/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs +++ b/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs @@ -93,6 +93,8 @@ namespace OpenSim.Region.ScriptEngine.Shared.Instance private UUID m_CurrentStateHash; private UUID m_RegionID; + public int DebugLevel { get; set; } + public Dictionary, KeyValuePair> LineMap { get; set; } private Dictionary m_Apis = new Dictionary(); @@ -703,21 +705,42 @@ namespace OpenSim.Region.ScriptEngine.Shared.Instance if (data.EventName == "collision") m_CollisionInQueue = false; } - -// m_log.DebugFormat("[XEngine]: Processing event {0} for {1}", data.EventName, this); + + SceneObjectPart part = Engine.World.GetSceneObjectPart(LocalID); + + if (DebugLevel >= 2) + m_log.DebugFormat( + "[SCRIPT INSTANCE]: Processing event {0} for {1}/{2}({3})/{4}({5}) @ {6}/{7}", + data.EventName, + ScriptName, + part.Name, + part.LocalId, + part.ParentGroup.Name, + part.ParentGroup.UUID, + part.AbsolutePosition, + part.ParentGroup.Scene.Name); m_DetectParams = data.DetectParams; if (data.EventName == "state") // Hardcoded state change { - // m_log.DebugFormat("[Script] Script {0}.{1} state set to {2}", - // PrimName, ScriptName, data.Params[0].ToString()); State = data.Params[0].ToString(); + + if (DebugLevel >= 1) + m_log.DebugFormat( + "[SCRIPT INSTANCE]: Changing state to {0} for {1}/{2}({3})/{4}({5}) @ {6}/{7}", + State, + ScriptName, + part.Name, + part.LocalId, + part.ParentGroup.Name, + part.ParentGroup.UUID, + part.AbsolutePosition, + part.ParentGroup.Scene.Name); + AsyncCommandManager.RemoveScript(Engine, LocalID, ItemID); - SceneObjectPart part = Engine.World.GetSceneObjectPart( - LocalID); if (part != null) { part.SetScriptEvents(ItemID, @@ -729,8 +752,6 @@ namespace OpenSim.Region.ScriptEngine.Shared.Instance if (Engine.World.PipeEventsForScript(LocalID) || data.EventName == "control") // Don't freeze avies! { - SceneObjectPart part = Engine.World.GetSceneObjectPart( - LocalID); // m_log.DebugFormat("[Script] Delivered event {2} in state {3} to {0}.{1}", // PrimName, ScriptName, data.EventName, State); diff --git a/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs b/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs index 986f658..828f2fb 100644 --- a/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs +++ b/OpenSim/Region/ScriptEngine/XEngine/XEngine.cs @@ -304,7 +304,7 @@ namespace OpenSim.Region.ScriptEngine.XEngine MainConsole.Instance.Commands.AddCommand( "Scripts", false, "scripts show", "scripts show []", "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 is given then only information on that script will be shown.", HandleShowScripts); @@ -323,22 +323,30 @@ namespace OpenSim.Region.ScriptEngine.XEngine MainConsole.Instance.Commands.AddCommand( "Scripts", false, "scripts resume", "scripts resume []", "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 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 []", "Stops all running scripts", - "Stops all running scripts." + "Stops all running scripts.\n" + "If a 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 []", "Starts all stopped scripts", - "Starts all stopped scripts." + "Starts all stopped scripts.\n" + "If a 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 ", "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 []", // "Turn on detailed xengine debugging.", @@ -347,6 +355,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 "); + 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); + } + /// /// Change debug level /// @@ -418,7 +461,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; } -- cgit v1.1 From 512e4c931379877a1fd8c35f41111431f0a85ff5 Mon Sep 17 00:00:00 2001 From: Justin Clark-Casey (justincc) Date: Wed, 12 Dec 2012 23:30:26 +0000 Subject: Log situations where workitem event threads are aborted on stop request because they failed to complete event processing within the given timeout. This is for bug hunting purposes where thread aborts may be causing dangling lock issues and subsequent vm crashes on mono (with ReaderWriterLockSlim, etc.) --- OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) (limited to 'OpenSim/Region/ScriptEngine') diff --git a/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs b/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs index 435e9dc..dfe8386 100644 --- a/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs +++ b/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs @@ -550,9 +550,9 @@ namespace OpenSim.Region.ScriptEngine.Shared.Instance // forcibly abort the work item (this aborts the underlying thread). if (!m_InSelfDelete) { -// m_log.ErrorFormat( -// "[SCRIPT INSTANCE]: Aborting script {0} {1} in prim {2} {3} {4} {5}", -// ScriptName, ItemID, PrimName, ObjectID, m_InSelfDelete, DateTime.Now.Ticks); + m_log.DebugFormat( + "[SCRIPT INSTANCE]: Aborting unstopped script {0} {1} in prim {2}, localID {3}, timeout was {4} ms", + ScriptName, ItemID, PrimName, LocalID, timeout); workItem.Abort(); } -- cgit v1.1