Chapter 13 - Diagnostics

CallerXXXAttribute

void Main()
{
  var x = MyProperty;
  MyMethod();
}

public string MyProperty
{
  get
  {
    CallMe("From a property.");
    return "";
  }
}

public void MyMethod()
{
  CallMe("From a method.");
}

void CallMe (string ordinaryParameter,
            [CallerMemberName] string memberName = "", // Must be an optional parameter
            [CallerFilePath] string sourceFilePath = "", // Must be an optional parameter
            [CallerLineNumber] int sourceLineNumber = 0 // Must be an optional parameter
            )
{
  Console.WriteLine ($"{nameof (CallMe)} called from {memberName}{Environment.NewLine}" +
                     $"  Parameter: {ordinaryParameter}{Environment.NewLine}" +
                     $"  File: {sourceFilePath}{Environment.NewLine}" +
                     $"  Line: {sourceLineNumber}{Environment.NewLine}");
}

Conditional Attribute Alternative Lambda

class Program
{
  public static bool EnableLogging;
  
  static void Main()
  {
    EnableLogging = true;
    Func<string> msg1 = () => { Console.WriteLine ("The first lambda was evaluated"); return "My first message"; };
    LogStatus (msg1);

    EnableLogging = false;
    Func<string> msg2 = () => { Console.WriteLine ("The second lambda was evaluated"); return "My second message"; };
    LogStatus (msg2);
    
    Console.WriteLine("Let's see what was logged:");
    Console.WriteLine(File.ReadAllText("Conditional.log"));
  }

  static void LogStatus (Func<string> message)
  {
    string logFilePath = "Conditional.log";
    if (EnableLogging)
      System.IO.File.AppendAllText (logFilePath, message() + "\r\n");
  }
}

Conditional Compilation

#define TESTMODE            // #define directives must be at top of file
#define PLAYMODE
//#undef PLAYMODE  // Cancels our define above if not commented out. Also cancels a define from the compiler e.g. through Visual Studio settings.
#define LOGGINGMODE

// Symbol names are uppercase by convention.

class Program
{
  static void Main()
  {
#if TESTMODE
    Console.WriteLine ("in test mode!"); 
#endif
#if TESTMODE && !PLAYMODE      // if TESTMODE and not PLAYMODE
    Console.WriteLine ("Test mode and NOT play mode"); 
#endif
#if PLAYMODE
    Console.WriteLine ("Play mode is defined.");
#endif
    LogStatus("Only if LOGGINGMODE is defined.");
  }

  [Conditional ("LOGGINGMODE")]
  static void LogStatus (string msg)
  {
    Console.WriteLine($"LOG: {msg}");
  }

}

Create Performance Counter

#LINQPad admin

string category = "Nutshell Monitoring";

// We'll create two counters in this category:
string eatenPerMin = "Macadamias eaten so far";
string tooHard = "Macadamias deemed too hard";

if (!PerformanceCounterCategory.Exists (category))
{
  CounterCreationDataCollection cd = new CounterCreationDataCollection();

  cd.Add (new CounterCreationData (eatenPerMin,
          "Number of macadamias consumed, including shelling time",
          PerformanceCounterType.NumberOfItems32));

  cd.Add (new CounterCreationData (tooHard,
          "Number of macadamias that will not crack, despite much effort",
          PerformanceCounterType.NumberOfItems32));

  // This line requires elevated permissions. Either run LINQPad as administrator (for this query only!) 
  // or create the category in a separate program you run as administrator.
  PerformanceCounterCategory.Create (category, "Test Category",
    PerformanceCounterCategoryType.SingleInstance, cd);
}

using (PerformanceCounter pc = new PerformanceCounter (category,
                                                       eatenPerMin, ""))
{
  pc.ReadOnly = false;
  pc.RawValue = 1000;
  pc.Increment();
  pc.IncrementBy (10);
  Console.WriteLine (pc.NextValue());    // 1011
}

Monitor Performance Counters

