1 files changed, 107 insertions, 39 deletions

diff --git a/OpenSim/Region/OptionalModules/Avatar/XmlRpcGroups/GroupsMessagingModule.cs b/OpenSim/Region/OptionalModules/Avatar/XmlRpcGroups/GroupsMessagingModule.cs
index fd804cd..e1b6abb 100644
--- a/OpenSim/Region/OptionalModules/Avatar/XmlRpcGroups/GroupsMessagingModule.cs
+++ b/OpenSim/Region/OptionalModules/Avatar/XmlRpcGroups/GroupsMessagingModule.cs
@@ -55,8 +55,8 @@ namespace OpenSim.Region.OptionalModules.Avatar.XmlRpcGroups
         private IGroupsServicesConnector m_groupData = null;
 
         // Config Options
-        private bool m_groupMessagingEnabled = false;
-        private bool m_debugEnabled = true;
+        private bool m_groupMessagingEnabled;
+        private bool m_debugEnabled;
 
         /// <summary>
         /// If enabled, module only tries to send group IMs to online users by querying cached presence information.
@@ -113,7 +113,7 @@ namespace OpenSim.Region.OptionalModules.Avatar.XmlRpcGroups
                 if (m_messageOnlineAgentsOnly)
                      m_usersOnlineCache = new ExpiringCache<UUID, PresenceInfo[]>();
 
-                m_debugEnabled = groupsConfig.GetBoolean("DebugEnabled", true);
+                m_debugEnabled = groupsConfig.GetBoolean("MessagingDebugEnabled", m_debugEnabled);
             }
 
             m_log.InfoFormat(
@@ -127,6 +127,14 @@ namespace OpenSim.Region.OptionalModules.Avatar.XmlRpcGroups
                 return;
             
             scene.RegisterModuleInterface<IGroupsMessagingModule>(this);
+
+            scene.AddCommand(
+                "Debug",
+                this,
+                "debug groups messaging verbose",
+                "debug groups messaging verbose <true|false>",
+                "This setting turns on very verbose groups messaging debugging",
+                HandleDebugGroupsMessagingVerbose);
         }
         
         public void RegionLoaded(Scene scene)
@@ -218,6 +226,26 @@ namespace OpenSim.Region.OptionalModules.Avatar.XmlRpcGroups
 
         #endregion
 
+        private void HandleDebugGroupsMessagingVerbose(object modules, string[] args)
+        {
+            if (args.Length < 5)
+            {
+                MainConsole.Instance.Output("Usage: debug groups messaging verbose <true|false>");
+                return;
+            }
+
+            bool verbose = false;
+            if (!bool.TryParse(args[4], out verbose))
+            {
+                MainConsole.Instance.Output("Usage: debug groups messaging verbose <true|false>");
+                return;
+            }
+
+            m_debugEnabled = verbose;
+
+            MainConsole.Instance.OutputFormat("{0} verbose logging set to {1}", Name, m_debugEnabled);
+        }
+
         /// <summary>
         /// Not really needed, but does confirm that the group exists.
         /// </summary>
