From e6d7303b296468a06ada761706e25d49587b308f Mon Sep 17 00:00:00 2001 From: John Hurliman Date: Thu, 5 Nov 2009 12:01:40 -0800 Subject: [PATCH] Applying #4332, optional packet statistics logging --- .../ClientStack/LindenUDP/LLClientView.cs | 4 + .../ClientStack/LindenUDP/LLUDPServer.cs | 111 ++++++++++++++++++ OpenSim/Region/Framework/Scenes/Scene.cs | 100 ++++++++++++++++ 3 files changed, 215 insertions(+) diff --git a/OpenSim/Region/ClientStack/LindenUDP/LLClientView.cs b/OpenSim/Region/ClientStack/LindenUDP/LLClientView.cs index 34cad7b5cf..101a44bf87 100644 --- a/OpenSim/Region/ClientStack/LindenUDP/LLClientView.cs +++ b/OpenSim/Region/ClientStack/LindenUDP/LLClientView.cs @@ -4905,6 +4905,10 @@ namespace OpenSim.Region.ClientStack.LindenUDP /// Throttling category for the packet 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 6165984c3b..c773c05905 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 093ca3ef1d..6edef11e0f 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 {