void Main()
{
  Console.WriteLine("Display current values of performance counters:");
  
  using PerformanceCounter pc1 = new PerformanceCounter ("Processor",
                                                        "% Processor Time",
                                                        "_Total");
  Console.WriteLine (pc1.NextValue());
  
  string procName = Process.GetCurrentProcess().ProcessName;
  using PerformanceCounter pc2 = new PerformanceCounter ("Process",
                                                        "Private Bytes",
                                                        procName);
  Console.WriteLine (pc2.NextValue());
  
  Console.WriteLine("Monitor performance counters:");

  EventWaitHandle stopper = new ManualResetEvent (false);

  new Thread (() =>
    Monitor ("Processor", "% Processor Time", "_Total", stopper)
  ).Start();

  new Thread (() =>
    Monitor ("LogicalDisk", "% Idle Time", "C:", stopper)
  ).Start();

  
  // When running in LINQPad, we'll monitor for 60 seconds then exit. Stop the query to end early.
  Console.WriteLine ("Monitoring - wait 60 seconds or stop query to quit");
  Thread.Sleep(60 * 1000);
  
  // In a console app, you can run until a key is pressed:
  //Console.WriteLine ("Monitoring - press any key to quit");
  //Console.ReadKey();
  
  stopper.Set();
}

void Monitor (string category, string counter, string instance,
                     EventWaitHandle stopper)
{
  if (!PerformanceCounterCategory.Exists (category))
    throw new InvalidOperationException ("Category does not exist");

  if (!PerformanceCounterCategory.CounterExists (counter, category))
    throw new InvalidOperationException ("Counter does not exist");

  if (instance == null) instance = "";   // "" == no instance (not null!)
  if (instance != "" &&
      !PerformanceCounterCategory.InstanceExists (instance, category))
    throw new InvalidOperationException ("Instance does not exist");

  float lastValue = 0f;
  using (PerformanceCounter pc = new PerformanceCounter (category,
                                                      counter, instance))
    while (!stopper.WaitOne (200, false))
    {
      float value = pc.NextValue();
      if (value != lastValue)         // Only write out the value
      {                               // if it has changed.
        Console.WriteLine (value);
        lastValue = value;
      }
    }
}

Processes with Info

foreach (Process p in Process.GetProcesses()
    .Where(pr => pr.ProcessName.StartsWith("L")) // Optional filter to narrow it down
  )
  using (p)
  {
    Console.WriteLine (p.ProcessName);
    Console.WriteLine ("   PID:      " + p.Id);
    Console.WriteLine ("   Memory:   " + p.WorkingSet64);
    Console.WriteLine ("   Threads:  " + p.Threads.Count);
    EnumerateThreads(p);
  }

void EnumerateThreads (Process p)
{
  try
  {
    foreach (ProcessThread pt in p.Threads)
    {
      Console.WriteLine (pt.Id);
      Console.WriteLine ("   State:    " + pt.ThreadState);
      Console.WriteLine ("   Priority: " + pt.PriorityLevel);
      Console.WriteLine ("   Started:  " + pt.StartTime);
      Console.WriteLine ("   CPU time: " + pt.TotalProcessorTime);
    }
  }
  catch (InvalidOperationException ex) // The process may go away while enumerating its threads
  {
    Console.WriteLine ($"Exception: {ex.Message}");
  }
  catch (Win32Exception ex) // We may not have access
  {
    Console.WriteLine ($"Exception: {ex.Message}");
  }
}

Read Event Log

Console.WriteLine("LOGS ON THIS COMPUTER");
foreach (EventLog l in EventLog.GetEventLogs())
{
  try
  {
    Console.WriteLine (l.LogDisplayName);
  }
  catch (Exception ex)
  {
    // The display name might be unavailable but this property still is available
    Console.WriteLine ($"Error processing an event log '{l.Log}': {ex.Message}");
  }
}

Console.WriteLine();
Console.WriteLine ("Appliation EVENT LOG");