@@ -246,8 +274,11 @@ namespace OpenSim.Region.OptionalModules.Avatar.XmlRpcGroups
         public void SendMessageToGroup(
             GridInstantMessage im, UUID groupID, UUID sendingAgentForGroupCalls, Func<GroupMembersData, bool> sendCondition)
         {
+            int requestStartTick = Environment.TickCount;
+
             List<GroupMembersData> groupMembers = m_groupData.GetGroupMembers(sendingAgentForGroupCalls, groupID);
             int groupMembersCount = groupMembers.Count;
+            HashSet<string> attemptDeliveryUuidSet = null;
 
             if (m_messageOnlineAgentsOnly)
             {
@@ -263,10 +294,12 @@ namespace OpenSim.Region.OptionalModules.Avatar.XmlRpcGroups
                     m_usersOnlineCache.Add(groupID, onlineAgents, m_usersOnlineCacheExpirySeconds);
                 }
 
-                HashSet<string> onlineAgentsUuidSet = new HashSet<string>();
-                Array.ForEach<PresenceInfo>(onlineAgents, pi => onlineAgentsUuidSet.Add(pi.UserID));
+                attemptDeliveryUuidSet 
+                    = new HashSet<string>(Array.ConvertAll<PresenceInfo, string>(onlineAgents, pi => pi.UserID));
 
-                groupMembers = groupMembers.Where(gmd => onlineAgentsUuidSet.Contains(gmd.AgentID.ToString())).ToList();
+                //Array.ForEach<PresenceInfo>(onlineAgents, pi => attemptDeliveryUuidSet.Add(pi.UserID));
+
+                //groupMembers = groupMembers.Where(gmd => onlineAgentsUuidSet.Contains(gmd.AgentID.ToString())).ToList();
 
     //            if (m_debugEnabled)
 //                    m_log.DebugFormat(
@@ -275,13 +308,14 @@ namespace OpenSim.Region.OptionalModules.Avatar.XmlRpcGroups
             }
             else
             {
+                attemptDeliveryUuidSet 
+                    = new HashSet<string>(groupMembers.ConvertAll<string>(gmd => gmd.AgentID.ToString()));
+
                 if (m_debugEnabled)
                     m_log.DebugFormat(
                         "[GROUPS-MESSAGING]: SendMessageToGroup called for group {0} with {1} visible members",
                         groupID, groupMembers.Count);
-            }
-
-            int requestStartTick = Environment.TickCount;
+            }           
 
             foreach (GroupMembersData member in groupMembers)
             {
@@ -309,7 +343,7 @@ namespace OpenSim.Region.OptionalModules.Avatar.XmlRpcGroups
 
                 // Copy Message
                 GridInstantMessage msg = new GridInstantMessage();
-                msg.imSessionID = groupID.Guid;
+                msg.imSessionID = im.imSessionID;
                 msg.fromAgentName = im.fromAgentName;
                 msg.message = im.message;
                 msg.dialog = im.dialog;
@@ -325,26 +359,51 @@ namespace OpenSim.Region.OptionalModules.Avatar.XmlRpcGroups
 
                 msg.toAgentID = member.AgentID.Guid;
 
-                IClientAPI client = GetActiveClient(member.AgentID);
-                if (client == null)
+                if (attemptDeliveryUuidSet.Contains(member.AgentID.ToString()))
                 {
-                    // If they're not local, forward across the grid
-                    if (m_debugEnabled) m_log.DebugFormat("[GROUPS-MESSAGING]: Delivering to {0} via Grid", member.AgentID);
-                    m_msgTransferModule.SendInstantMessage(msg, delegate(bool success) { });
+                    IClientAPI client = GetActiveClient(member.AgentID);
+                    if (client == null)
+                    {
+                        int startTick = Environment.TickCount;
+
+                        // If they're not local, forward across the grid
+                        m_msgTransferModule.SendInstantMessage(msg, delegate(bool success) { });
+
+                        if (m_debugEnabled) 
+                            m_log.DebugFormat(
+                                "[GROUPS-MESSAGING]: Delivering to {0} via grid took {1} ms", 
+                                member.AgentID, Environment.TickCount - startTick);
+                    }
+                    else
+                    {
+                        int startTick = Environment.TickCount;
+
+                        ProcessMessageFromGroupSession(msg, client);
+
+                        // Deliver locally, directly
+                        if (m_debugEnabled) 
+                            m_log.DebugFormat(
+                                "[GROUPS-MESSAGING]: Delivering to {0} locally took {1} ms", 
+                                member.AgentID, Environment.TickCount - startTick);
+                    }
                 }
                 else
                 {
-                    // Deliver locally, directly
-                    if (m_debugEnabled) m_log.DebugFormat("[GROUPS-MESSAGING]: Passing to ProcessMessageFromGroupSession to deliver to {0} locally", client.Name);
-                    ProcessMessageFromGroupSession(msg, client);
+                    int startTick = Environment.TickCount;
+
+                    m_msgTransferModule.HandleUndeliverableMessage(msg, delegate(bool success) { });
+
+                    if (m_debugEnabled) 
+                        m_log.DebugFormat(
+                            "[GROUPS-MESSAGING]: Handling undeliverable message for {0} took {1} ms", 
+                            member.AgentID, Environment.TickCount - startTick);
                 }
             }
 
