From 59b461ac0eaae1cc34bb82431106fdf0476037f3 Mon Sep 17 00:00:00 2001 From: Diva Canto Date: Thu, 1 Aug 2013 09:27:44 -0700 Subject: [PATCH 1/6] Issue: painfully slow terrain loading. The cause is commit d9d995914c5fba00d4ccaf66b899384c8ea3d5eb (r/23185) -- the WaitOne on the UDPServer. Putting it back to how it was done solves the issue. But this may impact CPU usage, so I'm pushing it to test if it does. --- OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs b/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs index 85fe1a4050..942c0447b0 100644 --- a/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs +++ b/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs @@ -246,7 +246,7 @@ namespace OpenSim.Region.ClientStack.LindenUDP /// This allows the outbound loop to only operate when there is data to send rather than continuously polling. /// Some data is sent immediately and not queued. That data would not trigger this event. /// - private AutoResetEvent m_dataPresentEvent = new AutoResetEvent(false); + //private AutoResetEvent m_dataPresentEvent = new AutoResetEvent(false); private Pool m_incomingPacketPool; @@ -907,7 +907,7 @@ namespace OpenSim.Region.ClientStack.LindenUDP PacketPool.Instance.ReturnPacket(packet); - m_dataPresentEvent.Set(); + //m_dataPresentEvent.Set(); } /// @@ -1919,12 +1919,12 @@ namespace OpenSim.Region.ClientStack.LindenUDP // If nothing was sent, sleep for the minimum amount of time before a // token bucket could get more tokens - //if (!m_packetSent) - // Thread.Sleep((int)TickCountResolution); + if (!m_packetSent) + Thread.Sleep((int)TickCountResolution); // // Instead, now wait for data present to be explicitly signalled. Evidence so far is that with // modern mono it reduces CPU base load since there is no more continuous polling. - m_dataPresentEvent.WaitOne(100); + //m_dataPresentEvent.WaitOne(100); Watchdog.UpdateThread(); } From 932c382737d155176bd7e0dcfaf9395d997a88fb Mon Sep 17 00:00:00 2001 From: "Justin Clark-Casey (justincc)" Date: Thu, 1 Aug 2013 18:11:50 +0100 Subject: [PATCH 2/6] Revert "Issue: painfully slow terrain loading. The cause is commit d9d995914c5fba00d4ccaf66b899384c8ea3d5eb (r/23185) -- the WaitOne on the UDPServer. Putting it back to how it was done solves the issue. But this may impact CPU usage, so I'm pushing it to test if it does." This reverts commit 59b461ac0eaae1cc34bb82431106fdf0476037f3. --- OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs b/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs index 942c0447b0..85fe1a4050 100644 --- a/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs +++ b/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs @@ -246,7 +246,7 @@ namespace OpenSim.Region.ClientStack.LindenUDP /// This allows the outbound loop to only operate when there is data to send rather than continuously polling. /// Some data is sent immediately and not queued. That data would not trigger this event. /// - //private AutoResetEvent m_dataPresentEvent = new AutoResetEvent(false); + private AutoResetEvent m_dataPresentEvent = new AutoResetEvent(false); private Pool m_incomingPacketPool; @@ -907,7 +907,7 @@ namespace OpenSim.Region.ClientStack.LindenUDP PacketPool.Instance.ReturnPacket(packet); - //m_dataPresentEvent.Set(); + m_dataPresentEvent.Set(); } /// @@ -1919,12 +1919,12 @@ namespace OpenSim.Region.ClientStack.LindenUDP // If nothing was sent, sleep for the minimum amount of time before a // token bucket could get more tokens - if (!m_packetSent) - Thread.Sleep((int)TickCountResolution); + //if (!m_packetSent) + // Thread.Sleep((int)TickCountResolution); // // Instead, now wait for data present to be explicitly signalled. Evidence so far is that with // modern mono it reduces CPU base load since there is no more continuous polling. - //m_dataPresentEvent.WaitOne(100); + m_dataPresentEvent.WaitOne(100); Watchdog.UpdateThread(); } From 0c4c084bed5175d8a5b25b8f915363f3b15b6e3a Mon Sep 17 00:00:00 2001 From: "Justin Clark-Casey (justincc)" Date: Thu, 1 Aug 2013 18:12:28 +0100 Subject: [PATCH 3/6] Try a different approach to slow terrain update by always cycling the loop immediately if any data was sent, rather than waiting. What I believe is happening is that on initial terrain send, this is done one packet at a time. With WaitOne, the outbound loop has enough time to loop and wait again after the first packet before the second, leading to a slower send. This approach instead does not wait if a packet was just sent but instead loops again, which appears to lead to a quicker send without losing the cpu benefit of not continually looping when there is no outbound data. --- OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs b/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs index 85fe1a4050..558fcb7ba3 100644 --- a/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs +++ b/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs @@ -1924,7 +1924,8 @@ namespace OpenSim.Region.ClientStack.LindenUDP // // Instead, now wait for data present to be explicitly signalled. Evidence so far is that with // modern mono it reduces CPU base load since there is no more continuous polling. - m_dataPresentEvent.WaitOne(100); + if (!m_packetSent) + m_dataPresentEvent.WaitOne(100); Watchdog.UpdateThread(); } From 216e785ca9ca7dee51c32e69952a79b6e87733d1 Mon Sep 17 00:00:00 2001 From: "Justin Clark-Casey (justincc)" Date: Thu, 1 Aug 2013 21:16:53 +0100 Subject: [PATCH 4/6] Add experimental "debug attachments throttle " setting (command line) and ThrottlePer100PrimsRezzed in [Attachments] in config This is an experimental setting to control cpu spikes when an attachment heavy avatar logs in or avatars with medium attachments lgoin simultaneously. It inserts a ms sleep specified in terms of attachments prims after each rez when an avatar logs in. Default is 0 (no throttling). "debug attachments " changes to "debug attachments log " which controls logging. A logging level of 1 will show the throttling performed if applicable. Also adds "debug attachments status" command to show current throttle and debug logging levels. --- .../Avatar/Attachments/AttachmentsModule.cs | 102 +++++++++++++++--- bin/OpenSimDefaults.ini | 7 ++ 2 files changed, 94 insertions(+), 15 deletions(-) diff --git a/OpenSim/Region/CoreModules/Avatar/Attachments/AttachmentsModule.cs b/OpenSim/Region/CoreModules/Avatar/Attachments/AttachmentsModule.cs index 2f5a76f747..97477d49f1 100644 --- a/OpenSim/Region/CoreModules/Avatar/Attachments/AttachmentsModule.cs +++ b/OpenSim/Region/CoreModules/Avatar/Attachments/AttachmentsModule.cs @@ -29,6 +29,7 @@ using System; using System.Collections.Generic; using System.Reflection; using System.IO; +using System.Threading; using System.Xml; using log4net; using Mono.Addins; @@ -50,6 +51,15 @@ namespace OpenSim.Region.CoreModules.Avatar.Attachments private static readonly ILog m_log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType); public int DebugLevel { get; set; } + + /// + /// Period to sleep per 100 prims in order to avoid CPU spikes when an avatar with many attachments logs in + /// or many avatars with a medium levels of attachments login simultaneously. + /// + /// + /// A value of 0 will apply no pause. The pause is specified in milliseconds. + /// + public int ThrottlePer100PrimsRezzed { get; set; } private Scene m_scene; private IInventoryAccessModule m_invAccessModule; @@ -66,9 +76,15 @@ namespace OpenSim.Region.CoreModules.Avatar.Attachments { IConfig config = source.Configs["Attachments"]; if (config != null) + { Enabled = config.GetBoolean("Enabled", true); + + ThrottlePer100PrimsRezzed = config.GetInt("ThrottlePer100PrimsRezzed", 0); + } else + { Enabled = true; + } } public void AddRegion(Scene scene) @@ -87,24 +103,43 @@ namespace OpenSim.Region.CoreModules.Avatar.Attachments MainConsole.Instance.Commands.AddCommand( "Debug", false, - "debug attachments", - "debug attachments [0|1]", - "Turn on attachments debugging\n" - + " <= 0 - turns off debugging\n" - + " >= 1 - turns on attachment message logging\n", - HandleDebugAttachments); + "debug attachments log", + "debug attachments log [0|1]", + "Turn on attachments debug logging", + " <= 0 - turns off debug logging\n" + + " >= 1 - turns on attachment message debug logging", + HandleDebugAttachmentsLog); + + MainConsole.Instance.Commands.AddCommand( + "Debug", + false, + "debug attachments throttle", + "debug attachments throttle ", + "Turn on attachments throttling.", + "This requires a millisecond value. " + + " == 0 - disable throttling.\n" + + " > 0 - sleeps for this number of milliseconds per 100 prims rezzed.", + HandleDebugAttachmentsThrottle); + + MainConsole.Instance.Commands.AddCommand( + "Debug", + false, + "debug attachments status", + "debug attachments status", + "Show current attachments debug status", + HandleDebugAttachmentsStatus); } // TODO: Should probably be subscribing to CloseClient too, but this doesn't yet give us IClientAPI } - private void HandleDebugAttachments(string module, string[] args) + private void HandleDebugAttachmentsLog(string module, string[] args) { int debugLevel; - if (!(args.Length == 3 && int.TryParse(args[2], out debugLevel))) + if (!(args.Length == 4 && int.TryParse(args[3], out debugLevel))) { - MainConsole.Instance.OutputFormat("Usage: debug attachments [0|1]"); + MainConsole.Instance.OutputFormat("Usage: debug attachments log [0|1]"); } else { @@ -114,6 +149,29 @@ namespace OpenSim.Region.CoreModules.Avatar.Attachments } } + private void HandleDebugAttachmentsThrottle(string module, string[] args) + { + int ms; + + if (args.Length == 4 && int.TryParse(args[3], out ms)) + { + ThrottlePer100PrimsRezzed = ms; + MainConsole.Instance.OutputFormat( + "Attachments rez throttle per 100 prims is now {0} in {1}", ThrottlePer100PrimsRezzed, m_scene.Name); + + return; + } + + MainConsole.Instance.OutputFormat("Usage: debug attachments throttle "); + } + + private void HandleDebugAttachmentsStatus(string module, string[] args) + { + MainConsole.Instance.OutputFormat("Settings for {0}", m_scene.Name); + MainConsole.Instance.OutputFormat("Debug logging level: {0}", DebugLevel); + MainConsole.Instance.OutputFormat("Throttle per 100 prims: {0}ms", ThrottlePer100PrimsRezzed); + } + /// /// Listen for client triggered running state changes so that we can persist the script's object if necessary. /// @@ -240,7 +298,7 @@ namespace OpenSim.Region.CoreModules.Avatar.Attachments List attachments = sp.Appearance.GetAttachments(); foreach (AvatarAttachment attach in attachments) { - uint p = (uint)attach.AttachPoint; + uint attachmentPt = (uint)attach.AttachPoint; // m_log.DebugFormat( // "[ATTACHMENTS MODULE]: Doing initial rez of attachment with itemID {0}, assetID {1}, point {2} for {3} in {4}", @@ -258,14 +316,28 @@ namespace OpenSim.Region.CoreModules.Avatar.Attachments { // If we're an NPC then skip all the item checks and manipulations since we don't have an // inventory right now. - RezSingleAttachmentFromInventoryInternal( - sp, sp.PresenceType == PresenceType.Npc ? UUID.Zero : attach.ItemID, attach.AssetID, p, true); + SceneObjectGroup objatt + = RezSingleAttachmentFromInventoryInternal( + sp, sp.PresenceType == PresenceType.Npc ? UUID.Zero : attach.ItemID, attach.AssetID, attachmentPt, true); + + + if (ThrottlePer100PrimsRezzed > 0) + { + int throttleMs = (int)Math.Round((float)objatt.PrimCount / 100 * ThrottlePer100PrimsRezzed); + + if (DebugLevel > 0) + m_log.DebugFormat( + "[ATTACHMENTS MODULE]: Throttling by {0}ms after rez of {1} with {2} prims for attachment to {3} on point {4} in {5}", + throttleMs, objatt.Name, objatt.PrimCount, sp.Name, attachmentPt, m_scene.Name); + + Thread.Sleep(throttleMs); + } } catch (Exception e) { UUID agentId = (sp.ControllingClient == null) ? (UUID)null : sp.ControllingClient.AgentId; m_log.ErrorFormat("[ATTACHMENTS MODULE]: Unable to rez attachment with itemID {0}, assetID {1}, point {2} for {3}: {4}\n{5}", - attach.ItemID, attach.AssetID, p, agentId, e.Message, e.StackTrace); + attach.ItemID, attach.AssetID, attachmentPt, agentId, e.Message, e.StackTrace); } } } @@ -919,8 +991,8 @@ namespace OpenSim.Region.CoreModules.Avatar.Attachments if (DebugLevel > 0) m_log.DebugFormat( - "[ATTACHMENTS MODULE]: Rezzed single object {0} for attachment to {1} on point {2} in {3}", - objatt.Name, sp.Name, attachmentPt, m_scene.Name); + "[ATTACHMENTS MODULE]: Rezzed single object {0} with {1} prims for attachment to {2} on point {3} in {4}", + objatt.Name, objatt.PrimCount, sp.Name, attachmentPt, m_scene.Name); // HasGroupChanged is being set from within RezObject. Ideally it would be set by the caller. objatt.HasGroupChanged = false; diff --git a/bin/OpenSimDefaults.ini b/bin/OpenSimDefaults.ini index dbafd5c834..2488bf16f0 100644 --- a/bin/OpenSimDefaults.ini +++ b/bin/OpenSimDefaults.ini @@ -703,11 +703,18 @@ ; on every login ReuseTextures = false + [Attachments] ; Controls whether avatar attachments are enabled. ; Defaults to true - only set to false for debugging purposes Enabled = true + ; Controls the number of milliseconds that are slept per 100 prims rezzed in attachments + ; Experimental setting to control CPU spiking when avatars with many attachments login + ; or when multiple avatars with medium level attachments login simultaneously. + ; If 0 then no throttling is performed. + ThrottlePer100PrimsRezzed = 0; + [Mesh] ; enable / disable Collada mesh support From 7b9a50721da3ac51ee3aa60ea946278d38a18426 Mon Sep 17 00:00:00 2001 From: teravus Date: Thu, 1 Aug 2013 16:30:29 -0500 Subject: [PATCH 5/6] * Thanks Plugh for pointing out that the constructor that takes a ulong regionhandle and saves it to to X,Y vars in the OpenSim.Framework.Location object was inverting the X and Y resulting in X and Y confusion. The test also used 256x256 in the uint,uint constructor so it was unable to determine if the X and Y components swapped. I don't expect much upheaval from this commit, not a lot of features were using the ulong Location object constructor. The database never stores the ulong regionhandle... the prims are loaded by region Guid. LLUDPServer used it to determine regions that it handled in a service definition where there was simply a X == X test which has the same logical result un-switched as it did switched. Again, thanks LibOMV for the regionhandle code. --- OpenSim/Framework/Location.cs | 16 ++++++++-------- OpenSim/Framework/Tests/LocationTest.cs | 14 +++++++------- 2 files changed, 15 insertions(+), 15 deletions(-) diff --git a/OpenSim/Framework/Location.cs b/OpenSim/Framework/Location.cs index 9504e03547..0b888347e7 100644 --- a/OpenSim/Framework/Location.cs +++ b/OpenSim/Framework/Location.cs @@ -33,10 +33,10 @@ namespace OpenSim.Framework [Serializable] public class Location : ICloneable { - private readonly int m_x; - private readonly int m_y; + private readonly uint m_x; + private readonly uint m_y; - public Location(int x, int y) + public Location(uint x, uint y) { m_x = x; m_y = y; @@ -44,21 +44,21 @@ namespace OpenSim.Framework public Location(ulong regionHandle) { - m_x = (int) regionHandle; - m_y = (int) (regionHandle >> 32); + m_x = (uint)(regionHandle >> 32); + m_y = (uint)(regionHandle & (ulong)uint.MaxValue); } public ulong RegionHandle { - get { return Utils.UIntsToLong((uint)m_x, (uint)m_y); } + get { return Utils.UIntsToLong(m_x, m_y); } } - public int X + public uint X { get { return m_x; } } - public int Y + public uint Y { get { return m_y; } } diff --git a/OpenSim/Framework/Tests/LocationTest.cs b/OpenSim/Framework/Tests/LocationTest.cs index a56ecb4049..af5f164d7f 100644 --- a/OpenSim/Framework/Tests/LocationTest.cs +++ b/OpenSim/Framework/Tests/LocationTest.cs @@ -51,21 +51,21 @@ namespace OpenSim.Framework.Tests [Test] public void locationXYRegionHandle() { - Location TestLocation1 = new Location(256000,256000); - Location TestLocation2 = new Location(1099511628032000); + Location TestLocation1 = new Location(255000,256000); + Location TestLocation2 = new Location(1095216660736000); Assert.That(TestLocation1 == TestLocation2); - Assert.That(TestLocation2.X == 256000 && TestLocation2.Y == 256000, "Test xy location doesn't match regionhandle provided"); + Assert.That(TestLocation2.X == 255000 && TestLocation2.Y == 256000, "Test xy location doesn't match regionhandle provided"); - Assert.That(TestLocation2.RegionHandle == 1099511628032000, + Assert.That(TestLocation2.RegionHandle == 1095216660736000, "Location RegionHandle Property didn't match regionhandle provided in constructor"); - TestLocation1 = new Location(256001, 256001); - TestLocation2 = new Location(1099511628032000); + TestLocation1 = new Location(255001, 256001); + TestLocation2 = new Location(1095216660736000); Assert.That(TestLocation1 != TestLocation2); - Assert.That(TestLocation1.Equals(256001, 256001), "Equals(x,y) failed to match the position in the constructor"); + Assert.That(TestLocation1.Equals(255001, 256001), "Equals(x,y) failed to match the position in the constructor"); Assert.That(TestLocation2.GetHashCode() == (TestLocation2.X.GetHashCode() ^ TestLocation2.Y.GetHashCode()), "GetHashCode failed to produce the expected hashcode"); From 68b98a8003e0ea7ed082b105ae82a644fb706796 Mon Sep 17 00:00:00 2001 From: "Justin Clark-Casey (justincc)" Date: Thu, 1 Aug 2013 23:16:41 +0100 Subject: [PATCH 6/6] minor: Add name to debug lludp packet level feedback on console --- OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs b/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs index 558fcb7ba3..5c38399c08 100644 --- a/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs +++ b/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs @@ -694,7 +694,7 @@ namespace OpenSim.Region.ClientStack.LindenUDP { DefaultClientPacketDebugLevel = newDebug; MainConsole.Instance.OutputFormat( - "Debug packet debug for new clients set to {0}", DefaultClientPacketDebugLevel); + "Debug packet debug for new clients set to {0} in {1}", DefaultClientPacketDebugLevel, m_scene.Name); } else {