aboutsummaryrefslogtreecommitdiffstatshomepage
path: root/OpenSim
diff options
context:
space:
mode:
authorOren Hurvitz2015-07-27 12:34:09 +0300
committerOren Hurvitz2015-08-11 08:42:31 +0100
commit5679cd0100feb5e74462ca8cb0dff0550a4f5d65 (patch)
tree495821fd0069c8ec02f1a45ca677553a4f63347d /OpenSim
parentReport "Script Execution Time" as the time spent executing the script in the ... (diff)
downloadopensim-SC-5679cd0100feb5e74462ca8cb0dff0550a4f5d65.zip
opensim-SC-5679cd0100feb5e74462ca8cb0dff0550a4f5d65.tar.gz
opensim-SC-5679cd0100feb5e74462ca8cb0dff0550a4f5d65.tar.bz2
opensim-SC-5679cd0100feb5e74462ca8cb0dff0550a4f5d65.tar.xz
Changed "Script Execution Time" to be the gross time, i.e. including handling it in XEngine
Previously the "Net Time" was reported: only the time actually spent in the script's code. This is not a correct indication of how much load the script places on the simulator, because scripts that change state often or have many events use up a lot of time just in the event handlers, and previously this time wasn't counted.
Diffstat (limited to 'OpenSim')
-rw-r--r--OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs340
1 files changed, 176 insertions, 164 deletions
diff --git a/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs b/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs
index d8ad62c..24b33f8 100644
--- a/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs
+++ b/OpenSim/Region/ScriptEngine/Shared/Instance/ScriptInstance.cs
@@ -753,208 +753,220 @@ namespace OpenSim.Region.ScriptEngine.Shared.Instance
753 if (Suspended) 753 if (Suspended)
754 return 0; 754 return 0;
755 755
756 EventParams data = null; 756 Stopwatch timer = new Stopwatch();
757 timer.Start();
758
759 try
760 {
761 return EventProcessorInt();
762 }
763 finally
764 {
765 timer.Stop();
766 ExecutionTime.AddSample(timer);
767 }
768 }
769 }
757 770
758 lock (EventQueue) 771 private object EventProcessorInt()
772 {
773 EventParams data = null;
774
775 lock (EventQueue)
776 {
777 data = (EventParams)EventQueue.Dequeue();
778 if (data == null) // Shouldn't happen
759 { 779 {
760 data = (EventParams)EventQueue.Dequeue(); 780 if (EventQueue.Count > 0 && Running && !ShuttingDown)
761 if (data == null) // Shouldn't happen
762 { 781 {
763 if (EventQueue.Count > 0 && Running && !ShuttingDown) 782 m_CurrentWorkItem = Engine.QueueEventHandler(this);
764 {
765 m_CurrentWorkItem = Engine.QueueEventHandler(this);
766 }
767 else
768 {
769 m_CurrentWorkItem = null;
770 }
771 return 0;
772 } 783 }
773 784 else
774 if (data.EventName == "timer")
775 m_TimerQueued = false;
776 if (data.EventName == "control")
777 { 785 {
778 if (m_ControlEventsInQueue > 0) 786 m_CurrentWorkItem = null;
779 m_ControlEventsInQueue--;
780 } 787 }
781 if (data.EventName == "collision") 788 return 0;
782 m_CollisionInQueue = false; 789 }
790
791 if (data.EventName == "timer")
792 m_TimerQueued = false;
793 if (data.EventName == "control")
794 {
795 if (m_ControlEventsInQueue > 0)
796 m_ControlEventsInQueue--;
783 } 797 }
798 if (data.EventName == "collision")
799 m_CollisionInQueue = false;
800 }
784 801
785 if (DebugLevel >= 2) 802 if (DebugLevel >= 2)
803 m_log.DebugFormat(
804 "[SCRIPT INSTANCE]: Processing event {0} for {1}/{2}({3})/{4}({5}) @ {6}/{7}",
805 data.EventName,
806 ScriptName,
807 Part.Name,
808 Part.LocalId,
809 Part.ParentGroup.Name,
810 Part.ParentGroup.UUID,
811 Part.AbsolutePosition,
812 Part.ParentGroup.Scene.Name);
813
814 m_DetectParams = data.DetectParams;
815
816 if (data.EventName == "state") // Hardcoded state change
817 {
818 State = data.Params[0].ToString();
819
820 if (DebugLevel >= 1)
786 m_log.DebugFormat( 821 m_log.DebugFormat(
787 "[SCRIPT INSTANCE]: Processing event {0} for {1}/{2}({3})/{4}({5}) @ {6}/{7}", 822 "[SCRIPT INSTANCE]: Changing state to {0} for {1}/{2}({3})/{4}({5}) @ {6}/{7}",
788 data.EventName, 823 State,
789 ScriptName, 824 ScriptName,
790 Part.Name, 825 Part.Name,
791 Part.LocalId, 826 Part.LocalId,
792 Part.ParentGroup.Name, 827 Part.ParentGroup.Name,
793 Part.ParentGroup.UUID, 828 Part.ParentGroup.UUID,
794 Part.AbsolutePosition, 829 Part.AbsolutePosition,
795 Part.ParentGroup.Scene.Name); 830 Part.ParentGroup.Scene.Name);
796 831
797 m_DetectParams = data.DetectParams; 832 AsyncCommandManager.StateChange(Engine,
833 LocalID, ItemID);
834 // we are effectively in the new state now, so we can resume queueing
835 // and processing other non-timer events
836 m_StateChangeInProgress = false;
798 837
799 if (data.EventName == "state") // Hardcoded state change 838 Part.SetScriptEvents(ItemID, (int)m_Script.GetStateEventFlags(State));
839 }
840 else
841 {
842 if (Engine.World.PipeEventsForScript(LocalID) ||
843 data.EventName == "control") // Don't freeze avies!
800 { 844 {
801 State = data.Params[0].ToString(); 845 // m_log.DebugFormat("[Script] Delivered event {2} in state {3} to {0}.{1}",
846 // PrimName, ScriptName, data.EventName, State);
802 847
803 if (DebugLevel >= 1) 848 try
804 m_log.DebugFormat(
805 "[SCRIPT INSTANCE]: Changing state to {0} for {1}/{2}({3})/{4}({5}) @ {6}/{7}",
806 State,
807 ScriptName,
808 Part.Name,
809 Part.LocalId,
810 Part.ParentGroup.Name,
811 Part.ParentGroup.UUID,
812 Part.AbsolutePosition,
813 Part.ParentGroup.Scene.Name);
814
815 AsyncCommandManager.StateChange(Engine,
816 LocalID, ItemID);
817 // we are effectively in the new state now, so we can resume queueing
818 // and processing other non-timer events
819 m_StateChangeInProgress = false;
820
821 Part.SetScriptEvents(ItemID, (int)m_Script.GetStateEventFlags(State));
822 }
823 else
824 {
825 if (Engine.World.PipeEventsForScript(LocalID) ||
826 data.EventName == "control") // Don't freeze avies!
827 { 849 {
828// m_log.DebugFormat("[Script] Delivered event {2} in state {3} to {0}.{1}", 850 m_CurrentEvent = data.EventName;
829// PrimName, ScriptName, data.EventName, State); 851 m_EventStart = DateTime.Now;
852 m_InEvent = true;
830 853
831 try 854 try
832 { 855 {
833 m_CurrentEvent = data.EventName;
834 m_EventStart = DateTime.Now;
835 m_InEvent = true;
836
837 Stopwatch timer = new Stopwatch();
838 timer.Start();
839
840 m_Script.ExecuteEvent(State, data.EventName, data.Params); 856 m_Script.ExecuteEvent(State, data.EventName, data.Params);
841 857 }
842 timer.Stop(); 858 finally
843 ExecutionTime.AddSample(timer); 859 {
844
845 m_InEvent = false; 860 m_InEvent = false;
846 m_CurrentEvent = String.Empty; 861 m_CurrentEvent = String.Empty;
862 }
847 863
848 if (m_SaveState) 864 if (m_SaveState)
849 { 865 {
850 // This will be the very first event we deliver 866 // This will be the very first event we deliver
851 // (state_entry) in default state 867 // (state_entry) in default state
852 // 868 //
853 SaveState(); 869 SaveState();
854 870
855 m_SaveState = false; 871 m_SaveState = false;
856 }
857 } 872 }
858 catch (Exception e) 873 }
874 catch (Exception e)
875 {
876 // m_log.DebugFormat(
877 // "[SCRIPT] Exception in script {0} {1}: {2}{3}",
878 // ScriptName, ItemID, e.Message, e.StackTrace);
879
880 if ((!(e is TargetInvocationException)
881 || (!(e.InnerException is SelfDeleteException)
882 && !(e.InnerException is ScriptDeleteException)
883 && !(e.InnerException is ScriptCoopStopException)))
884 && !(e is ThreadAbortException))
859 { 885 {
860// m_log.DebugFormat( 886 try
861// "[SCRIPT] Exception in script {0} {1}: {2}{3}",
862// ScriptName, ItemID, e.Message, e.StackTrace);
863
864 m_InEvent = false;
865 m_CurrentEvent = String.Empty;
866
867 if ((!(e is TargetInvocationException)
868 || (!(e.InnerException is SelfDeleteException)
869 && !(e.InnerException is ScriptDeleteException)
870 && !(e.InnerException is ScriptCoopStopException)))
871 && !(e is ThreadAbortException))
872 { 887 {
873 try 888 // DISPLAY ERROR INWORLD
874 { 889 string text = FormatException(e);
875 // DISPLAY ERROR INWORLD 890
876 string text = FormatException(e); 891 if (text.Length > 1000)
877 892 text = text.Substring(0, 1000);
878 if (text.Length > 1000) 893 Engine.World.SimChat(Utils.StringToBytes(text),
879 text = text.Substring(0, 1000); 894 ChatTypeEnum.DebugChannel, 2147483647,
880 Engine.World.SimChat(Utils.StringToBytes(text), 895 Part.AbsolutePosition,
881 ChatTypeEnum.DebugChannel, 2147483647, 896 Part.Name, Part.UUID, false);
882 Part.AbsolutePosition, 897
883 Part.Name, Part.UUID, false); 898
884 899 m_log.Debug(string.Format(
885 900 "[SCRIPT INSTANCE]: Runtime error in script {0} (event {1}), part {2} {3} at {4} in {5} ",
886 m_log.Debug(string.Format( 901 ScriptName,
887 "[SCRIPT INSTANCE]: Runtime error in script {0} (event {1}), part {2} {3} at {4} in {5} ", 902 data.EventName,
888 ScriptName, 903 PrimName,
889 data.EventName, 904 Part.UUID,
890 PrimName, 905 Part.AbsolutePosition,
891 Part.UUID, 906 Part.ParentGroup.Scene.Name),
892 Part.AbsolutePosition, 907 e);
893 Part.ParentGroup.Scene.Name),
894 e);
895 }
896 catch (Exception)
897 {
898 }
899 // catch (Exception e2) // LEGIT: User Scripting
900 // {
901 // m_log.Error("[SCRIPT]: "+
902 // "Error displaying error in-world: " +
903 // e2.ToString());
904 // m_log.Error("[SCRIPT]: " +
905 // "Errormessage: Error compiling script:\r\n" +
906 // e.ToString());
907 // }
908 } 908 }
909 else if ((e is TargetInvocationException) && (e.InnerException is SelfDeleteException)) 909 catch (Exception)
910 { 910 {
911 m_InSelfDelete = true;
912 Engine.World.DeleteSceneObject(Part.ParentGroup, false);
913 }
914 else if ((e is TargetInvocationException) && (e.InnerException is ScriptDeleteException))
915 {
916 m_InSelfDelete = true;
917 Part.Inventory.RemoveInventoryItem(ItemID);
918 }
919 else if ((e is TargetInvocationException) && (e.InnerException is ScriptCoopStopException))
920 {
921 if (DebugLevel >= 1)
922 m_log.DebugFormat(
923 "[SCRIPT INSTANCE]: Script {0}.{1} in event {2}, state {3} stopped co-operatively.",
924 PrimName, ScriptName, data.EventName, State);
925 } 911 }
912 // catch (Exception e2) // LEGIT: User Scripting
913 // {
914 // m_log.Error("[SCRIPT]: "+
915 // "Error displaying error in-world: " +
916 // e2.ToString());
917 // m_log.Error("[SCRIPT]: " +
918 // "Errormessage: Error compiling script:\r\n" +
919 // e.ToString());
920 // }
921 }
922 else if ((e is TargetInvocationException) && (e.InnerException is SelfDeleteException))
923 {
924 m_InSelfDelete = true;
925 Engine.World.DeleteSceneObject(Part.ParentGroup, false);
926 }
927 else if ((e is TargetInvocationException) && (e.InnerException is ScriptDeleteException))
928 {
929 m_InSelfDelete = true;
930 Part.Inventory.RemoveInventoryItem(ItemID);
931 }
932 else if ((e is TargetInvocationException) && (e.InnerException is ScriptCoopStopException))
933 {
934 if (DebugLevel >= 1)
935 m_log.DebugFormat(
936 "[SCRIPT INSTANCE]: Script {0}.{1} in event {2}, state {3} stopped co-operatively.",
937 PrimName, ScriptName, data.EventName, State);
926 } 938 }
927 } 939 }
928 } 940 }
941 }
929 942
930 // If there are more events and we are currently running and not shutting down, then ask the 943 // If there are more events and we are currently running and not shutting down, then ask the
931 // script engine to run the next event. 944 // script engine to run the next event.
932 lock (EventQueue) 945 lock (EventQueue)
933 { 946 {
934 EventsProcessed++; 947 EventsProcessed++;
935 948
936 if ((EventsProcessed == 1000) || (EventsProcessed == 10000) || ((EventsProcessed % 100000) == 0)) 949 if ((EventsProcessed == 1000) || (EventsProcessed == 10000) || ((EventsProcessed % 100000) == 0))
937 { 950 {
938 m_log.DebugFormat("[SCRIPT INSTANCE]: Script \"{0}\" (Object \"{1}\" {2} @ {3}.{4}, Item ID {5}, Asset {6}) in event {7}: processed {8:n0} script events", 951 m_log.DebugFormat("[SCRIPT INSTANCE]: Script \"{0}\" (Object \"{1}\" {2} @ {3}.{4}, Item ID {5}, Asset {6}) in event {7}: processed {8:n0} script events",
939 ScriptTask.Name, 952 ScriptTask.Name,
940 Part.ParentGroup.Name, Part.ParentGroup.UUID, Part.ParentGroup.AbsolutePosition, Part.ParentGroup.Scene.Name, 953 Part.ParentGroup.Name, Part.ParentGroup.UUID, Part.ParentGroup.AbsolutePosition, Part.ParentGroup.Scene.Name,
941 ScriptTask.ItemID, ScriptTask.AssetID, data.EventName, EventsProcessed); 954 ScriptTask.ItemID, ScriptTask.AssetID, data.EventName, EventsProcessed);
942 } 955 }
943 956
944 if (EventQueue.Count > 0 && Running && !ShuttingDown) 957 if (EventQueue.Count > 0 && Running && !ShuttingDown)
945 { 958 {
946 m_CurrentWorkItem = Engine.QueueEventHandler(this); 959 m_CurrentWorkItem = Engine.QueueEventHandler(this);
947 } 960 }
948 else 961 else
949 { 962 {
950 m_CurrentWorkItem = null; 963 m_CurrentWorkItem = null;
951 }
952 } 964 }
965 }
953 966
954 m_DetectParams = null; 967 m_DetectParams = null;
955 968
956 return 0; 969 return 0;
957 }
958 } 970 }
959 971
960 public int EventTime() 972 public int EventTime()
generated by cgit v1.1 at 2024-11-16 21:33:50 +0000