I'm experimenting with an alternative abstraction layer for logging that is build on top of the Reactive Extensions. This allows me to easily add features I need to my layer and map logs to any other logger I want (not shown). Filtering and buffering etc is also very easy because Rx already implements all that.
The story begins with the LoggerFactory. I use this to create the rootLogger which all other loggers use to publish their logs. In addition it can hold a collection of IComputables that are properties which are automatically added to each Log. Listeners can subscribe to a factory to listen for logs.
public interface ILoggerFactory
{
ILogger CreateLogger(string name);
}
public class LoggerFactory : IObservable<Log>
{
private readonly ConcurrentDictionary<SoftString, ILogger> _cache = new ConcurrentDictionary<SoftString, ILogger>();
private readonly Subject<Log> _rootLogger = new Subject<Log>();
public List<IComputable> AutoProperties { get; set; } = new List<IComputable>();
public IDisposable Subscribe(IObserver<Log> listener)
{
return _rootLogger.Subscribe(listener);
}
public ILogger CreateLogger(SoftString name)
{
return _cache.GetOrAdd(name, n =>
{
return new Logger(name, _rootLogger, AutoProperties);
});
}
}
Next comes the Logger. Upon creation it receives the rootLogger and the automatic-properties form a factory. The Log method renders the log and sends it to all listeners via the rootLogger.
public interface ILogger
{
SoftString Name { get; }
ILogger Log(Log logEntry);
}
public class Logger : ILogger
{
private readonly SoftString _name;
private readonly IObserver<Log> _rootLogger;
private readonly IEnumerable<IComputable> _autoProperties;
public Logger(SoftString name, IObserver<Log> rootLogger, IEnumerable<IComputable> autoProperties)
{
_name = name;
_rootLogger = rootLogger;
_autoProperties = autoProperties;
}
public SoftString Name => _name;
public ILogger Log(Log log)
{
_rootLogger.OnNext(log.Render(_autoProperties));
return this;
}
}
public enum LogLevel
{
Trace,
Debug,
Information,
Warning,
Error,
Fatal
}
Helper methods for logging are provided via extensions to the ILogger:
public static class LoggerExtensions
{
public static ILogger Trace(this ILogger logger, string message, Func<Log, Log> createLog = null)
{
return logger.Log(CreateLog(logger, LogLevel.Trace, message, null, createLog));
}
public static ILogger Debug(this ILogger logger, string message, Func<Log, Log> createLog = null)
{
return logger.Log(CreateLog(logger, LogLevel.Debug, message, null, createLog));
}
public static ILogger Warning(this ILogger logger, string message, Func<Log, Log> createLog = null)
{
return logger.Log(CreateLog(logger, LogLevel.Warning, message, null, createLog));
}
public static ILogger Information(this ILogger logger, string message, Func<Log, Log> createLog = null)
{
return logger.Log(CreateLog(logger, LogLevel.Information, message, null, createLog));
}
public static ILogger Error(this ILogger logger, string message, Exception exception, Func<Log, Log> createLog = null)
{
return logger.Log(CreateLog(logger, LogLevel.Error, message, exception, createLog));
}
public static ILogger Fatal(this ILogger logger, string message, Exception exception, Func<Log, Log> createLog = null)
{
return logger.Log(CreateLog(logger, LogLevel.Fatal, message, exception, createLog));
}
private static Log CreateLog(ILogger logger, LogLevel logLevel, string message, Exception exception, Func<Log, Log> customLog)
{
return (customLog ?? new Func<Log, Log>(l => l))(Log.Create(logger.Name, logLevel, message, exception));
}
public static LogScope BeginScope(this ILogger logger, object obj)
{
return LogScope.Push(DictionaryFactory.CreateFromProjection(obj));
}
}
The Log class itself is a Dictionary<> and for creation requires a few basic parameters that a log at leat must have.
public class Log : Dictionary<SoftString, object>
{
internal Log() { }
private Log(SoftString category, LogLevel logLevel, string message, Exception exception)
{
this[LogProperties.Category] = category;
this[LogProperties.LogLevel] = logLevel;
this[LogProperties.Message] = message;
if (exception != null)
{
this[LogProperties.Exception] = exception;
}
}
public static Log Create(SoftString category, LogLevel logLevel, string message, Exception exception)
{
return new Log(category, logLevel, message, exception);
}
}
The LogExtensions provide more helper methods like the Render method that executes all computables and concatenates various dictionaries to build the final log from scopes and automatic-properties.
public static class LogExtensions
{
public static Log Render(this Log log, IEnumerable<IComputable> autoProperties)
{
var result = new Log();
var properties = log
.Concat(autoProperties.ToDictionary(p => p.Name, p => (object)p))
.Concat(LogScope.Current.Flatten().SelectMany(x => x));
foreach (var item in properties)
{
if (item.Value is IComputable computable)
{
result[item.Key] = computable.Compute(log);
}
else
{
result[item.Key] = item.Value;
}
}
return result;
}
public static bool TryGetValue<T>(this Log log, SoftString name, out T value)
{
if (log.TryGetValue(name, out var obj) && obj is T result)
{
value = result;
return true;
}
value = default(T);
return false;
}
}
The names of most common properies are defined in a static class.
public static class LogProperties
{
public static readonly SoftString Category = nameof(Category);
public static readonly SoftString LogLevel = nameof(LogLevel);
public static readonly SoftString Message = nameof(Message);
public static readonly SoftString Exception = nameof(Exception);
public static readonly SoftString Elapsed = nameof(Elapsed);
public static readonly SoftString CallerMemberName = nameof(CallerMemberName);
public static readonly SoftString CallerLineNumber = nameof(CallerLineNumber);
public static readonly SoftString CallerFilePath = nameof(CallerFilePath);
}
The idea of scope is supported by LogScope class. I admit it is partialy based on the ASP.NET Core implementation for ConsoleLogScope but under the hood it's quite different. My sope is a dictionary and it can provide default properties like the Elapsed one.
public class LogScope : Dictionary<SoftString, object>, IDisposable
{
private static AsyncLocal<LogScope> _current = new AsyncLocal<LogScope>();
private LogScope(int depth, IDictionary<SoftString, object> state) : base(state)
{
Depth = depth;
this[LogProperties.Elapsed] = new Elapsed();
}
public LogScope Parent { get; private set; }
public int Depth { get; }
public string Name => $"{nameof(LogScope)}{Depth}";
public static LogScope Current
{
get => _current.Value;
set => _current.Value = value;
}
public static LogScope Push(IDictionary<SoftString, object> state)
{
return Current = new LogScope(Current?.Depth + 1 ?? 0, state)
{
Parent = Current
};
}
public void Dispose()
{
Current = Current.Parent;
}
}
Extensions for the LogScope help me to work with it when rendering logs or creating scopes by either flattening it or adding caller-info to it.
public static class LogScopeExtensions
{
public static IEnumerable<LogScope> Flatten(this LogScope scope)
{
var current = scope;
while (current != null)
{
yield return current;
current = current.Parent;
}
}
public static IDisposable WithCallerInfo(
this LogScope scope,
[CallerMemberName] string callerMemberName = null,
[CallerLineNumber] int callerLineNumber = 0,
[CallerFilePath] string callerFilePath = null
)
{
scope.Add(LogProperties.CallerMemberName, callerMemberName);
scope.Add(LogProperties.CallerLineNumber, callerLineNumber);
scope.Add(LogProperties.CallerFilePath, callerFilePath);
return scope;
}
}
Scope dictionaries are created from projections and are implemented in a DictionaryFactory.
internal static class DictionaryFactory
{
public static IDictionary<SoftString, object> CreateFromProjection(object obj)
{
return
obj?.GetType()
.GetProperties(BindingFlags.Public | BindingFlags.Instance)
.ToDictionary(p => SoftString.Create(p.Name), p => p.GetValue(obj))
?? new Dictionary<SoftString, object>();
}
}
Computable properties are based on the IComputable interface with a single method that requries the current log.
public interface IComputable : IEquatable<IComputable>
{
[AutoEqualityProperty]
SoftString Name { get; }
object Compute(Log logEntry);
}
public abstract class Computable : IComputable
{
protected Computable(SoftString name) => Name = name;
protected Computable() => Name = GetType().Name;
public SoftString Name { get; }
public abstract object Compute(Log logEntry);
public bool Equals(IComputable other) => AutoEquality<IComputable>.Comparer.Equals(this, other);
public override bool Equals(object obj) => Equals(obj as IComputable);
public override int GetHashCode() => AutoEquality<IComputable>.Comparer.GetHashCode(this);
}
public class UtcNow : Computable
{
public override object Compute(Log log) => DateTime.UtcNow;
}
public class Elapsed : Computable
{
public override object Compute(Log log)
{
return log.TryGetValue<Stopwatch>(LogProperties.Elapsed, out var stopwatch) ? stopwatch.Elapsed : TimeSpan.Zero;
}
}
public class Lambda : Computable
{
private readonly Func<Log, object> _compute;
public Lambda(SoftString name, Func<Log, object> compute) : base(name)
{
_compute = compute ?? throw new ArgumentNullException(nameof(compute));
}
public override object Compute(Log log) => _compute(log);
}
Example
To use the logger I first need to create a factory. Optionally I can specify automatic-properties.
var loggerFactory = new LoggerFactory
{
AutoProperties =
{
new UtcNow()
}
};
Then I need to subscribe some listeners with optional filtering.
loggerFactory
//.Where(l => (LogLevel)l["LogLevel"] == LogLevel.Debug)
.Subscribe(ConsoleObserver.Create());
Now I'm ready to log.
var logger = loggerFactory.CreateLogger("Test");
using (var scope = logger.BeginScope(new { Transaction = 123 }).WithCallerInfo())
{
logger.Information("Hallo!");
logger.Debug("This is a debug message.");
try
{
throw new DivideByZeroException();
}
catch (Exception ex)
{
logger.Error("Division failed!", ex);
}
}
An observer can be as simple as that:
public static class ConsoleObserver
{
public static IObserver<Log> Create() => Observer.Create<Log>(log => Console.WriteLine(log));
}
One of the output of this simple program is:
Key Value
--- -----
Category Test
LogLevel Information
Message Hallo!
UtcNow 25.10.2017 17:09:17
Transaction 123
Elapsed 00:00:00
CallerMemberName Main
CallerLineNumber 55
CallerFilePath C:\...\query_fnuete.cs
This implementation is a working proof-of-concept and it lacks null checks everywhere. I'll be adding them after implementing any improvements later.
Do you think this code can still be improved? Or is there anything terribly wrong with it?
*SoftString is my own custom type that represents a trimmed and case-insensitive string.