-            // Temporary for assessing how long it still takes to send messages to large online groups.
-            if (m_messageOnlineAgentsOnly)
+            if (m_debugEnabled)
                 m_log.DebugFormat(
-                    "[GROUPS-MESSAGING]: SendMessageToGroup for group {0} with {1} visible members, {2} online took {3}ms",
-                    groupID, groupMembersCount, groupMembers.Count(), Environment.TickCount - requestStartTick);
+                    "[GROUPS-MESSAGING]: Total SendMessageToGroup for group {0} with {1} members, {2} candidates for delivery took {3} ms",
+                    groupID, groupMembersCount, attemptDeliveryUuidSet.Count(), Environment.TickCount - requestStartTick);
         }
         
         #region SimGridEventHandlers
@@ -407,7 +466,10 @@ namespace OpenSim.Region.OptionalModules.Avatar.XmlRpcGroups
 
         private void ProcessMessageFromGroupSession(GridInstantMessage msg, IClientAPI client)
         {
-            if (m_debugEnabled) m_log.DebugFormat("[GROUPS-MESSAGING]: Session message from {0} going to agent {1}", msg.fromAgentName, msg.toAgentID);
+            if (m_debugEnabled) 
+                m_log.DebugFormat(
+                    "[GROUPS-MESSAGING]: Session message from {0} going to agent {1}, sessionID {2}, type {3}",
+                    msg.fromAgentName, msg.toAgentID, msg.imSessionID, (InstantMessageDialog)msg.dialog);
 
             UUID AgentID = new UUID(msg.fromAgentID);
             UUID GroupID = new UUID(msg.imSessionID);
@@ -431,8 +493,6 @@ namespace OpenSim.Region.OptionalModules.Avatar.XmlRpcGroups
                         // Add them to the session for now, and Invite them
                         m_groupData.AgentInvitedToGroupChatSession(AgentID, GroupID);
 
-                        UUID toAgentID = new UUID(msg.toAgentID);
-
                         GroupRecord groupInfo = m_groupData.GetGroupRecord(UUID.Zero, GroupID, null);
                         if (groupInfo != null)
                         {
@@ -577,15 +637,15 @@ namespace OpenSim.Region.OptionalModules.Avatar.XmlRpcGroups
             // Don't log any normal IMs (privacy!)
             if (m_debugEnabled && im.dialog != (byte)InstantMessageDialog.MessageFromAgent)
             {
-                m_log.WarnFormat("[GROUPS-MESSAGING]: IM: fromGroup({0})", im.fromGroup ? "True" : "False");
-                m_log.WarnFormat("[GROUPS-MESSAGING]: IM: Dialog({0})", (InstantMessageDialog)im.dialog);
-                m_log.WarnFormat("[GROUPS-MESSAGING]: IM: fromAgentID({0})", im.fromAgentID);
-                m_log.WarnFormat("[GROUPS-MESSAGING]: IM: fromAgentName({0})", im.fromAgentName);
-                m_log.WarnFormat("[GROUPS-MESSAGING]: IM: imSessionID({0})", im.imSessionID);
-                m_log.WarnFormat("[GROUPS-MESSAGING]: IM: message({0})", im.message);
-                m_log.WarnFormat("[GROUPS-MESSAGING]: IM: offline({0})", im.offline);
-                m_log.WarnFormat("[GROUPS-MESSAGING]: IM: toAgentID({0})", im.toAgentID);
-                m_log.WarnFormat("[GROUPS-MESSAGING]: IM: binaryBucket({0})", OpenMetaverse.Utils.BytesToHexString(im.binaryBucket, "BinaryBucket"));
+                m_log.DebugFormat("[GROUPS-MESSAGING]: IM: fromGroup({0})", im.fromGroup ? "True" : "False");
+                m_log.DebugFormat("[GROUPS-MESSAGING]: IM: Dialog({0})", (InstantMessageDialog)im.dialog);
+                m_log.DebugFormat("[GROUPS-MESSAGING]: IM: fromAgentID({0})", im.fromAgentID);
+                m_log.DebugFormat("[GROUPS-MESSAGING]: IM: fromAgentName({0})", im.fromAgentName);
+                m_log.DebugFormat("[GROUPS-MESSAGING]: IM: imSessionID({0})", im.imSessionID);
+                m_log.DebugFormat("[GROUPS-MESSAGING]: IM: message({0})", im.message);
+                m_log.DebugFormat("[GROUPS-MESSAGING]: IM: offline({0})", im.offline);
+                m_log.DebugFormat("[GROUPS-MESSAGING]: IM: toAgentID({0})", im.toAgentID);
+                m_log.DebugFormat("[GROUPS-MESSAGING]: IM: binaryBucket({0})", OpenMetaverse.Utils.BytesToHexString(im.binaryBucket, "BinaryBucket"));
             }
         }
 
@@ -596,7 +656,8 @@ namespace OpenSim.Region.OptionalModules.Avatar.XmlRpcGroups
         /// </summary>
         private IClientAPI GetActiveClient(UUID agentID)
         {
-            if (m_debugEnabled) m_log.WarnFormat("[GROUPS-MESSAGING]: Looking for local client {0}", agentID);
+            if (m_debugEnabled) 
+                m_log.DebugFormat("[GROUPS-MESSAGING]: Looking for local client {0}", agentID);
 
             IClientAPI child = null;
 
@@ -608,12 +669,16 @@ namespace OpenSim.Region.OptionalModules.Avatar.XmlRpcGroups
                 {
                     if (!sp.IsChildAgent)
                     {
-                        if (m_debugEnabled) m_log.WarnFormat("[GROUPS-MESSAGING]: Found root agent for client : {0}", sp.ControllingClient.Name);
+                        if (m_debugEnabled) 
+                            m_log.DebugFormat("[GROUPS-MESSAGING]: Found root agent for client : {0}", sp.ControllingClient.Name);
+
                         return sp.ControllingClient;
                     }
                     else
                     {
-                        if (m_debugEnabled) m_log.WarnFormat("[GROUPS-MESSAGING]: Found child agent for client : {0}", sp.ControllingClient.Name);
+                        if (m_debugEnabled) 
+                            m_log.DebugFormat("[GROUPS-MESSAGING]: Found child agent for client : {0}", sp.ControllingClient.Name);
+
                         child = sp.ControllingClient;
                     }
                 }
@@ -622,12 +687,15 @@ namespace OpenSim.Region.OptionalModules.Avatar.XmlRpcGroups
             // If we didn't find a root, then just return whichever child we found, or null if none
             if (child == null)
             {
-                if (m_debugEnabled) m_log.WarnFormat("[GROUPS-MESSAGING]: Could not find local client for agent : {0}", agentID);
+                if (m_debugEnabled) 
+                    m_log.DebugFormat("[GROUPS-MESSAGING]: Could not find local client for agent : {0}", agentID);
             }
             else
             {
-                if (m_debugEnabled) m_log.WarnFormat("[GROUPS-MESSAGING]: Returning child agent for client : {0}", child.Name);
+                if (m_debugEnabled) 
+                    m_log.DebugFormat("[GROUPS-MESSAGING]: Returning child agent for client : {0}", child.Name);
             }
+
             return child;
         }