I would like to correlate logging messages using a logging scope. I'm looking for an implementation for log4net, NLog, or System.Diagnostics.Trace. Below is a basic implementation that demonstrates the concept. The output from the program is this:
First level: Logging in the run method
First level: Logging one level down
Second scope: Another message
First level: Back from scope
Is there a more robust/general/proven/easy-to-use-with-some-framework version of what is done below?
class Program
{
private static readonly Log Log = new Log();
private static void Main()
{
using (new LoggingScope("First level"))
{
Run();
}
}
private static void Run()
{
Log.Info("Logging in the run method");
Run2();
}
private static void Run2()
{
Log.Info("Logging one level down");
using (new LoggingScope("Second scope"))
{
Log.Info("Another message");
}
Log.Info("Back from scope");
}
}
internal class Log
{
static Log()
{
CurrentScope = new Stack<string>();
}
private static Stack<string> CurrentScope { get; set; }
public static void PushScope(string name)
{
CurrentScope.Push(name);
}
public static void PopScope()
{
CurrentScope.Pop();
}
public void Info(string message)
{
var currentScope = CurrentScope.Count == 0 ? string.Empty : CurrentScope.Peek();
Console.WriteLine("{0}: {1}", currentScope, message);
}
}
internal class LoggingScope : IDisposable
{
private readonly string _name;
public LoggingScope(string id)
{
_name = Guid.NewGuid().ToString();
Log.PushScope(id);
CallContext.SetData(_name, id);
}
public void Dispose()
{
Log.PopScope();
CallContext.FreeNamedDataSlot(_name);
}
}
You are looking for nested diagnostic context (NDC):
Log.Info("Logging one level down");
using(ThreadContext.Stacks["NDC"].Push( requestid))
{
Log.Info("Another message");
}
Log.Info("Back from scope");
To get the scope in your log output use %property{NDC} in your conversion pattern:
<conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline" />