Implement TAP/multithread friendly logging scopes for Microsoft.Extensions.Logging.ILogger

Some time ago I wrote a post how to implement custom logger which writes logs to Azure storage blob container: Custom logger for .Net Core for writing logs to Azure BLOB storage. This logger implements ILogger interface from Microsoft.Extensions.Logging namespace. It works quite well but doesn't support logging scopes:

?

1	public IDisposable BeginScope<TState>(TState state) => default!;

Logging scopes are quite useful - they allow to specify additional information e.g. from each method log record was added, etc:

?

1 2 3 4 5 6 7 8 9 10

public void Foo() {     using (logger.BeginScope("Outer scope"))     {         ...         using (logger.BeginScope("Inner scope"))         {         }     } }

Important requirement for logging scopes is that it should work properly in Task-based asynchronous pattern (TAP) and multithread code (which is widely used nowadays). For that we will use AsyncLocal<T> class from .NET. For implementing scopes themselves we will use linked list (child-parent relation).

For implementing it we will create LogScopeProvider class which implements Microsoft.Extensions.Logging.IExternalScopeProvider interface (for creating this custom LogScopeProvider I used code from Microsoft.Extensions.Logging.Console namespace as base example):

?

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63

public class LogScopeProvider : IExternalScopeProvider {     private readonly AsyncLocal<LogScope> currentScope = new AsyncLocal<LogScope>();       public object Current => this.currentScope.Value?.State;       public LogScopeProvider() {}       public void ForEachScope<TState>(Action<object, TState> callback, TState state)     {         void Report(LogScope current)         {             if (current == null)             {                 return;             }             Report(current.Parent);             callback(current.State, state);         }           Report(this.currentScope.Value);     }       public IDisposable Push(object state)     {         LogScope parent = this.currentScope.Value;         var newScope = new LogScope(this, state, parent);         this.currentScope.Value = newScope;           return newScope;     }       private class LogScope : IDisposable     {         private readonly LogScopeProvider provider;         private bool isDisposed;           internal LogScope(LogScopeProvider provider, object state, LogScope parent)         {             this.provider = provider;             State = state;             Parent = parent;         }           public LogScope Parent { get; }           public object State { get; }           public override string ToString()         {             return State?.ToString();         }           public void Dispose()         {             if (!this.isDisposed)             {                 this.provider.currentScope.Value = Parent;                 this.isDisposed = true;             }         }     } }

Note that LogScopeProvider stores scopes as AsyncLocal<LogScope> which allows to use it in TAP code. So e.g. if we have await inside using(scope) it will be handled correctly:

?

1 2 3 4 5 6 7 8

public async Task Foo() {     using (logger.BeginScope("Outer scope"))     {         var result = await Bar();         ...     } }

Now returning to our BlobStorage: all we have to is to pass LogScopeProviderto its constructor, add current scope to the log record and return new scope when it is requested (check bold code):

?

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44

public class BlobLogger : ILogger {     private const string CONTAINER_NAME = "custom-logs";     private string connStr;     private string categoryName;     <b>private LogScopeProvider scopeProvider;</b>        public BlobLogger(string categoryName, string connStr, <b>LogScopeProvider scopeProvider</b>)     {         this.connStr = connStr;         this.categoryName = categoryName;         <b>this.scopeProvider = scopeProvider;</b>     }        public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception,         Func<TState, Exception?, string> formatter)     {         if (!IsEnabled(logLevel))         {             return;         }            <b>string scope = this.scopeProvider.Current as string;</b>         using (var ms = new MemoryStream(Encoding.UTF8.GetBytes($"[{this.categoryName}: {logLevel,-12}] <b>{scope}</b> {formatter(state, exception)}{Environment.NewLine}")))         {             var container = this.ensureContainer();             var now = DateTime.UtcNow;             var blob = container.GetAppendBlobClient($"{now:yyyyMMdd}/log.txt");             blob.CreateIfNotExists();             blob.AppendBlock(ms);         }     }        private BlobContainerClient ensureContainer()     {         var container = new BlobContainerClient(this.connStr, CONTAINER_NAME);         container.CreateIfNotExists();         return container;     }        public bool IsEnabled(LogLevel logLevel) => true;        public IDisposable BeginScope<TState>(TState state) => <b>this.scopeProvider.Push(state)</b>; }

That's it: now our logger also supports logging scopes.