Logging in .NET
The Power of C# Logs

C# logo

“It doesn’t work, fix it!” – is probably one of the most unpleasant things to hear from a user. But a simple “it doesn’t work” will not help much when trying to solve the issue, and swimming in your logs won’t either. What you really need is logging as much as possible but also having a strong logging strategy to understand context and identify root cause. Quick tip: logging only exception messages is not enough because it only gives you insights into the last element that failed and led to this error. It doesn’t provide any feedback on performances or tracing, no context about the error.

Let’s talk about logging: your C# logs will help you identify error patterns and track user happiness while using your software in a flash. If you want to extract the potential of your C# logs, keep reading: we will firstly review some basic elements about logging in C# before diving in more details such as standardization or how crucial context and metadata can be. Then we will see how C# logging library can help you with the above-mentioned points.

I. Basic C# logging

1) Logging to console

There is a native logging library in C#, called Tracesource – you can find it in System.Diagnostic. It has all you need for basic C# logging.

Here is an example of how to log with this library:
First define your logger In the configuration file (app.config):

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
 <system.diagnostics>
    <sources>
      <source name="TestLog" switchValue="All">
        <listeners>
          <add name="console" type="System.Diagnostics.ConsoleTraceListener"/>
        </listeners>
      </source>
    </sources>
  </system.diagnostics>
    <startup> 
        <supportedRuntime version="v4.0" sku=".NETFramework,Version=v4.5.2" />
    </startup>
</configuration>

Then define it in your code:

using System;
using System.Diagnostics;
class Program
    {
        private static TraceSource _source = new TraceSource("TestLog");
        static void Main(string[] args)
        {
            var i = 10; var j = 5;
            _source.TraceEvent(TraceEventType.Information, 0, "A calculation is about to start: {0}x{1}", i,j);
           ….
            }
}

This is the result you will get:

C# logging

In this case 0 is the event ID. We will explain how to use this type of information to better understand your logs while investigating an issue in Part II.

Since it is not always straightforward to use the advanced features of Diagnostic.Tracesource, it might be easier to access them with logging libraries such as log4net, Nlog or serilog. All of these libraries have very similar functions so we will only focus on one to set the example: log4net.

In the configuration file (app.config) we define the logger:

<configuration>
   <configSections>
    <section name="log4net" type="log4net.config.Log4NetConfigurationSectionHandler, log4net"/>
  </configSections>
  <log4net>
   <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
 <layout type="log4net.Layout.PatternLayout" />
   </appender>
<root>
<level value="DEBUG" />
<appender-ref ref="ConsoleAppender" />
</root>
  </log4net>

Then we define it in the code:

Using System;
class Program
    {
private static readonly log4net.ILog log = log4net.LogManager.GetLogger("TestLog");
        static void Main(string[] args)
        {
            var i = 10; var j = 5;
            log.Info($"A calculation is about to start: {i}x{j}");
          ...
}

C# logging

The first thing we notice is that we lost the logger name and the severity. We will see below how this is handled by logging libraries where all the setup has to be done in the configuration file.

2) Logging into a file

To have this message logged into a file with Tracesource, simply add two code lines in your configuration file:

<listeners>
...
<add name="texwritter" type="System.Diagnostics.TextWriterTraceListener" initializeData="C:\Logs\test.log" />
…
</listener>

You are thus adding a ‘listener’ that writes your logs into files. By adding listeners you are in control of the place your logs will be stacked.

The mechanics are the same for other logging libraries. When you log, your logger can have several listeners (or appenders, or enrichers – whatever the library you are using calls them) with different behaviors. So the same logger could log into the console, into a file, to a database or send emails.

Here is how you define an appender in your configuration file in log4net:

<log4net>
…
 <appender name="FileAppender" type="log4net.Appender.FileAppender">
      <file value="C:\Logs\MyLogFile.txt"/>
      <appendToFile value ="true" />
      <layout type="log4net.Layout.PatternLayout"/>
    </appender>
…
</log4net>
For the appender to be used, add it to the root part.

There are more options that control the filesize, buffer or file rotation while logging. Once you finish reading this article, we recommend you watch this complete tutorial if you wish to learn more about log4net capabilities.

3) What about exceptions in your C# logs?

a. Logging exceptions

Catching exceptions is easy in C# with the almighty try/catch blocks. But catching them all is not enough, you also need to log them in order to be aware of what happened in your code.

Let’s imagine that during a calculation a division by 0 occurs thus raising an exception. Thanks to a try/catch block, the exception is caught:

