Track exceptions to Azure Application Insights

src/Arcus.Observability.Telemetry.Serilog.Enrichers/Extensions/LogEventPropertyValueExtensions.cs

@@ -6,6 +6,9 @@
 // ReSharper disable once CheckNamespace
 namespace Serilog.Events
 {
+    /// <summary>
+    /// Extensions for event properties
+    /// </summary>
     public static class LogEventPropertyValueExtensions
     {
         /// <summary>
@@ -49,18 +52,39 @@ public static double GetAsDouble(this IReadOnlyDictionary<string, LogEventProper
         /// <remarks>The built-in <c>ToString</c> wraps the string with quotes</remarks>
         /// <param name="eventPropertyValues">Event property value to provide a string representation</param>
         /// <param name="propertyKey">Key of the property to return</param>
-        public static IReadOnlyDictionary<ScalarValue, LogEventPropertyValue> GetAsDictionary(this IReadOnlyDictionary<string, LogEventPropertyValue> eventPropertyValues, string propertyKey)
+        /// <param name="propertyDictionaryValues">Found information for the given property key</param>
+        public static bool TryGetAsDictionary(this IReadOnlyDictionary<string, LogEventPropertyValue> eventPropertyValues, string propertyKey, out IReadOnlyDictionary<ScalarValue, LogEventPropertyValue> propertyDictionaryValues)
         {
             Guard.NotNull(eventPropertyValues, nameof(eventPropertyValues));
 
-            var logEventPropertyValue = eventPropertyValues.GetValueOrDefault(propertyKey);
+            var propertyValue = eventPropertyValues.GetValueOrDefault(propertyKey);
+            if (propertyValue == null || propertyValue is DictionaryValue == false)
+            {
+                propertyDictionaryValues = null;
+                return false;
+            }
+
+            propertyDictionaryValues = (propertyValue as DictionaryValue).Elements;
+            return true;
+        }
+
+        /// <summary>
+        ///     Provide a string representation for a property key
+        /// </summary>
+        /// <remarks>The built-in <c>ToString</c> wraps the string with quotes</remarks>
+        /// <param name="eventPropertyValues">Event property value to provide a string representation</param>
+        /// <param name="propertyKey">Key of the property to return</param>
+        public static IReadOnlyDictionary<ScalarValue, LogEventPropertyValue> GetAsDictionary(this IReadOnlyDictionary<string, LogEventPropertyValue> eventPropertyValues, string propertyKey)
+        {
+            Guard.NotNull(eventPropertyValues, nameof(eventPropertyValues));
 
-            if (logEventPropertyValue is DictionaryValue == false)
+            var valueFound = TryGetAsDictionary(eventPropertyValues, propertyKey, out var propertyDictionaryValues);
+            if (valueFound == false)
             {
                 throw new NotSupportedException($"Value for '{propertyKey}' is not a dictionary");
             }
 
-            return (logEventPropertyValue as DictionaryValue).Elements;
+            return propertyDictionaryValues;
         }
 
         /// <summary>
@@ -151,4 +175,4 @@ public static string ToDecentString(this LogEventPropertyValue logEventPropertyV
             return propertyValueAsString;
         }
     }
-}
+}

src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Converters/ApplicationInsightsTelemetryConverter.cs

