Why doesn't Windows Azure Diagnostics reliably log?

Question

We are having problems getting Windows Azure Diagnostics to reliably log. It seems hit-or-miss and we don't understand why.

Here's our code that sometimes works, sometimes doesn't:

public class WorkerRole : RoleEntryPoint
{
    public override void Run()
    {
        Trace.WriteLine("Run() beginning.", LogLevel.Information.ToString());

        try
        {
            var logic = new WorkerAgent();
            logic.Go(false);
        }
        catch (Exception err)
        {
            Trace.WriteLine(err.ToString(), LogLevel.Critical.ToString());

            Run();
        }
    }

    public override bool OnStart()
    {
        // Initialize our Cloud Storage Configuration.
        AzureStorageObject.Initialize(AzureConfigurationLocation.AzureProjectConfiguration);

        // Initialize Azure Diagnostics

        try
        {
            //get the storage account using the default Diag connection string
            var cs = CloudStorageAccount.FromConfigurationSetting("Microsoft.WindowsAzure.Plugins.Diagnostics.ConnectionString");

            //get the diag manager
            var dm = cs.CreateRoleInstanceDiagnosticManager(RoleEnvironment.DeploymentId,
                                                            RoleEnvironment.CurrentRoleInstance.Role.Name,
                                                            RoleEnvironment.CurrentRoleInstance.Id);

            //get the current configuration but if that failed, get the values from config file
            var dc = dm.GetCurrentConfiguration() ?? DiagnosticMonitor.GetDefaultInitialConfiguration();

            //Windows Azure Logs
            dc.Logs.BufferQuotaInMB = 25;
            dc.Logs.ScheduledTransferLogLevelFilter = LogLevel.Verbose;
            dc.Logs.ScheduledTransferPeriod = TimeSpan.FromMinutes(1);

            //Windows Event Logs
            dc.WindowsEventLog.BufferQuotaInMB = 25;
            dc.WindowsEventLog.DataSources.Add("System!*");
            dc.WindowsEventLog.DataSources.Add("Application!*");
            dc.WindowsEventLog.ScheduledTransferPeriod = TimeSpan.FromMinutes(1);

            ////Performance Counters
            //dc.PerformanceCounters.BufferQuotaInMB = 25;
            //var perfConfig = new PerformanceCounterConfiguration
            //                     {
            //                         CounterSpecifier = @"\Processor(_Total)\% Processor Time",
            //                         SampleRate = TimeSpan.FromSeconds(60)
            //                     };
            //dc.PerformanceCounters.DataSources.Add(perfConfig);
            //dc.PerformanceCounters.ScheduledTransferPeriod = TimeSpan.FromMinutes(1);

            //Failed Request Logs
            dc.Directories.BufferQuotaInMB = 25;
            dc.Directories.ScheduledTransferPeriod = TimeSpan.FromMinutes(1);

            ////Infrastructure Logs
            //dc.DiagnosticInfrastructureLogs.BufferQuotaInMB = 25;
            //dc.DiagnosticInfrastructureLogs.ScheduledTransferLogLevelFilter = LogLevel.Verbose;
            //dc.DiagnosticInfrastructureLogs.ScheduledTransferPeriod = TimeSpan.FromMinutes(1);

            //Crash Dumps
            CrashDumps.EnableCollection(true);

            //overall quota; must be larger than the sum of all items
            dc.OverallQuotaInMB = 5000;

            //save the configuration
            dm.SetCurrentConfiguration(dc);
        }
        catch (Exception ex)
        {
            Trace.Write(ex.Message, LogLevel.Critical.ToString());
        }

        // give logging time to register itself and load up.
        Thread.Sleep(10000);

        Trace.WriteLine("Completed diagnostics initialization.", LogLevel.Information.ToString());

        return base.OnStart();
    }
}

Note that our AzureStorageObject.Initialize method replaces the standard CloudStorageAccount.SetConfigurationSettingPublisher method.

Using this code with absolutely no code changes or configuration changes, we can run it over and over and over in the emulator or deploy it over and over and over to Azure with equally unreliable results. Notice that what's SUPPOSED to happen is 1) setup WAD 2) sleep 10 seconds to give it time to finish (I was really grasping for straws when I added this) 3) log that WAD init is done 4) we log that Run() is called and then we go do all of our work (WorkerAgent has our while(true) loop in it). Sometimes this is what happenes. Sometimes, we don't get the logged message in 3) but we do get it in 4). Sometimes we don't get it in 3 or 4). Again, NOTHING changes in code or configuration and all of this points to Azure storage (not emulator storage).

Why isn't this reliably logging every time we call Trace.Write?

Answer 1

This question

TraceSource.TraceEvent() fails logging when Exception message contains non-printable characters

reports an issue when logging silently fails as a consequence of an exception being thrown while logging. Specifically in this case the log message can't be serialized.

The fix for this situation is to use HttpUtility.HtmlEncode to encode the exception text before it's logged in Azure.