Fully working Azure diagnostics example including log4net
Introduction
Azure diagnostics has been a pain for me for the past 6 months. It hasn't been working properly but it always seems to take so long to debug that it is easier to forget about it...except of course logging is ESSENTIAL for any useful working system. If people are seeing errors, it is sometimes possible to debug by looking at the code but if not, you need a specific error message or exception to be logged somewhere readable. The problem might not be caused by you but by the cloud host or whatever so you need to know what's what.Anyway....I have just installed the latest version of the Azure SDK (v2.2) and I know some things have been changed recently in the SDK so I cannot promise this will work in the same way on the earlier versions of the SDK.
Step 1 - Add log4net (optional)
This step is optional but I have chosen to use log4net for reasons that include the ability to send emails with any errors - especially useful in the early days where I don't expect too many! Also, it is very easy to configure multiple appenders in log4net in a pretty consistent way. You can log to file while debugging locally etc.In NuGet there is now a log4net package so simply go into Visual Studio and select Tools > Library Package Manager > Manage NuGet Packages for Solution (or alternatively, right-click the references folder of a project and select Manage NuGet Packages) and then search for log4net. This will add not only the dll but also an assembly redirect into your web.config and also a configuration section.
Optionally, you can move the log4net configuration out of web.config and into its own file. I have done this to keep web.config smaller. If you do this, web.config needs to contain:
<log4net configsource="log4net.config">
This is placed under the configuration element. Your log4net config file needs to have the following at the root level:
<?xml version="1.0" encoding="utf-8" ?>
<log4net>
etc...
You also need to do 2 things to make the log4net system work correctly. I used to only do the first of these but recently, it seems that the second is also required but I don't know whether that is because of other changes I have made>
1) Add the following to your global.asax code file above the namespace declaration. I think this can also go in AssemblyInfo.cs:
[assembly: log4net.Config.XmlConfigurator(ConfigFile="log4net.config", Watch=false)]
2) Wake up log4net by calling the following code in your Application_Start method in global.asax:
XmlConfigurator.Configure();
Step 2 - Adapt the log4net TraceAppender
If you are using log4net, the default TraceAppender does not understand the standard .Net logging levels which mean everything gets logged as Verbose level. It is easy to modify this behaviour by extending log4net.Appender.TraceAppender in your own code and map between the log4net and .Net logging levels:public class AzureTraceAppender : TraceAppender
{
protected override void Append(LoggingEvent loggingEvent)
{
var level = loggingEvent.Level;
var message = RenderLoggingEvent(loggingEvent);
if (level >= Level.Error)
Trace.TraceError(message);
else if (level >= Level.Warn)
Trace.TraceWarning(message);
else if (level >= Level.Info)
Trace.TraceInformation(message);
else
Trace.Write(message);
if (ImmediateFlush)
Trace.Flush();
}
}
When referencing this appender in your log4net config, you need to reference it by namespace and the name of your project output assembly:
<appender name="TraceAppender" type="namespace.to.AzureTraceAppender, YourAssemblyName">
<layout type="log4net.Layout.PatternLayout">
<conversionpattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline">
</conversionpattern></layout>
<threshold value="INFO"/>
</appender>
Step 3 - Extend DiagnosticMonitorTraceListener
The reason for this as stated in my previous post is that the Azure version does not honour the "filter" element and therefore dumps everything into the log file. This is a pain in Azure for the simple reason that there are loads of Azure platform events about things I don't even understand. This very quickly makes the logs unusable without some special tool to parse them. My previous post tells how to extend this MS class to add in the filtering functionality.Step 4 - Modify web.config to use the trace listener
web.config is normally where you specify your trace listeners. What these listeners do is they listen to trace sources (which in my case are created via log4net) and then they do something with these events as they are logged. The diagnostic monitor trace listener logs to file on your Azure machine in a special XML format which is why later we need to copy this data to somewhere more useful.In my web config, I have the following entry:
<system.diagnostics="">
<trace autoflush="true">
<listeners>
<clear />
<add name="AzureDiagnostics" type="namespace.to.DiagnosticMonTraceListener, YourAssemblyName">
<filter initializedata="Error" type="System.Diagnostics.EventTypeFilter">
</filter></add>
</listeners>
</trace>
</system>
And you will note I am only interested in Errors. If I used the MS version of this trace listener, that error filter would make no difference to the output.
Step 5 - Remove any redundant code from WebRole.cs
This is the default class name for the role entry point and used to be required to setup diagnostic transfer information but that can now all be done in the role configuration itself and is no longer needed in OnStart. All mine does is call the base class OnStart() - you might have other code in here unrelated to diagnostics though.Step 6 - Configure your transfers
Double-click the role in your cloud project to open up the role configuration pages and notice the diagnostics section at the bottom of the first page:
Ensure that Enable Diagnostics is ticked and then choose "Custom plan". Click the Edit button and set your options for transferring the event and application logs. It is up to you when to do these but the default is to transfer every 1 minute for the Application and Event logs and to choose verbose to copy off all messages (we are filtering in the application so it is OK to set verbose here).
By default, this will copy the data into the specified storage account for your application and into tables with fixed names: WADLogsTable (for events) and WADWindowsEventLogsTable for application events.
Step 7 - Log events from your code
How you do this will depend on whether you are using log4net or directly using the MS logging. If you are using log4net, create a private static log variable at the top of each class like this:private static readonly log4net.ILog log = log4net.LogManager.GetLogger(typeof(MyClassName));
and then call it in the following form:
log.Warn("OAuth2 invalid request");
You can also pass an exception as the second argument.
If you are not using log4net, then the logging is simply done like the following with no variable required:
Trace.TraceError("Some message", optionalException);
Step 8 - Debugging
I have had various problems in the past and if you have any problems, as with most debugging, the best idea is to start with a very simple example and not using log4net. Put a single Trace.TraceError() call in your class. Use the MS version of DiagnosticMonitorTraceListener with no filter in your web.config and see if you can get that simple example working. Then replace DiagnosticMonitorTraceListener with your own version without/with a filter and each time work out whether it is working.Remember it takes some time for the data to be transferred into the tables (depending on what you set as the transfer time).
From experience, the two most likely problems are incorrectly specified types in web.config or log4net.config (typos or using the wrong name for the assembly) or using the wrong versions or combinations of versions of the windows azure SDK dlls.
You can enable Remote Desktop on your roles, which will allow you to see the windows logs on the role itself if you are having problems - especially if the problems aren't causing any useful exceptions. log4net is designed to fail quietly!
Check your logging levels to make sure your events are not being filtered out at some point. log4net and the web.config entries as well as the diags config in your role can all affect whether a specific event level is passed through or blocked.
Sometimes, you might get an error logged about things that are incorrect (like configuration) but which somehow are still able to be logged. Pay attention to these because it is possible that the configuration you think you are using is not being loaded because of errors.