static void Main(string[] args)
        {
            ….
log.Info($"A calculation is about to start: {i}/{j}");
            try
            {
              //calculation done
            }
            catch(Exception e)
            {
	    log.Fatal(e);
            }
…
}

The exception is then added to the logs which automatically include the stack trace and the exception message:

C# logging

b. How to manage unhandled exceptions

If you forgot some try/catch blocks and an unhandled exception was thrown, there is a mechanism to catch it for you. And yes, it is really important to log them as they contain information about a totally unexpected behavior that could cause a crash of your application when you expect it the least.

To log unhandled exceptions you have to define a handler for them. Unlike logging properties that are defined in the configuration file, handling exceptions has to be done in the code:

public static void Main()
  	 {
		AppDomain currentDomain = AppDomain.CurrentDomain;
		currentDomain.UnhandledException += new UnhandledExceptionEventHandler(MyHandler);
		…
		//Start your application

	}
  
   static void MyHandler(object sender, UnhandledExceptionEventArgs e)
        {
            log.Fatal(e);
            ...
        }

The same thing can be done at thread level by using a ThreadExceptionHandler:

Thread.GetDomain().UnhandledException += new
    UnhandledExceptionEventHandler(MyThreadExceptionHandler);

Great, you are now able to manage unhandled exceptions and investigate them by checking your logs. You can also set an alert if you have a log management platform with alerting capacities and tackle them whenever they occur. If you want to read more about unhandled exceptions, here is an article on the topic.

But we’ve got bigger fish to fry so let’s move on to more enticing tips! Remember that the logger name and severity went missing from our C# log messages when first configuring your log4net library? Well the solution is adding context to your logs, because context is critical when troubleshooting or tracking user queries & activity. So let’s see how to do it.

II. The importance of metadatas and context

1) Adding context to your C# logs

Logging an error message or an exception provides valuable information. But more often than not, this is not enough. Sure, it’s important to know what system failed, but it’s even better to have the timestamp, the exact line in the code or even the method that failed. Context allows your team to identify and fix an issue faster. Just imagine knowing what happened before the error occurred, understanding the whole background – this is key information! We thus strongly advise you to include it in your log analysis.

As we saw previously, the Tracesource library has the logger name and the severity set by default. But you can add other fields thanks to the “traceOutputOptions” in the configuration file:

<listeners>
<add name="console" type="System.Diagnostics.ConsoleTraceListener" traceOutputOptions="ThreadId,ProcessId,Timestamp" />
</listeners>

This automatically adds those fields to every log message. It then looks as follows:

C# logging

Remember that you need to specify the list of wanted fields for all the listeners (in case you are not logging only into the console or into a file). This is not limited to a C# console logger.
Here is a list of the available fields for the Tracesource library. If you want to go beyond this rather small number of fields you can add to your context, go ahead and use a more advanced C# logging library!

Here’s where log4net (or an equivalent library) enters the game.

To add context to all your log messages using log4net, you need to add a conversionPattern to an appender in the configuration file. This way you can centralize the standardization of your messages which helps you avoid different message formats from developers.

In your configuration file you can add the following in the appender:

<appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
 <layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date{ABSOLUTE} [%logger] %level - %message - method -%method - line - %line"/>
</layout>
</appender>

Here’s the outcome:

C# logging

Check the full list of available fields for the log4net library here.

Once those elements are added to the configuration file, the standardization of your C# logs begins. Besides adding standard attributes to your log messages with the log4net library, you will need to add custom metadata and more context to your C# logs. For example, if your developers don’t use a common naming convention for variables, you will end up having different fields for the same C# log messages as such: user.id or user_id. Adding the right metas will spare you this trouble, let’s see how it’s done!

2) Relevant context for C# logs

To understand this better, we’ll take the following example: when a user clicks on a button, a calculation is done. Each calculation is done in its own thread. If several users do this at the same time and an error only occurred for one of them, knowing the context of the error is vital.

That’s when having the user, thread and event ID in the C# logs makes a lot of sense. You can attain this by using the log4net library and defining a conversionPattern in the configuration file:

<appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
      <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%date{ABSOLUTE} [%logger] [%thread] %level - eventID:%property{eventID} - userID:%property{userID} - %message - method -%method - line - %line" />
      </layout>
</appender>

Use a parameter like EventID and userID that can be defined at thread level:

static void Main(string[] args)
        {
//
 Thread firstThread =
                 new Thread(
                     example => Calculate(user1.id,event1.id)
                         );
            Thread secondThread =
                new Thread(
                    example => Calculate(user2.id, event2.id)
                        );

            firstThread.Start();
            secondThread.Start();
….
}

