Logging in Azure: Part 3-Trace/Event Logs

This is the third and final entry on this series on logging from an Azure hosted service.

These topics included:

1. Synchronizing a log file to blob storage
2. Using a custom log4net appender to write directly to table storage
3. Logging to the Trace log and synchronizing to table storage

These solutions are in order of complexity (in my opinion). Each topic outlines the structure of the solution, how to implement it, and the pros/cons of the solution compared to the others.

3. Logging to the Trace log

I left this solution for last not because of ease-of-use, the setup for trace logging is fairly simple, to me this is the most complex because of the amount of components in place.

There are a number of features built into the Azure Diagnostics Module. The purpose of this module is to forward valuable diagnostic information to a storage account, there it can be reviewed manually or consumed by an application like System Center Operations Manager. Trace logs are included in the diagnostic data that can be managed by the Azure Diagnostics Module. This final solution involves setting up the diagnostics monitor, configuring a Trace Listener, and finally configuring log4net to write to the Trace Log. This includes a few steps so in summary this is the path of the log message.

log4net >> Trace Log >> Diagnostics Listener >> Diagnostics Monitor >> Table Storage

A similar solution can be configured with Event Logs which has the following flow.

log4net >> Event Log >> Diagnostic Monitor >> Table Storage

Setup

This example will mainly use the app.config file for the Trace Listener configuration but this could also be done programmatically with the Trace static class.

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
  <configSections>
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
  </configSections>
  <log4net>
    <appender name="TraceAppender" type="log4net.Appender.TraceAppender">
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline" />
      </layout>
    </appender>
    <root>
      <level value="INFO" />
      <appender-ref ref="TraceAppender" />
    </root>
  </log4net>
  <system.diagnostics>
    <trace>
      <listeners>
        <add type="Microsoft.WindowsAzure.Diagnostics.DiagnosticMonitorTraceListener, Microsoft.WindowsAzure.Diagnostics, Version=1.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
          name="AzureDiagnostics">
          <filter type="" />
        </add>
      </listeners>
    </trace>
  </system.diagnostics>
</configuration>

Once the Diagnostic Monitor Trace Listener is setup the trace messages will be sent to the diagnostic monitor. The following code will setup and start the monitor.

public override bool OnStart()
{
    var diagnostics = DiagnosticMonitor.GetDefaultInitialConfiguration();

    diagnostics.Logs.ScheduledTransferLogLevelFilter = LogLevel.Verbose;
    diagnostics.Logs.ScheduledTransferPeriod = TimeSpan.FromMinutes(1);

    CloudStorageAccount account = CloudStorageAccount.Parse(
        RoleEnvironment.GetConfigurationSettingValue(
            "Microsoft.WindowsAzure.Plugins.Diagnostics.ConnectionString"));

    DiagnosticMonitor.Start(account, diagnostics);

    return base.OnStart();
}

Setting the Verbose level allows the log4net appender and filters to set logging level, this will allow all messages through to the logger. The Logs property configures the Trace logs, to setup the event logs use the .WindowsEventLogs property. Finally to configure log4net and write messages use the following code. This is the same code in all the solutions.

private ILog _logger;

public override void Run()
{
    XmlConfigurator.Configure();

    _logger = LogManager.GetLogger(GetType());

    _logger.Info("Starting Worker Role");

    while (true)
    {
        Thread.Sleep(10000);
        _logger.Info("Waiting 10 Seconds");
    }
}

Pros / Cons

Pros: This solution requires very little setup and can be done with mainly configuration. The log messages are stored in Table Storage, the message rows contain lots of information about the logging level, process and other Azure hosted service information. The biggest pro for this solution is that the log messages can be consumed by System Center Operations Manager. Also, the log tables can be managed with the PowerShell cmdlets.

Cons: If not configured correctly this solution can be difficult to debug, mainly due to the amount of components involved. Compared to Part 2 (straight to Table Storage) you have no control over the columns which makes querying for trends very difficult, even impossible since Table Storage does not support a “contains” clause.

Like all of the solutions the need to be combined with a log management system to archive or truncate the log messages. This is more important with Azure storage because you are charged per GB of storage.

Summary

I hope this series has given you some information on logging from an Azure Hosted Service. I know writing them has helped me work through some of the subtle differences in the logging mechanisms.

There are a variety of solutions for logging and diagnostics in Azure, the most common are the three presented. If you have any questions about the solutions please leave a comment or contact me on Twitter @tyler_gd.

As always, thank you for reading.

Logging in Azure: Part 2–Table Storage

This entry is part 2 in a series outlining different solutions for writing logs from an Azure hosted service.

So far the solutions include (subject to change):

1. Synchronizing a log file to blob storage
2. Using a custom log4net appender to write directly to table storage
3. Logging to the Trace log and synchronizing to table storage

These solutions are in order of complexity (in my opinion). Each topic will outline the structure of the solution, how to implement it, and the pros/cons of the solution compared to the others.

