C# – How to Handle Logging When Creating Libraries for Others

The importance of trace types must be chosen not because of where the trace is in code, but because the traced message is more or less important. Example:

Trace a "Start" event when beginning a method, which should represent a single logical operation or a pipeline, along with a string representation of the parameter values passed in to the method.

Use start type when you start a logical operation. This doesn't mean that the start trace must be at the beginning of a method, nor does it mean that a method must have a start trace.

This being said, in most cases, a logical operation will actually start at the beginning of the method. Otherwise, you should ask yourself if the code is refactored correctly.

Tracing parameters may also be a bad idea. You have to think what to trace, case by case. For example it is really bad to trace parameters of a method void Authenticate(string userName, string plainPassword).

Trace an "Information" event when inserting an item into the database.

It depends. Some items must be traced, but not every item.

• For example imagine you are actually inserting a log item into your database. Would you trace logs? And then log traces? And then trace the logging of the trace?
• Another example: you're inserting a sensitive data. This requires auditing. Since you audited the insertion, why tracing it?

Trace an "Information" event when taking one path or another in an important if/else statement.

Again, it depends.

Trace a "Critical" or "Error" in a catch block depending on weather this is a recoverable error.

The action taken after a non-recoverable error can be more than tracing. For example server-side, you would like to store the exception in the database for further analysis. Also, some exceptions are less important than others, and does not require tracing.

Trace a "Stop" event when finishing the execution of the method.

See the first point.

please clarify when best to trace Verbose and Warning event types.

Verbose:

Verbose is used to trace what you need to trace when something goes really wrong. It means that in most cases, you will disable the tracing of verbose messages, but sometimes, you have to debug some parts of your code to understand why something fails on an edge case.

You usually have lots of verbose messages which let you understand really well the application flow. It also means that those messages must be disabled most of the time because:

• otherwise, the log will grow really fast,
• you don't need them most of the time,
• they may contain sensitive data about the application flow.

Think about verbose as a tool you have to use when you don't have an access to the debugger.

Warning:

Warning type trace is used when something wrong and important happens, but is not too crucial to be treated as an error. For example low RAM may emit a warning, but there is no reason to trace an error, since your application can continue, even if it will be slower than usual.

Examples:

• Example 1: the application failed to open the file the user requested to open. The file exists and is not in use, permissions are set correctly, but something blocks the opening of a file. In this case, you will trace an error, since your application cannot manage this case and continue to work as expected by the user (i.e. actually read the file).

• Example 2: after inspection of the error in the first example, you find that the error is caused by the fact that the file path is longer than 259 characters. So you refactor your code to catch PathTooLongException. When, the next time, the user tries to open the same file, the new version of the application shows a message explaining that the file is too long and must be moved to another folder to shorten the full path in order to open this file in this application. You also trace a message.

• Example 3: your application spent twenty seconds opening and parsing a small file while most files take ten to one hundred milliseconds to open and parse. You trace a warning with relevant info: the type of disk where the file actually is, the file system, the size of the file, the exact time spent, the time the computer was on, etc. When the user complains that it takes twenty seconds to open the file, you take the trace to find what happens. You find for example that it takes so long to load the files from a network share when the computer have just started. You explain to the user that the delay is due to the network and is not related to your application.

• Example 4: the opened file is displayed incorrectly. You enable verbose trace where you actually see how the data is loaded from file and then parsed, step by step.

You're right in that this question is very much answered by, "what are your requirements", but this is my opinion.

Be sure that any event initiated by a user is traceable back to the user. Each logged event should state who is executing the event, or at least contains a transaction ID that can be traced back to the user creating the transaction. This will allow you to fulfill non-repudiation requirements where a user would not be able to deny creating the transaction.

I wouldn't recommend creating a new log file for each session. A better approach would be to create new log files once they reach a certain size (10 MB for instance). Or, just creating a new log file each day or week (depending on the size of the files). If there a lot of events being logged, a database may be better as it can handle large volumes of data easier and you will be able to query the results as needed.

For libraries, there are plenty out there for Java EE. Log 4J is fine. I've also used Apache's Commons Logging, but I prefer the combination of SLF4J and Logback personally - they are easy to use and integrate well with other logging frameworks.

You may also want to look into Aspect Oriented Programming to create the common logging events that will appear in a lot of methods. Specifically, AOP can help create debug logging for method enter / exit / throw. I've done AOP with Spring and can say it is very helpful keeping the code clean.

Speaking of logging levels, it will be very beneficial to make good use of each level as appropriate and create a secure way to change the level at runtime if you are experiencing issues.

Log only errors that would be beneficial to have logged. Tautological, maybe, but logging can often get out of hand. Having too many records to sift through means you will not be able to identify outliers or actual problems. Logging too little means you may miss an issue (if you didn't log it, it never happened), so, make good use of logging levels for these reasons as well. There may be no reason to log a user validation error (e.g., creating a new password less than the allowable number of chacters), but system errors should always be logged (e.g., unable to contact the database).

Likewise, only notify the user of what they need to know. They will need to know if the password they entered failed validation and why, but they don't need to know if the database is down (they only need to know that the site is experiencing issues and what they can do in the mean time - i.e., call a support number). Chattiness to the user should be kept to a minimum as constant error notifications that they can't personally resolve would be a poor user experience.

I suggest you take a look at OWASP's Logging Cheat Sheet for some more information on logging best practices.