ForContext destructures without loglevel check

[Pete Burgess]

In the following example, the variable in the ForContext call is destructured even if the log level is below verbose. Is there a fluent way to prevent this?

logger.ForContext("DeepObject",deepObject,true).Verbose("analysing{objectName}",deepObject.Name);

[nblum...@nblumhardt.com]

Hi Pete,

No, it's a limitation I don't think we can do much about automatically.

The simplest way around it is:

var logger = ...;

if (logger.IsEnabled(LogEventLevel.Verbose))

    logger = logger.ForContext(...);

logger.Verbose(...);

Hope this helps,

Nick

[Pete Burgess]

Thanks Nick, that;s the conclusion I came to.

You could support "lazy" destructuring: register the contexts as they are added, flagged as needing destructuring but only destructure them when emitting a message (and also set the destructured flag). This would allow adding a class-level context without destructuring it multiple times.

e.g.

var log = Log.ForContext("ContextObject", contextObject, true);
...
// Log level set to Debug
log.Verbose("log message doesn't emit - doesn't destructure contextObject");
...
log.Debug("first emitted message - destructures contectObject");
...
log.ForContext("messageContext", messageObject, true).Debug("contextObject already destructured - isn't destructured again; destructures messageContext");

We're actually re-exposing an internal log interface which forwards to Serilog, I think I'll change the internal interface to have log level method which returns an "ILevelLogger" that only supports ForContext and Write (at the pre-specified level) so we can use it thus:

// if LogLevel >= Verbose, destructure deepObject and emit message
log.AtVerbose.ForContext("DeepObject", deepObject, true).Write("log with context");
// non-context usage
log.AtVerbose.Write("log without context");
// existing usage still supported
log.ForContext("EarlyDestructured"
log.Verbose("old-style log without context");

If I were using Serilog.ILogger directly I'd create a static extension class to make an "ILevelLogger".

[nblum...@nblumhardt.com]

Thanks for the follow-up!

Destructuring has to happen immediately because accessing the value to be destructured "later on" may violate thread safety invariants of the program (e.g. if a derived logger is passed to another thread, or if the object is only available under a lock that is held at the call to ForContext() but has been released by the time Write() is called).

I'd guess this can be designed around with a different API, but the payoff's probably not enough to warrant the effort vs. the explicit level check in the workaround.

Cheers,
Nick

[Pete Burgess]

Thanks Nick; that makes complete sense with destructuring, I hadn't considered usages different than my own!

I still think the if check workaround is a little ugly but again, my suggested alternative fits my usage.