The Labs \ Source Viewer \ SSCLI \ System.Net \ BaseLoggingObject

  1. //------------------------------------------------------------------------------
  2. // <copyright file="_LoggingObject.cs" company="Microsoft">
  3. //
  4. // Copyright (c) 2006 Microsoft Corporation. All rights reserved.
  5. //
  6. // The use and distribution terms for this software are contained in the file
  7. // named license.txt, which can be found in the root of this distribution.
  8. // By using this software in any fashion, you are agreeing to be bound by the
  9. // terms of this license.
  10. //
  11. // You must not remove this notice, or any other, from this software.
  12. //
  13. // </copyright>
  14. //------------------------------------------------------------------------------
  15. //
  16. // We have function based stack and thread based logging of basic behavior. We
  17. // also now have the ability to run a "watch thread" which does basic hang detection
  18. // and error-event based logging. The logging code buffers the callstack/picture
  19. // of all COMNET threads, and upon error from an assert or a hang, it will open a file
  20. // and dump the snapsnot. Future work will allow this to be configed by registry and
  21. // to use Runtime based logging. We'd also like to have different levels of logging.
  22. //
  23. namespace System.Net
  24. {
  25.     using System.Collections;
  26.     using System.Collections.Generic;
  27.     using System.IO;
  28.     using System.Threading;
  29.     using System.Diagnostics;
  30.     using System.Security.Permissions;
  31.     using System.Security.Principal;
  32.     using System.Security;
  33.     using Microsoft.Win32;
  34.     using System.Runtime.ConstrainedExecution;
  35.     using System.Globalization;
  36.     using System.Configuration;
  37.    
  38.     //
  39.     // BaseLoggingObject - used to disable logging,
  40.     // this is just a base class that does nothing.
  41.     //
  42.    
  43.     internal class BaseLoggingObject
  44.     {
  45.        
  46.         internal BaseLoggingObject()
  47.         {
  48.         }
  49.        
  50.         internal virtual void EnterFunc(string funcname)
  51.         {
  52.         }
  53.        
  54.         internal virtual void LeaveFunc(string funcname)
  55.         {
  56.         }
  57.        
  58.         internal virtual void DumpArrayToConsole()
  59.         {
  60.         }
  61.        
  62.         internal virtual void PrintLine(string msg)
  63.         {
  64.         }
  65.        
  66.         internal virtual void DumpArray(bool shouldClose)
  67.         {
  68.         }
  69.        
  70.         internal virtual void DumpArrayToFile(bool shouldClose)
  71.         {
  72.         }
  73.        
  74.         internal virtual void Flush()
  75.         {
  76.         }
  77.        
  78.         internal virtual void Flush(bool close)
  79.         {
  80.         }
  81.        
  82.         internal virtual void LoggingMonitorTick()
  83.         {
  84.         }
  85.        
  86.         internal virtual void Dump(byte[] buffer)
  87.         {
  88.         }
  89.        
  90.         internal virtual void Dump(byte[] buffer, int length)
  91.         {
  92.         }
  93.        
  94.         internal virtual void Dump(byte[] buffer, int offset, int length)
  95.         {
  96.         }
  97.        
  98.         internal virtual void Dump(IntPtr pBuffer, int offset, int length)
  99.         {
  100.         }
  101.        
  102.     }
  103.     // class BaseLoggingObject
  104.    
  105.    
  106.     [Flags()]
  107.     internal enum ThreadKinds
  108.     {
  109.         Unknown = 0,
  110.        
  111.         // Mutually exclusive.
  112.         User = 1,
  113.         // Thread has entered via an API.
  114.         System = 2,
  115.         // Thread has entered via a system callback (e.g. completion port) or is our own thread.
  116.         // Mutually exclusive.
  117.         Sync = 4,
  118.         // Thread should block.
  119.         Async = 8,
  120.         // Thread should not block.
  121.         // Mutually exclusive, not always known for a user thread. Never changes.
  122.         Timer = 16,
  123.         // Thread is the timer thread. (Can't call user code.)
  124.         CompletionPort = 32,
  125.         // Thread is a ThreadPool completion-port thread.
  126.         Worker = 64,
  127.         // Thread is a ThreadPool worker thread.
  128.         Finalization = 128,
  129.         // Thread is the finalization thread.
  130.         Other = 256,
  131.         // Unknown source.
  132.         OwnerMask = User | System,
  133.         SyncMask = Sync | Async,
  134.         SourceMask = Timer | CompletionPort | Worker | Finalization | Other,
  135.        
  136.         // Useful "macros"
  137.         SafeSources = SourceMask & ~(Timer | Finalization),
  138.         // Methods that "unsafe" sources can call must be explicitly marked.
  139.         ThreadPool = CompletionPort | Worker
  140.         // Like Thread.CurrentThread.IsThreadPoolThread
  141.     }
  142.    
  143.     /// <internalonly/>
  144.     /// <devdoc>
  145.     /// </devdoc>
  146.     static internal class GlobalLog
  147.     {
  148.        
  149.         //
  150.         // Logging Initalization - I need to disable Logging code, and limit
  151.         // the effect it has when it is dissabled, so I use a bool here.
  152.         //
  153.         // This can only be set when the logging code is built and enabled.
  154.         // By specifing the "CSC_DEFINES=/D:TRAVE" in the build environment,
  155.         // this code will be built and then checks against an enviroment variable
  156.         // and a BooleanSwitch to see if any of the two have enabled logging.
  157.         //
  158.        
  159.         private static BaseLoggingObject Logobject = GlobalLog.LoggingInitialize();
  160.         [ReliabilityContract(Consistency.MayCorruptAppDomain, Cer.None)]
  161.         private static BaseLoggingObject LoggingInitialize()
  162.         {
  163.            
  164.             #if DEBUG
  165.             if (GetSwitchValue("SystemNetLogging", "System.Net logging module", false) && GetSwitchValue("SystemNetLog_ConnectionMonitor", "System.Net connection monitor thread", false)) {
  166.                 InitConnectionMonitor();
  167.             }
  168.             #endif // DEBUG
  169.             return new BaseLoggingObject();
  170.         }
  171.        
  172.        
  173.        
  174.         #if TRAVE || DEBUG
  175.         private static bool GetSwitchValue(string switchName, string switchDescription, bool defaultValue)
  176.         {
  177.             BooleanSwitch theSwitch = new BooleanSwitch(switchName, switchDescription);
  178.             new EnvironmentPermission(PermissionState.Unrestricted).Assert();
  179.             try {
  180.                 if (theSwitch.Enabled) {
  181.                     return true;
  182.                 }
  183.                 string environmentVar = Environment.GetEnvironmentVariable(switchName);
  184.                 defaultValue = environmentVar != null && environmentVar.Trim() == "1";
  185.             }
  186.             catch (ConfigurationException) {
  187.             }
  188.             finally {
  189.                 EnvironmentPermission.RevertAssert();
  190.             }
  191.             return defaultValue;
  192.         }
  193.         #endif // TRAVE || DEBUG
  194.        
  195.        
  196.         // Enables thread tracing, detects mis-use of threads.
  197.         #if DEBUG
  198.         [ThreadStatic()]
  199.         private static Stack<ThreadKinds> t_ThreadKindStack;
  200.        
  201.         private static Stack<ThreadKinds> ThreadKindStack {
  202.             get {
  203.                 if (t_ThreadKindStack == null) {
  204.                     t_ThreadKindStack = new Stack<ThreadKinds>();
  205.                 }
  206.                 return t_ThreadKindStack;
  207.             }
  208.         }
  209.         #endif
  210.        
  211.         static internal ThreadKinds CurrentThreadKind {
  212.             get {
  213.                 #if DEBUG
  214.                 return ThreadKindStack.Count > 0 ? ThreadKindStack.Peek() : ThreadKinds.Other;
  215.                 #else
  216.                 return ThreadKinds.Unknown;
  217.                 #endif
  218.             }
  219.         }
  220.        
  221.         #if DEBUG
  222.         // ifdef'd instead of conditional since people are forced to handle the return value.
  223.         // [Conditional("DEBUG")]
  224.         [ReliabilityContract(Consistency.MayCorruptAppDomain, Cer.None)]
  225.         static internal IDisposable SetThreadKind(ThreadKinds kind)
  226.         {
  227.             if ((kind & ThreadKinds.SourceMask) != ThreadKinds.Unknown) {
  228.                 throw new InternalException();
  229.             }
  230.            
  231.             // Ignore during shutdown.
  232.             if (NclUtilities.HasShutdownStarted) {
  233.                 return null;
  234.             }
  235.            
  236.             ThreadKinds threadKind = CurrentThreadKind;
  237.             ThreadKinds source = threadKind & ThreadKinds.SourceMask;
  238.            
  239.            
  240.             ThreadKindStack.Push((((kind & ThreadKinds.OwnerMask) == 0 ? threadKind : kind) & ThreadKinds.OwnerMask) | (((kind & ThreadKinds.SyncMask) == 0 ? threadKind : kind) & ThreadKinds.SyncMask) | (kind & ~(ThreadKinds.OwnerMask | ThreadKinds.SyncMask)) | source);
  241.            
  242.            
  243.             return new ThreadKindFrame();
  244.         }
  245.        
  246.         private class ThreadKindFrame : IDisposable
  247.         {
  248.             private int m_FrameNumber;
  249.            
  250.             internal ThreadKindFrame()
  251.             {
  252.                 m_FrameNumber = ThreadKindStack.Count;
  253.             }
  254.            
  255.             void IDisposable.Dispose()
  256.             {
  257.                 // Ignore during shutdown.
  258.                 if (NclUtilities.HasShutdownStarted) {
  259.                     return;
  260.                 }
  261.                
  262.                 if (m_FrameNumber != ThreadKindStack.Count) {
  263.                     throw new InternalException();
  264.                 }
  265.                
  266.                 ThreadKinds previous = ThreadKindStack.Pop();
  267.                
  268.             }
  269.         }
  270.         #endif
  271.        
  272.         [Conditional("DEBUG")]
  273.         [ReliabilityContract(Consistency.MayCorruptAppDomain, Cer.None)]
  274.         static internal void SetThreadSource(ThreadKinds source)
  275.         {
  276.             #if DEBUG
  277.             if ((source & ThreadKinds.SourceMask) != source || source == ThreadKinds.Unknown) {
  278.                 throw new ArgumentException("Must specify the thread source.", "source");
  279.             }
  280.            
  281.             if (ThreadKindStack.Count == 0) {
  282.                 ThreadKindStack.Push(source);
  283.                 return;
  284.             }
  285.            
  286.             if (ThreadKindStack.Count > 1) {
  287.                 Print("WARNING: SetThreadSource must be called at the base of the stack, or the stack has been corrupted.");
  288.                 while (ThreadKindStack.Count > 1) {
  289.                     ThreadKindStack.Pop();
  290.                 }
  291.             }
  292.            
  293.             if (ThreadKindStack.Peek() != source) {
  294.                 // SQL can fail to clean up the stack, leaving the default Other at the bottom. Replace it.
  295.                 Print("WARNING: The stack has been corrupted.");
  296.                 ThreadKinds last = ThreadKindStack.Pop() & ThreadKinds.SourceMask;
  297.                 Assert(last == source || last == ThreadKinds.Other, "Thread source changed.|Was:({0}) Now:({1})", last, source);
  298.                 ThreadKindStack.Push(source);
  299.             }
  300.             #endif
  301.         }
  302.        
  303.         [Conditional("DEBUG")]
  304.         [ReliabilityContract(Consistency.MayCorruptAppDomain, Cer.None)]
  305.         static internal void ThreadContract(ThreadKinds kind, string errorMsg)
  306.         {
  307.             ThreadContract(kind, ThreadKinds.SafeSources, errorMsg);
  308.         }
  309.        
  310.         [Conditional("DEBUG")]
  311.         [ReliabilityContract(Consistency.MayCorruptAppDomain, Cer.None)]
  312.         static internal void ThreadContract(ThreadKinds kind, ThreadKinds allowedSources, string errorMsg)
  313.         {
  314.             if ((kind & ThreadKinds.SourceMask) != ThreadKinds.Unknown || (allowedSources & ThreadKinds.SourceMask) != allowedSources) {
  315.                 throw new InternalException();
  316.             }
  317.            
  318.             ThreadKinds threadKind = CurrentThreadKind;
  319.             Assert((threadKind & allowedSources) != 0, errorMsg, "Thread Contract Violation.|Expected source:({0}) Actual source:({1})", allowedSources, threadKind & ThreadKinds.SourceMask);
  320.             Assert((threadKind & kind) == kind, errorMsg, "Thread Contract Violation.|Expected kind:({0}) Actual kind:({1})", kind, threadKind & ~ThreadKinds.SourceMask);
  321.         }
  322.        
  323.         #if DEBUG
  324.         // Enables auto-hang detection, which will "snap" a log on hang
  325.         static internal bool EnableMonitorThread = false;
  326.        
  327.         // Default value for hang timer
  328.         public const int DefaultTickValue = 1000 * 60 * 5;
  329.         // 5 minutes
  330.         #endif // DEBUG
  331.         [System.Diagnostics.Conditional("TRAVE")]
  332.         public static void AddToArray(string msg)
  333.         {
  334.         }
  335.        
  336.         [System.Diagnostics.Conditional("TRAVE")]
  337.         public static void Ignore(object msg)
  338.         {
  339.         }
  340.        
  341.         [System.Diagnostics.Conditional("TRAVE")]
  342.         [ReliabilityContract(Consistency.MayCorruptAppDomain, Cer.None)]
  343.         public static void Print(string msg)
  344.         {
  345.         }
  346.        
  347.         [System.Diagnostics.Conditional("TRAVE")]
  348.         public static void PrintHex(string msg, object value)
  349.         {
  350.         }
  351.        
  352.         [System.Diagnostics.Conditional("TRAVE")]
  353.         public static void Enter(string func)
  354.         {
  355.         }
  356.        
  357.         [System.Diagnostics.Conditional("TRAVE")]
  358.         public static void Enter(string func, string parms)
  359.         {
  360.         }
  361.        
  362.         [Conditional("DEBUG")]
  363.         [Conditional("_FORCE_ASSERTS")]
  364.         [ReliabilityContract(Consistency.MayCorruptAppDomain, Cer.None)]
  365.         public static void Assert(bool condition, string messageFormat, params object[] data)
  366.         {
  367.             if (!condition) {
  368.                 string fullMessage = string.Format(CultureInfo.InvariantCulture, messageFormat, data);
  369.                 int pipeIndex = fullMessage.IndexOf('|');
  370.                 if (pipeIndex == -1) {
  371.                     Assert(fullMessage);
  372.                 }
  373.                 else {
  374.                     int detailLength = fullMessage.Length - pipeIndex - 1;
  375.                     Assert(fullMessage.Substring(0, pipeIndex), detailLength > 0 ? fullMessage.Substring(pipeIndex + 1, detailLength) : null);
  376.                 }
  377.             }
  378.         }
  379.        
  380.         [Conditional("DEBUG")]
  381.         [Conditional("_FORCE_ASSERTS")]
  382.         [ReliabilityContract(Consistency.MayCorruptAppDomain, Cer.None)]
  383.         public static void Assert(string message)
  384.         {
  385.             Assert(message, null);
  386.         }
  387.        
  388.         [Conditional("DEBUG")]
  389.         [Conditional("_FORCE_ASSERTS")]
  390.         [ReliabilityContract(Consistency.MayCorruptAppDomain, Cer.None)]
  391.         public static void Assert(string message, string detailMessage)
  392.         {
  393.             try {
  394.                 Print("Assert: " + message + (!string.IsNullOrEmpty(detailMessage) ? ": " + detailMessage : ""));
  395.                 Print("*******");
  396.                 Logobject.DumpArray(false);
  397.             }
  398.             finally {
  399.                 #if DEBUG && !STRESS
  400.                 Debug.Assert(false, message, detailMessage);
  401.                 #else
  402.                 UnsafeNclNativeMethods.DebugBreak();
  403.                 Debugger.Break();
  404.                 #endif
  405.             }
  406.         }
  407.        
  408.        
  409.         [System.Diagnostics.Conditional("TRAVE")]
  410.         public static void LeaveException(string func, Exception exception)
  411.         {
  412.         }
  413.        
  414.         [System.Diagnostics.Conditional("TRAVE")]
  415.         public static void Leave(string func)
  416.         {
  417.         }
  418.        
  419.         [System.Diagnostics.Conditional("TRAVE")]
  420.         public static void Leave(string func, string result)
  421.         {
  422.         }
  423.        
  424.         [System.Diagnostics.Conditional("TRAVE")]
  425.         public static void Leave(string func, int returnval)
  426.         {
  427.         }
  428.        
  429.         [System.Diagnostics.Conditional("TRAVE")]
  430.         public static void Leave(string func, bool returnval)
  431.         {
  432.         }
  433.        
  434.         [System.Diagnostics.Conditional("TRAVE")]
  435.         public static void DumpArray()
  436.         {
  437.         }
  438.        
  439.         [System.Diagnostics.Conditional("TRAVE")]
  440.         public static void Dump(byte[] buffer)
  441.         {
  442.         }
  443.        
  444.         [System.Diagnostics.Conditional("TRAVE")]
  445.         public static void Dump(byte[] buffer, int length)
  446.         {
  447.         }
  448.        
  449.         [System.Diagnostics.Conditional("TRAVE")]
  450.         public static void Dump(byte[] buffer, int offset, int length)
  451.         {
  452.         }
  453.        
  454.         [System.Diagnostics.Conditional("TRAVE")]
  455.         public static void Dump(IntPtr buffer, int offset, int length)
  456.         {
  457.         }
  458.        
  459.         #if DEBUG
  460.         private class HttpWebRequestComparer : IComparer
  461.         {
  462.             public int Compare(object x1, object y1)
  463.             {
  464.                
  465.                 HttpWebRequest x = (HttpWebRequest)x1;
  466.                 HttpWebRequest y = (HttpWebRequest)y1;
  467.                
  468.                 if (x.GetHashCode() == y.GetHashCode()) {
  469.                     return 0;
  470.                 }
  471.                 else if (x.GetHashCode() < y.GetHashCode()) {
  472.                     return -1;
  473.                 }
  474.                 else if (x.GetHashCode() > y.GetHashCode()) {
  475.                     return 1;
  476.                 }
  477.                
  478.                 return 0;
  479.             }
  480.         }
  481.        
  482.         private class ConnectionMonitorEntry
  483.         {
  484.             public HttpWebRequest m_Request;
  485.             public int m_Flags;
  486.             public DateTime m_TimeAdded;
  487.             public Connection m_Connection;
  488.            
  489.             public ConnectionMonitorEntry(HttpWebRequest request, Connection connection, int flags)
  490.             {
  491.                 m_Request = request;
  492.                 m_Connection = connection;
  493.                 m_Flags = flags;
  494.                 m_TimeAdded = DateTime.Now;
  495.             }
  496.         }
  497.        
  498.         private static ManualResetEvent s_ShutdownEvent;
  499.         private static SortedList s_RequestList;
  500.        
  501.         internal const int WaitingForReadDoneFlag = 1;
  502.         #endif
  503.        
  504.         #if DEBUG
  505.         private static void ConnectionMonitor()
  506.         {
  507.             while (!s_ShutdownEvent.WaitOne(DefaultTickValue, false)) {
  508.                 if (GlobalLog.EnableMonitorThread) {
  509.                 }
  510.                
  511.                 int hungCount = 0;
  512.                 lock (s_RequestList) {
  513.                     DateTime dateNow = DateTime.Now;
  514.                     DateTime dateExpired = dateNow.AddSeconds(-DefaultTickValue);
  515.                     foreach (ConnectionMonitorEntry monitorEntry in s_RequestList.GetValueList()) {
  516.                         if (monitorEntry != null && (dateExpired > monitorEntry.m_TimeAdded)) {
  517.                             hungCount++;
  518.                             monitorEntry.m_Connection.Debug(monitorEntry.m_Request.GetHashCode());
  519.                         }
  520.                     }
  521.                 }
  522.                 Assert(hungCount == 0, "Warning: Hang Detected on Connection(s) of greater than {0} ms. {1} request(s) hung.|Please Dump System.Net.GlobalLog.s_RequestList for pending requests, make sure your streams are calling Close(), and that your destination server is up.", DefaultTickValue, hungCount);
  523.             }
  524.         }
  525.         #endif // DEBUG
  526.        
  527.         #if DEBUG
  528.         [ReliabilityContract(Consistency.MayCorruptAppDomain, Cer.None)]
  529.         static internal void AppDomainUnloadEvent(object sender, EventArgs e)
  530.         {
  531.             s_ShutdownEvent.Set();
  532.         }
  533.         #endif
  534.        
  535.         #if DEBUG
  536.         [System.Diagnostics.Conditional("DEBUG")]
  537.         private static void InitConnectionMonitor()
  538.         {
  539.             s_RequestList = new SortedList(new HttpWebRequestComparer(), 10);
  540.             s_ShutdownEvent = new ManualResetEvent(false);
  541.             AppDomain.CurrentDomain.DomainUnload += new EventHandler(AppDomainUnloadEvent);
  542.             AppDomain.CurrentDomain.ProcessExit += new EventHandler(AppDomainUnloadEvent);
  543.             Thread threadMonitor = new Thread(new ThreadStart(ConnectionMonitor));
  544.             threadMonitor.IsBackground = true;
  545.             threadMonitor.Start();
  546.         }
  547.         #endif
  548.        
  549.         [System.Diagnostics.Conditional("DEBUG")]
  550.         static internal void DebugAddRequest(HttpWebRequest request, Connection connection, int flags)
  551.         {
  552.             #if DEBUG
  553.             // null if the connection monitor is off
  554.             if (s_RequestList == null)
  555.                 return;
  556.            
  557.             lock (s_RequestList) {
  558.                 Assert(!s_RequestList.ContainsKey(request), "s_RequestList.ContainsKey(request)|A HttpWebRequest should not be submitted twice.");
  559.                
  560.                 ConnectionMonitorEntry requestEntry = new ConnectionMonitorEntry(request, connection, flags);
  561.                
  562.                 try {
  563.                     s_RequestList.Add(request, requestEntry);
  564.                 }
  565.                 catch {
  566.                 }
  567.             }
  568.             #endif
  569.         }
  570.        
  571.         [System.Diagnostics.Conditional("DEBUG")]
  572.         static internal void DebugRemoveRequest(HttpWebRequest request)
  573.         {
  574.             #if DEBUG
  575.             // null if the connection monitor is off
  576.             if (s_RequestList == null)
  577.                 return;
  578.            
  579.             lock (s_RequestList) {
  580.                 Assert(s_RequestList.ContainsKey(request), "!s_RequestList.ContainsKey(request)|A HttpWebRequest should not be removed twice.");
  581.                
  582.                 try {
  583.                     s_RequestList.Remove(request);
  584.                 }
  585.                 catch {
  586.                 }
  587.             }
  588.             #endif
  589.         }
  590.        
  591.         [System.Diagnostics.Conditional("DEBUG")]
  592.         static internal void DebugUpdateRequest(HttpWebRequest request, Connection connection, int flags)
  593.         {
  594.             #if DEBUG
  595.             // null if the connection monitor is off
  596.             if (s_RequestList == null)
  597.                 return;
  598.            
  599.             lock (s_RequestList) {
  600.                 if (!s_RequestList.ContainsKey(request)) {
  601.                     return;
  602.                 }
  603.                
  604.                 ConnectionMonitorEntry requestEntry = new ConnectionMonitorEntry(request, connection, flags);
  605.                
  606.                 try {
  607.                     s_RequestList.Remove(request);
  608.                     s_RequestList.Add(request, requestEntry);
  609.                 }
  610.                 catch {
  611.                 }
  612.             }
  613.             #endif
  614.         }
  615.     }
  616.     // class GlobalLog
  617. }
  618. // namespace System.Net

Developer Fusion