1

From what I understand, Serilogs UseSerilogRequestLogging utilizes IDiagnosticContext and adds the properties that has ben set to it to the last log entry of the request.

Works fine, but how can I utilize IDiagnosticContext myself to set variables in things like a background task that doesn't have a http context to collect a bucket of properties and add to a certain log entry myself?

I guess something in the lines of using their AmbientDiagnosticContextCollector with Begin and TryComplete?

Psuedo code of what I'm after:

diagnosticContext.Begin();

diagnosticContext.Set("foo", 1);
diagnosticContext.Set("bar", 2);

diagnosticContext.Complete();

logger.Log("Completed in {Seconds}", seconds, diagnosticContext.Properties);

// Entry should contain properties { seconds: <elapsed seconds>, foo: 1, bar: 2 }
Johan
  • 35,120
  • 54
  • 178
  • 293
  • Are you sure that using [LogContext](https://github.com/serilog/serilog/wiki/Enrichment#the-logcontext) doesn't accomplish what you want? – mason Jul 27 '23 at 23:46
  • @mason Yes, I want a bucket of additional properties added to a specific entry - not write shared properties to all entries within the same context. – Johan Jul 28 '23 at 00:14
  • @mason Updated with an example – Johan Jul 28 '23 at 00:19
  • Does the last part of my answer address what you want? https://stackoverflow.com/a/48594025/1139830 – mason Jul 28 '23 at 02:58
  • @mason Hmm I'm afraid not, thanks though. What I'm after is more of a way to collect a bunch of properties along the scope and dump them in a log entry of my choice. I think this explains it better than me https://benfoster.io/blog/serilog-best-practices/#diagnostic-context – Johan Jul 28 '23 at 08:28
  • @Johan based on your description `LogContext` seems to do exactly what is needed - wrap the "entry of your choice" logging into `using LogContext.Push....` and that's it. – Guru Stron Jul 31 '23 at 09:53

1 Answers1

0

Yes, I want a bucket of additional properties added to a specific entry - not write shared properties to all entries within the same context.

But this is what contexts/scopes are for. Just wrap the logging line into scope in using. For example using the build-in ILogger.BeginScope:

var log = new LoggerConfiguration()
    .Enrich.FromLogContext()
    .WriteTo.Console(new JsonFormatter())
    .CreateLogger();

var services = new ServiceCollection();

services.AddLogging(builder => builder.AddSerilog(log));
var sp = services.BuildServiceProvider();
var logger = sp.GetRequiredService<ILogger<Program>>();
var scopeInfoDict = new Dictionary<string, object>
       {
           {"foo", 1}
       };
int seconds = 100; // do some work
scopeInfoDict.Add("bar", 42); // enrich
// ...
using (logger.BeginScope(scopeInfoDict)) // use the "context" for specific entry
{
    logger.LogInformation("Completed in {Seconds}", seconds);
}
logger.LogInformation("No contextual properties");

Which results in:

{"Timestamp":"2023-07-31T13:05:39.0692467+03:00","Level":"Information","MessageTemplate":"Completed in {Seconds}","Properties":{"Seconds":100,"SourceContext":"Program","foo":1,"bar":42}}
{"Timestamp":"2023-07-31T13:05:39.0945963+03:00","Level":"Information","MessageTemplate":"No contextual properties","Properties":{"SourceContext":"Program"}}

Or using Serilog's LogContext:

// ...
using (LogContext.PushProperty("foo", 1))
using (LogContext.PushProperty("bar", 42))
{
    logger.Information("Completed in {Seconds}", seconds);
}
logger.Information("No contextual properties");

UPD:

As you have suggested in the comments you can follow the approach with resolving the DiagnosticContext as the RequestLoggingMiddleware does, but in background job there would be no middleware so you will need to implement something similar.

Personally I would go with custom service for that, to be a little bit more decoupled from Serilog/ASP.NET Core Serilog specific infrastructure:

services.AddScoped<Dictionary<string, object>>(); // sample code, better use some custom type, potentially over concurrent collection.

services.AddLogging(builder => builder.AddSerilog(log));

var sp = services.BuildServiceProvider();
// create scope in worker per "iteration" 
using (var serviceScope = sp.CreateScope())
{
    var ssp = serviceScope.ServiceProvider;
    var logger = ssp.GetRequiredService<ILogger<Program>>();
    ssp.GetRequiredService<Dictionary<string, object>>()
        .Add("foo", 1);
    int seconds = 100; // do some work
    ssp.GetRequiredService<Dictionary<string, object>>().Add("bar", 42); // enrich

    // log with the scope info
    using (logger.BeginScope(ssp.GetRequiredService<Dictionary<string, object>>())) // use the "context" for specific entry
    {
        logger.LogInformation("Completed in {Seconds}", seconds);
    }
    logger.LogInformation("No contextual properties");
}
Guru Stron
  • 102,774
  • 10
  • 95
  • 132
  • Right, but if I log multiple rows within a same scope, they all get the properties. I want a single place to collect them and dump them to a specific entry, just like this middleware does here https://github.com/serilog/serilog-aspnetcore/blob/e6e51d8f64f50833bb539734816a91d5efd669b4/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs#L78C6-L78C6 – Johan Jul 31 '23 at 10:21
  • @Johan then collect them into dictionary and wrap the needed into corresponding scope. – Guru Stron Jul 31 '23 at 10:23
  • @Johan I don't know if there is a build-in functionality for that (i.e. accumulate something in context but add it to message only when some condition), but I highly doubt that there is. Maybe something could be achieved via custom enricher but I would argue better solution would be using custom functionality outside the logger (i.e. for example create scoped service to store some context info for logging and then write to it or read from it when needed and perform work in special scopes). – Guru Stron Jul 31 '23 at 10:37
  • I think using `BeginCollection` and `TryComplete` of a `DiagnosticContext` should do the trick. It's registered here https://github.com/serilog/serilog-aspnetcore/blob/e6e51d8f64f50833bb539734816a91d5efd669b4/src/Serilog.AspNetCore/SerilogWebHostBuilderExtensions.cs#L154C12-L154C12 – Johan Jul 31 '23 at 10:55
  • I just wanted to make sure I don't reinvent anything that they have more convenient services for, but I think this is as close as one can get. – Johan Jul 31 '23 at 10:57
  • @Johan nice find. It should. It uses `AsyncLocal` internally which I was thinking to suggest/use for custom enricher. Though this is basically the same what I suggested but more tightly bound to Serilog infrastructure and personally I would go with the custom collection via DI scopes which is more decoupled way to do this. – Guru Stron Jul 31 '23 at 11:06
  • @Johan also note that `TryComplete` is called by middleware which logs special entry based on saved properties - [source code](https://github.com/serilog/serilog-aspnetcore/blob/e6e51d8f64f50833bb539734816a91d5efd669b4/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs#L94), there would be no middleware in the background worker. So you still will need to do something like I have described. – Guru Stron Jul 31 '23 at 11:19
  • Right, but injecting DiagnosticContext in the background worker, start with BeginCollection() before any work is done and collect using TryComplete I think should do the trick. Just as the middleware does. – Johan Jul 31 '23 at 11:40
  • @Johan yes, it will, though, again, I would argue using DI scopes with custom service in general should be better approach. You can even make it disposable and perform logging in the dispose (scope will dispose all the controlled/created services) – Guru Stron Jul 31 '23 at 11:44
  • 1
    Yes, I guess it's a similar approach at the end of the day. Thanks for the talk, I got the info I needed – Johan Jul 31 '23 at 12:03