As much fun as it is to step through code with a debugger, I usually prefer to use System.Diagnostics.Debug and Trace with DebugView to see what’s happening in realtime. This is particularly handy to track intermediate results in higher-order functions that you might not be able to step into. However, it’s not always convenient to insert debugging statements amongst the composed expressions of F#, PowerShell or LINQ.
An alternative first came to mind while working in F#:
let dbg x = System.Diagnostics.Debug.WriteLine(x |> sprintf "%A"); x
(Read |> as “as next parameter to”.) We can then use this function anywhere to peek at a value, perhaps an intermediate list in this trivial example:
let data = [1..10]
|> List.filter (fun i -> i%3 = 0) |> dbg
|> List.map (fun i -> i*i)
Indeed [3; 6; 9] are traced as multiples of three. Not a particularly convincing example, but it should be pretty easy to imagine a more complex algorithm for which unintrusive tracing would be useful.
This works pretty well with F#’s |> operator to push values forward, but what about C#? Given my posting history, it shouldn’t be hard to guess where I’m going with this…
Extension Methods
So if |> is “as next parameter to”, the . of an extension method call might read “as first parameter to”. So we can implement a roughly equivalent function (sans F#’s nice deep-print formatter "%A") like so:
public static T Debug<T>(this T value)
{
Debug.WriteLine(value);
return value;
}
public static T Dbg<T>(this T value, string category)
{
Debug.WriteLine(value, category);
return value;
}
I find the optional label handy to keep different traces separate. Looking again, there’s an overload that accepts a category, so we’ll use that instead. So why might this be useful? Maybe we want to log the value assigned within an object initializer:
var q = new SPQuery() {
Query = GetMyQuery().Debug("Query")
};
Rather than store the query string to a temporary variable or retrieve the property after it’s been set, we can just trace the value inline. Or consider a LINQ example:
var items = from SPListItem item in list.GetItems(q)
let url = new SPFieldUrlValue(item["URL"] as string)
where url.Url.Debug("URL").StartsWith(baseUrl, StringComparison.OrdinalIgnoreCase)
select new
{
Title = item.Title.Debug("Title"),
Description = url.Description,
};
Here we log all URLs that pass through, even the ones excluded from the result by the predicate. This would be much harder to implement efficiently without inline logging.
This technique works great for simple objects with a useful ToString(), but what about more complex objects? As has often been the answer lately, we can use higher-order functions:
public static T Dbg<T, R>(this T value, Func<T, R> selector)
{
Debug.WriteLine(selector(value));
return value;
}
public static T Dbg<T, R>(this T value, string category, Func<T, R> selector)
{
Debug.WriteLine(selector(value), category);
return value;
}
Now we can provide a delegate to trace whatever we want without affecting the object itself. For example, we can easily trace a row count for the DataView being returned:
public DataView GetResults()
{
var myTable = GetDataTable();
// Process data...
return myTable.DefaultView.Dbg("Result Count", v => v.Count);
}
I could go on, but you get the idea.
PowerShell Filter
Finally, we can implement similar functionality in PowerShell using a filter with an optional scriptblock parameter:
filter Debug([scriptblock] $sb = { $_ })
{
[Diagnostics.Debug]::WriteLine((& $sb))
$_
}
PS > 1..3 | Debug { $_*2 } | %{ $_*$_ }
1
4
9
Which traces 2, 4, 6, as expected.
Update 4/19/2009: Changed functions to use category overloads. And another point to consider: if the value being traced could be null, selector should be designed accordingly to avoid NullReferenceException. There’s nothing worse than bugs introduced by tracing or logging.
Solutionizing .NET 