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

2 files changed, 78 insertions, 19 deletions

diff --git a/OpenSim/Framework/Servers/ServerBase.cs b/OpenSim/Framework/Servers/ServerBase.cs
index c258ff6..fd56587 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 2de596e..b39dc5f 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
-    }
-
     /// <summary>
     /// Miscellaneous utility functions
     /// </summary>
@@ -127,13 +118,19 @@ namespace OpenSim.Framework
         private static readonly ILog m_log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType);
 
         /// <summary>
-        /// 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
         /// </summary>
-        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)
@@ -2143,6 +2147,23 @@ namespace OpenSim.Framework
         }
 
         /// <summary>
+        /// Returns whether the thread should be logged. Some very common threads aren't logged,
+        /// to avoid filling up the log.
+        /// </summary>
+        /// <param name="stackTrace">A partial stack trace of where the thread was queued</param>
+        /// <returns>Whether to log this thread</returns>
+        private static bool ShouldLogThread(string stackTrace)
+        {
+            if (LogThreadPool < 3)
+            {
+                if (stackTrace.Contains("BeginFireQueueEmpty"))
+                    return false;
+            }
+            
+            return true;
+        }
+
+        /// <summary>
         /// Returns a stack trace for a thread added using FireAndForget().
         /// </summary>
         /// <param name="full">Will contain the full stack trace</param>