Capturing Custom Logs from Azure Worker Roles using Azure Diagnostics

In this post I’ll show you how to correctly configure diagnostics in an Azure Worker Role to push custom log files (NLog, Log4Net etc.) to Azure Storage using the in-built Azure Diagnostics Agent.

 

Configuring our Custom Logger – NLog

I’m not a massive fan of the recommended Azure Worker Role logging process, namely using the Trace.WriteLine() method as I don’t feel as though it provides sufficient flexibility for my logging needs and I think it looks crap when my code is liberally scattered with Trace.WriteLine() statements, code is art and all that.

NLog, on the other hand, provides all the flexibility I need including log file layout formatting, log file archiving – with granulatrity down to one minute – and archive file cleanup to name just a few. Having used it as the main logging tool on several projects, I feel completely at home with this particular library and want to use it within my Worker Role implementations.

I won’t go into how to add NLog (or any other logging framework you may use) to your project as there are loads of examples on the interweb, however I will share with you my Azure Worker Role app.config file which shows the configuration I have for my logging:

On line 8 we define our MessageWorker target which instructs NLog to:

  • Write our (current) log file to ‘MessageWorker_Current.log‘ (the fileName property) with a particular log-file layout (the layout property);
  • Create archives every day (the archiveEvery property) with an archive filename of ‘MessageWorker_{#}.log‘ (the archiveFilename property) – the ‘{#}’ in the archive filename is expanded to a date/time when an archive file is created (the archiveNumbering and archiveDateFormat properties);
  • Maintains a rolling 14 day window of archive files, deleting anything older (the maxArchiveFiles property);
  • Not perform concurrent writes (the concurrentWrites property) or to keep files open (the keepFilesOpen property) which I discovered helps the Azure Diagnostics Agent consistently copy log files to Blob Sstorage – your mileage may vary with these settings.

These configuration settings result in a number of files in our log directory – in the screenshot below I am archiving every minute:

Message Worker Logs

 

Define a Local Storage Resource

It is recommended that custom log files are written to Local Storage Resources on the Azure Worker Role VM. Local Storage Resources are reserved directories in the file system of the VM in which the Worker Role instance is running. Further information about Local Storage can be found online at MSDN.

In order to define Local Storage, we add a LocalResources section to the ServiceDefinition.csdef file and define our ‘CustomLogs’ Local Storage, as shown on line 16 below. The cleanOnRoleRecycle tell Azure not to delete the Local Storage if the role is recycled (restarted or scaled up/down) and the sizeInMB tells Azure how much Local Storage to allocate on the VM.

On an Azure Worker Role VM, the Local Resources directory could be found at: C:\Resources\Directory\[GUID].[WorkerRoleName]

On a local development machine, the Local Resources directory can be found at: C:\Users\[USER]\AppData\Local\dftmp\Resources\[GUID]\directory\CustomLogs

 

Configure NLog to Write Log Files to the Local Storage Resource

When using Local Storage Resources, we don’t know the actual directory name for the resource (and therefore our log files) until runtime. As a result, we need to update our NLog Target’s fileName and archiveFilename property as the Worker Role starts. To do this, we need a small helper to re-configure the targets:

This helper is passed the NLog Target to be updated and the directory path of the Local Storage Resource that is made available at runtime:

  • On line 11, we retrieve the FileTarget from our NLog configuration based on the supplied Target name.
  • On lines 16 & 17, we retrieve the current log filename and the archive filename (stripping a trailing apostrophe which appears to come from somewhere).
  • On lines 20 & 21, we combine the current log filename and archive filename with the supplied base directory (which contains the Local Storage directory passed to this method).
  • On line 28, we re-configure the existing loggers, activating these changes.

This helper is called within the Worker Role’s OnStart() method:

On line 15, we call the SetLogTargetBaseDirectory() method passing the NLog Target from our app.config file and the directory of the Local Stroage Resource, obtained by calling:

RoleEnvironment.GetLocalResource(“CustomLogs”).RootPath

where “CustomLogs” is the name of the Local Storage defined in the ServiceDefinition.csdef file (see the earlier Define a Local Storage Resource section). RoleEnvironment is a class located in the Microsoft.WindowsAzure.ServiceRuntime namespace.

 

Configuring Azure Diagnostics

Our final step in the process is to configure diagnostics, which instructs the Azure Diagnostics Agent what diagnostics data should be captured and where it should be stored. This configuration can be performed either by configuration (via the diagnostics.wadcfg file), or through code in the OnStart() method of the Worker Role. Be aware that there is an order of precendence for configuration diagnostic data – take a look at Diagnostics Configuration Mechanisms and Order of Precedence for more information.

The important lines for our custom logging solution are found in the <DataSources> element between lines 6 & 10:

  • Line 7 – <DirectoryConfiguration> details the Azure Storage Container where the custom log files should be written; and
  • Line 8 – <LocalResource> details the Local Storage Resource where the log files reside.

 

Bringing it all Together

Lets recap on the various moving parts we needed to get this up and running:

  • Configure the app.config file for your Worker Role, adding the required NLog configuration. Check that this is working locally before trying to push the settings to the cloud.
  • Define a Local Storage Resource in your the ServiceDefinition.csdef file for your Cloud Service Project where log files will be written to – in this blog post we have called our resource ‘CustomLogs’.
  • Add functionality to update the NLog target’s filename and archive filename at runtime by querying the Local Resource’s Root Path in the Worker Role’s OnStart() method.
  • Add a DataSources section to the diagnostics.wadcfg file instructing the Azure Diagnostics Agent to push custom log files from the Local Storage Resource to the specified Azure Blob Container.

With all of the required pieces in place we can deploy to our Cloud Service on Azure as usual, either through Visual Studio or the Management Portal. Give the service time to spin-up and we should hopefully start to see our log files appear in the specified container within Azure Storage – in the screenshot below, log files are being archived once a day and copied to the Storage Container at approx. 2 mins past midnight every morning:

Custom Log Files Copied to Azure  Storage Container
Custom Log Files Copied to Azure Storage Container – Click to enlarge

 

Gotchas

In closing, there is one gotcha that I would like to highlight. When a Cloud Service Project is deployed to a Cloud Service in Azure, the diagnostics configuration (derived from the diagnostics.wadcfg file) is written to a control configuration blob in the wad-control-container container, as specified in the Diagnostics Connection String (setting Microsoft.WindowsAzure.Plugins.Diagnostics.ConnectionString) from the deployed ServiceConfiguration.Cloud.cscfg configuration file.

Azure wad-control-container
Azure PaaS Control Configuration Blob – Click to enlarge

The purpose of this file is detailed as follows in the MSDN article Diagnostics Configuration Mechanisms and Order of Precedence:

A control configuration blob will be created for each role instance whenever a role without a blob starts. The wad-control-container blob has the highest precedence for controlling behavior and any changes to the blob will take effect the next time the instance polls for changes. The default polling interval is once per minute.

In order for any changes that you make to the diagnostics.wadcfg file to take effect, you will need to delete this control configuration blob and have Azure re-create it when the role re-starts. Otherwise, Azure will continue to use the outdated diagnostics configuration from this control configuration blob and log-files won’t be copied to Azure Storage.

Advertisements

Serializing Custom .Net Types for use with the Azure Redis Cache

In my previous post I looked at a real-world example of using the new Azure Redis Cache. One thing that was missing was the storing of custom .Net Types as cache values, which we’ll look at here.

The RedisValue Type

The Microsoft Azure documentation recommends using the StackExchange.Redis API for accessing the Redis Cache. This API stores cache values within the RedisValue type, which has a number of implcit conversions from primitive .Net types (Int32, Int64, Double, Boolean etc.), but conversions from the RedisValue type to the primitive .Net type need to be made explicitily.

For example, setting an int as the cache value is implicit, while retrieving an int from a cache value needs to be cast (the following screenshot is from the MSDN documentation):

Cache Serializer - Get and Set of Primitive Types

In addition to the implicit/explicit conversion of primitive data types, the RedisValue type can store binary data as the cache value. This means that we can serialize a custom .Net type into a byte array and pass that as the cache value within the StringSet() method; we can then retrieve that cache value using the StringGet() method and deserialize the byte array back to the custom type.

To complete the serialization/deserialization, we need a helper class, which is shown below. This class is inspired by the sample on MSDN (Work with .Net objects in the cache) but is tweaked slightly:

Note that during deserialization, if the byte array is null, a default instance of type T will be returned. This caught me out when I was initially testing, so beware that it is returning the value you expect.

Using these helpers with the StackExchange.Redis API’s StringSet() and StringGet() methods to store custom .Net types makes life really easy:

To retrieve a custom type, we call the StringGet() method, passing the cache Key and deserialize the returned byte array into the .Net Guid type; In order to determine whether the cache item was found, I check whether the returned cacheItem equals Guid.Empty, which is the value returned by default(T) for the Guid type from the Deserialize() method.

To store a custom .Net type (in this case a GUID), call the StringSet() method and instead of passing a primitive type as the cache value, we serialize our cache item and pass the resulting byte array.

Azure Redis Cache – A Real World Example

Read the second post in this series: Serializing Custom .Net Types for use with the Azure Redis Cache.

I spend a lot of my time at the moment architecting and writing integration code against Dynamics CRM 2011 and 2013. My current project is based on Azure Worker Roles and sucks CRUD messages from an SFTP Server (yep, FTP), maps them to CRM Entities before finally calling the appropriate CRUD operation on the XRM Service Proxy with the new Entity instance.

I need to repeatedly retrieve an Entity Reference to common ‘reference’ data on Create and Update – data that is loaded once and hardly ever changes (such as Products, Agent Codes, Cost Centres etc.) At the moment, I’m hitting CRM each and every time I need to grab the Entity Reference, which isn’t particularly efficient, slows down the overall solution and will start to incur unnecessary Azure data-egress charges at some point in the life-cycle of the application.

Azure Redis Cache

The Azure Redis Cache is the new cache offering from Microsoft which supersedes the Managed Service Cache (an instance of the AppFabric Cache) and In-Role Cache (a cache based on Cloud Services).

The Azure Redis Cache is based on the open-source Redis cache, an advanced key-value cache and store. More information about the project can be found at http://redis.io/.

The Azure offering comes in two flavours: Basic (a single-node deployment, primarily for dev/test) and Standard (a replicated cache in a two-node primary/secondary configuration, with automatic replication between the two nodes (managed by the Azure Fabric) and a high-availability SLA, primarily for production use). For the purposes of this blog-post I am using a Basic instance.

A Real World Example

I use an Entity Reference Provider in my code which implements a bunch of simple methods to retrieve the Guid of the Entity I’m interested in – in the example below, I am retrieving the Guid to the Product Entity:

RetrieveProductEntityReference() Method - Pre Cache Implementation

In order to cache-ify this method using the Azure Redis Cache we first need to spin-up  a new instance of the Redis Cache in the Azure Portal (see Getting Started with Azure Redis Cache in the Azure Documentation for further information).

We then create a connection to the Redis Cache using the ConnectionMultiplexer.Connect() method. Be aware that calling this method is expensive and the resulting object should be re-used thoughout your code, hence why I create an instance in the constructor for the provider:

Entity Reference Provider - Constructor

That’s all the setup required to use the Azure Redis Cache and we can now concentrate on retrieving and storing values in our cache. At a high level, the approach will be:

  • Attempt to retrieve a Guid for the referenced Entity from the cache based on a specified cache key.
  • If nothing is found in the cache for the key, we will retrieve the value from XRM itself and then populate the cache with that value.
  • We will finally return the Guid (retrieved either from the Cache or XRM).

The full implementation of the reworked RetrieveProductEntityReference() method with a cache implementation is shown below.

Note that I am keeping things simple here and converting my Guid to a string and vice-a-versa (I plan on showing how to cache custom types in a separate post).

With a connection to the Cache we need to retrieve a reference to the cache database. The GetDatabase() method is a lightweight method call and can be performed as required:

RetrieveProductEntityReference - Breakdown-1

We then define a cache key and attempt to get the item from the cache that has that key:

RetrieveProductEntityReference - Breakdown-2

If the cache item is null, there was no item in the cache with the supplied key (either it has never been set, or a previous cache item with that key has expired).

RetrieveProductEntityReference - Breakdown-3

If that is the case, we go off and retrieve the actual Entity Guid from XRM and assign the Guid to the (previously defined) cacheItem:

RetrieveProductEntityReference - Breakdown-4

We then add the cache item (containing the newly retrieved Guid) to the cache using the cache.StringSet() method, passing the previously defined cache key, item and a timespan which defines when the item will expire in the cache (the expiry timespan is optional):

Finally, we return the Guid contained within the cache item which has either been retrieved directly from XRM or the cache itself:

RetrieveProductEntityReference - Breakdown-6

A Performance Improvement?

Just to give you an idea of numbers, using a very small test sample of 50 iterations over this method, retrieving from the cache takes (on average) 32ms, while hitting the XRM Service Proxy takes 209ms (we are hitting Dynamics CRM 2013 Online).

Putting this into context, if I didn’t use the cache, it would take me 10.45 seconds to perform 50 iterations of this method, vs. 1.8 seconds for the cache implementation (which includes the initial hit to retrieve the data from XRM).