@@ -13,6 +13,7 @@ namespace Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights.Conver
     /// </summary>
     public class ApplicationInsightsTelemetryConverter : TelemetryConverterBase
     {
+        private readonly ExceptionTelemetryConverter _exceptionTelemetryConverter = new ExceptionTelemetryConverter();
         private readonly TraceTelemetryConverter _traceTelemetryConverter = new TraceTelemetryConverter();
         private readonly EventTelemetryConverter _eventTelemetryConverter = new EventTelemetryConverter();
         private readonly MetricTelemetryConverter _metricTelemetryConverter = new MetricTelemetryConverter();
@@ -34,6 +35,11 @@ public class ApplicationInsightsTelemetryConverter : TelemetryConverterBase
         /// <param name="formatProvider">The instance to control formatting.</param>
         public override IEnumerable<ITelemetry> Convert(LogEvent logEvent, IFormatProvider formatProvider)
         {
+            if (logEvent.Exception != null)
+            {
+                return _exceptionTelemetryConverter.Convert(logEvent, formatProvider);
+            }
+
             if (logEvent.MessageTemplate.Text.StartsWith(MessagePrefixes.RequestViaHttp))
             {
                 return _requestTelemetryConverter.Convert(logEvent, formatProvider);

src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Converters/CustomTelemetryConverter.cs

@@ -46,12 +46,14 @@ public override IEnumerable<ITelemetry> Convert(LogEvent logEvent, IFormatProvid
         /// <param name="telemetry">The destination telemetry instance to add the properties to.</param>
         protected void AssignTelemetryContextProperties(LogEvent logEvent, ISupportProperties telemetry)
         {
-            var eventContext = logEvent.Properties.GetAsDictionary(ContextProperties.EventTracking.EventContext);
-
-            foreach (KeyValuePair<ScalarValue, LogEventPropertyValue> contextProperty in eventContext)
+            var eventContextFound = logEvent.Properties.TryGetAsDictionary(ContextProperties.EventTracking.EventContext, out var eventContext);
+            if (eventContextFound)
             {
-                var value = contextProperty.Value.ToDecentString();
-                telemetry.Properties.Add(contextProperty.Key.ToDecentString(), value);
+                foreach (KeyValuePair<ScalarValue, LogEventPropertyValue> contextProperty in eventContext)
+                {
+                    var value = contextProperty.Value.ToDecentString();
+                    telemetry.Properties.Add(contextProperty.Key.ToDecentString(), value);
+                }
             }
         }
 

src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Converters/ExceptionTelemetryConverter.cs

@@ -0,0 +1,24 @@
+using System;
+using Microsoft.ApplicationInsights.DataContracts;
+using Serilog.Events;
+
+namespace Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights.Converters
+{
+    /// <summary>
+    /// Represents a conversion from a Serilog <see cref="LogEvent"/> to an Application Insights <see cref="ExceptionTelemetry"/> instance.
+    /// </summary>
+    public class ExceptionTelemetryConverter : CustomTelemetryConverter<ExceptionTelemetry>
+    {
+        /// <summary>
+        ///     Creates a telemetry entry for a given log event
+        /// </summary>
+        /// <param name="logEvent">Event that was logged and written to this sink</param>
+        /// <param name="formatProvider">Provider to format event</param>
+        /// <returns>Telemetry entry to emit to Azure Application Insights</returns>
+        protected override ExceptionTelemetry CreateTelemetryEntry(LogEvent logEvent, IFormatProvider formatProvider)
+        {
+            var exceptionTelemetry = new ExceptionTelemetry(logEvent.Exception);
+            return exceptionTelemetry;
+        }
+    }
+}

src/Arcus.Observability.Tests.Integration/Serilog/Sinks/ApplicationInsights/ApplicationInsightsSinkTests.cs

@@ -63,7 +63,11 @@ protected async Task RetryAssertUntilTelemetryShouldBeAvailableAsync(Func<Task>
         protected async Task RetryAssertUntilTelemetryShouldBeAvailableAsync(Func<Task> assertion, TimeSpan timeout)
         {
             await Policy.TimeoutAsync(timeout)
-                        .WrapAsync(Policy.Handle<Exception>()
+                        .WrapAsync(Policy.Handle<Exception>(exception =>
+                            {
+                                _outputWriter.WriteLine($"Failed to contact Azure Application Insights. Reason: {exception.Message}");
+                                return true;
+                            })
                                          .WaitAndRetryForeverAsync(index => TimeSpan.FromSeconds(1)))
                         .ExecuteAsync(assertion);
         }

src/Arcus.Observability.Tests.Integration/Serilog/Sinks/ApplicationInsights/ExceptionTests.cs

@@ -0,0 +1,71 @@
+using System;
+using System.Threading.Tasks;
+using Microsoft.Azure.ApplicationInsights;
+using Microsoft.Azure.ApplicationInsights.Models;
+using Microsoft.Extensions.Logging;
+using Serilog;
+using Xunit;
+using Xunit.Abstractions;
+using ILogger = Microsoft.Extensions.Logging.ILogger;
+
+namespace Arcus.Observability.Tests.Integration.Serilog.Sinks.ApplicationInsights
+{
+    public class ExceptionTests : ApplicationInsightsSinkTests
+    {
+        public ExceptionTests(ITestOutputHelper outputWriter) : base(outputWriter)
+        {
+        }
+
+        [Fact]
+        public async Task LogException_SinksToApplicationInsights_ResultsInExceptionTelemetry()
+        {
+            // Arrange
+            string message = BogusGenerator.Lorem.Sentence();
+            var exception = new PlatformNotSupportedException(message);
+            using (ILoggerFactory loggerFactory = CreateLoggerFactory())
+            {
+                ILogger logger = loggerFactory.CreateLogger<ApplicationInsightsSinkTests>();
+
+                // Act
+                logger.LogCritical(exception, exception.Message);
+            }
+
+            // Assert
+            using (ApplicationInsightsDataClient client = CreateApplicationInsightsClient())
+            {
+                await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () =>
+                {
+                    EventsResults<EventsExceptionResult> results = await client.GetExceptionEventsAsync(filter: OnlyLastHourFilter);
+                    Assert.Contains(results.Value, result => result.Exception.OuterMessage == exception.Message);
+                });
+            }
+        }
+
+        [Fact]
+        public async Task LogExceptionWithComponentName_SinksToApplicationInsights_ResultsInTelemetryWithComponentName()
+        {
+            // Arrange
+            string message = BogusGenerator.Lorem.Sentence();
+            string componentName = BogusGenerator.Commerce.ProductName();
+            var exception = new PlatformNotSupportedException(message);
+            using (ILoggerFactory loggerFactory = CreateLoggerFactory(config => config.Enrich.WithComponentName(componentName)))
+            {
+                ILogger logger = loggerFactory.CreateLogger<ApplicationInsightsSinkTests>();
+
+                // Act
+                logger.LogCritical(exception, exception.Message);
+            }
+
+            // Assert
+            using (ApplicationInsightsDataClient client = CreateApplicationInsightsClient())
+            {
+                await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () =>
+                {
+                    EventsResults<EventsExceptionResult> results = await client.GetExceptionEventsAsync(filter: OnlyLastHourFilter);
+                    Assert.NotEmpty(results.Value);
+                    Assert.Contains(results.Value, result => result.Exception.OuterMessage == exception.Message && result.Cloud.RoleName == componentName);
+                });
+            }
+        }
+    }
+}

src/Arcus.Observability.Tests.Unit/Serilog/ApplicationInsightsTelemetryConverterTests.cs

@@ -11,8 +11,6 @@
 using Microsoft.AspNetCore.Http;
 using Microsoft.Extensions.Logging;
 using Moq;
-using Newtonsoft.Json;
-using Newtonsoft.Json.Linq;
 using Serilog;
 using Serilog.Core;
 using Serilog.Events;
@@ -177,15 +175,15 @@ public void LogDependency_WithDependency_CreatesDependencyTelemetry()
                 Assert.Equal(TruncateToSeconds(startTime), dependencyTelemetry.Timestamp);
                 Assert.Equal(duration, dependencyTelemetry.Duration);
                 Assert.True(dependencyTelemetry.Success);
-                
+
                 AssertContainsTelemetryProperty(dependencyTelemetry, "CustomSetting", "Approved");
             });
         }
 
         [Fact]
         public void LogServiceBusDependency_WithServiceBusDependency_CreatesDependencyTelemetry()
         {
-             // Arrange
+            // Arrange
             var spySink = new InMemoryLogSink();
             string operationId = $"operation-id-{Guid.NewGuid()}";
             ILogger logger = CreateLogger(spySink, config => config.Enrich.WithProperty(ContextProperties.Correlation.OperationId, operationId));
@@ -224,7 +222,7 @@ public void LogServiceBusDependency_WithServiceBusDependency_CreatesDependencyTe
                 Assert.Equal(TruncateToSeconds(startTime), dependencyTelemetry.Timestamp);
                 Assert.Equal(duration, dependencyTelemetry.Duration);
                 Assert.True(dependencyTelemetry.Success);
-                
+
                 AssertContainsTelemetryProperty(dependencyTelemetry, "Namespace", "azure.servicebus.namespace");
                 AssertContainsTelemetryProperty(dependencyTelemetry, "EntityType", entityType.ToString());
             });
