Event Counter metric support for ingestion response time

BASE/Test/Microsoft.ApplicationInsights.Test/Microsoft.ApplicationInsights.Tests/Channel/TransmissionTest.cs

@@ -15,6 +15,8 @@
     using Microsoft.ApplicationInsights.TestFramework;
     using Microsoft.VisualStudio.TestTools.UnitTesting;
     using System.CodeDom;
+    using Microsoft.ApplicationInsights.Extensibility.Implementation.Tracing;
+    using System.Diagnostics.Tracing;
 
     public class TransmissionTest
     {
@@ -86,6 +88,7 @@ public void SetsTimeoutToSpecifiedValue()
         public class SendAsync
         {
             private readonly Uri testUri = new Uri("https://127.0.0.1/");
+            private const long AllKeywords = -1;
 
             [TestMethod]
             public async Task SendAsyncUsesPostMethodToSpecifiedHttpEndpoint()
@@ -363,6 +366,85 @@ public async Task SendAsyncReturnsCorrectHttpResponseWrapperWithRetryHeaderWhenN
                 }
 
             }
+
+#if NETCOREAPP2_1
+            [TestMethod]
+            public async Task SendAsyncLogsIngestionReponseTimeEventCounter()
+            {
+                var handler = new HandlerForFakeHttpClient
+                {
+                    InnerHandler = new HttpClientHandler(),
+                    OnSendAsync = (req, cancellationToken) =>
+                    {
+                        return Task.FromResult<HttpResponseMessage>(new HttpResponseMessage());
+                    }
+                };
+
+                using (var fakeHttpClient = new HttpClient(handler))
+                {
+                    // Instantiate Transmission with the mock HttpClient
+                    Transmission transmission = new Transmission(testUri, new byte[] { 1, 2, 3, 4, 5 }, fakeHttpClient, string.Empty, string.Empty);
+
+                    using (var listener = new TestEventListener())
+                    {
+                        var eventCounterArguments = new Dictionary<string, string>
+                        {
+                            {"EventCounterIntervalSec", "1"}
+                        };
+
+                        listener.EnableEvents(CoreEventSource.Log, EventLevel.LogAlways, (EventKeywords)AllKeywords, eventCounterArguments);
+
+                        HttpWebResponseWrapper result = await transmission.SendAsync();
+
+                        // VERIFY
+                        // We validate by checking SDK traces.
+                        var allTraces = listener.Messages.ToList();
+                        var traces = allTraces.Where(item => item.EventName == "EventCounters").ToList();
+                        Assert.AreEqual(1, traces.Count);
+                        var payload = (IDictionary<string, object>)traces[0].Payload[0];
+                        Assert.AreEqual("IngestionEndpoint-ResponseTimeMsec", payload["Name"].ToString());
+                        Assert.AreNotEqual(0, (float)payload["IntervalSec"]);
+                    }
+                }
+            }
+#endif
+            [TestMethod]
+            public async Task SendAsyncLogsIngestionReponseTimeAndStatusCode()
+            {
+                var handler = new HandlerForFakeHttpClient
+                {
+                    InnerHandler = new HttpClientHandler(),
+                    OnSendAsync = (req, cancellationToken) =>
+                    {
+                        return Task.FromResult<HttpResponseMessage>(new HttpResponseMessage());
+                    }
+                };
+
+                using (var fakeHttpClient = new HttpClient(handler))
+                {
+                    // Instantiate Transmission with the mock HttpClient
+                    Transmission transmission = new Transmission(testUri, new byte[] { 1, 2, 3, 4, 5 }, fakeHttpClient, string.Empty, string.Empty);
+
+                    using (var listener = new TestEventListener())
+                    {
+                        var eventCounterArguments = new Dictionary<string, string>
+                        {
+                            {"EventCounterIntervalSec", "1"}
+                        };
+
+                        listener.EnableEvents(CoreEventSource.Log, EventLevel.LogAlways, (EventKeywords)AllKeywords, eventCounterArguments);
+
+                        HttpWebResponseWrapper result = await transmission.SendAsync();
+
+                        // VERIFY
+                        // We validate by checking SDK traces.
+                        var allTraces = listener.Messages.ToList();
+                        // Event 67 is logged after response from breeze.
+                        var traces = allTraces.Where(item => item.EventId == 67).ToList();
+                        Assert.AreEqual(1, traces.Count);
+                    }
+                }
+            }
         }
     }
 

