Update: Added the BreakParameter.
I have made it an (arguably bad) habit of manually adding the class and method name as a prefix to all my log lines. It is not that I enjoy typing out the same strings over and over, it's that I do not always trust things like the NLog callsite. Using the stack frame to identify a calling method always requires a bit of cleverness on the part of the author, as you never can be totally sure when you are dealing with a wrapper class or an async call stack.
I was recently introduced to the Caller Information attributes in C# 5, and now I think I am in love.
Disclaimer: I have not used this very much yet, but I intend to start! I think that these attributes are absolutely brilliant in their simplicity: a compiler trick to insert debug information directly into your code. That is freak'n sweet, and it's performant! I am not sure how this flew under my radar, but now that I know about it....
Below is a little T4 template that I wrote up to generate overloads for Common Logging that will include caller information. To customize this for your needs, just update the the GetFormat method at the bottom of the template.
Unit Tests
1: using System;
2: using System.Collections.Generic;
3: using Common.Logging.Simple;
4: using Xunit;
5:
6: namespace Common.Logging.Tests
7: {
8: /// <summary>
9: /// Tests for Common Logging extensions that use Caller Information
10: /// https://msdn.microsoft.com/en-us/library/mt653988.aspx
11: /// </summary>
12: public class LogCallTests
13: {
14: [Fact]
15: public void LogFromMethod()
16: {
17: var log = new QueueSimpleLogger();
18: var ex = new Exception("Boom");
19:
20: log.Debug("Hello");
21: log.Debug("World", ex);
22:
23: log.DebugCall("Hello");
24: log.DebugCall("World", ex);
25:
26: log.WarnFormat("Hello - {0}", "Zero");
27: log.WarnFormat("World - {0}", ex, "Zero");
28:
29: log.WarnFormatCall("Hello - {0}", "Zero");
30: log.WarnFormatCall("World - {0}", ex, "Zero");
31:
32: Assert.Equal(8, log.Queue.Count);
33:
34: Assert.Equal("Hello", log.Queue.Dequeue());
35: Assert.Equal("World - Ex: Boom", log.Queue.Dequeue());
36:
37: Assert.Equal("LogCallTests.LogFromMethod(23) - Hello", log.Queue.Dequeue());
38: Assert.Equal("LogCallTests.LogFromMethod(24) - World - Ex: Boom", log.Queue.Dequeue());
39:
40: Assert.Equal("Hello - Zero", log.Queue.Dequeue());
41: Assert.Equal("World - Zero - Ex: Boom", log.Queue.Dequeue());
42:
43: Assert.Equal("LogCallTests.LogFromMethod(29) - Hello - Zero", log.Queue.Dequeue());
44: Assert.Equal("LogCallTests.LogFromMethod(30) - World - Zero - Ex: Boom", log.Queue.Dequeue());
45: }
46:
47: [Fact]
48: public void LogFromAction()
49: {
50: var log = new QueueSimpleLogger();
51: var ex = new Exception("Boom");
52: Action action = () =>
53: {
54: log.Debug("Hello");
55: log.Debug("World", ex);
56:
57: log.DebugCall("Hello");
58: log.DebugCall("World", ex);
59:
60: log.WarnFormat("Hello - {0}", "Zero");
61: log.WarnFormat("World - {0}", ex, "Zero");
62:
63: log.WarnFormatCall("Hello - {0}", "Zero");
64: log.WarnFormatCall("World - {0}", ex, "Zero");
65: };
66:
67: action();
68:
69: Assert.Equal(8, log.Queue.Count);
70:
71: Assert.Equal("Hello", log.Queue.Dequeue());
72: Assert.Equal("World - Ex: Boom", log.Queue.Dequeue());
73:
74: Assert.Equal("LogCallTests.LogFromAction(57) - Hello", log.Queue.Dequeue());
75: Assert.Equal("LogCallTests.LogFromAction(58) - World - Ex: Boom", log.Queue.Dequeue());
76:
77: Assert.Equal("Hello - Zero", log.Queue.Dequeue());
78: Assert.Equal("World - Zero - Ex: Boom", log.Queue.Dequeue());
79:
80: Assert.Equal("LogCallTests.LogFromAction(63) - Hello - Zero", log.Queue.Dequeue());
81: Assert.Equal("LogCallTests.LogFromAction(64) - World - Zero - Ex: Boom", log.Queue.Dequeue());
82: }
83:
84: private class QueueSimpleLogger : AbstractSimpleLogger
85: {
86: public readonly Queue<string> Queue = new Queue<string>();
87:
88: public QueueSimpleLogger()
89: : base(string.Empty, LogLevel.All, true, true, true, string.Empty)
90: {
91: }
92:
93: protected override void WriteInternal(LogLevel level, object message, Exception exception)
94: {
95: var s = message.ToString();
96: if (exception != null) s += " - Ex: " + exception.Message;
97: Queue.Enqueue(s);
98: }
99: }
100: }
101: }
LogExtension.cs (Part of a Generated File)
using System;
using System.Runtime.CompilerServices;
using System.Text.RegularExpressions;
// ReSharper disable once CheckNamespace
namespace Common.Logging
{
public static class LogExtensions
{
public static Regex ClassNameRegex = new Regex(@"([\w]+)\.[\w]+$", RegexOptions.Compiled);
/* ... */
public static void DebugCall(
this ILog log,
object message,
BreakParameter breakParameter = default(BreakParameter),
[CallerMemberName] string memberName = "",
[CallerFilePath] string sourceFilePath = "",
[CallerLineNumber] int sourceLineNumber = 0)
{
if (!log.IsDebugEnabled) return;
var newFormat = GetFormat(message.ToString(), memberName, sourceFilePath, sourceLineNumber);
log.Debug(
newFormat);
}
public static void DebugCall(
this ILog log,
object message,
Exception ex,
BreakParameter breakParameter = default(BreakParameter),
[CallerMemberName] string memberName = "",
[CallerFilePath] string sourceFilePath = "",
[CallerLineNumber] int sourceLineNumber = 0)
{
if (!log.IsDebugEnabled) return;
var newFormat = GetFormat(message.ToString(), memberName, sourceFilePath, sourceLineNumber);
log.Debug(
newFormat,
ex);
}
public static void DebugFormatCall(
this ILog log,
string format,
object arg0,
BreakParameter breakParameter = default(BreakParameter),
[CallerMemberName] string memberName = "",
[CallerFilePath] string sourceFilePath = "",
[CallerLineNumber] int sourceLineNumber = 0)
{
if (!log.IsDebugEnabled) return;
var newFormat = GetFormat(format, memberName, sourceFilePath, sourceLineNumber);
log.DebugFormat(
newFormat,
arg0);
}
public static void DebugFormatCall(
this ILog log,
string format,
Exception ex,
object arg0,
BreakParameter breakParameter = default(BreakParameter),
[CallerMemberName] string memberName = "",
[CallerFilePath] string sourceFilePath = "",
[CallerLineNumber] int sourceLineNumber = 0)
{
if (!log.IsDebugEnabled) return;
var newFormat = GetFormat(format, memberName, sourceFilePath, sourceLineNumber);
log.DebugFormat(
newFormat,
ex,
arg0);
}
/* ... */
[MethodImpl(MethodImplOptions.AggressiveInlining)]
private static string GetFormat(string format, string memberName, string sourceFilePath, int sourceLineNumber)
{
var m = ClassNameRegex.Match(sourceFilePath);
return m.Success
? $"{m.Groups[1].Value}.{memberName}({sourceLineNumber}) - {format}"
: format;
}
public struct BreakParameter
{
}
}
}
LogExtension.tt (T4 Template)
<#@ template debug="false" hostspecific="false" language="C#" #>
<#@ assembly name="System.Core" #>
<#@ import namespace="System.Linq" #>
<#@ import namespace="System.Text" #>
<#@ import namespace="System.Collections.Generic" #>
<#@ output extension=".cs" #>
using System;
using System.Runtime.CompilerServices;
using System.Text.RegularExpressions;
// ReSharper disable once CheckNamespace
namespace Common.Logging
{
public static class LogExtensions
{
public static Regex ClassNameRegex = new Regex(@"([\w]+)\.[\w]+$", RegexOptions.Compiled);
<# foreach(var level in new [] { "Trace", "Debug", "Info", "Warn", "Error", "Fatal" }) { #>
<# for(var argCount = 0; argCount <= 8; argCount++) { #>
<# var suffix = argCount == 0 ? "" : "Format"; #>
<# var varType = argCount == 0 ? "object" : "string"; #>
<# var varName = argCount == 0 ? "message" : "format"; #>
<# var vartoString = argCount == 0 ? ".ToString()" : ""; #>
<# for(var hasException = 0; hasException < 2; hasException++) { #>
public static void <#= level #><#= suffix #>Call(
this ILog log,
<#= varType #> <#= varName #>,
<# if (hasException == 1) { #>
Exception ex,
<# } #>
<# for(var i = 0; i < argCount; i++) { #>
object arg<#= i #>,
<# } #>
BreakParameter breakParameter = default(BreakParameter),
[CallerMemberName] string memberName = "",
[CallerFilePath] string sourceFilePath = "",
[CallerLineNumber] int sourceLineNumber = 0)
{
if (!log.Is<#= level #>Enabled) return;
var newFormat = GetFormat(<#= varName #><#= vartoString #>, memberName, sourceFilePath, sourceLineNumber);
log.<#= level #><#= suffix #>(
newFormat<# if (hasException == 1) { #>,
ex<# } #><# for(var i = 0; i < argCount; i++) { #>,
arg<#= i #><# } #>);
}
<# } #>
<# } #>
<# } #>
[MethodImpl(MethodImplOptions.AggressiveInlining)]
private static string GetFormat(string format, string memberName, string sourceFilePath, int sourceLineNumber)
{
var m = ClassNameRegex.Match(sourceFilePath);
return m.Success
? $"{m.Groups[1].Value}.{memberName}({sourceLineNumber}) - {format}"
: format;
}
public struct BreakParameter
{
}
}
}
Enjoy,
Tom
No comments:
Post a Comment