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);
}
}