Fixes ApplicationInsights exception handling (#9)

* Make logging sample clearer

* Add exception correlation in Application Insights
Minor adjustments to documentation, including PowerShell runner

Author: fbeltrao

README.md

@@ -97,28 +97,51 @@ To quickly see the application running using pre-built docker images and docker-
 
 ### Using OpenTelemetry
 
+1. Clone this repository
 1. Open terminal under `ready-to-run\sample`
 1. Execute `docker-compose up`
-1. Generate load with `watch -n 2 curl --request GET http://localhost:5001/api/enqueue/WebSiteA`
-1. View traces in [Jaeger](http://localhost:16686/)
-1. View metrics by searching for "Enqueued_Item" in [Prometheus](http://localhost:9090)
-1. Build dashboards in [Grafana](http://localhost:3000/) (admin/password1)
+1. Generate load in terminal with
+
+```bash
+watch -n 2 curl --request GET http://localhost:5001/api/enqueue/WebSiteA
+```
+
+for PowerShell use this script:
+
+```Powershell
+while (1) {Invoke-WebRequest -Uri http://localhost:5001/api/enqueue/WebSiteA; sleep 2}
+```
+
+4. View traces in [Jaeger](http://localhost:16686/)
+5. View metrics by searching for "Enqueued_Item" in [Prometheus](http://localhost:9090)
+6. Build dashboards in [Grafana](http://localhost:3000/) (admin/password1)
 
 ### Using Application Insights SDK
 
+1. Clone this repository
 1. Open terminal under `ready-to-run\sample`
-2. Add .env file with following content:
+1. Create file `ready-to-run\sample\.env` with following content:
 
 ```env
 USE_APPLICATIONINSIGHTS=true
 USE_OPENTELEMETRY=false
 AI_INSTRUMENTATIONKEY=<ENTER-APPLICATION-INSIGHTS-INSTRUMENTATION-KEY>
 ```
 
-3. Execute `docker-compose up`
-4. Generate load with `watch -n 2 curl --request GET http://localhost:5001/api/enqueue/WebSiteA`
-5. View logs, traces and metrics in Azure Portal Application Insights
+4. Execute `docker-compose up`
+5. Generate load in terminal with
 
+```bash
+watch -n 2 curl --request GET http://localhost:5001/api/enqueue/WebSiteA
+```
+
+for PowerShell use this script:
+
+```Powershell
+while (1) {Invoke-WebRequest -Uri http://localhost:5001/api/enqueue/WebSiteA; sleep 2}
+```
+
+5. View logs, traces and metrics in Azure Portal Application Insights
 
 ## Conclusion
 

media/003-ai-e2e-traces-and-logs.jpg

@@ -15,3 +15,8 @@ scrape_configs:
     scrape_interval: 5s
     static_configs:
          - targets: ['sample.mainapi:9184']
+
+  - job_name: 'rabbitmq-processor'
+    scrape_interval: 5s
+    static_configs:
+         - targets: ['sample.rabbitmqprocessor:9185']

media/003-ai-e2e-traces.jpg

@@ -15,3 +15,8 @@ scrape_configs:
     scrape_interval: 5s
     static_configs:
          - targets: ['host.docker.internal:9184']
+
+  - job_name: 'rabbitmq-processor'
+    scrape_interval: 5s
+    static_configs:
+         - targets: ['host.docker.internal:9185']

media/03-ai-custom-tracing.png

@@ -30,12 +30,15 @@ services:
       - SampleApp__UseOpenTelemetry=${USE_OPENTELEMETRY-true}
       - SampleApp__ApplicationInsightsInstrumentationKey=${AI_INSTRUMENTATIONKEY-}
       - SampleApp__ApplicationInsightsForOpenTelemetryInstrumentationKey=${AI_INSTRUMENTATIONKEY_OPENTELEMETRY-}
+      - OpenTelemetry__Prometheus__Url=http://sample.rabbitmqprocessor:9185/metrics/
       - OpenTelemetry__Jaeger__AgentHost=${JAEGER_AGENTHOST-jaeger}
     depends_on:
       - rabbitmq
       - sample.timeapi
       - prometheus
       - jaeger
+    ports:
+      - "9185:9185"
 
   sample.timeapi:
     image: fbeltrao/dotnetobservabilitysample-timeapi

media/04-ai-span-error-search.png

@@ -119,6 +119,10 @@ To generate load use the following script:
 watch -n 1 curl --request  GET http://localhost:5002/api/time/dbtime
 ```
 
+```powershell
+while (1) {Invoke-WebRequest -Uri http://localhost:5002/api/time/dbtime; sleep 1}
+```
+
 ## Where to go next
 
 - [Back to overview](./README.md)

media/04-ai-trace-and-logs.png

@@ -116,6 +116,11 @@ To generate load use the following script:
 watch -n 1 curl --request  GET  http://localhost:5001/api/dbtime
 ```
 
+```powershell
+while (1) {Invoke-WebRequest -Uri http://localhost:5001/api/dbtime; sleep 1}
+```
+
+
 ## Where to go next
 
 - [Back to overview](./README.md)

media/04-ot-span-error-search.png

@@ -243,18 +243,30 @@ Enqueuing from "WebSiteA" every 2 seconds
 watch -n 2 curl --request GET http://localhost:5001/api/enqueue/WebSiteA
 ```
 
+```powershell
+while (1) {Invoke-WebRequest -Uri http://localhost:5001/api/enqueue/WebSiteA; sleep 2}
+```
+
 Enqueuing from "WebSiteB" every 10 seconds
 
 ```bash
 watch -n 10 curl --request GET http://localhost:5001/api/enqueue/WebSiteB
 ```
 
+```powershell
+while (1) {Invoke-WebRequest -Uri http://localhost:5001/api/enqueue/WebSiteB; sleep 10}
+```
+
 Enqueuing from "WebSiteC" every 30 seconds
 
 ```bash
 watch -n 30 curl --request GET http://localhost:5001/api/enqueue/WebSiteC
 ```
 
+```powershell
+while (1) {Invoke-WebRequest -Uri http://localhost:5001/api/enqueue/WebSiteC; sleep 30}
+```
+
 ## Where to go next
 
 - [Back to overview](./README.md)

media/04-ot-span-error.png

@@ -1,6 +1,8 @@
 using System;
+using System.Diagnostics;
 using System.Reflection;
 using Microsoft.ApplicationInsights.Channel;
+using Microsoft.ApplicationInsights.DataContracts;
 using Microsoft.ApplicationInsights.Extensibility;
 
 namespace Sample.Common

media/05-ai-e2e-logs-with-exception.png

@@ -161,7 +161,7 @@ static IServiceCollection AddSampleOpenTelemetry(this IServiceCollection service
                     // Add start/stop lifetime support
                     services.AddHostedService<PromotheusExporterHostedService>();
 
-                    Console.WriteLine("Using OpenTelemetry Prometheus exporter");
+                    Console.WriteLine($"Using OpenTelemetry Prometheus exporter in '{prometheusExporterOptions.Url}'");
                 }
             }
 

media/05-ai-e2e-with-exception.png

@@ -145,16 +145,17 @@ public void BasicPublish(string exchange, string routingKey, bool mandatory, IBa
                     activity.AddTag(Constants.RoutingKeyTagName, routingKey);
 
                 diagnosticSource.StartActivity(activity, null);
+            }
 
-                basicProperties = basicProperties ?? model.CreateBasicProperties();
-                if (basicProperties.Headers == null)
-                {
-                    basicProperties.Headers = new Dictionary<string, object>();
-                }
-
-                basicProperties.Headers.Add(TraceParent.HeaderKey, activity.Id);
+            // Add into the header the current activity identifier
+            basicProperties = basicProperties ?? model.CreateBasicProperties();
+            if (basicProperties.Headers == null)
+            {
+                basicProperties.Headers = new Dictionary<string, object>();
             }
 
+            basicProperties.Headers.Add(TraceParent.HeaderKey, Activity.Current.Id);
+
             try
             {
                 model.BasicPublish(exchange, routingKey, mandatory, basicProperties, body);

media/05-ai-metric-error-explained.png

@@ -8,9 +8,6 @@
   <ItemGroup>
     <PackageReference Include="RabbitMQ.Client" Version="5.1.2" />
     <PackageReference Include="System.Diagnostics.DiagnosticSource" Version="4.7.0" />
-  </ItemGroup>
-
-  <ItemGroup>
     <PackageReference Include="Microsoft.ApplicationInsights" Version="2.12.0" />
     <PackageReference Include="OpenTelemetry" Version="0.2.0-alpha.151" />
   </ItemGroup>

media/05-ai-metric-error.png

@@ -0,0 +1,25 @@
+using System;
+using System.Runtime.Serialization;
+
+namespace Sample.RabbitMQProcessor
+{
+    [Serializable]
+    public class InvalidEventNameException : Exception
+    {
+        public InvalidEventNameException()
+        {
+        }
+
+        public InvalidEventNameException(string message) : base(message)
+        {
+        }
+
+        public InvalidEventNameException(string message, Exception innerException) : base(message, innerException)
+        {
+        }
+
+        protected InvalidEventNameException(SerializationInfo info, StreamingContext context) : base(info, context)
+        {
+        }
+    }
+}

prometheus.yml

@@ -0,0 +1,63 @@
+using System;
+using System.Collections.Generic;
+using Microsoft.ApplicationInsights;
+using Microsoft.ApplicationInsights.Metrics;
+using Microsoft.Extensions.DependencyInjection;
+using OpenTelemetry.Metrics;
+using OpenTelemetry.Metrics.Configuration;
+using OpenTelemetry.Trace;
+using Sample.Common;
+
+namespace Sample.RabbitMQProcessor
+{
+    public class Metrics : IAppMetrics
+    {
+        private readonly Metric appInsightsProcessedItemCounter;
+        private readonly Metric appInsightsProcessedFailedItemCounter;
+
+        private Meter meter;
+        private Counter<long> openTelemetryProcessedItemCounter;
+        private Counter<long> openTelemetryProcessedFailedItemCounter;
+
+        public Metrics(IServiceProvider serviceProvider)
+        {
+            var telemetryClient = serviceProvider.GetService<TelemetryClient>();
+            if (telemetryClient != null)
+            {
+                this.appInsightsProcessedItemCounter = telemetryClient.GetMetric(new MetricIdentifier("Sample App", "Processed Item", "Source"));
+                this.appInsightsProcessedFailedItemCounter = telemetryClient.GetMetric(new MetricIdentifier("Sample App", "Processed Failed Item", "Source"));
+            }
+        }
+
+        void IAppMetrics.Initialize(MeterFactory meterFactory)
+        {
+            this.meter = meterFactory.GetMeter("Sample App");
+            this.openTelemetryProcessedItemCounter = meter.CreateInt64Counter("Processed Item");
+            this.openTelemetryProcessedFailedItemCounter = meter.CreateInt64Counter("Processed Failed Item");
+
+        }
+
+        public void TrackItemProcessed(double metricValue, string source, bool succeeded)
+        {            
+            appInsightsProcessedItemCounter?.TrackValue(succeeded ? 1 : 0, source);
+            appInsightsProcessedFailedItemCounter?.TrackValue(succeeded ? 0 : 1, source);
+
+            if (meter != null)
+            {
+                var context = default(SpanContext);
+                var labelSet = new Dictionary<string, string>() 
+                {
+                    { "Source", source },
+                };
+
+                openTelemetryProcessedItemCounter.Add(context, succeeded ? 1 : 0, this.meter.GetLabelSet(labelSet));
+                openTelemetryProcessedFailedItemCounter.Add(context, succeeded ? 0 : 1, this.meter.GetLabelSet(labelSet));
+
+                // Collect is called here explicitly as there is 
+                // no controller implementation yet.
+                // TODO: There should be no need to cast to MeterSdk.
+                //(meter as MeterSdk).Collect();
+            }
+        }
+    }
+}

ready-to-run/prometheus-grafana/prometheus.yml

@@ -24,6 +24,8 @@ public static IHostBuilder CreateHostBuilder(string[] args)
                 .ConfigureServices((hostContext, services) =>
                 {
                     services.AddWorkerSampleTelemetry(hostContext.Configuration);
+                    services.AddSingleton<IAppMetrics, Metrics>();
+                    services.AddSingleton(x => (Metrics)x.GetRequiredService<IAppMetrics>());
 
                     services.AddHttpClient();
                     services.AddHostedService<WebQueueConsumerHostedService>();