private static void Calculate(int userID, int eventID)
{         
 log4net.LogicalThreadContext.Properties["eventID"] = eventID;
 log4net.LogicalThreadContext.Properties["userID"] = userID;
 //do calculation and logs 
	...
 log.Info($"Step {i} in my calculation");
	...
}

C# logging

We clearly see that the error occurred for user 123 and that it failed after the step 2 of the calculation in the thread 12.

User context does not help you understand what failed but when and how it failed as well as what pattern caused the error.

So first of all, you should log every user’s actions with a unique userID in order to track them separately.
Secondly, using a system of eventID for specific tasks can help filtering through the sea of C# logs.
For instance when a user creates an object that triggers a call to the database and an item creation, think of adding an eventID to every log across all steps starting with the user click up to the database item creation, until the pop up displays that the item was correctly created.

You can also use context for tracking multi-threaded parts of your code.

Having your hands on such information is key to quickly identifying all the logs related to a specific user action and limiting time loss in understanding errors. That’s why it is so beneficial to enrich your C# logs by adding as much user & code application context as possible. Also keep in mind that ensuring a standardized format across your project is crucial – for this, we highly recommend the JSON format. We’ll explain it in the following chapter.

3) The C# logger name

One thing that’s important when it comes to C# logs is having one logger per class. This allows you to use the same name for a specific class and for the corresponding logger, making it easier to immediately retrieve the class & namespace of what you want to analyze. Plus, you can easily copy paste the logger definition when creating a new class instead of typing a logger name each time. What you can use to achieve this is:

private static readonly log4net.ILog log = log4net.LogManager.GetLogger(
System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);

Which leads to a result like this:

C# logging

III. How to use C# logs thanks to JSON format

So you know what there is to know about context, we’re moving on to centralizing your logs and to the JSON format.

1) Centralize your logs

If you have a software deployed on several servers, it is a pain to connect to each one of them to check log files and see what happened. Solve this by centralizing your logs in one single place where the context and metadata become relevant for all logs and comparing different sources of C# logs turns into a breeze. By the way, using a log management platform will do just that for you!

2) Reveal the hidden value of your logs w/ JSON

JSON format

We previously saw how important it is to have a standardized format for our C# logs as it is very hard to work with -or even understand- logs in multiple formats. What JSON does is enable you to extract the relevant fields and have a better visual result when troubleshooting, instead of struggling to read into your raw log files.

Besides fields, JSON will enable you to collect metrics or numerical values which are usually available in the logs but lost somewhere in the message.


And if you brought a log management platform into the equation, you could extract these values from logs and plot their evolution over time as well as check context. This greatly facilitates monitoring your app perf. Just a quick glimpse of what you could do below:

response time

A log management platform should also allow you to filter your data. Logmatic.io for instance allows extracting context and filtering per application name, server name or any other custom field – thanks to the JSON format.

filter host

3) How to log in JSON

To log in JSON with the log4net library you need to modify the appender as follows:

<log4net>
   …
    <appender name="JsonFileAppender" type="log4net.Appender.FileAppender">
    <threshold value="DEBUG"/>
    <file value="C:\Logs\myJsonLogfile.json" />
    <appendToFile value="true" />
      <layout type="log4net.Layout.SerializedLayout, log4net.Ext.Json">
        <decorator type="log4net.Layout.Decorators.StandardTypesDecorator, log4net.Ext.Json" />
        <default />
      </layout>
    </appender>
...
  </log4net>

So if we log a simple message:

var i = 10; var j = 5;
 log.Info($"A calculation is about to start: {i}x{j}");

We obtain the following log in the JSON format:

{"date":"2017-03-10T15:13:53.1302217+01:00","level":"INFO","appname":"ConsoleApplication1.vshost.exe","logger":"ConsoleApplication1.Program","thread":"10","message":"A calculation is about to start: 10x5"}

Time to make the most of your C# logs

Now that you have all the tools to a standardized and structured log format filled with contextual information, it is time to think about the next step. Usually users detect errors and submit them to a support team. The support team then gets the developers’ attention and, you guessed it, the developers will check in the logs to find & fix the error.

But what if you could break this cycle by being alerted when an error occurred before the user is affected? This could be done directly in the logging library or by using a log management platform that enables you to create alerts on any wanted field you added to your logs.
Logging can help you troubleshoot your application but also be one step ahead of your users. Your logs are a gold mine filled with information ready to be used – start right away!


There are more technology-specific best practices articles coming. Stay posted by subscribing to the Newsletter or following us on Twitter.

Related Posts

Get notified when new content is published