EventLog log = new EventLog ("Application");

Console.WriteLine ("Total entries: " + log.Entries.Count);

EventLogEntry last = log.Entries [log.Entries.Count - 1];
Console.WriteLine ("Index:   " + last.Index);
Console.WriteLine ("Source:  " + last.Source);
Console.WriteLine ("Type:    " + last.EntryType);
Console.WriteLine ("Time:    " + last.TimeWritten);
Console.WriteLine ("Message: " + last.Message);

log.EnableRaisingEvents = true;
log.EntryWritten += DisplayEntry;

// Monitor for event log entries for 60 seconds
// If running in LINQPad, you can stop the query to end early
Thread.Sleep(60 * 1000); 

static void DisplayEntry (object sender, EntryWrittenEventArgs e)
{
  EventLogEntry entry = e.Entry;
  Console.WriteLine (entry.Message);
}

Trace Listeners

#define TRACE

void Main()
{
  // This will NOT run within LINQPad but will run in a program
  
  Trace.Listeners.Clear();
  
  // Add a writer that appends to the trace.txt file:
  var fileListener = new TextWriterTraceListener("trace.txt");
  Trace.Listeners.Add(fileListener);
  
  // Obtain the Console's output stream, then add that as a listener:
  System.IO.TextWriter tw = Console.Out;
  Trace.Listeners.Add(new TextWriterTraceListener(tw));
  
  // Set up a Windows Event log source and then create/add listener.
  // CreateEventSource requires administrative elevation, so this would
  // typically be done in application setup.
  
  /* The following requires Administrator permission to run and is Windows-specific
  if (!EventLog.SourceExists ("DemoApp"))
    EventLog.CreateEventSource ("DemoApp", "Application");
  
  Trace.Listeners.Add (new EventLogTraceListener ("DemoApp"));
  */
  
  Console.WriteLine("Writing to trace. Will appear on console and in trace.txt.");
  
  Trace.WriteLine("Foo");
  
  bool myCondition = true;
  Trace.WriteLineIf (myCondition, "This will write");
  Trace.WriteLineIf (!myCondition, "This will NOT write");
  
  Console.WriteLine ("Done writing to trace. Let's see what's in trace.txt:");
  fileListener.Close();
  Console.WriteLine (File.ReadAllText ("trace.txt"));
  
}

// Define other methods, classes and namespaces here

Bad Program-CPU Inefficient

// This program is intentially written to perform poorly. You can run it while experimenting with the diagnostics techniques described in Chapter 13.

void Main()
{
  // The diagnostic tools need our process ID:
  Console.WriteLine ($"Our process ID {Process.GetCurrentProcess().Id}");
  Console.WriteLine("Waiting 10 seconds to allow trace start.");
  Thread.Sleep(10000);
  Console.WriteLine(MaxSubarraySlow(LongRandomArray(7000))); // Input value 7000 runs for 1-2 minutes on modern hardware
}

// This poor implementation of the maximum subarray problem gives O(n^3) performance
// For an O(n) solution, look up Kadane's algorithm.
// This method calculates the largest sum you can get by adding the value at contiguous array indices.
int MaxSubarraySlow (int[] array)
{
  if (array?.Count() == 0) throw new ArgumentException ("Array must have elements.");

  Stopwatch maxTimer = Stopwatch.StartNew();
  int highestSum = int.MinValue;
  for (int i = 0; i < array.Length; i++) // Left bound of subarray
    for (int j = i + 1; j < array.Length; j++) // Right bound of subarray
    {
      int subarraySum = 0;
      for (int n = i; n <= j; n++) subarraySum += array [n];
      highestSum = Math.Max (highestSum, subarraySum);
      if (subarraySum == highestSum) // Max found (could equal prior max)
      {
        MyEventCounterSource.Log.Request (highestSum, maxTimer.ElapsedMilliseconds);
        maxTimer.Restart();
      }
    }
  return highestSum;
}

