Silly Logging Question

Kevin Marois

I'm using Serilog. It seems way over-engineered to me, but I'm stuck with it. And, the docs arn't very helpful IMO. My question is about log levels. For Serilog, there's documentation like this[^] and examples like this:

Log.Verbose("Here's a Verbose message.");
Log.Debug("Here's a Debug message. Only Public Properties (not fields) are shown on structured data. Structured data: {@sampleData}. Simple data: {simpleData}.", structuredData, simpleData);
Log.Information(new Exception("Exceptions can be put on all log levels"), "Here's an Info message.");
Log.Warning("Here's a Warning message.");
Log.Error(new Exception("This is an exception."), "Here's an Error message.");
Log.Fatal("Here's a Fatal message.");

Neither the docs nor the examples explain very well where/how you would actually use each of these levels. For example, let's says I have this method:

private void DoSomeProcessing(string inputFile, bool someParam)
{
Log.Information("Inside DoSomeProcessing");

if (someParam)
{
    Log.Warning("Just letting you know that 'someParam' = true");
}

if (string.IsNullOrEmpty(inputFile))
{
    Log.Error("inputFile is null");
    throw new ArgumentNullException(nameof(inputFile));
}

try
{
    Log.Information("Doing the processing");
    var a = 10 + 20;

    Log.Information("Doing some more");
    var b = 10 + a;

    Log.Information("And even more");
    var v = a + b;
}
catch (Exception e)
{
    Log.Fatal("Something terrible happened here!");
    throw e;
}

}

Exception logging I get, but is this how you would Info and Debug? Writing out lines all over the place? Also, I have "MinimumLevel": "Debug" in my appsettings.json, yet all of these line get written out. I'm guuessing I'm not understanding how to use it right. Can someone shed some light? Thanks

In theory, theory and practice are the same. But in practice, they never are.” If it's not broken, fix it until it is. Everything makes sense in someone's mind.

Mircea Neacsu

They seem to explain it pretty well in the doc link you provided[^]:

Quote:

The MinimumLevel configuration object provides for one of the log event levels to be specified as the minimum. In the example above, log events with level Debug and higher will be processed and ultimately written to the console.

(highlight is mine). As a general strategy, I think you would probably have a setting somewhere that changes the minimum log level and you would come up with rules like: - Verbose level is for all function enrty/exit points - Debug level is for parameters and results - Info level is for start/stop of big actions and so on, and so on...

Mircea

jschell

The reality is that first, regardless of logging library, this is never clear in terms of practical programming. Additionally keep in mind that a potential exists that different logging levels might impact execution flow. There are three usage scenarios - Production - QA - Developer Some would claim that Error/Warn is only appropriate for Production. That however is simplistic and it will not work in non-trivial situations. That is because for larger systems debugging production problems often requires looking at execution flow. So logging that represents the successful execution of code (trace logging.) A perfect example of this is a job system or microservice (ms). In production the question will come up as to 'why' the job/request is not being handled. With logging one can see that the job/ms is actually running. Not just a specific requests, but all requests. Then trace logging shows or doesn't show that a specific request was handled. And how it was handled. Trace logging would use a log level of 'Info'. So Prod would use Error/Warn/Info. The claim would (and will) be made that the log level 'Debug' allows one to turn something on in production for more information. But often that doesn't matter because the failure occurred yesterday, so attempting to figure it out today with more logging is seldom going to help. The 'Debug' level is often used by developers because of this. But developers often do silly things like log only the index of a for variable. So no context just the value. Which makes sense when they are figuring out a problem but will make no sense and likely add a LOT of noise if you really do turn on 'Debug' in production. Because of that then one must do code reviews to insure at least that Debug logging provides a context and does not cause significant (useless) noise. All of that then comes back to QA. What should they run? If you actually want to allow Debug logging and it will be turned on in production then you then need to test both with it on and with it off. So testing twice. Both to insure there is not too much noise and that it does not interfere with functionality. Due to all of that for me I limit all code check ins to Error/Warn/Info. And in practice I haven't even used Warn for a very long time.

Kevin Marois wrote:

Exception logging I get, but is this how you would Info and Debug?

Pseudo code for a trace log entry.

Log.Info("CreateRequest: RequestId=<