9 files changed, 64 insertions, 70 deletions

diff --git a/OpenSim/Framework/AvatarAppearance.cs b/OpenSim/Framework/AvatarAppearance.cs
index a4bb765..9494410 100644
--- a/OpenSim/Framework/AvatarAppearance.cs
+++ b/OpenSim/Framework/AvatarAppearance.cs
@@ -329,9 +329,8 @@ namespace OpenSim.Framework
 
         public AvatarAppearance(UUID owner)
         {
-// DEBUG ON
-            m_log.WarnFormat("[AVATAR APPEARANCE] create empty appearance for {0}",owner);
-// DEBUG OFF
+//            m_log.WarnFormat("[AVATAR APPEARANCE]: create empty appearance for {0}",owner);
+
             m_serial = 1;
             m_owner = owner;
 
@@ -345,9 +344,8 @@ namespace OpenSim.Framework
         
         public AvatarAppearance(UUID avatarID, OSDMap map)
         {
-// DEBUG ON
-            m_log.WarnFormat("[AVATAR APPEARANCE] create appearance for {0} from OSDMap",avatarID);
-// DEBUG OFF
+//            m_log.WarnFormat("[AVATAR APPEARANCE]: create appearance for {0} from OSDMap",avatarID);
+
             m_owner = avatarID;
             Unpack(map);
             SetHeight();
@@ -355,9 +353,8 @@ namespace OpenSim.Framework
         
         public AvatarAppearance(UUID avatarID, AvatarWearable[] wearables, Primitive.TextureEntry textureEntry, byte[] visualParams)
         {
-// DEBUG ON
-            m_log.WarnFormat("[AVATAR APPEARANCE] create initialized appearance for {0}",avatarID);
-// DEBUG OFF
+//            m_log.WarnFormat("[AVATAR APPEARANCE] create initialized appearance for {0}",avatarID);
+            
             m_serial = 1;
             m_owner = avatarID;
 
@@ -383,9 +380,8 @@ namespace OpenSim.Framework
 
         public AvatarAppearance(AvatarAppearance appearance)
         {
-// DEBUG ON
-            m_log.WarnFormat("[AVATAR APPEARANCE] create from an existing appearance");
-// DEBUG OFF
+//            m_log.WarnFormat("[AVATAR APPEARANCE] create from an existing appearance");
+
             if (appearance == null)
             {
                 m_serial = 1;
@@ -479,10 +475,9 @@ namespace OpenSim.Framework
                 }
 
                 changed = true;
-// DEBUG ON
-                if (newface != null)
-                    m_log.WarnFormat("[AVATAR APPEARANCE] index {0}, new texture id {1}",i,newface.TextureID);
-// DEBUG OFF
+                
+//                if (newface != null)
+//                    m_log.WarnFormat("[AVATAR APPEARANCE]: index {0}, new texture id {1}",i,newface.TextureID);
             }
 
             m_texture = textureEntry;
@@ -742,7 +737,7 @@ namespace OpenSim.Framework
                 }
                 else
                 {
-                    m_log.Warn("[AVATARAPPEARANCE] failed to unpack wearables");
+                    m_log.Warn("[AVATAR APPEARANCE]: failed to unpack wearables");
                 }
 
                 // Avatar Textures
@@ -760,7 +755,7 @@ namespace OpenSim.Framework
                 }
                 else
                 {
-                    m_log.Warn("[AVATARAPPEARANCE] failed to unpack textures");
+                    m_log.Warn("[AVATAR APPEARANCE]: failed to unpack textures");
                 }
 
                 // Visual Parameters
@@ -772,7 +767,7 @@ namespace OpenSim.Framework
                 }
                 else
                 {
-                    m_log.Warn("[AVATARAPPEARANCE] failed to unpack visual parameters");
+                    m_log.Warn("[AVATAR APPEARANCE]: failed to unpack visual parameters");
                 }
 
                 // Attachments