int [] LongRandomArray (int size)
{
  return Enumerable.Repeat (0, size).Select (i => rnd.Next()).ToArray();
}

Random rnd = new Random();

[EventSource (Name = "My-Subarray-MaxUpdated")]
public sealed class MyEventCounterSource : EventSource
{
  public static MyEventCounterSource Log = new MyEventCounterSource();
  private EventCounter requestCounter;

  private MyEventCounterSource() : base (EventSourceSettings.EtwSelfDescribingEventFormat)
  {
    this.requestCounter = new EventCounter ("Highest sum updated", this);
  }

  public void Request (int currentMax, float elapsedMSec)
  {
    WriteEvent (1, currentMax, elapsedMSec);
    this.requestCounter.WriteMetric (elapsedMSec);
  }
}

Bad Program-Too Much Recursion

// This program is intentially written to perform poorly. You can run it while experimenting with the diagnostics techniques described in Chapter 13.

void Main()
{
  // The diagnostic tools need our process ID:
  Console.WriteLine($"Our process ID {Process.GetCurrentProcess().Id}");
  Console.WriteLine(FibonacciSlow(50)); // Input value of 50 runs for 1-2 minutes on modern hardware
}

// This poor implementation gives a large call stack and O(2^n) performance.
// Far better solutions are known.
ulong FibonacciSlow(ulong fibOf)
{
  if (fibOf <= 1) return 1;
  
  return FibonacciSlow(fibOf - 1) + FibonacciSlow(fibOf - 2);
}

Bad Program-Memory Not Released

// This program is intentially written to perform poorly. You can run it while experimenting with the diagnostics techniques described in Chapter 13.

void Main()
{
  // The diagnostic tools need our process ID:
  Console.WriteLine ($"Our process ID {Process.GetCurrentProcess().Id}");
  MemoryLeak();
}

static Dictionary<string, int> cacheThatNeverCleansUp = new Dictionary<string, int>();

void MemoryLeak()
{
  // Pretend this is an expensive calculation worth caching
  int CalculateSentenceScore (string sentence)
  {
    Stopwatch watch = Stopwatch.StartNew();
    try
    {
      if (cacheThatNeverCleansUp.TryGetValue (sentence, out int score))
        return score;

      var calculatedScore = sentence.Split (' ').Count();
      cacheThatNeverCleansUp.Add (sentence, calculatedScore);
      return calculatedScore;
    }
    finally
    {
      MyEventCounterSource.Log.Request(sentence, (float)watch.ElapsedMilliseconds);
    }
  }

  while (true) // Simulate e.g. a web service that keeps taking requests
  {
    var input = RandomSentence();
    var score = CalculateSentenceScore (input);
    // A web service might return the score to a caller    
  }
}

string RandomSentence()
{
  const string alpha = "abcdefghijklmnopqrstuvwxyz";
  List<string> words = new List<string>();
  int numWords = rnd.Next (2, 15);
  for (int w = 0; w < numWords; w++)
  {
    int wordLen = rnd.Next (1, 10);
    words.Add (new string (Enumerable.Repeat (alpha, wordLen)
      .Select (_ => _ [rnd.Next (_.Length)]).ToArray()));
  }
  return string.Join (' ', words);
}

int [] LongRandomArray (int size)
{
  return Enumerable.Repeat (0, size).Select (i => rnd.Next()).ToArray();
}

Random rnd = new Random();

[EventSource(Name = "My-EventCounter-Minimal")]
public sealed class MyEventCounterSource : EventSource
{
  public static MyEventCounterSource Log = new MyEventCounterSource();
  private EventCounter requestCounter;

  private MyEventCounterSource() : base (EventSourceSettings.EtwSelfDescribingEventFormat)
  {
    this.requestCounter = new EventCounter ("Sentence Request", this);
  }

  public void Request (string sentence, float elapsedMSec)
  {
    WriteEvent (1, sentence, elapsedMSec);
    this.requestCounter.WriteMetric (elapsedMSec);
  }
}