2. Using a custom appender to write to Table Storage

Compared to the previous solution this has fewer components, but requires more to setup. In Part 1 the Diagnostics Module did most of the work, the only requirement was a location that contained log files. There were 2 main phases, writing to a file then synchronizing the file to blobs. There was no dependency between the mechanism creating the file (log4net) and the sync process (Diagnostics Module).

In this solution we will create a log4net appender which takes logging events and persists them directly to table storage. Here we will have a direct dependency between log4net and Azure Table Storage. Even with that dependency this solution can be configured into an existing application because the code itself only interacts with the log4net API.

Before I start the implementation, this code is based off a blog post and source code by Vidar Kongsli.

Table Storage Entity

An Entity object is required to store data to Table Storage. This can contain as much or as little data as needed.

public sealed class LogEventEntity : TableServiceEntity
{
    public LogEventEntity()
    {
        var now = DateTime.UtcNow;
        PartitionKey = string.Format("{0:yyyy-MM}", now);
        RowKey = string.Format("{0:dd HH:mm:ss.fff}-{1}",
                                now, Guid.NewGuid());
    }

    public string Identity { get; set; }
    public string ThreadName { get; set; }
    public string LoggerName { get; set; }
    public string Level { get; set; }
    public string Message { get; set; }
    public string Domain { get; set; }
    public string RoleInstance { get; set; }
    public string DeploymentId { get; set; }
}

Some other implementations implement a subclass of Table Service Context but, as I mentioned in a previous post, I don’t think that is necessary.

log4net Appender Implementation

To implement a log4net appender just inherit from AppenderSkeleton. When this appender is activated we need to setup the table storage configuration and create a new table data context instance. For the purposes of this article I’ll assume that this appender will only be used in an Azure hosted service context and use the configuration from the Role Environment. Table Storage can be used from anywhere so to make this implementation more portable just add more configuration.

public class TableStorageAppender : AppenderSkeleton
{
    private string _connectionStringKey =
        "Microsoft.WindowsAzure.Plugins.Diagnostics.ConnectionString";
    private string _tableName = "LogEntities";
    private TableServiceContext _dataContext;

    public string ConnectionStringKey
    {
        get { return _connectionStringKey; }
        set { _connectionStringKey = value; }
    }

    public string TableName
    {
        get { return _tableName; }
        set { _tableName = value; }
    }

    public override void ActivateOptions()
    {
        base.ActivateOptions();

        var connectionString = RoleEnvironment.GetConfigurationSettingValue(ConnectionStringKey);
        var account = CloudStorageAccount.Parse(connectionString);

        var tableClient = account.CreateCloudTableClient();
        tableClient.CreateTableIfNotExist(TableName);

        _dataContext = tableClient.GetDataServiceContext();
    }

    protected override void Append(LoggingEvent loggingEvent)
    {
        try
        {
            var entity = new LogEventEntity
                                {
                                    RoleInstance = RoleEnvironment.CurrentRoleInstance.Id,
                                    DeploymentId = RoleEnvironment.DeploymentId,
                                    Message = loggingEvent.RenderedMessage,
                                    Level = loggingEvent.Level.Name,
                                    LoggerName = loggingEvent.LoggerName,
                                    Domain = loggingEvent.Domain,
                                    ThreadName = loggingEvent.ThreadName,
                                    Identity = loggingEvent.Identity
                                };

            _dataContext.AddObject(TableName, entity);
            _dataContext.SaveChanges();
        }
        catch (DataServiceRequestException drex )
        {
            ErrorHandler.Error("Could not write log entry", drex);
        }
    }
}

Notice that 2 properties were added, for the configuration key the only reason that the diagnostics string is being used is out of convenience. This solution does not depend on the diagnostics module.

Configuration

Now that we have the storage entity and the appender the final step is to setup the appender in our log4net configuration section. When adding this implementation as a reference note that 3 other assemblies are needed:

Microsoft.WindowsAzure.ServiceRuntime

Microsoft.WindowsAzure.StorageClient

System.Data.Services.Client

To add this appender with no changes to the default configuration add the following to the app.config file

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
  <configsections>
    <section type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" name="log4net" />
  </configsections>
  <log4net>
    <appender type="AzureLogAppender.TableStorageAppender, AzureLogAppender" name="TableStorageAppender">
    </appender>
    <root>
      <level value="INFO" />
      <appender-ref ref="TableStorageAppender" />
    </root>
  </log4net>
</configuration>

In this example I used a separate assembly for the appender (AzureLogAppender.dll) and referenced the assembly in the role project.

Pros / Cons

Pros: This solution requires some code but gives you full control over the logging component. Compared to the log files and trace logging, there are fewer components and less dependencies. With table storage the log messages can be easily queried for errors or trends.

Cons: The appender is less slightly slower then the out-of-the-box file appenders. Also, if left unmanaged the log table will continue to grow. These issues can be overcome with some thread management and a log truncating process.

