Applying #4332, optional packet statistics logging

3 files changed, 215 insertions, 0 deletions

diff --git a/OpenSim/Region/ClientStack/LindenUDP/LLClientView.cs b/OpenSim/Region/ClientStack/LindenUDP/LLClientView.cs
index 34cad7b..101a44b 100644
--- a/OpenSim/Region/ClientStack/LindenUDP/LLClientView.cs
+++ b/OpenSim/Region/ClientStack/LindenUDP/LLClientView.cs
@@ -4905,6 +4905,10 @@ namespace OpenSim.Region.ClientStack.LindenUDP
         /// <param name="throttlePacketType">Throttling category for the packet</param>
         protected void OutPacket(Packet packet, ThrottleOutPacketType throttlePacketType)
         {
+            #region BinaryStats
+            LLUDPServer.LogPacketHeader(false, m_circuitCode, 0, packet.Type, (ushort)packet.Length);
+            #endregion BinaryStats
+
             m_udpServer.SendPacket(m_udpClient, packet, throttlePacketType, true);
         }
 
diff --git a/OpenSim/Region/ClientStack/LindenUDP/LLUDPServer.cs b/OpenSim/Region/ClientStack/LindenUDP/LLUDPServer.cs
index 6165984..c773c05 100644
--- a/OpenSim/Region/ClientStack/LindenUDP/LLUDPServer.cs
+++ b/OpenSim/Region/ClientStack/LindenUDP/LLUDPServer.cs
@@ -27,6 +27,7 @@
 
 using System;
 using System.Collections.Generic;
+using System.IO;
 using System.Net;
 using System.Net.Sockets;
 using System.Reflection;
@@ -204,6 +205,31 @@ namespace OpenSim.Region.ClientStack.LindenUDP
                 TextureSendLimit = 20;
             }
 
+            #region BinaryStats
+            config = configSource.Configs["Statistics.Binary"];
+            m_shouldCollectStats = false;
+            if (config != null)
+            {
+               if (config.Contains("enabled") && config.GetBoolean("enabled"))
+               {
+                   if (config.Contains("collect_packet_headers"))
+                       m_shouldCollectStats = config.GetBoolean("collect_packet_headers");
+                   if (config.Contains("packet_headers_period_seconds"))
+                   {
+                       binStatsMaxFilesize = TimeSpan.FromSeconds(config.GetInt("region_stats_period_seconds"));
+                   }
+                   if (config.Contains("stats_dir"))
+                   {
+                       binStatsDir = config.GetString("stats_dir");
+                   }
+               }
+               else
+               {
+                   m_shouldCollectStats = false;
+               }
+           }
+           #endregion BinaryStats
+
             m_throttle = new TokenBucket(null, sceneThrottleBps, sceneThrottleBps);
             m_throttleRates = new ThrottleRates(configSource);
         }
@@ -679,6 +705,10 @@ namespace OpenSim.Region.ClientStack.LindenUDP
 
             #endregion Incoming Packet Accounting
 
+            #region BinaryStats
+            LogPacketHeader(true, udpClient.CircuitCode, 0, packet.Type, (ushort)packet.Length);
+            #endregion BinaryStats
+
             #region Ping Check Handling
 
             if (packet.Type == PacketType.StartPingCheck)
@@ -700,6 +730,87 @@ namespace OpenSim.Region.ClientStack.LindenUDP
             packetInbox.Enqueue(new IncomingPacket(udpClient, packet));
         }
 
