Diagnostics of Cloud Services – Custom Trace Listener

In this part of the series, I am going to talk about instrumenting diagnostic features for cloud services (web and worker roles) with a custom trace listener implementation in respect to new Windows Azure SDK for .NET (April 2013, version 2.0).

Before starting the implementation, I would suggest you to get an overview of the new SDK. A perfect resource for this would be Scott Guthrie’s blog here. As you can see, one of the areas improved noticeably since v1.8 is diagnostics and key items of which are:

  • Built-in diagnostic features for Azure web site enhancements
  • Being able to diagnose cloud services directly from Visual Studio
  • Being able to change diagnostic configuration settings while application running.

 

In .NET world, to diagnose and monitor an application, you need to implement a listener that listens the source which is the application itself for events (debug, trace, etc.) and a writer that persist the messages that captured through the listener to intended path (file, database table, storage table, etc.).

Listener

All (custom or built-in) listeners are derived from System.Diagnostics.TraceListener. I am going to implement a table storage listener, as name implies, it will outputs the captures to an Azure storage table. Here is the whole class implementation:

 

   1: using System;

   2: using System.Collections.Generic;

   3: using System.Data.Services.Client;

   4: using System.Text;

   5: using System.Diagnostics;

   6: using Microsoft.WindowsAzure.Storage;

   7: using Microsoft.WindowsAzure.Storage.Table;

   8:  

   9: namespace ToDoCommon

  10: {

  11:     public class TableTraceListener : TraceListener

  12:     {

  13:         #region Fields      

  14:         readonly string _connectionString;

  15:         readonly string _diagnosticsTable = "CustomLogTable";

  16:  

  17:         [ThreadStatic]

  18:         static StringBuilder _messageBuffer;

  19:  

  20:         readonly object _initializationSection = new object();

  21:         bool _isInitialized;

  22:  

  23:         CloudTableClient _tableStorage;

  24:         readonly object _traceLogAccess = new object();

  25:         readonly List<LogEntry> _traceLog = new List<LogEntry>();

  26:         #endregion

  27:  

  28:         #region Constructors

  29:  

  30:         public TableTraceListener()

  31:             : this("Microsoft.WindowsAzure.Plugins.Diagnostics.ConnectionString")

  32:         {

  33:         }

  34:  

  35:         public TableTraceListener(string connectionString)

  36:             : base("TableTraceListener")

  37:         {

  38:             _connectionString = connectionString;

  39:         }

  40:  

  41:         public TableTraceListener(string connectionString, string tableName)

  42:             : base("TableTraceListener")

  43:         {

  44:             _connectionString = connectionString;

  45:             _diagnosticsTable = tableName;

  46:         }

  47:         #endregion

  48:  

  49:         #region Methods

  50:  

  51:         /// <summary>

  52:         /// Flushes the entries to the storage table

  53:         /// </summary>

  54:         public override void Flush()

  55:         {

  56:             if (!_isInitialized)

  57:             {

  58:                 lock (_initializationSection)

  59:                 {

  60:                     if (!_isInitialized)

  61:                     {

  62:                         Initialize();

  63:                     }

  64:                 }

  65:             }

  66:  

  67:             var context = _tableStorage.GetTableServiceContext();

  68:             context.MergeOption = MergeOption.AppendOnly;

  69:             lock (_traceLogAccess)

  70:             {

  71:                 _traceLog.ForEach(entry => context.AddObject(_diagnosticsTable, entry));

  72:                 _traceLog.Clear();

  73:             }

  74:  

  75:             if (context.Entities.Count > 0)

  76:             {

  77:                 context.BeginSaveChangesWithRetries(SaveChangesOptions.None, 

  78:                     (ar) => context.EndSaveChangesWithRetries(ar), null);

  79:             }

  80:         }

  81:         /// <summary>

  82:         /// Creates the storage table object

  83:         /// </summary>

  84:         private void Initialize()

  85:         {

  86:             var account = CloudStorageAccount.Parse(_connectionString);

  87:             _tableStorage = account.CreateCloudTableClient();

  88:             _tableStorage.GetTableReference(_diagnosticsTable).CreateIfNotExists();

  89:             _isInitialized = true;

  90:         } 

  91:         

  92:         public override bool IsThreadSafe

  93:         {

  94:             get

  95:             {

  96:                 return true;

  97:             }

  98:         }

  99:  

 100:         #region Trace and Write Methods

 101:         /// <summary>

 102:         /// Writes the message to a string buffer

 103:         /// </summary>

 104:         /// <param name="message">the Message</param>

 105:         public override void Write(string message)

 106:         {

 107:             if (_messageBuffer == null)

 108:                 _messageBuffer = new StringBuilder();

 109:  

 110:             _messageBuffer.Append(message);

 111:         }

 112:  

 113:         /// <summary>

 114:         /// Writes the message with a line breaker to a string buffer

 115:         /// </summary>

 116:         /// <param name="message"></param>

 117:         public override void WriteLine(string message)

 118:         {

 119:             if (_messageBuffer == null)

 120:                 _messageBuffer = new StringBuilder();

 121:  

 122:             _messageBuffer.AppendLine(message);

 123:         }

 124:         /// <summary>

 125:         /// Appends the trace information and message

 126:         /// </summary>

 127:         /// <param name="eventCache">the Event Cache</param>

 128:         /// <param name="source">the Source</param>

 129:         /// <param name="eventType">the Event Type</param>

 130:         /// <param name="id">the Id</param>

 131:         /// <param name="message">the Message</param>

 132:         public override void TraceEvent(TraceEventCache eventCache, string source, TraceEventType eventType, int id, string message)

 133:         {

 134:             base.TraceEvent(eventCache, source, eventType, id, message);

 135:             AppendEntry(id, eventType, eventCache);

 136:         }

 137:  

 138:         /// <summary>

 139:         /// Adds the trace information to a collection of LogEntry objects

 140:         /// </summary>

 141:         /// <param name="id">the Id</param>

 142:         /// <param name="eventType">the Event Type</param>

 143:         /// <param name="eventCache">the EventCache</param>

 144:         private void AppendEntry(int id, TraceEventType eventType, TraceEventCache eventCache)

 145:         {

 146:             if (_messageBuffer == null)

 147:                 _messageBuffer = new StringBuilder();

 148:  

 149:             var message = _messageBuffer.ToString();

 150:             _messageBuffer.Length = 0;

 151:  

 152:             if (message.EndsWith(Environment.NewLine))

 153:                 message = message.Substring(0, message.Length - Environment.NewLine.Length);

 154:  

 155:             if (message.Length == 0)

 156:                 return;

 157:  

 158:             var entry = new LogEntry()

 159:             {

 160:                 PartitionKey = string.Format("{0:D10}", eventCache.Timestamp >> 30),

 161:                 RowKey = string.Format("{0:D19}", eventCache.Timestamp),

 162:                 EventTickCount = eventCache.Timestamp,

 163:                 Level = (int)eventType,

 164:                 EventId = id,

 165:                 Pid = eventCache.ProcessId,

 166:                 Tid = eventCache.ThreadId,

 167:                 Message = message

 168:             };

 169:  

 170:             lock (_traceLogAccess)

 171:                 _traceLog.Add(entry);

 172:         }

 173:  

 174:         #endregion

 175:  

 176:         #endregion

 177:     }

 178: }

   1: using Microsoft.WindowsAzure.Storage.Table.DataServices;

   2:  

   3: namespace ToDoCommon

   4: {

   5:     public class LogEntry : TableServiceEntity

   6:     {

   7:         public long EventTickCount { get; set; }

   8:         public int Level { get; set; }

   9:         public int EventId { get; set; }

  10:         public int Pid { get; set; }

  11:         public string Tid { get; set; }

  12:         public string Message { get; set; }

  13:     }

  14: }

