If you’ve been writing code for any reasonable amount of time, then it’s virtually impossible that you haven’t handled logging in any way, since it’s one of the most essential parts of modern, “real life” app development.
If you’re a .NET developer, then you’ve probably used some of the many famous logging frameworks available for use on this platform. Today’s post will cover one of these frameworks: log4net.
Getting started with logging—and also the concept of a logging framework—can be a daunting task. This post will feature a gentle but complete introduction to log4net.
After following this tutorial, you’ll have a firm grasp of what’s log4net about, how to install and use it, and what the most important best practices are that you should try to adopt. Let’s get started.
Before we dive into the nuts and bolts of how to use log4net, we need to understand what this thing is about.
So, what is log4net?
Log4net is a logging framework for the .NET platform. It’s definitely not the only one, but it’s one of the most popular frameworks out there.
A logging framework is a tool that can dramatically reduce the burden of dealing with logs. Logging is an essential aspect of software development.
Whether you’re developing a simple application or a complex enterprise-level system, effective logging can help you troubleshoot issues, monitor application behavior, and track events.
When you employ a framework, it takes care of many of the important yet annoying aspects of logging: where to log in, whether to append to an existing file or create a new one, the formatting of the log message, and more.
Another very important issue that a logging framework takes care of for you is log targets. By adopting a logging framework, it becomes easy to write your logs to different places by simply changing your configuration.
You can write your .NET logs to a file on disk, a database, a log management system, or potentially dozens of other places, all without changing your code.
The easiest way to add Log4net to your project is by using NuGet Package Manager. Open your Visual Studio project, right-click on your project in Solution Explorer, and select “Manage NuGet Packages.” Search for “Log4net” and install the package.
You can also run this quick command from the Package Manager Console:
PM> Install-Package log4net
Add a new file to your project in Visual Studio called log4net.config and be sure to set a property for the file. Set Copy to Output Directory to Copy Always. This is important because we need the log4net.config file to be copied to the bin folder when you build and run your app.
To get you started quickly, copy this log4net config and put it in your new log4net.config file. This will log messages to the console and a log file. We will discuss more about logging appenders further down.
<log4net>
<root>
<level value="ALL" />
<appender-ref ref="console" />
<appender-ref ref="file" />
</root>
<appender name="console" type="log4net.Appender.ConsoleAppender">
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date %level %logger - %message%newline" />
</layout>
</appender>
<appender name="file" type="log4net.Appender.RollingFileAppender">
<file value="myapp.log" />
<appendToFile value="true" />
<rollingStyle value="Size" />
<maxSizeRollBackups value="5" />
<maximumFileSize value="10MB" />
<staticLogFileName value="true" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date [%thread] %level %logger - %message%newline" />
</layout>
</appender>
</log4net>
The next thing we need to do is tell log4net where to load its configuration so that it actually works. I suggest putting this in your AssemblyInfo.cs file.
You can find it under the Properties section in your project:
Add this to the bottom of your AssemblyInfo file.
[assembly: log4net.Config.XmlConfigurator(ConfigFile = "log4net.config")]
Now you can modify your app to log something and try it out!
class Program
{
private static readonly log4net.ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);
static void Main(string[] args)
{
log.Info("Hello logging world!");
Console.WriteLine("Hit enter");
Console.ReadLine();
}
}
Appenders are how you direct where you want your logs sent. The most popular of the standard appenders are most likely the ConsoleAppender, File Appender, Database Appender, and RollingFileAppender.
The Console Appender is one of the simplest and most commonly used appenders. It’s primarily intended for development and debugging, as it outputs log messages to the console, making them easily visible during the development phase.
The File Appender is crucial in production environments, where logs need to be persisted for analysis and auditing. It logs messages to text files, allowing for later inspection and tracking of application behavior.
For applications that require centralized log storage and compliance with auditing requirements, the Database Appender is invaluable. It logs messages to a database, ensuring that log data is stored securely and can be accessed for analysis.
The RollingFile Appender is a specialized version of the file appender. It helps manage log files by creating new files when a certain size or time threshold is reached. This prevents log files from growing excessively and becoming unwieldy.
I would also try the DebugAppender if you want to see your log statements in the Visual Studio Debug window so you don’t have to open a log file.
If you are using a Console, check out the ColoredConsoleAppender.
Be sure to use Debug, Info, Warning, Error, and Fatal logging levels as appropriate within your code. Don’t log everything as Debug. Be sure to think about how you would be viewing the logs and what you want to see later when coding your logging statements.
You can specify in your log4net config which log4net logging levels you want to log.
This is really valuable if you want to specify only certain levels to be logged to a specific log appender or to reduce logging in production. This allows you to log more or less data without changing your code.
log4net levels:
Declaring any variable in your code has overhead. When I have been doing some profiling sessions in the past to optimize code, I have noticed that the constructors on the LogManager object can use a lot of CPU.
Declare it as static and use this little trick so you don’t have to hard code the class type.
private static readonly log4net.ILog log
= log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);
From time to time, you may have problems with a specific appender, or issues working with it.
To help resolve these issues, enable internal log4net logging via your web.config file.
<configuration>
<appSettings>
<add key="log4net.Internal.Debug" value="true"/>
</appSettings>
</configuration>
You can then specify where the logging is written to.
<configuration>
...
<system.diagnostics>
<trace autoflush="true">
<listeners>
<add
name="textWriterTraceListener"
type="System.Diagnostics.TextWriterTraceListener"
initializeData="C:\tmp\log4net.txt" />
</listeners>
</trace>
</system.diagnostics>
...
</configuration>
Trying to query logs in SQL is very difficult if you log any real volume. You are much better off sending your logs to Elasticsearch or a log management service that can provide full-text indexing and more functionality with your logs.
The last thing you want to do is send any sort of email from an appender. They either get ignored over time or something starts throwing a lot of exceptions and then your app starts sending thousands of errors. Although, there is a SmtpAppender if you really want to do this.
If you want to send alerts about exceptions, send your exceptions to an error-tracking product, like Retrace, which is designed for this.
They can also de-dupe your errors so you can figure out when an error is truly new, track its history, and track error rates.
Capturing logs and logging them to a file on disk is great. But if you want to search your logs across multiple servers and applications, you need to send all of your logs to a central repository.
There are a lot of log management solutions that can help you with this, or you can even set up your own elastic search cluster for it.
If you want to query all the files on disk, consider using VisualLogParser.
Filters can be configured to suppress specific log messages. Take a look at these examples.
Here’s how you can filter by the text on the log messages.
<filter type="log4net.Filter.StringMatchFilter">
<stringToMatch value="test" /> <!-- Can filter by string or regex -->
</filter>
Here, you can filter by the log level:
<filter type="log4net.Filter.LevelRangeFilter">
<levelMin value="INFO" />
<levelMax value="FATAL" />
</filter>
If you want to do something that the standard appenders do not support, you can search online for one or write your own.
One example could be an appender for writing to Azure Storage. Once upon a time, we wrote one to send our logs to Azure Table storage to centralize them. We couldn’t really query them due to the lack of full-text indexing, but we could view them.
As an example of a custom appender, you can review the source code for our appender for sending logs to Retrace.
You can modify your configuration to change what fields are outputting and in what format using pattern layouts.
<appender name="LogFileAppender" type="log4net.Appender.RollingFileAppender">
<param name="File" value="stackify.log" />
<param name="AppendToFile" value="true" />
<rollingStyle value="Size" />
<maxSizeRollBackups value="10" />
<maximumFileSize value="10MB" />
<staticLogFileName value="true" />
<layout type="log4net.Layout.PatternLayout">
<param name="ConversionPattern" value="%-5p %d{MM-dd hh:mm:ss.ffff} [%thread] %m%n" />
</layout>
</appender>
Using the layout above, write the level (%p), current date time (%d), thread # (%thread), the message (%m), and a new line (%n). The -5 in the %-5p is to set the width of the field to 5 characters.
Here are some other notable fields you can log, although they can have a big performance impact on your app and would not be recommended for high-volume logging on a production application.
A layout like this:
<layout type="log4net.Layout.PatternLayout">
<param name="ConversionPattern" value="%-5p%d{ yyyy-MM-dd HH:mm:ss} – [%thread] %m method:%method %n stacktrace:%stacktrace{5} %n type:%type %n line: %line %n" />
</layout>
Produces a log message like this:
ERROR 2017-02-06 09:38:10 – [10] Error downloading web request method:ThrowWebException
stacktrace:Microsoft.VisualStudio.HostingProcess.HostProc.RunUsersAssembly > System.AppDomain.ExecuteAssembly > System.AppDomain._nExecuteAssembly > ConsoleApplication1.Program.Main > ConsoleApplication1.Class1.ThrowWebException
type:ConsoleApplication1.Class1
line: 26
You can also log custom fields to help give some more context about the user, customer, or transaction related to the log statements.
The below example sets a custom property called customer. You can then modify your log4net pattern layout to include %property{customer} to output it in your logs.
log4net.ThreadContext.Properties["customer"] = "My Customer Name";
log.Debug("We are going to try and do a web request");
try
{
Class1.ThrowWebException();
}
catch (Exception ex)
{
log.Error("Error trying to do something", ex);
}
log.Debug("We are done with the web request");
Additionally, you can assign objects in contexts to use what it calls “active property values.” When the log message is written, the ToString() method will be called which can dynamically do something.
This can be used to write transaction IDs to help correlate messages to a web request or transaction!
//Create our little helper class
public class ActivityIdHelper
{
public override string ToString()
{
if (Trace.CorrelationManager.ActivityId == Guid.Empty)
{
Trace.CorrelationManager.ActivityId = Guid.NewGuid();
}
return Trace.CorrelationManager.ActivityId.ToString();
}
}
In your global.asax or Startup.cs class, subscribe to an event for when a request first starts.
public override void Init()
{
base.Init();
this.Error += WebApiApplication_Error;
this.BeginRequest += WebApiApplication_BeginRequest;
this.EndRequest += WebApiApplication_EndRequest;
}
void WebApiApplication_BeginRequest(object sender, EventArgs e)
{
//set the property to our new object
log4net.LogicalThreadContext.Properties["activityid"] = new ActivityIdHelper();
log.Debug("WebApiApplication_BeginRequest");
}
If you add %property{activity} to your pattern layout, you can now see a transaction ID in your logs like so.
Your log messages may still look like spaghetti, but at least you can easily see which ones go together.
DEBUG 02-06 02:51:58.6347 – a69640f7-d47d-4aa4-99c9-13cfd9ab93c2 WebApiApplication_BeginRequest
DEBUG 02-06 02:51:58.6382 – a69640f7-d47d-4aa4-99c9-13cfd9ab93c2 Starting KitchenAsync - Call redis
DEBUG 02-06 02:51:58.9315 – b8a3bcee-e82e-4298-b27f-6481b256b5ad Finished KitchenAsync
DEBUG 02-06 02:51:59.1285 – a69640f7-d47d-4aa4-99c9-13cfd9ab93c2 Call Webclient
DEBUG 02-06 02:51:59.1686 – 54218fab-bd1b-4c77-9ff8-ebef838dfb82 WebApiApplication_BeginRequest
DEBUG 02-06 02:51:59.1746 – 54218fab-bd1b-4c77-9ff8-ebef838dfb82 Starting KitchenAsync - Call redis
DEBUG 02-06 02:51:59.4378 – a69640f7-d47d-4aa4-99c9-13cfd9ab93c2 Finished KitchenAsync
DEBUG 02-06 02:51:59.6450 – 54218fab-bd1b-4c77-9ff8-ebef838dfb82 Call Webclient
DEBUG 02-06 02:51:59.9294 – 54218fab-bd1b-4c77-9ff8-ebef838dfb82 Finished KitchenAsync
You could use the same strategy as above to dynamically grab ASP.NET request info to add to your log message.
public class WebRequestInfo
{
public override string ToString()
{
return HttpContext.Current?.Request?.RawUrl + ", " + HttpContext.Current?.Request?.UserAgent;
}
}
void WebApiApplication_BeginRequest(object sender, EventArgs e)
{
log4net.LogicalThreadContext.Properties["activityid"] = new ActivityIdHelper();
log4net.LogicalThreadContext.Properties["requestinfo"] = new WebRequestInfo();
log.Debug("WebApiApplication_BeginRequest");
}
By default, you can log an object to it and it will serialize it with its default renderers.
log.Debug(new {color="red", int1 = 1});
Output:
DEBUG 2017-02-06 15:07:25 – [8] { color = red, int1 = 1 }
But what if you want to log your entire log message as JSON?
There are several Nuget packages related to log4net and JSON, but the support and docs for all of them seem a little sketchy.
I would recommend just making your own JsonLayout class that does it. There is a good sample on GitHub. You could then control exactly how you log the JSON and which fields you log.
Output from the GitHub JsonLayout:
{
"processSessionId" : "225ba696-6607-4abc-95f6-df8e0438e898",
"level" : "DEBUG",
"messageObject" : "Finished KitchenAsync",
"renderedMessage" : "Finished KitchenAsync",
"timestampUtc" : "2017-02-06T21:20:07.5690494Z",
"logger" : "WebApp2.Controllers.TestController",
"thread" : "69",
"exceptionObject" : null,
"exceptionObjectString" : null,
"userName" : "IIS APPPOOL\\WebApp2",
"domain" : "/LM/W3SVC/1/ROOT/WebApp2-10-131308895921693643",
"identity" : "",
"location" : "WebApp2.Controllers.TestController+d__27.MoveNext(C:\\BitBucket\\PrefixTests\\WebApp2\\Controllers\\TestController.cs:477)",
"pid" : 14428,
"machineName" : "LAPTOP-1UJ70V4E",
"workingSet" : 352481280,
"osVersion" : "Microsoft Windows NT 10.0.14393.0",
"is64bitOS" : true,
"is64bitProcess" : true,
"properties" : {
"requestinfo" : {},
"activityid" : {},
"log4net:UserName" : "IIS APPPOOL\\WebApp2",
"log4net:Identity" : "",
"log4net:HostName" : "LAPTOP-1UJ70V4E"
}
}
If you want to really get the value of structured logging, you will want to send your logs to a log management tool that can index all the fields and enable powerful searching and analytics capabilities.
Learn more here: What is structured logging and why developers need it.
Log files can quickly become a spaghetti mess of log messages. Especially with web apps that have lots of AJAX requests going on that all do logging.
I highly recommend using Prefix, Stackify’s FREE .NET Profiler to view your logs per web request, along with SQL queries, HTTP calls, and much more.
Logging is an essential part of modern software development. Deploying a piece of software to a production environment without any type of logging would be unthinkable nowadays. Doing so would amount to taking a walk in a huge city, during rush hour, blindfolded.
Software is a very complex thing. When you release an application, and deploy it to a (potentially) unknown environment, you can’t know for sure that everything is going to work as intended.
If something goes wrong—and it will—logging is one of the few ways you can use to “go back in time,” understand the problem, and fix it.
Today’s post covered the log4net logging framework. You learned what a logging framework is, and how it can relieve the burden you might face as a developer having to come up with a logging strategy.
We also shared a list of best practices and tips you can start employing right away to make your journey with log4net easier.
Thanks for reading, and see you next time.
Stackify's APM tools are used by thousands of .NET, Java, PHP, Node.js, Python, & Ruby developers all over the world.
Explore Retrace's product features to learn more.
If you would like to be a guest contributor to the Stackify blog please reach out to [email protected]
