From 84d7227dfd8fc7e673b3015e2b5495d1752e16a3 Mon Sep 17 00:00:00 2001 From: Oren Hurvitz Date: Thu, 16 Jan 2014 15:08:45 +0200 Subject: [PATCH] Changed LogThreadPool to have 4 logging levels. Added console command "debug threadpool level" to set the logging level. Resolves http://opensimulator.org/mantis/view.php?id=6945 --- OpenSim/Framework/Servers/ServerBase.cs | 38 ++++++++++++++++ OpenSim/Framework/Util.cs | 59 +++++++++++++++++-------- 2 files changed, 78 insertions(+), 19 deletions(-) diff --git a/OpenSim/Framework/Servers/ServerBase.cs b/OpenSim/Framework/Servers/ServerBase.cs index c258ff6403..fd5658787c 100644 --- a/OpenSim/Framework/Servers/ServerBase.cs +++ b/OpenSim/Framework/Servers/ServerBase.cs @@ -279,6 +279,17 @@ namespace OpenSim.Framework.Servers "debug threadpool status", "Show current debug threadpool parameters.", HandleDebugThreadpoolStatus); + + m_console.Commands.AddCommand( + "Debug", false, "debug threadpool level", + "debug threadpool level 0.." + Util.MAX_THREADPOOL_LEVEL, + "Turn on logging of activity in the main thread pool.", + "Log levels:\n" + + " 0 = no logging\n" + + " 1 = only first line of stack trace; don't log common threads\n" + + " 2 = full stack trace; don't log common threads\n" + + " 3 = full stack trace, including common threads\n", + HandleDebugThreadpoolLevel); m_console.Commands.AddCommand( "Debug", false, "force gc", @@ -432,6 +443,33 @@ namespace OpenSim.Framework.Servers } } + private static void HandleDebugThreadpoolLevel(string module, string[] cmdparams) + { + if (cmdparams.Length < 4) + { + MainConsole.Instance.Output("Usage: debug threadpool level 0.." + Util.MAX_THREADPOOL_LEVEL); + return; + } + + string rawLevel = cmdparams[3]; + int newLevel; + + if (!int.TryParse(rawLevel, out newLevel)) + { + MainConsole.Instance.OutputFormat("{0} is not a valid debug level", rawLevel); + return; + } + + if (newLevel < 0 || newLevel > Util.MAX_THREADPOOL_LEVEL) + { + MainConsole.Instance.OutputFormat("{0} is outside the valid debug level range of 0.." + Util.MAX_THREADPOOL_LEVEL, newLevel); + return; + } + + Util.LogThreadPool = newLevel; + MainConsole.Instance.OutputFormat("LogThreadPool set to {0}", newLevel); + } + private void HandleForceGc(string module, string[] args) { Notice("Manually invoking runtime garbage collection"); diff --git a/OpenSim/Framework/Util.cs b/OpenSim/Framework/Util.cs index 2de596e8f5..b39dc5f3bf 100644 --- a/OpenSim/Framework/Util.cs +++ b/OpenSim/Framework/Util.cs @@ -110,15 +110,6 @@ namespace OpenSim.Framework public int MaxConcurrentWorkItems { get; set; } } - [Flags] - public enum DebugFlagsEnum : uint - { - None = 0, - - // Log every invocation of a thread using the threadpool - LogThreadPool = 0x01 - } - /// /// Miscellaneous utility functions /// @@ -127,13 +118,19 @@ namespace OpenSim.Framework private static readonly ILog m_log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType); /// - /// Flags that enable additional debugging. + /// Log-level for the thread pool: + /// 0 = no logging + /// 1 = only first line of stack trace; don't log common threads + /// 2 = full stack trace; don't log common threads + /// 3 = full stack trace, including common threads /// - public static DebugFlagsEnum DebugFlags { get; set; } + public static int LogThreadPool { get; set; } + + public static readonly int MAX_THREADPOOL_LEVEL = 3; static Util() { - DebugFlags = DebugFlagsEnum.None; + LogThreadPool = 0; } private static uint nextXferID = 5000; @@ -1921,6 +1918,7 @@ namespace OpenSim.Framework public long ThreadFuncNum { get; set; } public string StackTrace { get; set; } private string context; + public bool LogThread { get; set; } public IWorkItemResult WorkItem { get; set; } public Thread Thread { get; set; } @@ -1932,6 +1930,7 @@ namespace OpenSim.Framework { ThreadFuncNum = threadFuncNum; this.context = context; + LogThread = true; Thread = null; Running = false; Aborted = false; @@ -2027,7 +2026,7 @@ namespace OpenSim.Framework { WaitCallback realCallback; - bool loggingEnabled = (DebugFlags & DebugFlagsEnum.LogThreadPool) != 0; + bool loggingEnabled = LogThreadPool > 0; long threadFuncNum = Interlocked.Increment(ref nextThreadFuncNum); ThreadInfo threadInfo = new ThreadInfo(threadFuncNum, context); @@ -2051,7 +2050,7 @@ namespace OpenSim.Framework try { - if (loggingEnabled || (threadFuncOverloadMode == 1)) + if ((loggingEnabled || (threadFuncOverloadMode == 1)) && threadInfo.LogThread) m_log.DebugFormat("Run threadfunc {0} (Queued {1}, Running {2})", threadFuncNum, numQueued1, numRunning1); Culture.SetCurrentCulture(); @@ -2072,7 +2071,7 @@ namespace OpenSim.Framework threadInfo.Ended(); ThreadInfo dummy; activeThreads.TryRemove(threadFuncNum, out dummy); - if (loggingEnabled || (threadFuncOverloadMode == 1)) + if ((loggingEnabled || (threadFuncOverloadMode == 1)) && threadInfo.LogThread) m_log.DebugFormat("Exit threadfunc {0} ({1})", threadFuncNum, FormatDuration(threadInfo.Elapsed())); } }; @@ -2097,11 +2096,16 @@ namespace OpenSim.Framework { string full, partial; GetFireAndForgetStackTrace(out full, out partial); - m_log.DebugFormat("Queue threadfunc {0} (Queued {1}, Running {2}) {3}{4}", - threadFuncNum, numQueued, numRunningThreadFuncs, - (context == null) ? "" : ("(" + context + ") "), - loggingEnabled ? full : partial); threadInfo.StackTrace = full; + threadInfo.LogThread = ShouldLogThread(partial); + + if (threadInfo.LogThread) + { + m_log.DebugFormat("Queue threadfunc {0} (Queued {1}, Running {2}) {3}{4}", + threadFuncNum, numQueued, numRunningThreadFuncs, + (context == null) ? "" : ("(" + context + ") "), + (LogThreadPool >= 2) ? full : partial); + } } switch (FireAndForgetMethod) @@ -2142,6 +2146,23 @@ namespace OpenSim.Framework } } + /// + /// Returns whether the thread should be logged. Some very common threads aren't logged, + /// to avoid filling up the log. + /// + /// A partial stack trace of where the thread was queued + /// Whether to log this thread + private static bool ShouldLogThread(string stackTrace) + { + if (LogThreadPool < 3) + { + if (stackTrace.Contains("BeginFireQueueEmpty")) + return false; + } + + return true; + } + /// /// Returns a stack trace for a thread added using FireAndForget(). ///