What we do here, in summary:

  1. created a storage table
  2. converted captured trace information(trace event cache, type, message, etc.) to a TableServiceEntity object called LogEntry,
  3. then overrided Flush functionality that persists the trace information in table service  entity collection to the storage table created in step 1

And now time to add the listener:

   1: public static void ConfigureTraceListener(string diagConn, string tableName)

   2: {

   3:     Trace.Listeners.Clear();

   4:     string traceName = typeof(TableTraceListener).Name; 

   5:     var listener =

   6:         new TableTraceListener(diagConn, tableName)

   7:         {

   8:             Name = traceName

   9:         };

  10:  

  11:     Trace.Listeners.Add(listener);

  12:     Trace.AutoFlush = true;

  13: }

In this code block, we do construct the TableTraceListener with 2 strings:

  • connection string: set in the service configuration file pointing to the storage table created step 1 above. This is set to “UseDevelopmentStorage=true” when run locally (pointing to local development storage).
  • table name: the name of the table created in step 1 above.

 

Logger

Nothing much to say here.

   1: using System;

   2: using System.Text;

   3: using System.Diagnostics;

   4:  

   5: namespace ToDoCommon

   6: {

   7:     public class Logger:ILogger

   8:     {

   9:         static Logger _instance;

  10:         public static ILogger Instance

  11:         {

  12:             get { return _instance ?? (_instance = new Logger()); }

  13:         }

  14:  

  15:         public void LogError(Exception ex)

  16:         {

  17:             var sb = new StringBuilder();

  18:             sb.AppendLine();

  19:             var innerEx = ex.InnerException;

  20:             while (innerEx != null)

  21:             {

  22:                 sb.AppendFormat("t Inner Exc Message: {0}rn", innerEx.Message);

  23:                 innerEx = innerEx.InnerException;

  24:             }

  25:  

  26:             sb.AppendLine("StackTrace: " + ex.StackTrace);            

  27:             LogEntry(sb.ToString(), EventLogEntryType.Error);

  28:         }

  29:  

  30:         public void LogEntry(string message, EventLogEntryType type)

  31:         {

  32:             switch (type)

  33:             {

  34:                 case EventLogEntryType.Error:

  35:                     Trace.TraceError(message);

  36:                     break;

  37:                 case EventLogEntryType.Information:

  38:                     Trace.TraceInformation(message);

  39:                     break;

  40:                 case EventLogEntryType.Warning:

  41:                     Trace.TraceWarning(message);

  42:                     break;

  43:             }

  44:         }

  45:     }

  46: }