So that is the table storage logging solution. The next solution involves a combination of the log4net configuration and diagnostic module to wrote to the Windows Azure Diagnostic Trace logs.

Thank you.

Logging in Azure: Part 1

Migrating an existing application to Windows Azure can be fairly simple. Many of the technologies used on-premise (like IIS or SQL) can be directly transferred to Azure services. There are however a few components of the applications architecture that need to be revisited. One of those components may be logging. There are a few application diagnostics features that will work the same in the cloud, like Tracing, Profiling, and Windows Event Logs for example, with the help of the Diagnostics module. One diagnostic feature that is often customized is Logging.

Many applications simply use a rolling file logger that may write to the local directory or a shared drive. This process may work well when you have a persistent server but in Windows Azure all the Web and Worker Roles are stateless so writing to the local file system becomes a problem.

There are many solutions to this problem. Over the next few posts I am going to go through what the solutions are, how to implement them, and the considerations between the different solutions. All of them will use a common logging framework called log4net.

So far the solutions will include (subject to change):

1. Synchronizing a log file to blob storage
2. Using a custom log4net appender to write directly to table storage
3. Logging to the Trace log and synchronizing to table storage

These solutions are in order of complexity (in my opinion). Each topic will outline the structure of the solution, how to implement it, and the pros/cons of the solution compared to the others.

1. Synchronizing a log file to blob storage

This solution seems like the simplest because much of the work is taken care of for you. That being said, there were a few “gotchas” the first time I implemented this.

Setting up log4net

I used a basic Worker Role as an example, to start create a new Azure project with a Worker Role.

To obtain the log4net .dll you can just install the log4net NuGet package. Once you have that add the following configuration to the app.config file.

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
  <configSections>
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
  </configSections>
  <log4net>
    <appender name="FileAppender" type="log4net.Appender.FileAppender">
      <file value="logslog-file.txt" />
      <appendToFile value="true" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline" />
      </layout>
    </appender>
    <root>
      <level value="INFO" />
      <appender-ref ref="FileAppender" />
    </root>
  </log4net>
</configuration>

This will setup a basic log file appender to write the log4net logs to a file. To test out the logger replace the Run method in the WorkerRole.cs file with the following.

private ILog _logger;

public override void Run()
{
    XmlConfigurator.Configure();

    _logger = LogManager.GetLogger(GetType());

    _logger.Info("Starting Worker Role");

    while (true)
    {
        Thread.Sleep(10000);
        _logger.Info("Waiting 10 Seconds");
    }
}

Setting up the Azure Diagnostics Module

Now for the tricky part, configuring the Windows Azure Diagnostics module.

public override bool OnStart()
{
    var logFilePath = 
	Path.Combine(Environment.CurrentDirectory, "logs");

    var logDir = new DirectoryConfiguration
                        {
                            Container = "wad-log4net",
                            DirectoryQuotaInMB = 100,
                            Path = logFilePath
                        };

    var diagnostics = DiagnosticMonitor.GetDefaultInitialConfiguration();
    diagnostics.Directories.ScheduledTransferPeriod = TimeSpan.FromMinutes(1);
    diagnostics.Directories.DataSources.Add(logDir);

    CloudStorageAccount account = CloudStorageAccount.Parse(
        RoleEnvironment.GetConfigurationSettingValue(
            "Microsoft.WindowsAzure.Plugins.Diagnostics.ConnectionString"));

    DiagnosticMonitor.Start(account, diagnostics);

    return base.OnStart();
}

So the diagnostics module will synchronize a directory (in this case /logs) to blob store. Whatever files exist in that directory will be uploaded every minute (defined by the ScheduledTransferPeriod) and replace the files that were in the blob. If the diagnostics completed successfully you should have a file in the wad-control-container blob container with a directory node that matches this information (note: there will be another crash dump directory that is configured by default). Once 1 minute has passed, diagnostics should create a “wad-log4net” (or name of your choosing) container with the sync’d files.

The contents of the directory will not be duplicated in the blob container. For this reason I’d suggest looking into using a Rolling File Log Appender with log4net so you do not loose any logs when 1 file becomes too large.

If you are having issues with the diagnostics setup on your local machine watch the emulator console for “[Diagnostics]” and “[MonAgentHost]” trace logs.

Note: I used a Worker Role for simplicity, if you are using a Web Role the log4net configuration should go in the Global.asax.cs file and the Diagnostics Module config should stay in the OnStart. There is no dependency on log4net you can use any framework to generate log files.

Pros / Cons

Pros: This solution can easily be setup for applications that currently use file logging with minimal effort and almost no code changes. Also, this solution uses the diagnostics module which contains a rich set of synchronization features and capabilities which you will not have to write yourself.

Cons: The logs themselves are contained in files which can make issue discovery more difficult. The following solutions write messages to table storage which can be easily queried for certain messages.

Stay tuned this week for the remaining logging solutions.

Please refer to this GIST for the source code: https://gist.github.com/2395186

Thank you.