@@ -233,7 +231,7 @@ public void LogServiceBusDependency_WithServiceBusDependency_CreatesDependencyTe
         [Fact]
         public void LogServiceBusQueueDependency_WithServiceBusDependency_CreatesDependencyTelemetry()
         {
-             // Arrange
+            // Arrange
             var spySink = new InMemoryLogSink();
             string operationId = $"operation-id-{Guid.NewGuid()}";
             ILogger logger = CreateLogger(spySink, config => config.Enrich.WithProperty(ContextProperties.Correlation.OperationId, operationId));
@@ -271,7 +269,7 @@ public void LogServiceBusQueueDependency_WithServiceBusDependency_CreatesDepende
                 Assert.Equal(TruncateToSeconds(startTime), dependencyTelemetry.Timestamp);
                 Assert.Equal(duration, dependencyTelemetry.Duration);
                 Assert.True(dependencyTelemetry.Success);
-                
+
                 AssertContainsTelemetryProperty(dependencyTelemetry, "Namespace", "azure.servicebus.namespace");
                 AssertContainsTelemetryProperty(dependencyTelemetry, "EntityType", ServiceBusEntityType.Queue.ToString());
             });
@@ -280,7 +278,7 @@ public void LogServiceBusQueueDependency_WithServiceBusDependency_CreatesDepende
         [Fact]
         public void LogServiceBusTopicDependency_WithServiceBusDependency_CreatesDependencyTelemetry()
         {
-             // Arrange
+            // Arrange
             var spySink = new InMemoryLogSink();
             string operationId = $"operation-id-{Guid.NewGuid()}";
             ILogger logger = CreateLogger(spySink, config => config.Enrich.WithProperty(ContextProperties.Correlation.OperationId, operationId));
@@ -318,7 +316,7 @@ public void LogServiceBusTopicDependency_WithServiceBusDependency_CreatesDepende
                 Assert.Equal(TruncateToSeconds(startTime), dependencyTelemetry.Timestamp);
                 Assert.Equal(duration, dependencyTelemetry.Duration);
                 Assert.True(dependencyTelemetry.Success);
-                
+
                 AssertContainsTelemetryProperty(dependencyTelemetry, "Namespace", "azure.servicebus.namespace");
                 AssertContainsTelemetryProperty(dependencyTelemetry, "EntityType", ServiceBusEntityType.Topic.ToString());
             });