Please note that web role and associated web application run on different processes. Therefore, you need to add the listener in both places.

My Solution

One picture says a million words, so does here:

image

… and Show Time

All I need to do now, in order to have diagnostic feature enabled in my solution, is to call ToDoCommon.Util.ConfigureTraceListener(diagConnection, tableName) from the method “OnStart” of the role entry point classes of each role (web and worker) and from global.asax. Below, global.asax is shared:

   1: using System;

   2: using System.Web;

   3: using System.Web.Http;

   4: using System.Web.Mvc;

   5: using System.Web.Optimization;

   6: using System.Web.Routing;

   7: using Microsoft.WindowsAzure.ServiceRuntime;

   8: using ToDoCommon;

   9:  

  10: namespace ToDoListWeb

  11: {

  12:     // Note: For instructions on enabling IIS6 or IIS7 classic mode, 

  13:     // visit http://go.microsoft.com/?LinkId=9394801

  14:  

  15:     public class MvcApplication : HttpApplication

  16:     {

  17:         protected void Application_Start()

  18:         {

  19:             AreaRegistration.RegisterAllAreas();

  20:  

  21:             WebApiConfig.Register(GlobalConfiguration.Configuration);

  22:             FilterConfig.RegisterGlobalFilters(GlobalFilters.Filters);

  23:             RouteConfig.RegisterRoutes(RouteTable.Routes);

  24:             BundleConfig.RegisterBundles(BundleTable.Bundles);

  25:             AuthConfig.RegisterAuth();

  26:  

  27:             var diagConnection = RoleEnvironment.GetConfigurationSettingValue("DiagConnection");

  28:             var tableName = RoleEnvironment.GetConfigurationSettingValue("DiagTableName");

  29:  

  30:             Util.ConfigureTraceListener(diagConnection, tableName);

  31:         }

  32:  

  33:         protected void Application_OnError(object sender, EventArgs e)

  34:         {

  35:             var ex = Server.GetLastError();

  36:             Server.ClearError();

  37:  

  38:             Logger.Instance.LogError(ex);

  39:         }

  40:     }

  41: }

 

To test the solution, I have created a dummy page and called the trace functionality from a method:

   1: public ActionResult Details(int id = 0)

   2: { 

   3:     Logger.Instance.LogEntry("Dummy Informative log entry", EventLogEntryType.Information);

   4:     Logger.Instance.LogEntry("Dummy Warning log entry", EventLogEntryType.Warning);

   5:     Logger.Instance.LogEntry("Dummy Error log entry", EventLogEntryType.Error);

   6:  

   7:     var todoitem = _context.ToDoItems.Find(id);

   8:     if (todoitem == null)

   9:     {

  10:         throw new ArgumentOutOfRangeException();

  11:         //return HttpNotFound();

  12:     }

  13:     Trace.Flush();

  14:     return View(todoitem);

  15: }

 

And the result confirms the success!

image

 

Conclusion

In this post, I have implemented a custom trace listener that captures the diagnostic events (trace, debug, and trace source) in the application and writes to a Windows Azure storage table. Advantages of this custom tracing are being able to implement the instrumentation the way you want (lighter perhapsWinking smile) and being able to define the table name yourself.

Please note that the code blocks shared here are for demonstration purposes; I would suggest you to review your needs (trace switch, buffering, application monitoring capability, etc.) before using them in alive systems. Additionally, I do recommend investigate the configure before customization approach which I will be talking in my next post. Stay tunedSmile

Leave a Reply

Please log in using one of these methods to post your comment:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Google photo

You are commenting using your Google account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s

This site uses Akismet to reduce spam. Learn how your comment data is processed.