+        #region BinaryStats
+
+        public class PacketLogger
+        {
+            public DateTime StartTime;
+            public string Path = null;
+            public System.IO.BinaryWriter Log = null;
+        }
+
+        public static PacketLogger PacketLog;
+
+        protected static bool m_shouldCollectStats = false;
+        // Number of seconds to log for
+        static TimeSpan binStatsMaxFilesize = TimeSpan.FromSeconds(300);
+        static object binStatsLogLock = new object();
+        static string binStatsDir = "";
+
+        public static void LogPacketHeader(bool incoming, uint circuit, byte flags, PacketType packetType, ushort size)
+        {
+            if (!m_shouldCollectStats) return;
+
+            // Binary logging format is TTTTTTTTCCCCFPPPSS, T=Time, C=Circuit, F=Flags, P=PacketType, S=size
+
+            // Put the incoming bit into the least significant bit of the flags byte
+            if (incoming)
+                flags |= 0x01;
+            else
+                flags &= 0xFE;
+
+            // Put the flags byte into the most significant bits of the type integer
+            uint type = (uint)packetType;
+            type |= (uint)flags << 24;
+
+            // m_log.Debug("1 LogPacketHeader(): Outside lock");
+            lock (binStatsLogLock)
+            {
+                DateTime now = DateTime.Now;
+
+                // m_log.Debug("2 LogPacketHeader(): Inside lock. now is " + now.Ticks);
+                try
+                {
+                    if (PacketLog == null || (now > PacketLog.StartTime + binStatsMaxFilesize))
+                    {
+                        if (PacketLog != null && PacketLog.Log != null)
+                        {
+                            PacketLog.Log.Close();
+                        }
+
+                        // First log file or time has expired, start writing to a new log file
+                        PacketLog = new PacketLogger();
+                        PacketLog.StartTime = now;
+                        PacketLog.Path = (binStatsDir.Length > 0 ? binStatsDir + System.IO.Path.DirectorySeparatorChar.ToString() : "")
+                                + String.Format("packets-{0}.log", now.ToString("yyyyMMddHHmmss"));
+                        PacketLog.Log = new BinaryWriter(File.Open(PacketLog.Path, FileMode.Append, FileAccess.Write));
+                    }
+
+                    // Serialize the data
+                    byte[] output = new byte[18];
+                    Buffer.BlockCopy(BitConverter.GetBytes(now.Ticks), 0, output, 0, 8);
+                    Buffer.BlockCopy(BitConverter.GetBytes(circuit), 0, output, 8, 4);
+                    Buffer.BlockCopy(BitConverter.GetBytes(type), 0, output, 12, 4);
+                    Buffer.BlockCopy(BitConverter.GetBytes(size), 0, output, 16, 2);
+
+                    // Write the serialized data to disk
+                    if (PacketLog != null && PacketLog.Log != null)
+                        PacketLog.Log.Write(output);
+                }
+                catch (Exception ex)
+                {
+                    m_log.Error("Packet statistics gathering failed: " + ex.Message, ex);
+                    if (PacketLog.Log != null)
+                    {
+                        PacketLog.Log.Close();
+                    }
+                    PacketLog = null;
+                }
+            }
+        }
+
+        #endregion BinaryStats
+
         private void HandleUseCircuitCode(object o)
         {
             object[] array = (object[])o;
diff --git a/OpenSim/Region/Framework/Scenes/Scene.cs b/OpenSim/Region/Framework/Scenes/Scene.cs
index 093ca3e..6edef11 100644
--- a/OpenSim/Region/Framework/Scenes/Scene.cs
+++ b/OpenSim/Region/Framework/Scenes/Scene.cs
@@ -36,6 +36,7 @@ using System.Timers;
 using System.Xml;
 using Nini.Config;
 using OpenMetaverse;
+using OpenMetaverse.Packets;
 using OpenMetaverse.Imaging;
 using OpenSim.Framework;
 using OpenSim.Services.Interfaces;
@@ -397,6 +398,73 @@ namespace OpenSim.Region.Framework.Scenes
 
         #endregion
 
+        #region BinaryStats
+
+        public class StatLogger
+        {
+            public DateTime StartTime;
+            public string Path;
+            public System.IO.BinaryWriter Log;
+        }
+        static StatLogger m_statLog = null;
+        static TimeSpan m_statLogPeriod = TimeSpan.FromSeconds(300);
+        static string m_statsDir = String.Empty;
+        static Object m_statLockObject = new Object();
+        private void LogSimStats(SimStats stats)
+        {
+            SimStatsPacket pack = new SimStatsPacket();
+            pack.Region = new SimStatsPacket.RegionBlock();
+            pack.Region.RegionX = stats.RegionX;
+            pack.Region.RegionY = stats.RegionY;
+            pack.Region.RegionFlags = stats.RegionFlags;
+            pack.Region.ObjectCapacity = stats.ObjectCapacity;
+            //pack.Region = //stats.RegionBlock;
+            pack.Stat = stats.StatsBlock;
+            pack.Header.Reliable = false;
+
+            // note that we are inside the reporter lock when called
+            DateTime now = DateTime.Now;
+
+            // hide some time information into the packet
+            pack.Header.Sequence = (uint)now.Ticks;
+
+            lock (m_statLockObject) // m_statLog is shared so make sure there is only executer here
+            {
+                try
+                {
+                    if (m_statLog == null || now > m_statLog.StartTime + m_statLogPeriod)
+                    {
+                        // First log file or time has expired, start writing to a new log file
+                        if (m_statLog != null && m_statLog.Log != null)
+                        {
+                            m_statLog.Log.Close();
+                        }
+                        m_statLog = new StatLogger();
+                        m_statLog.StartTime = now;
+                        m_statLog.Path = (m_statsDir.Length > 0 ? m_statsDir + System.IO.Path.DirectorySeparatorChar.ToString() : "")
+                                + String.Format("stats-{0}.log", now.ToString("yyyyMMddHHmmss"));
+                        m_statLog.Log = new BinaryWriter(File.Open(m_statLog.Path, FileMode.Append, FileAccess.Write));
+                    }
+
+                    // Write the serialized data to disk
+                    if (m_statLog != null && m_statLog.Log != null)
+                        m_statLog.Log.Write(pack.ToBytes());
+                }
+                catch (Exception ex)
+                {
+                    m_log.Error("statistics gathering failed: " + ex.Message, ex);
+                    if (m_statLog != null && m_statLog.Log != null)
+                    {
+                        m_statLog.Log.Close();
+                    }
+                    m_statLog = null;
+                }
+            }
+            return;
+        }
+
+        #endregion
+
         #region Constructors
 
         public Scene(RegionInfo regInfo, AgentCircuitManager authen,
@@ -582,6 +650,38 @@ namespace OpenSim.Region.Framework.Scenes
                 }
 
                 m_log.Info("[SCENE]: Using the " + m_update_prioritization_scheme + " prioritization scheme");
+
+                #region BinaryStats
+
+                try
+                {
+                    IConfig statConfig = m_config.Configs["Statistics.Binary"];
+                    if (statConfig.Contains("enabled") && statConfig.GetBoolean("enabled"))
+                    {
+                        if (statConfig.Contains("collect_region_stats"))
+                        {
+                            if (statConfig.GetBoolean("collect_region_stats"))
+                            {
+                                // if enabled, add us to the event. If not enabled, I won't get called
+                                StatsReporter.OnSendStatsResult += LogSimStats;
+                            }
+                        }
+                        if (statConfig.Contains("region_stats_period_seconds"))
+                        {
+                            m_statLogPeriod = TimeSpan.FromSeconds(statConfig.GetInt("region_stats_period_seconds"));
+                        }
+                        if (statConfig.Contains("stats_dir"))
+                        {
+                            m_statsDir = statConfig.GetString("stats_dir");
+                        }
+                    }
+                }
+                catch
+                {
+                    // if it doesn't work, we don't collect anything
+                }
+
+                #endregion BinaryStats
             }
             catch
             {