ASP.NET 5 Logging

Logging lets your application capture run-time information that can prove invaluable when debugging problems or analyzing performance issues.  ASP.NET 5 has a default logging implementation that logs to the console, debugger, event log, or to a trace source.  If these targets don’t meet your application’s needs, you can replace the default implementation with a third-party solution, or create your own custom logger.

In this post, we’ll cover the following topics:

Logging Levels

Logging systems typically group messages by severity or purpose.  At design time, you assign a level to log messages, and at run-time, you configure the level of messages that the application logs.  For example, you might write code to log a detailed message at the start of a method that includes the method’s parameter values.  This might be useful during development, but would not be logged in production.

ASP.NET 5 RC1 supports the following log levels:

LogLevel Recommended Use
Critical Reserve for the most severe exceptions in your application, typically ones that would indicate an system-wide failure and require immediate attention.
Error Use for exceptions that prevent the application from performing its current task, but don’t indicate an system-wide failure.
Warning Use for situations that may require investigation, but don’t prevent the application from continuing.
Information General messages used to track application flow.
Verbose Detailed messages that would be used during development.
Debug Similar to Verbose, but may also include sensitive information.

There is one other level, None, which you use when configuring the logger. This level directs the logger not to write messages of any level.

Note:  Post RC1, the developers renamed Debug to Trace, and Verbose to Debug. They did this to better align these levels with those used by other logging systems.

As mentioned above, we would normally use configuration settings to control the level of messages being logged, but for our examples we will set a hard-coded level.

The Default Loggers

For our first example, we will focus on two of the default loggers: the ConsoleLogger and the DebuggerLogger. We will look at logging to the event log later in this post.

To use the ConsoleLogger, we include the following dependencies in the project.json file:

In our Startup.Configure method, we take an ILoggerFactory, which the application uses to create logger instances as needed. We configure the minimum logging level on the ILoggerFactory instance and add the ConsoleLogger.

Note: Post RC1, the developers removed the MinimumLevel property from ILoggerFactory. In practice, this property was confusing since the methods to add loggers also offer a minimum level setting, so the change was welcome.

Next we create a simple class to illustrate logging messages at different levels. This class takes an ILogger<T>, which we will use to write log messages. ILogger<T> inherits from ILogger and uses the type name of T as the category name for log messages.

In our examples, we rely on DI to inject an instance of ILogger into our class, but ILoggerFactory has a CreateLogger method you can use to create a logger for a specific category.

When we run the application, we see the following output on the console:

logging-cli-01

Because we are logging at the Debug level, we also see logging messages from the framework. If you change the level to Information, you will only see messages from the application.

Our Visual Studio project will add the DebuggerLogger to the list of dependencies:

We also add it to the ILoggerFactory:

Now when we debug the application in Visual Studio, we see log messages in the output window:

logging-debug-01

Since we also added the ConsoleLogger, you can run the Visual Studio project from the command line and see messages logged to the console as well.

You can find source code for these examples here:

Logging with Serilog

Serilog is a popular third-party logging solution with an extensive catalog of sinks (targets for log messages).  At this time, only a few sinks besides the ones that come with the Serilog package are available for dnxcore50, but this will improve over time.

To use Serilog as your application logger, add the following dependencies:

In the Startup constructor, set up Serilog:

And in the Configure method, add Serilog:

Now when we run the application from the console, we see Serilog’s output in the console, and browsing to the project folder, we see the rolling log file for the current date:

serilog-console-01

serilog-file-01

You can find source code for these examples here:

Logging to the Event Log

A common target for log messages on Windows systems is the event log, and writing messages to the event log is similar to our previous examples, with two exceptions:

  1. Logging to the event log is only available for dnx451.
  2. You must create a source for event messages.  Technically, it is not required for the default EventLogLogger, but you’ll want to do this for any professionally developed application.

To write to the event log using the default logger, add the following dependency to the project.json file:

We will add the following class for our event IDs:

and update our logger calls to include an event ID.

In this case, our event IDs align with log levels, but you can use whatever makes sense for your application.

In the Startup.Configure method, you could add the EventLogLogger to loggerFactory as shown below:

If you do this, you’ll see entries in the event viewer that complain about missing event descriptions:

event-message-01

To correct this, we need to create an event message source.  I based much of what follows on information from this blog post.

To create the message source, we need the following tools:

  • Message Compiler: mc.exe
  • Resource Compiler: rc.exe
  • Visual C++ Linker: link.exe

If the message compiler and resource compiler aren’t available and you have installed Visual C++, install the Windows SDK.

To create the message source, first create a message file.  For details on the file format, see this MSDN page:  Message Text Files.  For this example, we will use this file:

Note:  you will need to encode this file as ANSI or Unicode, specifically UCS-2 LE BOM, not UTF-8 (when using Notepad++).

logging-encoding

Now, from the Developer Command Prompt, run the following commands:

Note: the -u switch is not used if the message file encoding is ANSI.

The screenshot below shows what you can expect to see when running these commands.

compile-messages

Once you have the .dll with your messages, you will need to add an entry to the registry.  Using Regedit, add the following entry under HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\EventLog\Application:

regedit

Now that we have a message file registered for the “Log App” source, we need to update our Startup.Configure method:

We have used the EventLogSettings to indicate our “Log App” source, and now we see these message in the event viewer:

event-message-02

To use Serilog to write to the event log, set up your application dependencies as follows:

One idiosyncrasy of the Serilog event log sink is that it uses the values of the Serilog.Evnet.LogEventLevel enumeration as event IDs.  If you log an event that lines up with Serilog’s Verbose level, you’ll see an event ID of 0.  Because of this, we need to create a new message file for Serilog:

We’ll run through the same process outlined above to create a message source dll, and add it to the registry with a source name of “Serilog App”.

Because the log level determines the event ID, we can delete the MyEventIds class and change the logging calls to omit the event ID:

When we run the application, we see the expected events in the event viewer:

serilog-event-message-01

You can find source code for these examples here:

Creating a Custom Logger

Finally, if none of the default or third-party loggers meet your needs, you can create a custom logger. This example simply writes out messages to a file, but you can see where it could be changed to write out to another target.

First, we’ll define an ILogger implementation. Our implementation ignores scopes, which serve to logically group log messages. This example of using a NoopDisposable comes from the DebuggerLogger implementation. You can look through other logger implementations on github to see how you might implement scopes if you need them.

Next, we define an ILoggerProvider implementation, which will create instances of the MyLogger class:

Finally, we create an extension method to add the MyLoggerProvider:

Now we can update the Startup.Configure method to add our custom logger provider:

When we run the application and browse to a page, we see our custom log file created:

custom-logger-01

You can find source code for these examples here:

2 Comment

  1. Sam says: Reply

    I have not been able to get this to work when deploying on IIS 7/8. Works perfectly fine when running in IIS. Any ideas why that might be the case?

    1. Jeff Ogata says: Reply

      Does the application pool identity have permission to write to the log output folder? That’s the most common problem I run into. Here’s a blog post showing how to grant permissions to the app pool identity: https://www.bluevalleytech.com/techtalk/blog/assigning-ntfs-folder-permission-to-iis7-application-pools/

Leave a Reply