We need you! We're working hard on the next version of Developer Fusion - Let us know what you think we should be up to!

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

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