BASE/src/Microsoft.ApplicationInsights/Channel/Transmission.cs

@@ -2,6 +2,7 @@
 {
     using System;
     using System.Collections.Generic;
+    using System.Diagnostics;
     using System.IO;
     using System.Net;
     using System.Net.Http;
@@ -159,9 +160,16 @@ public virtual async Task<HttpWebResponseWrapper> SendAsync()
                             // "The request failed due to an underlying issue such as network connectivity, DNS failure, server certificate validation or timeout."
                             // i.e for Server errors (500 status code), no exception is thrown. Hence this method should read the response and status code,
                             // and return correct HttpWebResponseWrapper to give any Retry policies a chance to retry as needed.
+                            var stopwatch = new Stopwatch();
+                            stopwatch.Start();
 
                             using (var response = await client.SendAsync(request, ct.Token).ConfigureAwait(false))
                             {
+                                stopwatch.Stop();
+                                CoreEventSource.Log.BreezeResponseTime(response != null ? (int)response.StatusCode : -1, stopwatch.ElapsedMilliseconds);
+                                // Log breeze respose time as event counter metric.
+                                CoreEventSource.Log.BreezeResponseTimeEventCounter(stopwatch.ElapsedMilliseconds);
+
                                 if (response != null)
                                 {
                                     wrapper = new HttpWebResponseWrapper

BASE/src/Microsoft.ApplicationInsights/Extensibility/Implementation/Tracing/CoreEventSource.cs

@@ -9,8 +9,19 @@ internal sealed class CoreEventSource : EventSource
     {
         public static readonly CoreEventSource Log = new CoreEventSource();
 
+#if NETSTANDARD2_0
+        public EventCounter BreezeResponseTimeCounter;
+#endif
+
         private readonly ApplicationNameProvider nameProvider = new ApplicationNameProvider();
 
+#if NETSTANDARD2_0
+        private CoreEventSource()
+        {
+            this.BreezeResponseTimeCounter = new EventCounter("IngestionEndpoint-ResponseTimeMsec", this);
+        }
+#endif
+
         public static bool IsVerboseEnabled
         {
             [NonEvent]
@@ -620,6 +631,17 @@ public void InitializationIsSkippedForSampledItem(string appDomainName = "Incorr
 
         #endregion
 
+        [Event(67, Message = "Backend has responded with {0} status code in {1}ms.", Level = EventLevel.Informational)]
+        public void BreezeResponseTime(int responseCode, float responseDurationInMs, string appDomainName = "Incorrect") => this.WriteEvent(67, responseCode, responseDurationInMs, this.nameProvider.Name);
+
+        [NonEvent]
+        public void BreezeResponseTimeEventCounter(float responseDurationInMs)
+        {
+#if NETSTANDARD2_0
+            this.BreezeResponseTimeCounter.WriteMetric(responseDurationInMs);
+#endif
+        }
+
         /// <summary>
         /// Keywords for the PlatformEventSource.
         /// </summary>

CHANGELOG.md

@@ -2,7 +2,7 @@
 
 ## VNext
 [WorkerService package is modified to depend on 2.1.1 on Microsoft.Extensions.DependencyInjection so that it can be used in .NET Core 2.1 projects without nuget errors.](https://github.com/microsoft/ApplicationInsights-dotnet/issues/1677)
-
+- [New: EventCounter to track Ingestion Endpoint Response Time] (https://github.com/microsoft/ApplicationInsights-dotnet/pull/1796)
 
 ## Version 2.14.0
 - no changes since beta.