@@ -699,6 +697,36 @@ public void LogEvent_WithEvent_CreatesEventTelemetry()
             });
         }
 
+        [Fact]
+        public void LogException_WithException_CreatesExceptionTelemetry()
+        {
+            // Arrange
+            string platform = $"platform-id-{Guid.NewGuid()}";
+            var exception = new PlatformNotSupportedException(platform);
+            var spySink = new InMemoryLogSink();
+            string operationId = $"operation-id-{Guid.NewGuid()}";
+            ILogger logger = CreateLogger(spySink, config => config.Enrich.WithProperty(ContextProperties.Correlation.OperationId, operationId));
+
+            logger.LogCritical(exception, exception.Message);
+            LogEvent logEvent = Assert.Single(spySink.CurrentLogEmits);
+            Assert.NotNull(logEvent);
+
+            var converter = ApplicationInsightsTelemetryConverter.Create();
+
+            // Act
+            IEnumerable<ITelemetry> telemetries = converter.Convert(logEvent, formatProvider: null);
+
+            // Assert
+            Assert.Collection(telemetries, telemetry =>
+            {
+                var exceptionTelemetryType = Assert.IsType<ExceptionTelemetry>(telemetry);
+                Assert.NotNull(exceptionTelemetryType);
+                Assert.NotNull(exceptionTelemetryType.Exception);
+                Assert.Equal(exception.Message, exceptionTelemetryType.Exception.Message);
+                AssertOperationContext(exceptionTelemetryType, operationId);
+            });
+        }
+
         [Fact]
         public void LogMetric_WithMetric_CreatesMetricTelemetry()
         {
@@ -778,7 +806,7 @@ public void LogInformationWithMachineName_Without_CreatesTraceTelemetryWithPodNa
             // Arrange
             var spySink = new InMemoryLogSink();
             string operationId = $"operation-id-{Guid.NewGuid()}";
-            ILogger logger = CreateLogger(spySink, config => 
+            ILogger logger = CreateLogger(spySink, config =>
             {
                 return config.Enrich.WithProperty(ContextProperties.Correlation.OperationId, operationId)
                              .Enrich.WithProperty(General.ComponentName, "component")
@@ -838,7 +866,7 @@ private static HttpRequest CreateStubRequest(HttpMethod httpMethod, string reque
         private static HttpResponse CreateStubResponse(HttpStatusCode statusCode)
         {
             var response = new Mock<HttpResponse>();
-            response.Setup(res => res.StatusCode).Returns((int) statusCode);
+            response.Setup(res => res.StatusCode).Returns((int)statusCode);
 
             return response.Object;
         }