@@ -786,7 +781,7 @@ namespace OpenSim.Framework
             }
             catch (Exception e)
             {
-                m_log.ErrorFormat("[AVATARAPPEARANCE] unpack failed badly: {0}",e.Message);
+                m_log.ErrorFormat("[AVATAR APPEARANCE]: unpack failed badly: {0}{1}", e.Message, e.StackTrace);
             }
         }
 
diff --git a/OpenSim/Framework/Capabilities/Caps.cs b/OpenSim/Framework/Capabilities/Caps.cs
index 872de9a..7b0e053 100644
--- a/OpenSim/Framework/Capabilities/Caps.cs
+++ b/OpenSim/Framework/Capabilities/Caps.cs
@@ -988,9 +988,7 @@ namespace OpenSim.Framework.Capabilities
 
         public void BakedTextureUploaded(UUID assetID, byte[] data)
         {
-// DEBUG ON
-            m_log.WarnFormat("[CAPS]: Received baked texture {0}", assetID.ToString());
-// DEBUG OFF
+//            m_log.WarnFormat("[CAPS]: Received baked texture {0}", assetID.ToString());
             AssetBase asset;
             asset = new AssetBase(assetID, "Baked Texture", (sbyte)AssetType.Texture, m_agentID.ToString());
             asset.Data = data;
diff --git a/OpenSim/Region/ClientStack/LindenUDP/LLUDPServer.cs b/OpenSim/Region/ClientStack/LindenUDP/LLUDPServer.cs
index 624814a..183aec0 100644
--- a/OpenSim/Region/ClientStack/LindenUDP/LLUDPServer.cs
+++ b/OpenSim/Region/ClientStack/LindenUDP/LLUDPServer.cs
@@ -615,8 +615,7 @@ namespace OpenSim.Region.ClientStack.LindenUDP
 
             // UseCircuitCode handling
             if (packet.Type == PacketType.UseCircuitCode)
-            {
-                m_log.Debug("[LLUDPSERVER]: Handling UseCircuitCode packet from " + buffer.RemoteEndPoint);
+            {                
                 object[] array = new object[] { buffer, packet };
 
                 if (m_asyncPacketHandling)
@@ -827,9 +826,12 @@ namespace OpenSim.Region.ClientStack.LindenUDP
 
         private void HandleUseCircuitCode(object o)
         {
+            DateTime startTime = DateTime.Now;
             object[] array = (object[])o;
             UDPPacketBuffer buffer = (UDPPacketBuffer)array[0];
             UseCircuitCodePacket packet = (UseCircuitCodePacket)array[1];
+            
+            m_log.DebugFormat("[LLUDPSERVER]: Handling UseCircuitCode request from {0}", buffer.RemoteEndPoint);
 
             IPEndPoint remoteEndPoint = (IPEndPoint)buffer.RemoteEndPoint;
 
@@ -838,6 +840,10 @@ namespace OpenSim.Region.ClientStack.LindenUDP
 
             // Acknowledge the UseCircuitCode packet
             SendAckImmediate(remoteEndPoint, packet.Header.Sequence);
+            
+            m_log.DebugFormat(
+                "[LLUDPSERVER]: Handling UseCircuitCode request from {0} took {1}ms", 
+                buffer.RemoteEndPoint, (DateTime.Now - startTime).Milliseconds);            
         }
 
         private void SendAckImmediate(IPEndPoint remoteEndpoint, uint sequenceNumber)
diff --git a/OpenSim/Region/CoreModules/Avatar/AvatarFactory/AvatarFactoryModule.cs b/OpenSim/Region/CoreModules/Avatar/AvatarFactory/AvatarFactoryModule.cs
index bfbbcf8..e2755c8 100644
--- a/OpenSim/Region/CoreModules/Avatar/AvatarFactory/AvatarFactoryModule.cs
+++ b/OpenSim/Region/CoreModules/Avatar/AvatarFactory/AvatarFactoryModule.cs
@@ -117,7 +117,7 @@ namespace OpenSim.Region.CoreModules.Avatar.AvatarFactory
             ScenePresence sp = m_scene.GetScenePresence(client.AgentId);
             if (sp == null)
             {
-                m_log.WarnFormat("[AVFACTORY] SetAppearance unable to find presence for {0}",client.AgentId);
+                m_log.WarnFormat("[AVATAR FACTORY MODULE]: SetAppearance unable to find presence for {0}", client.AgentId);
                 return false;
             }
 
@@ -147,14 +147,12 @@ namespace OpenSim.Region.CoreModules.Avatar.AvatarFactory
         /// <param name="visualParam"></param>
         public void SetAppearance(IClientAPI client, Primitive.TextureEntry textureEntry, byte[] visualParams)
         {
-// DEBUG ON
-            m_log.WarnFormat("[AVFACTORY] SetAppearance for {0}",client.AgentId);
-// DEBUG OFF
+//            m_log.WarnFormat("[AVATAR FACTORY MODULE]: SetAppearance for {0}",client.AgentId);
 
             ScenePresence sp = m_scene.GetScenePresence(client.AgentId);
             if (sp == null)
             {
-                m_log.WarnFormat("[AVFACTORY] SetAppearance unable to find presence for {0}",client.AgentId);
+                m_log.WarnFormat("[AVATAR FACTORY MODULE]: SetAppearance unable to find presence for {0}",client.AgentId);
                 return;
             }
             
@@ -212,8 +210,8 @@ namespace OpenSim.Region.CoreModules.Avatar.AvatarFactory
         {
             if (m_scene.AssetService.Get(textureID.ToString()) == null)
             {
-                m_log.WarnFormat("[AVFACTORY]: Missing baked texture {0} ({1}) for avatar {2}",
-                                 textureID,idx,client.Name);
+                m_log.WarnFormat("[AVATAR FACTORY MODULE]: Missing baked texture {0} ({1}) for avatar {2}",
+                                 textureID, idx, client.Name);
                 return false;
             }
             return true;
@@ -223,9 +221,7 @@ namespace OpenSim.Region.CoreModules.Avatar.AvatarFactory
 
         public void QueueAppearanceSend(UUID agentid)
         {
-// DEBUG ON
-            m_log.WarnFormat("[AVFACTORY] Queue appearance send for {0}",agentid);
-// DEBUG OFF                
+//            m_log.WarnFormat("[AVATAR FACTORY MODULE]: Queue appearance send for {0}",agentid);              
 
             // 100 nanoseconds (ticks) we should wait
             long timestamp = DateTime.Now.Ticks + Convert.ToInt64(m_sendtime * 10000000); 
@@ -238,9 +234,7 @@ namespace OpenSim.Region.CoreModules.Avatar.AvatarFactory
         
         public void QueueAppearanceSave(UUID agentid)
         {
-// DEBUG ON
-            m_log.WarnFormat("[AVFACTORY] Queue appearance save for {0}",agentid);
-// DEBUG OFF                
+//            m_log.WarnFormat("[AVATAR FACTORY MODULE]: Queue appearance save for {0}",agentid);             
 
             // 100 nanoseconds (ticks) we should wait
             long timestamp = DateTime.Now.Ticks + Convert.ToInt64(m_savetime * 10000000); 
@@ -256,13 +250,11 @@ namespace OpenSim.Region.CoreModules.Avatar.AvatarFactory
             ScenePresence sp = m_scene.GetScenePresence(agentid);
             if (sp == null)
             {
-                m_log.WarnFormat("[AVFACTORY] Agent {0} no longer in the scene",agentid);
+                m_log.WarnFormat("[AVATAR FACTORY MODULE]: Agent {0} no longer in the scene", agentid);
                 return;
             }
 
-// DEBUG ON
-            m_log.WarnFormat("[AVFACTORY] Handle appearance send for {0}",agentid);
-// DEBUG OFF                
+//            m_log.WarnFormat("[AVATAR FACTORY MODULE]: Handle appearance send for {0}", agentid);             
 
             // Send the appearance to everyone in the scene
             sp.SendAppearanceToAllOtherAgents();
@@ -288,7 +280,7 @@ namespace OpenSim.Region.CoreModules.Avatar.AvatarFactory
             ScenePresence sp = m_scene.GetScenePresence(agentid);
             if (sp == null)
             {
-                m_log.WarnFormat("[AVFACTORY] Agent {0} no longer in the scene",agentid);
+                m_log.WarnFormat("[AVATAR FACTORY MODULE]: Agent {0} no longer in the scene", agentid);
                 return;
             }
 
@@ -339,13 +331,12 @@ namespace OpenSim.Region.CoreModules.Avatar.AvatarFactory
             ScenePresence sp = m_scene.GetScenePresence(client.AgentId);
             if (sp == null)
             {
-                m_log.WarnFormat("[AVFACTORY] SendWearables unable to find presence for {0}",client.AgentId);
+                m_log.WarnFormat("[AVATAR FACTORY MODULE]: SendWearables unable to find presence for {0}", client.AgentId);
                 return;
             }
-            
-// DEBUG ON
-            m_log.WarnFormat("[AVFACTORY]: Received request for wearables of {0}", client.AgentId);
-// DEBUG OFF            
+
+//            m_log.WarnFormat("[AVATAR FACTORY MODULE]: Received request for wearables of {0}", client.AgentId);
+           
             client.SendWearables(sp.Appearance.Wearables,sp.Appearance.Serial++);
         }
 
@@ -359,13 +350,11 @@ namespace OpenSim.Region.CoreModules.Avatar.AvatarFactory
             ScenePresence sp = m_scene.GetScenePresence(client.AgentId);
             if (sp == null)
             {
-                m_log.WarnFormat("[AVFACTORY] AvatarIsWearing unable to find presence for {0}",client.AgentId);
+                m_log.WarnFormat("[AVATAR FACTORY MODULE]: AvatarIsWearing unable to find presence for {0}", client.AgentId);
                 return;
             }
             
-// DEBUG ON
-            m_log.WarnFormat("[AVFACTORY]: AvatarIsWearing called for {0}",client.AgentId);
-// DEBUG OFF
+//            m_log.WarnFormat("[AVATAR FACTORY MODULE]: AvatarIsWearing called for {0}",client.AgentId);
 
             AvatarAppearance avatAppearance = new AvatarAppearance(sp.Appearance);
 
@@ -409,7 +398,7 @@ namespace OpenSim.Region.CoreModules.Avatar.AvatarFactory
                         else
                         {
                             m_log.ErrorFormat(
-                                "[AVFACTORY]: Can't find inventory item {0} for {1}, setting to default", 
+                                "[AVATAR FACTORY MODULE]: Can't find inventory item {0} for {1}, setting to default", 
                                 appearance.Wearables[i].ItemID, (WearableType)i);
                             
                             appearance.Wearables[i].ItemID = UUID.Zero;
@@ -420,7 +409,7 @@ namespace OpenSim.Region.CoreModules.Avatar.AvatarFactory
             }
             else
             {
-                m_log.WarnFormat("[AVFACTORY]: user {0} has no inventory, appearance isn't going to work", userID);
+                m_log.WarnFormat("[AVATAR FACTORY MODULE]: user {0} has no inventory, appearance isn't going to work", userID);
             }
         }
     }
diff --git a/OpenSim/Region/CoreModules/ServiceConnectorsOut/GridUser/ActivityDetector.cs b/OpenSim/Region/CoreModules/ServiceConnectorsOut/GridUser/ActivityDetector.cs
index a64f785..6543845 100644
--- a/OpenSim/Region/CoreModules/ServiceConnectorsOut/GridUser/ActivityDetector.cs
+++ b/OpenSim/Region/CoreModules/ServiceConnectorsOut/GridUser/ActivityDetector.cs
@@ -1,4 +1,4 @@
-/*
+/*
  * Copyright (c) Contributors, http://opensimulator.org/
  * See CONTRIBUTORS.TXT for a full list of copyright holders.
  *
@@ -65,7 +65,7 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.GridUser
 
         public void OnMakeRootAgent(ScenePresence sp)
         {
-            m_log.DebugFormat("[ACTIVITY DETECTOR]: Detected root presence {0} in {1}", sp.UUID, sp.Scene.RegionInfo.RegionName);
+//            m_log.DebugFormat("[ACTIVITY DETECTOR]: Detected root presence {0} in {1}", sp.UUID, sp.Scene.RegionInfo.RegionName);
             m_GridUserService.SetLastPosition(sp.UUID.ToString(), UUID.Zero, sp.Scene.RegionInfo.RegionID, sp.AbsolutePosition, sp.Lookat);
         }
 
diff --git a/OpenSim/Region/CoreModules/ServiceConnectorsOut/Presence/PresenceDetector.cs b/OpenSim/Region/CoreModules/ServiceConnectorsOut/Presence/PresenceDetector.cs
index 62b8278..fa5b873 100644
--- a/OpenSim/Region/CoreModules/ServiceConnectorsOut/Presence/PresenceDetector.cs
+++ b/OpenSim/Region/CoreModules/ServiceConnectorsOut/Presence/PresenceDetector.cs
@@ -1,4 +1,4 @@
-/*
+/*
  * Copyright (c) Contributors, http://opensimulator.org/
  * See CONTRIBUTORS.TXT for a full list of copyright holders.
  *
@@ -71,7 +71,7 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Presence
 
         public void OnMakeRootAgent(ScenePresence sp)
         {
-            m_log.DebugFormat("[PRESENCE DETECTOR]: Detected root presence {0} in {1}", sp.UUID, sp.Scene.RegionInfo.RegionName);
+//            m_log.DebugFormat("[PRESENCE DETECTOR]: Detected root presence {0} in {1}", sp.UUID, sp.Scene.RegionInfo.RegionName);
             m_PresenceService.ReportAgent(sp.ControllingClient.SessionId, sp.Scene.RegionInfo.RegionID);
         }
 
diff --git a/OpenSim/Region/CoreModules/World/WorldMap/WorldMapModule.cs b/OpenSim/Region/CoreModules/World/WorldMap/WorldMapModule.cs
index fdbbccf..9869f4a 100644
--- a/OpenSim/Region/CoreModules/World/WorldMap/WorldMapModule.cs
+++ b/OpenSim/Region/CoreModules/World/WorldMap/WorldMapModule.cs
@@ -324,7 +324,7 @@ namespace OpenSim.Region.CoreModules.World.WorldMap
             if (threadrunning) return;
             threadrunning = true;
 
-            m_log.Debug("[WORLD MAP]: Starting remote MapItem request thread");
+//            m_log.Debug("[WORLD MAP]: Starting remote MapItem request thread");
 
             Watchdog.StartThread(process, "MapItemRequestThread", ThreadPriority.BelowNormal, true);
         }
diff --git a/OpenSim/Region/Framework/Scenes/ScenePresence.cs b/OpenSim/Region/Framework/Scenes/ScenePresence.cs
index afafa5b..8aa507f 100644
--- a/OpenSim/Region/Framework/Scenes/ScenePresence.cs
+++ b/OpenSim/Region/Framework/Scenes/ScenePresence.cs
@@ -1075,9 +1075,11 @@ namespace OpenSim.Region.Framework.Scenes
         /// </summary>
         public void CompleteMovement(IClientAPI client)
         {
-// DEBUG ON
-            m_log.WarnFormat("[SCENE PRESENCE]: CompleteMovement for {0}",UUID);
-// DEBUG OFF
+            DateTime startTime = DateTime.Now;
+            
+            m_log.DebugFormat(
+                "[SCENE PRESENCE]: Completing movement of {0} into region {1}", 
+                client.Name, Scene.RegionInfo.RegionName);
 
             Vector3 look = Velocity;
             if ((look.X == 0) && (look.Y == 0) && (look.Z == 0))
@@ -1125,6 +1127,10 @@ namespace OpenSim.Region.Framework.Scenes
                 if (friendsModule != null)
                     friendsModule.SendFriendsOnlineIfNeeded(ControllingClient);
             }
+
+            m_log.DebugFormat(
+                "[SCENE PRESENCE]: Completing movement of {0} into region {1} took {2}ms", 
+                client.Name, Scene.RegionInfo.RegionName, (DateTime.Now - startTime).Milliseconds);            
         }
 
         /// <summary>
@@ -2378,7 +2384,7 @@ namespace OpenSim.Region.Framework.Scenes
             if (remoteAvatar == null)
                 return;
 
-            IClientAPI cl=remoteAvatar.ControllingClient;
+            IClientAPI cl = remoteAvatar.ControllingClient;
             if (cl == null)
                 return;
 
@@ -2387,13 +2393,13 @@ namespace OpenSim.Region.Framework.Scenes
 
             if (LocalId == remoteAvatar.LocalId)
             {
-                m_log.WarnFormat("[SP] An agent is attempting to send data to itself; {0}",UUID);
+                m_log.WarnFormat("[SCENEPRESENCE]: An agent is attempting to send avatar data to itself; {0}", UUID);
                 return;
             }
 
             if (IsChildAgent)
             {
-                m_log.WarnFormat("[SCENEPRESENCE] A child agent is attempting to send out avatar data");
+                m_log.WarnFormat("[SCENEPRESENCE]: A child agent is attempting to send out avatar data; {0}", UUID);
                 return;
             }
             
@@ -2476,14 +2482,14 @@ namespace OpenSim.Region.Framework.Scenes
             {
                 if (m_scene.AvatarFactory.ValidateBakedTextureCache(m_controllingClient))
                 {
-                    m_log.WarnFormat("[SP] baked textures are in the ache for {0}",Name);
+//                    m_log.WarnFormat("[SCENEPRESENCE]: baked textures are in the cache for {0}", Name);
                     m_controllingClient.SendAppearance(
                         m_appearance.Owner,m_appearance.VisualParams,m_appearance.Texture.GetBytes());
                 }
             }
             else
             {
-                m_log.WarnFormat("[SP] AvatarFactory not set");
+                m_log.WarnFormat("[SCENEPRESENCE]: AvatarFactory not set for {0}", Name);
             }
 
             SendInitialFullUpdateToAllClients();
@@ -2495,7 +2501,7 @@ namespace OpenSim.Region.Framework.Scenes
         public void SendAppearanceToAllOtherAgents()
         {
 // DEBUG ON
-            m_log.WarnFormat("[SP] Send appearance from {0} to all other agents",m_uuid);
+//            m_log.WarnFormat("[SCENEPRESENCE]: Send appearance from {0} to all other agents", m_uuid);
 // DEBUG OFF
             m_perfMonMS = Util.EnvironmentTickCount();
 
@@ -2518,7 +2524,7 @@ namespace OpenSim.Region.Framework.Scenes
         {
             if (LocalId == avatar.LocalId)
             {
-                m_log.WarnFormat("[SP] An agent is attempting to send data to itself; {0}",UUID);
+                m_log.WarnFormat("[SCENE PRESENCE]: An agent is attempting to send appearance data to itself; {0}", UUID);
                 return;
             }
 
diff --git a/OpenSim/Services/PresenceService/PresenceService.cs b/OpenSim/Services/PresenceService/PresenceService.cs
index 976153f..09c31c3 100644
--- a/OpenSim/Services/PresenceService/PresenceService.cs
+++ b/OpenSim/Services/PresenceService/PresenceService.cs
@@ -88,7 +88,7 @@ namespace OpenSim.Services.PresenceService
 
         public bool ReportAgent(UUID sessionID, UUID regionID)
         {
-            m_log.DebugFormat("[PRESENCE SERVICE]: ReportAgent with session {0} in region {1}", sessionID, regionID);
+//            m_log.DebugFormat("[PRESENCE SERVICE]: ReportAgent with session {0} in region {1}", sessionID, regionID);
             try
             {
                 PresenceData pdata = m_Database.Get(sessionID);