From be337488e6501c0100be2a20353f7acb90968045 Mon Sep 17 00:00:00 2001 From: abaranch Date: Tue, 24 May 2016 16:01:18 -0700 Subject: [PATCH 01/30] Add additional tracing in case of verbose tracing --- .../ErrorHandlingTransmissionPolicyTest.cs | 68 +++++++++++- .../TransmissionPolicyHelpersTest.cs | 75 +++++++++++++ .../Implementation/TransmissionPolicyTest.cs | 70 ------------ .../Shared.Tests/Shared.Tests.projitems | 1 + .../Managed/Shared/Channel/Transmission.cs | 7 +- .../Implementation/Tracing/CoreEventSource.cs | 9 ++ .../ErrorHandlingTransmissionPolicy.cs | 38 ++++++- .../PartialSuccessTransmissionPolicy.cs | 32 ++---- .../ThrottlingTransmissionPolicy.cs | 7 +- .../Implementation/TransmissionPolicy.cs | 74 +------------ .../TransmissionPolicyHelpers.cs | 103 ++++++++++++++++++ .../Shared/Shared.projitems | 1 + 12 files changed, 312 insertions(+), 173 deletions(-) create mode 100644 Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TransmissionPolicyHelpersTest.cs create mode 100644 src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs index 2782294353..5a89047730 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs @@ -6,6 +6,7 @@ #endif using System.Collections.Generic; using System.Collections.Specialized; + using System.Globalization; using System.Linq; using System.Net; using System.Threading; @@ -182,6 +183,71 @@ public void CatchesAndLogsSynchronousExceptionsThrownByTransmitterWhenResumingTr CatchesAndLogsExceptionThrownByTransmitter(policy, transmitter, exception); } + [TestMethod] + public void LogsAdditionalTracesIfResponseIsProvided() + { + using (var listener = new TestEventListener()) + { + // Arrange: + const long AllKeywords = -1; + listener.EnableEvents(TelemetryChannelEventSource.Log, EventLevel.LogAlways, (EventKeywords)AllKeywords); + + Transmission enqueuedTransmission = null; + var transmitter = new StubTransmitter + { + OnEnqueue = transmission => { enqueuedTransmission = transmission; } + }; + + var policy = new TestableErrorHandlingTransmissionPolicy + { + BackOffTime = TimeSpan.FromMilliseconds(10) + }; + + policy.Initialize(transmitter); + + var failedTransmission = new StubTransmission(); + var response = new HttpWebResponseWrapper {Content = this.GetBackendResponse(2, 1, new[] { "123" })}; + + // Act: + transmitter.OnTransmissionSent(new TransmissionProcessedEventArgs(failedTransmission, CreateException(statusCode: 408), response)); + + // Assert: + var traces = listener.Messages.ToList(); + Assert.True(traces.Count > 2); + Assert.Equal(23, traces[0].EventId); // failed to send + Assert.Equal(7, traces[1].EventId); // additional trace + Assert.Equal("Explanation", traces[1].Payload[0]); + } + } + + private string GetBackendResponse(int itemsReceived, int itemsAccepted, string[] errorCodes, int indexStartWith = 0) + { + string singleItem = "{{" + + "\"index\": {0}," + + "\"statusCode\": {1}," + + "\"message\": \"Explanation\"" + + "}}"; + + string errorList = string.Empty; + for (int i = 0; i < errorCodes.Length; ++i) + { + string errorCode = errorCodes[i]; + if (!string.IsNullOrEmpty(errorList)) + { + errorList += ","; + } + + errorList += string.Format(CultureInfo.InvariantCulture, singleItem, indexStartWith + i, errorCode); + } + + return + "{" + + "\"itemsReceived\": " + itemsReceived + "," + + "\"itemsAccepted\": " + itemsAccepted + "," + + "\"errors\": [" + errorList + "]" + + "}"; + } + private static Task ThrowAsync(Exception e) { var tcs = new TaskCompletionSource(null); @@ -219,7 +285,7 @@ private class TestableErrorHandlingTransmissionPolicy : ErrorHandlingTransmissio { public TimeSpan BackOffTime { get; set; } - public override TimeSpan GetBackOffTime(NameValueCollection headers = null) + protected override TimeSpan GetBackOffTime(NameValueCollection headers = null) { return this.BackOffTime; } diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TransmissionPolicyHelpersTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TransmissionPolicyHelpersTest.cs new file mode 100644 index 0000000000..0d6503322f --- /dev/null +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TransmissionPolicyHelpersTest.cs @@ -0,0 +1,75 @@ + namespace Microsoft.ApplicationInsights.WindowsServer.Channel.Implementation +{ + using System; + using System.Collections.Generic; + using System.Globalization; + using System.Net; + using System.Text; + using Microsoft.ApplicationInsights.Channel.Implementation; + using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Implementation; + using Microsoft.VisualStudio.TestTools.UnitTesting; + using Assert = Xunit.Assert; + + [TestClass] + public class TransmissionPolicyHelpersTest + { + [TestClass] + public class GetBackOffTime + { + [TestMethod] + public void NoErrorDelayIsSameAsSlotDelay() + { + TimeSpan delay = TransmissionPolicyHelpers.GetBackOffTime(0, new WebHeaderCollection()); + Assert.Equal(TimeSpan.FromSeconds(10), delay); + } + + [TestMethod] + public void FirstErrorDelayIsSameAsSlotDelay() + { + TimeSpan delay = TransmissionPolicyHelpers.GetBackOffTime(1, new WebHeaderCollection()); + Assert.Equal(TimeSpan.FromSeconds(10), delay); + } + + [TestMethod] + public void UpperBoundOfDelayIsMaxDelay() + { + TimeSpan delay = TransmissionPolicyHelpers.GetBackOffTime(int.MaxValue, new WebHeaderCollection()); + Assert.InRange(delay, TimeSpan.FromSeconds(10), TimeSpan.FromSeconds(3600)); + } + + [TestMethod] + public void RetryAfterFromHeadersHasMorePriorityThanExponentialRetry() + { + WebHeaderCollection headers = new WebHeaderCollection(); + headers.Add("Retry-After", DateTimeOffset.UtcNow.AddSeconds(30).ToString("O")); + + TimeSpan delay = TransmissionPolicyHelpers.GetBackOffTime(0, headers); + + Xunit.Assert.InRange(delay, TimeSpan.FromSeconds(20), TimeSpan.FromSeconds(30)); + } + + [TestMethod] + public void AssertIfDateParseErrorCausesDefaultDelay() + { + WebHeaderCollection headers = new WebHeaderCollection(); + headers.Add("Retry-After", "no one can parse me"); + + TimeSpan delay = TransmissionPolicyHelpers.GetBackOffTime(0, headers); + Assert.Equal(TimeSpan.FromSeconds(10), delay); + } + + [TestMethod] + public void RetryAfterOlderThanNowCausesDefaultDelay() + { + // An old date + string retryAfterDateString = DateTime.Now.AddMinutes(-1).ToString("R", CultureInfo.InvariantCulture); + + WebHeaderCollection headers = new WebHeaderCollection(); + headers.Add("Retry-After", retryAfterDateString); + + TimeSpan delay = TransmissionPolicyHelpers.GetBackOffTime(0, headers); + Assert.Equal(TimeSpan.FromSeconds(10), delay); + } + } + } +} diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TransmissionPolicyTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TransmissionPolicyTest.cs index 4f22112a4e..6c1d0cf354 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TransmissionPolicyTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TransmissionPolicyTest.cs @@ -102,76 +102,6 @@ public void MaxStorageCapacityCanBeSetByPolicy() Assert.Equal(42, policy.MaxStorageCapacity); } - [TestClass] - public class GetBackOffTime : ErrorHandlingTransmissionPolicyTest - { - [TestMethod] - public void NoErrorDelayIsSameAsSlotDelay() - { - var policy = new TestableTransmissionPolicy(); - TimeSpan delay = policy.GetBackOffTime(new WebHeaderCollection()); - Assert.Equal(TimeSpan.FromSeconds(10), delay); - } - - [TestMethod] - public void FirstErrorDelayIsSameAsSlotDelay() - { - var policy = new TestableTransmissionPolicy(); - policy.ConsecutiveErrors = 1; - TimeSpan delay = policy.GetBackOffTime(new WebHeaderCollection()); - Assert.Equal(TimeSpan.FromSeconds(10), delay); - } - - [TestMethod] - public void UpperBoundOfDelayIsMaxDelay() - { - var policy = new TestableTransmissionPolicy(); - policy.ConsecutiveErrors = int.MaxValue; - TimeSpan delay = policy.GetBackOffTime(new WebHeaderCollection()); - Assert.InRange(delay, TimeSpan.FromSeconds(10), TimeSpan.FromSeconds(3600)); - } - - [TestMethod] - public void RetryAfterFromHeadersHasMorePriorityThanExponentialRetry() - { - WebHeaderCollection headers = new WebHeaderCollection(); - headers.Add("Retry-After", DateTimeOffset.UtcNow.AddSeconds(30).ToString("O")); - - var policy = new TestableTransmissionPolicy(); - policy.ConsecutiveErrors = 0; - TimeSpan delay = policy.GetBackOffTime(headers); - - Assert.InRange(delay, TimeSpan.FromSeconds(20), TimeSpan.FromSeconds(30)); - } - - [TestMethod] - public void AssertIfDateParseErrorCausesDefaultDelay() - { - WebHeaderCollection headers = new WebHeaderCollection(); - headers.Add("Retry-After", "no one can parse me"); - - var policy = new TestableTransmissionPolicy(); - policy.ConsecutiveErrors = 0; - TimeSpan delay = policy.GetBackOffTime(headers); - Assert.Equal(TimeSpan.FromSeconds(10), delay); - } - - [TestMethod] - public void RetryAfterOlderThanNowCausesDefaultDelay() - { - // An old date - string retryAfterDateString = DateTime.Now.AddMinutes(-1).ToString("R", CultureInfo.InvariantCulture); - - WebHeaderCollection headers = new WebHeaderCollection(); - headers.Add("Retry-After", retryAfterDateString); - - var policy = new TestableTransmissionPolicy(); - policy.ConsecutiveErrors = 0; - TimeSpan delay = policy.GetBackOffTime(headers); - Assert.Equal(TimeSpan.FromSeconds(10), delay); - } - } - private class TestableTransmissionPolicy : TransmissionPolicy { public new Transmitter Transmitter diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Shared.Tests.projitems b/Test/ServerTelemetryChannel.Test/Shared.Tests/Shared.Tests.projitems index c71b979511..3e3e08675e 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Shared.Tests.projitems +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Shared.Tests.projitems @@ -37,6 +37,7 @@ + diff --git a/src/Core/Managed/Shared/Channel/Transmission.cs b/src/Core/Managed/Shared/Channel/Transmission.cs index 96aa24ad07..d4f27147d5 100644 --- a/src/Core/Managed/Shared/Channel/Transmission.cs +++ b/src/Core/Managed/Shared/Channel/Transmission.cs @@ -1,4 +1,6 @@ -namespace Microsoft.ApplicationInsights.Channel +using Microsoft.ApplicationInsights.Extensibility.Implementation.Tracing; + +namespace Microsoft.ApplicationInsights.Channel { using System; using System.Collections.Generic; @@ -234,7 +236,8 @@ private async Task SendRequestAsync(WebRequest request) { // Return content only for 206 for performance reasons // Currently we do not need it in other cases - if (httpResponse.StatusCode == HttpStatusCode.PartialContent) + if (httpResponse.StatusCode == HttpStatusCode.PartialContent || + CoreEventSource.Log.IsVerboseEnabled) { wrapper = new HttpWebResponseWrapper { diff --git a/src/Core/Managed/Shared/Extensibility/Implementation/Tracing/CoreEventSource.cs b/src/Core/Managed/Shared/Extensibility/Implementation/Tracing/CoreEventSource.cs index eb80daba92..5df927eb0d 100644 --- a/src/Core/Managed/Shared/Extensibility/Implementation/Tracing/CoreEventSource.cs +++ b/src/Core/Managed/Shared/Extensibility/Implementation/Tracing/CoreEventSource.cs @@ -14,6 +14,15 @@ internal sealed class CoreEventSource : EventSource private readonly ApplicationNameProvider nameProvider = new ApplicationNameProvider(); + public bool IsVerboseEnabled + { + [NonEvent] + get + { + return Log.IsEnabled(EventLevel.Verbose, (EventKeywords)(-1)); + } + } + /// /// Logs the information when there operation to track is null. /// diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs index 4b7098e8c0..601fc5b70f 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs @@ -1,9 +1,11 @@ namespace Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Implementation { using System; + using System.Collections.Specialized; using System.Net; using System.Threading.Tasks; + using Microsoft.ApplicationInsights.Channel.Implementation; using Microsoft.ApplicationInsights.Extensibility.Implementation; #if NET45 @@ -12,7 +14,9 @@ internal class ErrorHandlingTransmissionPolicy : TransmissionPolicy, IDisposable { - private TaskTimer pauseTimer = new TaskTimer { Delay = TimeSpan.FromSeconds(SlotDelayInSeconds) }; + private TaskTimer pauseTimer = new TaskTimer { Delay = TimeSpan.FromSeconds(TransmissionPolicyHelpers.SlotDelayInSeconds) }; + + public int ConsecutiveErrors { get; set; } public override void Initialize(Transmitter transmitter) { @@ -27,15 +31,16 @@ public void Dispose() } private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEventArgs e) - { + { var webException = e.Exception as WebException; if (webException != null) - { + { this.ConsecutiveErrors++; HttpWebResponse httpWebResponse = webException.Response as HttpWebResponse; if (httpWebResponse != null) { TelemetryChannelEventSource.Log.TransmissionSendingFailedWebExceptionWarning(e.Transmission.Id, webException.Message, (int)httpWebResponse.StatusCode); + AdditionalVerboseTracing(e); switch (httpWebResponse.StatusCode) { @@ -67,6 +72,7 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve else { TelemetryChannelEventSource.Log.TransmissionSendingFailedWebExceptionWarning(e.Transmission.Id, webException.Message, (int)HttpStatusCode.InternalServerError); + AdditionalVerboseTracing(e); } } else @@ -74,12 +80,38 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve if (e.Exception != null) { TelemetryChannelEventSource.Log.TransmissionSendingFailedWarning(e.Transmission.Id, e.Exception.Message); + AdditionalVerboseTracing(e); } this.ConsecutiveErrors = 0; } } + protected virtual TimeSpan GetBackOffTime(NameValueCollection headers) + { + return TransmissionPolicyHelpers.GetBackOffTime(this.ConsecutiveErrors, headers); + } + + private void AdditionalVerboseTracing(TransmissionProcessedEventArgs args) + { + // For perf reason deserialize only when verbose tracing is enabled + if (TelemetryChannelEventSource.Log.IsVerboseEnabled) + { + BackendResponse backendResponse = TransmissionPolicyHelpers.GetBackendResponse(args); + + if (backendResponse != null && backendResponse.Errors != null) + { + foreach (var error in backendResponse.Errors) + { + if (error != null) + { + TelemetryChannelEventSource.Log.ItemRejectedByEndpointWarning(error.Message); + } + } + } + } + } + private void Dispose(bool disposing) { if (disposing) diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs index e02849e14b..c7984ec39a 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs @@ -3,7 +3,7 @@ using System; using System.Threading.Tasks; - using System.Web.Script.Serialization; + using Microsoft.ApplicationInsights.Channel.Implementation; using Microsoft.ApplicationInsights.Channel; using Microsoft.ApplicationInsights.Extensibility.Implementation; @@ -14,9 +14,9 @@ internal class PartialSuccessTransmissionPolicy : TransmissionPolicy, IDisposable { - private readonly JavaScriptSerializer serializer = new JavaScriptSerializer(); + private TaskTimer pauseTimer = new TaskTimer { Delay = TimeSpan.FromSeconds(TransmissionPolicyHelpers.SlotDelayInSeconds) }; - private TaskTimer pauseTimer = new TaskTimer { Delay = TimeSpan.FromSeconds(SlotDelayInSeconds) }; + public int ConsecutiveErrors { get; set; } public override void Initialize(Transmitter transmitter) { @@ -56,28 +56,16 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve private string ParsePartialSuccessResponse(Transmission initialTransmission, TransmissionProcessedEventArgs args) { - BackendResponse backendResponse; - string responseContent = args.Response.Content; - try - { - backendResponse = this.serializer.Deserialize(responseContent); - } - catch (ArgumentException exp) - { - TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); - this.ConsecutiveErrors = 0; - return null; - } - catch (InvalidOperationException exp) - { - TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); + BackendResponse backendResponse = TransmissionPolicyHelpers.GetBackendResponse(args); + + if (backendResponse == null) + { this.ConsecutiveErrors = 0; return null; } - + string newTransmissions = null; - - if (backendResponse != null && backendResponse.ItemsAccepted != backendResponse.ItemsReceived) + if (backendResponse.ItemsAccepted != backendResponse.ItemsReceived) { string[] items = JsonSerializer .Deserialize(initialTransmission.Content) @@ -126,7 +114,7 @@ private void DelayFutureProcessing(HttpWebResponseWrapper response) this.Apply(); // Back-off for the Delay duration and enable sending capacity - this.pauseTimer.Delay = this.GetBackOffTime(response.RetryAfterHeader); + this.pauseTimer.Delay = TransmissionPolicyHelpers.GetBackOffTime(this.ConsecutiveErrors, response.RetryAfterHeader); this.pauseTimer.Start(() => { this.MaxBufferCapacity = null; diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ThrottlingTransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ThrottlingTransmissionPolicy.cs index 23adb17d75..e8481a7ebb 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ThrottlingTransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ThrottlingTransmissionPolicy.cs @@ -4,6 +4,7 @@ using System.Net; using System.Threading.Tasks; + using Microsoft.ApplicationInsights.Channel.Implementation; using Microsoft.ApplicationInsights.Extensibility.Implementation; #if NET45 @@ -12,7 +13,9 @@ internal class ThrottlingTransmissionPolicy : TransmissionPolicy, IDisposable { - private TaskTimer pauseTimer = new TaskTimer { Delay = TimeSpan.FromSeconds(SlotDelayInSeconds) }; + private TaskTimer pauseTimer = new TaskTimer { Delay = TimeSpan.FromSeconds(TransmissionPolicyHelpers.SlotDelayInSeconds) }; + + public int ConsecutiveErrors { get; set; } public void Dispose() { @@ -39,7 +42,7 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve if (httpWebResponse.StatusCode == (HttpStatusCode)ResponseStatusCodes.ResponseCodeTooManyRequests || httpWebResponse.StatusCode == (HttpStatusCode)ResponseStatusCodes.ResponseCodeTooManyRequestsOverExtendedTime) { - this.pauseTimer.Delay = this.GetBackOffTime(httpWebResponse.Headers); + this.pauseTimer.Delay = TransmissionPolicyHelpers.GetBackOffTime(this.ConsecutiveErrors, httpWebResponse.Headers); TelemetryChannelEventSource.Log.ThrottlingRetryAfterParsedInSec(this.pauseTimer.Delay.TotalSeconds); this.MaxSenderCapacity = 0; diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicy.cs index 9cd3aafd5b..d1ed6d256e 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicy.cs @@ -5,19 +5,13 @@ internal abstract class TransmissionPolicy { - protected const int SlotDelayInSeconds = 10; - private const int MaxDelayInSeconds = 3600; - private readonly string policyName; - private readonly Random random = new Random(); - + protected TransmissionPolicy() { this.policyName = this.GetType().ToString(); } - public int ConsecutiveErrors { get; set; } - public int? MaxSenderCapacity { get; protected set; } public int? MaxBufferCapacity { get; protected set; } @@ -53,45 +47,6 @@ public virtual void Initialize(Transmitter transmitter) this.Transmitter = transmitter; } - // Calculates the time to wait before retrying in case of an error based on - // http://en.wikipedia.org/wiki/Exponential_backoff - public virtual TimeSpan GetBackOffTime(string headerValue) - { - TimeSpan retryAfterTimeSpan; - if (!this.TryParseRetryAfter(headerValue, out retryAfterTimeSpan)) - { - double delayInSeconds; - - if (this.ConsecutiveErrors <= 1) - { - delayInSeconds = SlotDelayInSeconds; - } - else - { - double backOffSlot = (Math.Pow(2, this.ConsecutiveErrors) - 1) / 2; - var backOffDelay = this.random.Next(1, (int)Math.Min(backOffSlot * SlotDelayInSeconds, int.MaxValue)); - delayInSeconds = Math.Max(Math.Min(backOffDelay, MaxDelayInSeconds), SlotDelayInSeconds); - } - - TelemetryChannelEventSource.Log.BackoffTimeSetInSeconds(delayInSeconds); - retryAfterTimeSpan = TimeSpan.FromSeconds(delayInSeconds); - } - - TelemetryChannelEventSource.Log.BackoffInterval(retryAfterTimeSpan.TotalSeconds); - return retryAfterTimeSpan; - } - - public virtual TimeSpan GetBackOffTime(NameValueCollection headers) - { - string retryAfterHeader = string.Empty; - if (headers != null) - { - retryAfterHeader = headers.Get("Retry-After"); - } - - return this.GetBackOffTime(retryAfterHeader); - } - protected void LogCapacityChanged() { if (this.MaxSenderCapacity.HasValue) @@ -121,32 +76,5 @@ protected void LogCapacityChanged() TelemetryChannelEventSource.Log.StorageCapacityReset(this.policyName); } } - - private bool TryParseRetryAfter(string retryAfter, out TimeSpan retryAfterTimeSpan) - { - retryAfterTimeSpan = TimeSpan.FromSeconds(0); - - if (string.IsNullOrEmpty(retryAfter)) - { - return false; - } - - var now = DateTimeOffset.UtcNow; - DateTimeOffset retryAfterDate; - if (DateTimeOffset.TryParse(retryAfter, out retryAfterDate)) - { - if (retryAfterDate > now) - { - retryAfterTimeSpan = retryAfterDate - now; - return true; - } - - return false; - } - - TelemetryChannelEventSource.Log.TransmissionPolicyRetryAfterParseFailedWarning(retryAfter); - - return false; - } } } diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs new file mode 100644 index 0000000000..4a46515127 --- /dev/null +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs @@ -0,0 +1,103 @@ +using System; +using System.Collections.Specialized; +using System.Web.Script.Serialization; +using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Implementation; + +namespace Microsoft.ApplicationInsights.Channel.Implementation +{ + internal static class TransmissionPolicyHelpers + { + public const int SlotDelayInSeconds = 10; + private const int MaxDelayInSeconds = 3600; + private static readonly Random Random = new Random(); + private static readonly JavaScriptSerializer Serializer = new JavaScriptSerializer(); + + public static BackendResponse GetBackendResponse(TransmissionProcessedEventArgs args) + { + BackendResponse backendResponse; + string responseContent = args.Response.Content; + try + { + backendResponse = Serializer.Deserialize(responseContent); + } + catch (ArgumentException exp) + { + TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); + backendResponse = null; + } + catch (InvalidOperationException exp) + { + TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); + backendResponse = null; + } + + return backendResponse; + } + + // Calculates the time to wait before retrying in case of an error based on + // http://en.wikipedia.org/wiki/Exponential_backoff + public static TimeSpan GetBackOffTime(int consecutiveErrors, string headerValue) + { + TimeSpan retryAfterTimeSpan; + if (!TryParseRetryAfter(headerValue, out retryAfterTimeSpan)) + { + double delayInSeconds; + + if (consecutiveErrors <= 1) + { + delayInSeconds = SlotDelayInSeconds; + } + else + { + double backOffSlot = (Math.Pow(2, consecutiveErrors) - 1) / 2; + var backOffDelay = Random.Next(1, (int)Math.Min(backOffSlot * SlotDelayInSeconds, int.MaxValue)); + delayInSeconds = Math.Max(Math.Min(backOffDelay, MaxDelayInSeconds), SlotDelayInSeconds); + } + + TelemetryChannelEventSource.Log.BackoffTimeSetInSeconds(delayInSeconds); + retryAfterTimeSpan = TimeSpan.FromSeconds(delayInSeconds); + } + + TelemetryChannelEventSource.Log.BackoffInterval(retryAfterTimeSpan.TotalSeconds); + return retryAfterTimeSpan; + } + + public static TimeSpan GetBackOffTime(int consecutiveErrors, NameValueCollection headers) + { + string retryAfterHeader = string.Empty; + if (headers != null) + { + retryAfterHeader = headers.Get("Retry-After"); + } + + return GetBackOffTime(consecutiveErrors, retryAfterHeader); + } + + private static bool TryParseRetryAfter(string retryAfter, out TimeSpan retryAfterTimeSpan) + { + retryAfterTimeSpan = TimeSpan.FromSeconds(0); + + if (string.IsNullOrEmpty(retryAfter)) + { + return false; + } + + var now = DateTimeOffset.UtcNow; + DateTimeOffset retryAfterDate; + if (DateTimeOffset.TryParse(retryAfter, out retryAfterDate)) + { + if (retryAfterDate > now) + { + retryAfterTimeSpan = retryAfterDate - now; + return true; + } + + return false; + } + + TelemetryChannelEventSource.Log.TransmissionPolicyRetryAfterParseFailedWarning(retryAfter); + + return false; + } + } +} diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Shared.projitems b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Shared.projitems index d4a1f46560..e7084dde47 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Shared.projitems +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Shared.projitems @@ -22,6 +22,7 @@ + From 456f7460694f768f941747957205c1b9f902112e Mon Sep 17 00:00:00 2001 From: abaranch Date: Tue, 24 May 2016 16:49:40 -0700 Subject: [PATCH 02/30] Stylecop --- .../Managed/Shared/Channel/Transmission.cs | 6 +++--- .../ErrorHandlingTransmissionPolicy.cs | 20 +++++++++---------- .../PartialSuccessTransmissionPolicy.cs | 4 ++-- .../TransmissionPolicyHelpers.cs | 12 +++++------ 4 files changed, 21 insertions(+), 21 deletions(-) diff --git a/src/Core/Managed/Shared/Channel/Transmission.cs b/src/Core/Managed/Shared/Channel/Transmission.cs index d4f27147d5..116a1e52cb 100644 --- a/src/Core/Managed/Shared/Channel/Transmission.cs +++ b/src/Core/Managed/Shared/Channel/Transmission.cs @@ -1,6 +1,4 @@ -using Microsoft.ApplicationInsights.Extensibility.Implementation.Tracing; - -namespace Microsoft.ApplicationInsights.Channel +namespace Microsoft.ApplicationInsights.Channel { using System; using System.Collections.Generic; @@ -13,6 +11,8 @@ namespace Microsoft.ApplicationInsights.Channel using System.Threading; using System.Threading.Tasks; using Microsoft.ApplicationInsights.Extensibility.Implementation; + using Microsoft.ApplicationInsights.Extensibility.Implementation.Tracing; + #if CORE_PCL || NET45 || NET46 using TaskEx = System.Threading.Tasks.Task; #endif diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs index 601fc5b70f..08da01256e 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs @@ -30,17 +30,22 @@ public void Dispose() GC.SuppressFinalize(this); } + protected virtual TimeSpan GetBackOffTime(NameValueCollection headers) + { + return TransmissionPolicyHelpers.GetBackOffTime(this.ConsecutiveErrors, headers); + } + private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEventArgs e) - { + { var webException = e.Exception as WebException; if (webException != null) - { + { this.ConsecutiveErrors++; HttpWebResponse httpWebResponse = webException.Response as HttpWebResponse; if (httpWebResponse != null) { TelemetryChannelEventSource.Log.TransmissionSendingFailedWebExceptionWarning(e.Transmission.Id, webException.Message, (int)httpWebResponse.StatusCode); - AdditionalVerboseTracing(e); + this.AdditionalVerboseTracing(e); switch (httpWebResponse.StatusCode) { @@ -72,7 +77,7 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve else { TelemetryChannelEventSource.Log.TransmissionSendingFailedWebExceptionWarning(e.Transmission.Id, webException.Message, (int)HttpStatusCode.InternalServerError); - AdditionalVerboseTracing(e); + this.AdditionalVerboseTracing(e); } } else @@ -80,18 +85,13 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve if (e.Exception != null) { TelemetryChannelEventSource.Log.TransmissionSendingFailedWarning(e.Transmission.Id, e.Exception.Message); - AdditionalVerboseTracing(e); + this.AdditionalVerboseTracing(e); } this.ConsecutiveErrors = 0; } } - protected virtual TimeSpan GetBackOffTime(NameValueCollection headers) - { - return TransmissionPolicyHelpers.GetBackOffTime(this.ConsecutiveErrors, headers); - } - private void AdditionalVerboseTracing(TransmissionProcessedEventArgs args) { // For perf reason deserialize only when verbose tracing is enabled diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs index c7984ec39a..390cdf066b 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs @@ -3,9 +3,9 @@ using System; using System.Threading.Tasks; + using Microsoft.ApplicationInsights.Channel; using Microsoft.ApplicationInsights.Channel.Implementation; - using Microsoft.ApplicationInsights.Channel; using Microsoft.ApplicationInsights.Extensibility.Implementation; #if NET45 @@ -63,7 +63,7 @@ private string ParsePartialSuccessResponse(Transmission initialTransmission, Tra this.ConsecutiveErrors = 0; return null; } - + string newTransmissions = null; if (backendResponse.ItemsAccepted != backendResponse.ItemsReceived) { diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs index 4a46515127..4070e9be66 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs @@ -1,10 +1,10 @@ -using System; -using System.Collections.Specialized; -using System.Web.Script.Serialization; -using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Implementation; - -namespace Microsoft.ApplicationInsights.Channel.Implementation +namespace Microsoft.ApplicationInsights.Channel.Implementation { + using System; + using System.Collections.Specialized; + using System.Web.Script.Serialization; + using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Implementation; + internal static class TransmissionPolicyHelpers { public const int SlotDelayInSeconds = 10; From c30d873658993feb644066d3e8272310ee165dfd Mon Sep 17 00:00:00 2001 From: abaranch Date: Tue, 24 May 2016 17:10:21 -0700 Subject: [PATCH 03/30] Checks for null --- .../TransmissionPolicyHelpers.cs | 35 +++++++++++-------- 1 file changed, 21 insertions(+), 14 deletions(-) diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs index 4070e9be66..d822811c9f 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs @@ -14,21 +14,28 @@ internal static class TransmissionPolicyHelpers public static BackendResponse GetBackendResponse(TransmissionProcessedEventArgs args) { - BackendResponse backendResponse; - string responseContent = args.Response.Content; - try - { - backendResponse = Serializer.Deserialize(responseContent); - } - catch (ArgumentException exp) - { - TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); - backendResponse = null; - } - catch (InvalidOperationException exp) + BackendResponse backendResponse = null; + + if (args != null && args.Response != null) { - TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); - backendResponse = null; + string responseContent = args.Response.Content; + try + { + if (!string.IsNullOrEmpty(responseContent)) + { + backendResponse = Serializer.Deserialize(responseContent); + } + } + catch (ArgumentException exp) + { + TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); + backendResponse = null; + } + catch (InvalidOperationException exp) + { + TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); + backendResponse = null; + } } return backendResponse; From 814e2fd4f606876e33864f9b93d5980cdb61ed96 Mon Sep 17 00:00:00 2001 From: abaranch Date: Wed, 25 May 2016 17:02:43 -0700 Subject: [PATCH 04/30] Unit tests --- .../Helpers/BackendResponseHelper.cs | 36 +++++++++++++ .../ErrorHandlingTransmissionPolicyTest.cs | 41 ++++----------- .../PartialSuccessTransmissionPolicyTest.cs | 43 +++------------- .../TransmissionPolicyHelpersTest.cs | 44 ++++++++++++++-- .../Shared.Tests/Shared.Tests.projitems | 1 + buildDebug.cmd | 15 ++++++ .../Managed/Shared/Channel/Transmission.cs | 3 +- .../ErrorHandlingTransmissionPolicy.cs | 50 +++++++++++++------ .../PartialSuccessTransmissionPolicy.cs | 7 ++- .../TelemetryChannelEventSource.cs | 5 +- .../TransmissionPolicyHelpers.cs | 32 ++++++------ 11 files changed, 171 insertions(+), 106 deletions(-) create mode 100644 Test/ServerTelemetryChannel.Test/Shared.Tests/Helpers/BackendResponseHelper.cs create mode 100644 buildDebug.cmd diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Helpers/BackendResponseHelper.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Helpers/BackendResponseHelper.cs new file mode 100644 index 0000000000..0ce886bee1 --- /dev/null +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Helpers/BackendResponseHelper.cs @@ -0,0 +1,36 @@ +namespace Microsoft.ApplicationInsights.WindowsServer.Channel.Helpers +{ + using System.Globalization; + + public static class BackendResponseHelper + { + public static string CreateBackendResponse(int itemsReceived, int itemsAccepted, string[] errorCodes, + int indexStartWith = 0) + { + string singleItem = "{{" + + "\"index\": {0}," + + "\"statusCode\": {1}," + + "\"message\": \"Explanation\"" + + "}}"; + + string errorList = string.Empty; + for (int i = 0; i < errorCodes.Length; ++i) + { + string errorCode = errorCodes[i]; + if (!string.IsNullOrEmpty(errorList)) + { + errorList += ","; + } + + errorList += string.Format(CultureInfo.InvariantCulture, singleItem, indexStartWith + i, errorCode); + } + + return + "{" + + "\"itemsReceived\": " + itemsReceived + "," + + "\"itemsAccepted\": " + itemsAccepted + "," + + "\"errors\": [" + errorList + "]" + + "}"; + } + } +} diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs index 5a89047730..830dc61adf 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs @@ -12,8 +12,8 @@ using System.Threading; using System.Threading.Tasks; using Microsoft.ApplicationInsights.Channel; - using Microsoft.ApplicationInsights.DataContracts; using Microsoft.ApplicationInsights.Extensibility.Implementation; + using Microsoft.ApplicationInsights.WindowsServer.Channel.Helpers; using Microsoft.ApplicationInsights.Web.TestFramework; using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Helpers; #if NET40 @@ -21,6 +21,8 @@ #endif using Microsoft.VisualStudio.TestTools.UnitTesting; using Assert = Xunit.Assert; + using System.Text; + using System.IO; #if NET45 using TaskEx = System.Threading.Tasks.Task; #endif @@ -206,7 +208,7 @@ public void LogsAdditionalTracesIfResponseIsProvided() policy.Initialize(transmitter); var failedTransmission = new StubTransmission(); - var response = new HttpWebResponseWrapper {Content = this.GetBackendResponse(2, 1, new[] { "123" })}; + var response = new HttpWebResponseWrapper {Content = BackendResponseHelper.CreateBackendResponse(2, 1, new[] { "123" })}; // Act: transmitter.OnTransmissionSent(new TransmissionProcessedEventArgs(failedTransmission, CreateException(statusCode: 408), response)); @@ -220,34 +222,6 @@ public void LogsAdditionalTracesIfResponseIsProvided() } } - private string GetBackendResponse(int itemsReceived, int itemsAccepted, string[] errorCodes, int indexStartWith = 0) - { - string singleItem = "{{" + - "\"index\": {0}," + - "\"statusCode\": {1}," + - "\"message\": \"Explanation\"" + - "}}"; - - string errorList = string.Empty; - for (int i = 0; i < errorCodes.Length; ++i) - { - string errorCode = errorCodes[i]; - if (!string.IsNullOrEmpty(errorList)) - { - errorList += ","; - } - - errorList += string.Format(CultureInfo.InvariantCulture, singleItem, indexStartWith + i, errorCode); - } - - return - "{" + - "\"itemsReceived\": " + itemsReceived + "," + - "\"itemsAccepted\": " + itemsAccepted + "," + - "\"errors\": [" + errorList + "]" + - "}"; - } - private static Task ThrowAsync(Exception e) { var tcs = new TaskCompletionSource(null); @@ -273,7 +247,14 @@ private static void CatchesAndLogsExceptionThrownByTransmitter(ErrorHandlingTran private static WebException CreateException(int statusCode) { + string content = BackendResponseHelper.CreateBackendResponse(3,1, new [] {"500"}); + var bytes = Encoding.UTF8.GetBytes(content); + var responseStream = new MemoryStream(); + responseStream.Write(bytes, 0, bytes.Length); + responseStream.Seek(0, SeekOrigin.Begin); + var mockWebResponse = new Moq.Mock(); + mockWebResponse.Setup(c => c.GetResponseStream()).Returns(responseStream); mockWebResponse.SetupGet((webRes) => webRes.StatusCode).Returns((HttpStatusCode)statusCode); diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/PartialSuccessTransmissionPolicyTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/PartialSuccessTransmissionPolicyTest.cs index 21d575cc3c..58ecb8c6a6 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/PartialSuccessTransmissionPolicyTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/PartialSuccessTransmissionPolicyTest.cs @@ -7,6 +7,7 @@ using Microsoft.ApplicationInsights.Channel; using Microsoft.ApplicationInsights.DataContracts; using Microsoft.ApplicationInsights.Extensibility.Implementation; + using Microsoft.ApplicationInsights.WindowsServer.Channel.Helpers; using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Helpers; using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Implementation; using Microsoft.VisualStudio.TestTools.UnitTesting; @@ -38,7 +39,7 @@ public void IfItemIsRejectedOnlyThisItemIsUploadedBack() var items = new List { new EventTelemetry(), new EventTelemetry() }; Transmission transmission = new Transmission(new Uri("http://uri"), items, "type", "encoding"); - string response = this.GetBackendResponse( + string response = BackendResponseHelper.CreateBackendResponse( itemsReceived: 2, itemsAccepted: 1, errorCodes: new[] { "429" }); @@ -69,7 +70,7 @@ public void IfItemsAreRejectedTheyAreUploadedBackAsASingleTransmission() var items = new List { new EventTelemetry(), new EventTelemetry() }; Transmission transmission = new Transmission(new Uri("http://uri"), items, "type", "encoding"); - string response = this.GetBackendResponse( + string response = BackendResponseHelper.CreateBackendResponse( itemsReceived: 3, itemsAccepted: 0, errorCodes: new[] { "408", "503", "500" }); @@ -95,7 +96,7 @@ public void IfNumberOfRecievedItemsEqualsToNumberOfAcceptedErrorsListIsIgnored() var items = new List { new EventTelemetry(), new EventTelemetry() }; Transmission transmission = new Transmission(new Uri("http://uri"), items, "type", "encoding"); - string response = this.GetBackendResponse( + string response = BackendResponseHelper.CreateBackendResponse( itemsReceived: 2, itemsAccepted: 2, errorCodes: new[] { "408", "408" }); @@ -131,7 +132,7 @@ public void NewTransmissionCreatedByIndexesFromResponse() }; Transmission transmission = new Transmission(new Uri("http://uri"), items, "type", "encoding"); - string response = this.GetBackendResponse( + string response = BackendResponseHelper.CreateBackendResponse( itemsReceived: 3, itemsAccepted: 1, errorCodes: new[] { "439", "439" }); @@ -167,7 +168,7 @@ public void IfMultipleItemsAreRejectedNumberOfErrorsIsIncreasedByOne() var items = new List { new EventTelemetry(), new EventTelemetry() }; Transmission transmission = new Transmission(new Uri("http://uri"), items, "type", "encoding"); - string response = this.GetBackendResponse( + string response = BackendResponseHelper.CreateBackendResponse( itemsReceived: 100, itemsAccepted: 95, errorCodes: new[] { "500", "500", "503", "503", "429" }); @@ -228,7 +229,7 @@ public void IfIndexMoreThanNumberOfItemsInTransmissionIgnoreError() Transmission transmission = new Transmission(new Uri("http://uri"), items, "type", "encoding"); // Index is 0-based - string response = this.GetBackendResponse( + string response = BackendResponseHelper.CreateBackendResponse( itemsReceived: 2, itemsAccepted: 1, errorCodes: new[] { "408" }, @@ -261,7 +262,7 @@ public void DoesNotSendTransmissionForUnsupportedCodes() var items = new List { new EventTelemetry(), new EventTelemetry() }; Transmission transmission = new Transmission(new Uri("http://uri"), items, "type", "encoding"); - string response = this.GetBackendResponse( + string response = BackendResponseHelper.CreateBackendResponse( itemsReceived: 50, itemsAccepted: 45, errorCodes: new[] { "400", "402", "502", "409", "417" }); @@ -277,33 +278,5 @@ public void DoesNotSendTransmissionForUnsupportedCodes() Assert.Equal(0, policy.ConsecutiveErrors); Assert.Equal(0, enqueuedTransmissions.Count); } - - private string GetBackendResponse(int itemsReceived, int itemsAccepted, string[] errorCodes, int indexStartWith = 0) - { - string singleItem = "{{" + - "\"index\": {0}," + - "\"statusCode\": {1}," + - "\"message\": \"Explanation\"" + - "}}"; - - string errorList = string.Empty; - for (int i=0; i + diff --git a/buildDebug.cmd b/buildDebug.cmd new file mode 100644 index 0000000000..c1aca7894f --- /dev/null +++ b/buildDebug.cmd @@ -0,0 +1,15 @@ +@echo off + +call "%VS120COMNTOOLS%\VsDevCmd.bat" + +SET PATH=%PATH%;%systemdrive%\Windows\Microsoft.NET\Framework\v4.0.30319\; +SET ProjectName=Msbuild.All + +SET Configuration=Debug + +SET Platform="Mixed Platforms" +msbuild dirs.proj /nologo /m:1 /fl /toolsversion:14.0 /flp:logfile=%ProjectName%.%Platform%.log;v=d /flp1:logfile=%ProjectName%.%Platform%.wrn;warningsonly /flp2:logfile=%ProjectName%.%Platform%.err;errorsonly /p:Configuration=%Configuration% /p:Platform=%Platform% /p:RunCodeAnalysis="False" /flp3:logfile=%ProjectName%.%Platform%.prf;performancesummary /flp4:logfile=%ProjectName%.%Platform%.exec.log;showcommandline /p:BuildSingleFilePackage=true + +PAUSE + + diff --git a/src/Core/Managed/Shared/Channel/Transmission.cs b/src/Core/Managed/Shared/Channel/Transmission.cs index 116a1e52cb..e53b31e80c 100644 --- a/src/Core/Managed/Shared/Channel/Transmission.cs +++ b/src/Core/Managed/Shared/Channel/Transmission.cs @@ -236,8 +236,7 @@ private async Task SendRequestAsync(WebRequest request) { // Return content only for 206 for performance reasons // Currently we do not need it in other cases - if (httpResponse.StatusCode == HttpStatusCode.PartialContent || - CoreEventSource.Log.IsVerboseEnabled) + if (httpResponse.StatusCode == HttpStatusCode.PartialContent) { wrapper = new HttpWebResponseWrapper { diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs index 08da01256e..d07072e17e 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs @@ -2,12 +2,13 @@ { using System; using System.Collections.Specialized; + using System.IO; using System.Net; using System.Threading.Tasks; using Microsoft.ApplicationInsights.Channel.Implementation; using Microsoft.ApplicationInsights.Extensibility.Implementation; - + #if NET45 using TaskEx = System.Threading.Tasks.Task; #endif @@ -44,8 +45,12 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve HttpWebResponse httpWebResponse = webException.Response as HttpWebResponse; if (httpWebResponse != null) { - TelemetryChannelEventSource.Log.TransmissionSendingFailedWebExceptionWarning(e.Transmission.Id, webException.Message, (int)httpWebResponse.StatusCode); - this.AdditionalVerboseTracing(e); + TelemetryChannelEventSource.Log.TransmissionSendingFailedWebExceptionWarning( + e.Transmission.Id, + webException.Message, + (int)httpWebResponse.StatusCode, + httpWebResponse.StatusDescription); + this.AdditionalVerboseTracing(httpWebResponse); switch (httpWebResponse.StatusCode) { @@ -76,8 +81,7 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve } else { - TelemetryChannelEventSource.Log.TransmissionSendingFailedWebExceptionWarning(e.Transmission.Id, webException.Message, (int)HttpStatusCode.InternalServerError); - this.AdditionalVerboseTracing(e); + TelemetryChannelEventSource.Log.TransmissionSendingFailedWebExceptionWarning(e.Transmission.Id, webException.Message, (int)HttpStatusCode.InternalServerError, null); } } else @@ -85,30 +89,48 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve if (e.Exception != null) { TelemetryChannelEventSource.Log.TransmissionSendingFailedWarning(e.Transmission.Id, e.Exception.Message); - this.AdditionalVerboseTracing(e); } this.ConsecutiveErrors = 0; } } - private void AdditionalVerboseTracing(TransmissionProcessedEventArgs args) + private void AdditionalVerboseTracing(HttpWebResponse httpResponse) { // For perf reason deserialize only when verbose tracing is enabled - if (TelemetryChannelEventSource.Log.IsVerboseEnabled) + if (TelemetryChannelEventSource.Log.IsVerboseEnabled && httpResponse != null) { - BackendResponse backendResponse = TransmissionPolicyHelpers.GetBackendResponse(args); - - if (backendResponse != null && backendResponse.Errors != null) + try { - foreach (var error in backendResponse.Errors) + var stream = httpResponse.GetResponseStream(); + if (stream != null) { - if (error != null) + using (StreamReader content = new StreamReader(stream)) { - TelemetryChannelEventSource.Log.ItemRejectedByEndpointWarning(error.Message); + string response = content.ReadToEnd(); + + if (!string.IsNullOrEmpty(response)) + { + BackendResponse backendResponse = TransmissionPolicyHelpers.GetBackendResponse(response); + + if (backendResponse != null && backendResponse.Errors != null) + { + foreach (var error in backendResponse.Errors) + { + if (error != null) + { + TelemetryChannelEventSource.Log.ItemRejectedByEndpointWarning(error.Message); + } + } + } + } } } } + catch (Exception) + { + // This code is for tracing purposes only; it cannot not throw + } } } diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs index 390cdf066b..ade16cc9c5 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs @@ -56,7 +56,12 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve private string ParsePartialSuccessResponse(Transmission initialTransmission, TransmissionProcessedEventArgs args) { - BackendResponse backendResponse = TransmissionPolicyHelpers.GetBackendResponse(args); + BackendResponse backendResponse = null; + + if (args != null && args.Response != null) + { + backendResponse = TransmissionPolicyHelpers.GetBackendResponse(args.Response.Content); + } if (backendResponse == null) { diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs index d93c399194..aed1d5dde4 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs @@ -144,14 +144,15 @@ public void TransmissionSentSuccessfully(string transmissionId, int capacity, st this.WriteEvent(22, transmissionId ?? string.Empty, capacity, this.ApplicationName); } - [Event(23, Message = "TransmissionSendingFailed. TransmissionId: {0}. Message: {1}. StatusCode: {2}.", Level = EventLevel.Warning)] - public void TransmissionSendingFailedWebExceptionWarning(string transmissionId, string exceptionMessage, int statusCode, string appDomainName = "Incorrect") + [Event(23, Message = "TransmissionSendingFailed. TransmissionId: {0}. Message: {1}. StatusCode: {2}. Description: {3}.", Level = EventLevel.Warning)] + public void TransmissionSendingFailedWebExceptionWarning(string transmissionId, string exceptionMessage, int statusCode, string description, string appDomainName = "Incorrect") { this.WriteEvent( 23, transmissionId ?? string.Empty, exceptionMessage ?? string.Empty, statusCode, + description ?? string.Empty, this.ApplicationName); } diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs index d822811c9f..fb1267b7b1 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs @@ -12,31 +12,27 @@ internal static class TransmissionPolicyHelpers private static readonly Random Random = new Random(); private static readonly JavaScriptSerializer Serializer = new JavaScriptSerializer(); - public static BackendResponse GetBackendResponse(TransmissionProcessedEventArgs args) + public static BackendResponse GetBackendResponse(string responseContent) { BackendResponse backendResponse = null; - if (args != null && args.Response != null) + try { - string responseContent = args.Response.Content; - try + if (!string.IsNullOrEmpty(responseContent)) { - if (!string.IsNullOrEmpty(responseContent)) - { - backendResponse = Serializer.Deserialize(responseContent); - } - } - catch (ArgumentException exp) - { - TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); - backendResponse = null; - } - catch (InvalidOperationException exp) - { - TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); - backendResponse = null; + backendResponse = Serializer.Deserialize(responseContent); } } + catch (ArgumentException exp) + { + TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); + backendResponse = null; + } + catch (InvalidOperationException exp) + { + TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); + backendResponse = null; + } return backendResponse; } From 795d9d945db17bbb69e0ad3b3f77e9e78207486d Mon Sep 17 00:00:00 2001 From: abaranch Date: Wed, 1 Jun 2016 12:59:15 -0700 Subject: [PATCH 05/30] Change version format from x.x.x.x to x.x.x-x --- .gitignore | 1 + Test/CoreSDK.Test/Shared/TelemetryClientTest.cs | 8 +++++++- src/Core/Managed/Shared/TelemetryClient.cs | 14 +++++++++----- 3 files changed, 17 insertions(+), 6 deletions(-) diff --git a/.gitignore b/.gitignore index 91f96a8e1e..6919f1ca9c 100644 --- a/.gitignore +++ b/.gitignore @@ -6,6 +6,7 @@ *.user *.sln.docstates .vs +*.sln.dotsettings # Build results [Dd]ebug/ diff --git a/Test/CoreSDK.Test/Shared/TelemetryClientTest.cs b/Test/CoreSDK.Test/Shared/TelemetryClientTest.cs index fb3388b6fc..37a23ec00e 100644 --- a/Test/CoreSDK.Test/Shared/TelemetryClientTest.cs +++ b/Test/CoreSDK.Test/Shared/TelemetryClientTest.cs @@ -733,6 +733,12 @@ public void TrackWhenChannelIsNullWillThrowInvalidOperationException() [TestMethod] public void TrackAddsSdkVerionByDefault() { + string versonStr = Assembly.GetAssembly(typeof(TelemetryConfiguration)).GetCustomAttributes(false) + .OfType() + .First() + .Version; + Version version = new Version(versonStr); + var configuration = new TelemetryConfiguration { TelemetryChannel = new StubTelemetryChannel(), InstrumentationKey = Guid.NewGuid().ToString() }; var client = new TelemetryClient(configuration); @@ -740,7 +746,7 @@ public void TrackAddsSdkVerionByDefault() EventTelemetry eventTelemetry = new EventTelemetry("test"); client.Track(eventTelemetry); - Assert.StartsWith("dotnet: ", eventTelemetry.Context.Internal.SdkVersion); + Assert.Equal("dotnet:"+ version.ToString(3) + "-" + version.Revision, eventTelemetry.Context.Internal.SdkVersion); } [TestMethod] diff --git a/src/Core/Managed/Shared/TelemetryClient.cs b/src/Core/Managed/Shared/TelemetryClient.cs index c576b3240a..d582f0979d 100644 --- a/src/Core/Managed/Shared/TelemetryClient.cs +++ b/src/Core/Managed/Shared/TelemetryClient.cs @@ -18,7 +18,7 @@ /// public sealed class TelemetryClient { - private const string VersionPrefix = "dotnet: "; + private const string VersionPrefix = "dotnet:"; private readonly TelemetryConfiguration configuration; private TelemetryContext context; @@ -369,7 +369,7 @@ public void Initialize(ITelemetry telemetry) // Currenly backend requires SDK version to comply "name: version" if (string.IsNullOrEmpty(telemetry.Context.Internal.SdkVersion)) { - var version = LazyInitializer.EnsureInitialized(ref this.sdkVersion, this.GetAssemblyVersion); + var version = LazyInitializer.EnsureInitialized(ref this.sdkVersion, this.GetSdkVersion); telemetry.Context.Internal.SdkVersion = version; } } @@ -432,18 +432,22 @@ public void Flush() this.configuration.TelemetryChannel.Flush(); } - private string GetAssemblyVersion() + private string GetSdkVersion() { #if !CORE_PCL - return VersionPrefix + typeof(TelemetryClient).Assembly.GetCustomAttributes(false) + string versionStr = typeof(TelemetryClient).Assembly.GetCustomAttributes(false) .OfType() .First() .Version; + #else - return VersionPrefix + typeof(TelemetryClient).GetTypeInfo().Assembly.GetCustomAttributes() + string versionStr = typeof(TelemetryClient).GetTypeInfo().Assembly.GetCustomAttributes() .First() .Version; #endif + + Version version = new Version(versionStr); + return VersionPrefix + version.ToString(3) + "-" + version.Revision; } } } From 16875fc44d86298c98e8c69d5d85a087ec313235 Mon Sep 17 00:00:00 2001 From: abaranch Date: Wed, 1 Jun 2016 13:16:00 -0700 Subject: [PATCH 06/30] Fix unit test --- .../Implementation/ErrorHandlingTransmissionPolicyTest.cs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs index 830dc61adf..75b2462aaf 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs @@ -214,8 +214,8 @@ public void LogsAdditionalTracesIfResponseIsProvided() transmitter.OnTransmissionSent(new TransmissionProcessedEventArgs(failedTransmission, CreateException(statusCode: 408), response)); // Assert: - var traces = listener.Messages.ToList(); - Assert.True(traces.Count > 2); + var traces = listener.Messages.Where(item => item.Level == EventLevel.Warning).ToList(); + Assert.Equal(2, traces.Count); Assert.Equal(23, traces[0].EventId); // failed to send Assert.Equal(7, traces[1].EventId); // additional trace Assert.Equal("Explanation", traces[1].Payload[0]); From edf17c13c81efc0abcc497925fb0f51cc994fad7 Mon Sep 17 00:00:00 2001 From: abaranch Date: Thu, 2 Jun 2016 14:20:36 -0700 Subject: [PATCH 07/30] Change unit test --- Test/CoreSDK.Test/Shared/TelemetryClientTest.cs | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/Test/CoreSDK.Test/Shared/TelemetryClientTest.cs b/Test/CoreSDK.Test/Shared/TelemetryClientTest.cs index 37a23ec00e..a8de55366a 100644 --- a/Test/CoreSDK.Test/Shared/TelemetryClientTest.cs +++ b/Test/CoreSDK.Test/Shared/TelemetryClientTest.cs @@ -733,11 +733,12 @@ public void TrackWhenChannelIsNullWillThrowInvalidOperationException() [TestMethod] public void TrackAddsSdkVerionByDefault() { + // split version by 4 numbers manually so we do not do the same as in the product code and actually test it string versonStr = Assembly.GetAssembly(typeof(TelemetryConfiguration)).GetCustomAttributes(false) .OfType() .First() .Version; - Version version = new Version(versonStr); + string[] versionParts = new Version(versonStr).ToString().Split('.'); var configuration = new TelemetryConfiguration { TelemetryChannel = new StubTelemetryChannel(), InstrumentationKey = Guid.NewGuid().ToString() }; var client = new TelemetryClient(configuration); @@ -746,7 +747,7 @@ public void TrackAddsSdkVerionByDefault() EventTelemetry eventTelemetry = new EventTelemetry("test"); client.Track(eventTelemetry); - Assert.Equal("dotnet:"+ version.ToString(3) + "-" + version.Revision, eventTelemetry.Context.Internal.SdkVersion); + Assert.Equal("dotnet:"+ string.Join(".", versionParts[0], versionParts[1], versionParts[2]) + "-" + versionParts[3], eventTelemetry.Context.Internal.SdkVersion); } [TestMethod] From da89f8aa9079a26c4508959997f4d9482e321485 Mon Sep 17 00:00:00 2001 From: abaranch Date: Thu, 2 Jun 2016 16:03:41 -0700 Subject: [PATCH 08/30] Start 2.2-beta1 --- GlobalStaticVersion.props | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/GlobalStaticVersion.props b/GlobalStaticVersion.props index f12d9de439..35a83bfc6b 100644 --- a/GlobalStaticVersion.props +++ b/GlobalStaticVersion.props @@ -6,14 +6,14 @@ Update for every public release. --> 2 - 1 + 2 0 - beta4 + beta1 - 2016-03-08 + 2016-06-02 .PreReleaseVersion $(MSBuildThisFileDirectory)$(PreReleaseVersionFileName) From 8c02b66eed7ccded6a53804c8cab4834dde40273 Mon Sep 17 00:00:00 2001 From: abaranch Date: Mon, 6 Jun 2016 13:59:55 -0700 Subject: [PATCH 09/30] Add check against Validate endpoint --- .../Net40/Core.Net40.Tests.csproj | 10 +++ Test/CoreSDK.Test/Net40/packages.config | 1 + .../Shared/TelemetryClientTest.cs | 70 ++++++++++++++++++- 3 files changed, 80 insertions(+), 1 deletion(-) diff --git a/Test/CoreSDK.Test/Net40/Core.Net40.Tests.csproj b/Test/CoreSDK.Test/Net40/Core.Net40.Tests.csproj index f07f1d6971..8c23bc8f1e 100644 --- a/Test/CoreSDK.Test/Net40/Core.Net40.Tests.csproj +++ b/Test/CoreSDK.Test/Net40/Core.Net40.Tests.csproj @@ -63,6 +63,16 @@ + + + ..\..\..\..\packages\Microsoft.Net.Http.2.2.29\lib\net45\System.Net.Http.Extensions.dll + True + + + ..\..\..\..\packages\Microsoft.Net.Http.2.2.29\lib\net45\System.Net.Http.Primitives.dll + True + + diff --git a/Test/CoreSDK.Test/Net40/packages.config b/Test/CoreSDK.Test/Net40/packages.config index 39bccfd597..338f4b0737 100644 --- a/Test/CoreSDK.Test/Net40/packages.config +++ b/Test/CoreSDK.Test/Net40/packages.config @@ -6,6 +6,7 @@ + diff --git a/Test/CoreSDK.Test/Shared/TelemetryClientTest.cs b/Test/CoreSDK.Test/Shared/TelemetryClientTest.cs index a8de55366a..f405fdb01b 100644 --- a/Test/CoreSDK.Test/Shared/TelemetryClientTest.cs +++ b/Test/CoreSDK.Test/Shared/TelemetryClientTest.cs @@ -3,14 +3,19 @@ using System; using System.Collections.Generic; using System.ComponentModel; + using System.Diagnostics; #if CORE_PCL || NET45 || NET46 using System.Diagnostics.Tracing; #endif using System.Linq; + using System.Net; + using System.Net.Http; using System.Reflection; + using System.Text; using Microsoft.ApplicationInsights.Channel; using Microsoft.ApplicationInsights.DataContracts; using Microsoft.ApplicationInsights.Extensibility; + using Microsoft.ApplicationInsights.Extensibility.Implementation; using Microsoft.ApplicationInsights.Extensibility.Implementation.Platform; using Microsoft.ApplicationInsights.Extensibility.Implementation.Tracing; using Microsoft.ApplicationInsights.TestFramework; @@ -786,7 +791,70 @@ public void AllTelemetryIsSentWithDefaultSamplingRate() Assert.Equal(ItemsToGenerate, sentTelemetry.Count); } - + + #endregion + + #region ValidateEndpoint + + [TestMethod] + public void SendEventToValidateEndpoint() + { + EventTelemetry telemetry1 = new EventTelemetry(); + MetricTelemetry telemetry2 = new MetricTelemetry(); + DependencyTelemetry telemetry3 = new DependencyTelemetry(); + ExceptionTelemetry telemetry4 = new ExceptionTelemetry(); + MetricTelemetry telemetry5 = new MetricTelemetry(); + PageViewTelemetry telemetry6 = new PageViewTelemetry(); + PerformanceCounterTelemetry telemetry7 = new PerformanceCounterTelemetry(); + RequestTelemetry telemetry8 = new RequestTelemetry(); + SessionStateTelemetry telemetry9 = new SessionStateTelemetry(); + TraceTelemetry telemetry10 = new TraceTelemetry(); + + var telemetryItems = new List + { + telemetry1, + telemetry2, + telemetry3, + telemetry4, + telemetry5, + telemetry6, + telemetry7, + telemetry8, + telemetry9, + telemetry10 + }; + + // ChuckNorrisTeamUnitTests resource in Prototypes5 + var config = new TelemetryConfiguration { InstrumentationKey = "fafa4b10-03d3-4bb0-98f4-364f0bdf5df8" }; + var telemetryClient = new TelemetryClient(config); + + telemetryClient.Initialize(telemetry1); + telemetryClient.Initialize(telemetry2); + telemetryClient.Initialize(telemetry3); + telemetryClient.Initialize(telemetry4); + telemetryClient.Initialize(telemetry5); + telemetryClient.Initialize(telemetry6); + telemetryClient.Initialize(telemetry7); + telemetryClient.Initialize(telemetry8); + telemetryClient.Initialize(telemetry9); + telemetryClient.Initialize(telemetry10); + + string json = JsonSerializer.SerializeAsString(telemetryItems); + + HttpClient client = new HttpClient(); + var result = client.PostAsync( + "https://dc.services.visualstudio.com/v2/validate", + new ByteArrayContent(Encoding.UTF8.GetBytes(json))).GetAwaiter().GetResult(); + + if (result.StatusCode != HttpStatusCode.OK) + { + var response = result.Content.ReadAsStringAsync().GetAwaiter().GetResult(); + Trace.WriteLine(response); + } + + Assert.Equal(HttpStatusCode.OK, result.StatusCode); + } + #endregion private TelemetryClient InitializeTelemetryClient(ICollection sentTelemetry) From 17d1c7f481e9b10959cc1cc9b35deb52bcbd01c5 Mon Sep 17 00:00:00 2001 From: David Duffy Date: Tue, 7 Jun 2016 18:22:41 -0700 Subject: [PATCH 10/30] Switched to using reflection to create the desired condition for testing an expected exception. --- Test/CoreSDK.Test/Shared/Channel/TransmissionTest.cs | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/Test/CoreSDK.Test/Shared/Channel/TransmissionTest.cs b/Test/CoreSDK.Test/Shared/Channel/TransmissionTest.cs index a2ef471e7c..4ff7cc46c0 100644 --- a/Test/CoreSDK.Test/Shared/Channel/TransmissionTest.cs +++ b/Test/CoreSDK.Test/Shared/Channel/TransmissionTest.cs @@ -3,6 +3,7 @@ using System; using System.IO; using System.Net; + using System.Reflection; using System.Text; using System.Threading; using System.Threading.Tasks; @@ -160,11 +161,12 @@ public void ThrowsInvalidOperationExceptionWhenTransmissionIsAlreadySending() { var request = new StubWebRequest(); request.OnBeginGetRequestStream = (callback, state) => TaskEx.Delay(TimeSpan.FromMilliseconds(10)).AsAsyncResult(callback, request); - + var transmission = new TestableTransmission(); transmission.OnCreateRequest = uri => request; - - Task dontWait = transmission.SendAsync(); + + FieldInfo isSendingField = typeof(Transmission).GetField("isSending", BindingFlags.NonPublic | BindingFlags.Instance); + isSendingField.SetValue(transmission, 1, BindingFlags.SetField | BindingFlags.NonPublic | BindingFlags.Instance, null, null); await AssertEx.ThrowsAsync(() => transmission.SendAsync()); }); } From 45fae90d0cb583f53440c15a07d98750d3e9c357 Mon Sep 17 00:00:00 2001 From: David Duffy Date: Wed, 8 Jun 2016 14:30:05 -0700 Subject: [PATCH 11/30] Removed unneeded code. --- Test/CoreSDK.Test/Shared/Channel/TransmissionTest.cs | 5 ----- 1 file changed, 5 deletions(-) diff --git a/Test/CoreSDK.Test/Shared/Channel/TransmissionTest.cs b/Test/CoreSDK.Test/Shared/Channel/TransmissionTest.cs index 4ff7cc46c0..95be2d3789 100644 --- a/Test/CoreSDK.Test/Shared/Channel/TransmissionTest.cs +++ b/Test/CoreSDK.Test/Shared/Channel/TransmissionTest.cs @@ -159,12 +159,7 @@ public void ThrowsInvalidOperationExceptionWhenTransmissionIsAlreadySending() { AsyncTest.Run(async () => { - var request = new StubWebRequest(); - request.OnBeginGetRequestStream = (callback, state) => TaskEx.Delay(TimeSpan.FromMilliseconds(10)).AsAsyncResult(callback, request); - var transmission = new TestableTransmission(); - transmission.OnCreateRequest = uri => request; - FieldInfo isSendingField = typeof(Transmission).GetField("isSending", BindingFlags.NonPublic | BindingFlags.Instance); isSendingField.SetValue(transmission, 1, BindingFlags.SetField | BindingFlags.NonPublic | BindingFlags.Instance, null, null); await AssertEx.ThrowsAsync(() => transmission.SendAsync()); From d10ae54b705a7206a4c31278cfb88ce04698c7ba Mon Sep 17 00:00:00 2001 From: abaranch Date: Thu, 9 Jun 2016 15:43:13 -0700 Subject: [PATCH 12/30] Add ExceptionTelemetry.Message property --- CHANGELOG.md | 5 ++ .../DataContracts/ExceptionTelemetryTest.cs | 50 +++++++++++++++++++ .../DataContracts/ExceptionTelemetry.cs | 41 +++++++++++++-- 3 files changed, 92 insertions(+), 4 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index b4e3ed027f..7a852be2f5 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,11 @@ This changelog will be used to generate documentation on [release notes page](http://azure.microsoft.com/en-us/documentation/articles/app-insights-release-notes-dotnet/). + +## Version 2.2.0-beta1 + +- Add ExceptionTelemetry.Message property. If it is provided it is used instead of Exception.Message property for the ounter-most exception. + ## Version 2.1.0-beta4 - [Bug fix](https://github.com/Microsoft/ApplicationInsights-dotnet-server/issues/76) diff --git a/Test/CoreSDK.Test/Shared/DataContracts/ExceptionTelemetryTest.cs b/Test/CoreSDK.Test/Shared/DataContracts/ExceptionTelemetryTest.cs index aeacd6da34..375b177bf6 100644 --- a/Test/CoreSDK.Test/Shared/DataContracts/ExceptionTelemetryTest.cs +++ b/Test/CoreSDK.Test/Shared/DataContracts/ExceptionTelemetryTest.cs @@ -110,6 +110,56 @@ public void SerializeWritesItemVersionAsExpectedByEndpoint() Assert.Equal(2, item.Data.BaseData.Ver); } + [TestMethod] + public void SerializeUsesExceptionMessageIfTelemetryMessageNotProvided() + { + ExceptionTelemetry original = CreateExceptionTelemetry(new ArgumentException("Test")); + var item = TelemetryItemTestHelper.SerializeDeserializeTelemetryItem(original); + + Assert.Equal("Test", item.Data.BaseData.Exceptions[0].Message); + } + + [TestMethod] + public void SerializeTelemetryMessageAsOuterExceptionMessage() + { + ExceptionTelemetry original = CreateExceptionTelemetry(new ArgumentException("Test")); + original.Message = "Custom"; + var item = TelemetryItemTestHelper.SerializeDeserializeTelemetryItem(original); + + Assert.Equal("Custom", item.Data.BaseData.Exceptions[0].Message); + } + + [TestMethod] + public void SerializeUsesExceptionMessageForInnerExceptions() + { + Exception outerException = new ArgumentException("Outer", new Exception("Inner")); + ExceptionTelemetry original = CreateExceptionTelemetry(outerException); + + original.Message = "Custom"; + var item = TelemetryItemTestHelper.SerializeDeserializeTelemetryItem(original); + + Assert.Equal("Custom", item.Data.BaseData.Exceptions[0].Message); + Assert.Equal("Inner", item.Data.BaseData.Exceptions[1].Message); + } + + [TestMethod] + public void SerializeUsesExceptionMessageForInnerAggregateExceptions() + { + Exception innerException1 = new ArgumentException("Inner1"); + Exception innerException2 = new ArgumentException("Inner2"); + + AggregateException aggregateException = new AggregateException("AggregateException", new [] {innerException1, innerException2}); + + ExceptionTelemetry original = CreateExceptionTelemetry(aggregateException); + + original.Message = "Custom"; + var item = TelemetryItemTestHelper.SerializeDeserializeTelemetryItem(original); + + Assert.Equal("Custom", item.Data.BaseData.Exceptions[0].Message); + Assert.Equal("Inner1", item.Data.BaseData.Exceptions[1].Message); + Assert.Equal("Inner2", item.Data.BaseData.Exceptions[2].Message); + } + [TestMethod] public void SerializeWritesItemHandledAtAsExpectedByEndpoint() { diff --git a/src/Core/Managed/Shared/DataContracts/ExceptionTelemetry.cs b/src/Core/Managed/Shared/DataContracts/ExceptionTelemetry.cs index 4486aa94ba..3cd75a9503 100644 --- a/src/Core/Managed/Shared/DataContracts/ExceptionTelemetry.cs +++ b/src/Core/Managed/Shared/DataContracts/ExceptionTelemetry.cs @@ -20,6 +20,7 @@ public sealed class ExceptionTelemetry : ITelemetry, ISupportProperties, ISuppor private readonly TelemetryContext context; private Exception exception; + private string message; private double samplingPercentage = Constants.DefaultSamplingPercentage; @@ -92,6 +93,31 @@ public Exception Exception } } + /// + /// Gets and sets ExceptionTelemetry message. + /// + public string Message + { + get + { + return this.message; + } + + set + { + this.message = value; + + if (this.Data.exceptions != null && this.Data.exceptions.Count > 0) + { + this.Data.exceptions[0].message = value; + } + else + { + this.UpdateExceptions(this.Exception); + } + } + } + /// /// Gets a dictionary of application-defined exception metrics. /// @@ -141,7 +167,7 @@ void ITelemetry.Sanitize() this.Metrics.SanitizeMeasurements(); } - private static void ConvertExceptionTree(Exception exception, ExceptionDetails parentExceptionDetails, List exceptions) + private void ConvertExceptionTree(Exception exception, ExceptionDetails parentExceptionDetails, List exceptions) { if (exception == null) { @@ -149,6 +175,13 @@ private static void ConvertExceptionTree(Exception exception, ExceptionDetails p } ExceptionDetails exceptionDetails = PlatformSingleton.Current.GetExceptionDetails(exception, parentExceptionDetails); + + // For upper level exception see if Message was provided and do not use exceptiom.message in that case + if (parentExceptionDetails == null && !string.IsNullOrWhiteSpace(this.Message)) + { + exceptionDetails.message = this.Message; + } + exceptions.Add(exceptionDetails); AggregateException aggregate = exception as AggregateException; @@ -156,12 +189,12 @@ private static void ConvertExceptionTree(Exception exception, ExceptionDetails p { foreach (Exception inner in aggregate.InnerExceptions) { - ExceptionTelemetry.ConvertExceptionTree(inner, exceptionDetails, exceptions); + this.ConvertExceptionTree(inner, exceptionDetails, exceptions); } } else if (exception.InnerException != null) { - ExceptionTelemetry.ConvertExceptionTree(exception.InnerException, exceptionDetails, exceptions); + this.ConvertExceptionTree(exception.InnerException, exceptionDetails, exceptions); } } @@ -169,7 +202,7 @@ private void UpdateExceptions(Exception exception) { // collect the set of exceptions detail info from the passed in exception List exceptions = new List(); - ExceptionTelemetry.ConvertExceptionTree(exception, null, exceptions); + this.ConvertExceptionTree(exception, null, exceptions); // trim if we have too many, also add a custom exception to let the user know we're trimed if (exceptions.Count > Constants.MaxExceptionCountToSave) From cd30deea04657b4045c38895b0fd3c2e63770b73 Mon Sep 17 00:00:00 2001 From: abaranch Date: Thu, 9 Jun 2016 15:46:32 -0700 Subject: [PATCH 13/30] Stylecop --- src/Core/Managed/Shared/DataContracts/ExceptionTelemetry.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Core/Managed/Shared/DataContracts/ExceptionTelemetry.cs b/src/Core/Managed/Shared/DataContracts/ExceptionTelemetry.cs index 3cd75a9503..4539ff9d53 100644 --- a/src/Core/Managed/Shared/DataContracts/ExceptionTelemetry.cs +++ b/src/Core/Managed/Shared/DataContracts/ExceptionTelemetry.cs @@ -94,7 +94,7 @@ public Exception Exception } /// - /// Gets and sets ExceptionTelemetry message. + /// Gets or sets ExceptionTelemetry message. /// public string Message { From aa08808d2520f90c0f96fc1ce2913ec0220ff8d8 Mon Sep 17 00:00:00 2001 From: abaranch Date: Mon, 13 Jun 2016 13:31:19 -0700 Subject: [PATCH 14/30] Make unit test more stable --- .../TestFramework/Shared/TestEventListener.cs | 17 +++++++++++++---- .../TestFramework/Shared/TestEventListener.cs | 15 +++++++-------- 2 files changed, 20 insertions(+), 12 deletions(-) diff --git a/Test/CoreSDK.Test/TestFramework/Shared/TestEventListener.cs b/Test/CoreSDK.Test/TestFramework/Shared/TestEventListener.cs index 5b3b5b3ca5..7bf36b14d3 100644 --- a/Test/CoreSDK.Test/TestFramework/Shared/TestEventListener.cs +++ b/Test/CoreSDK.Test/TestFramework/Shared/TestEventListener.cs @@ -1,6 +1,7 @@ namespace Microsoft.ApplicationInsights.TestFramework { using System; + using System.Collections.Concurrent; using System.Collections.Generic; #if CORE_PCL || NET45 || NET46 using System.Diagnostics.Tracing; @@ -12,12 +13,12 @@ internal class TestEventListener : EventListener { - private readonly Queue events; + private readonly ConcurrentQueue events; private readonly AutoResetEvent eventWritten; public TestEventListener() { - this.events = new Queue(); + this.events = new ConcurrentQueue(); this.eventWritten = new AutoResetEvent(false); this.OnOnEventWritten = e => { @@ -40,8 +41,16 @@ public IEnumerable Messages } while (this.events.Count != 0) - { - yield return this.events.Dequeue(); + { + EventWrittenEventArgs nextEvent; + if (this.events.TryDequeue(out nextEvent)) + { + yield return nextEvent; + } + else + { + throw new InvalidOperationException(); + } } } } diff --git a/Test/ServerTelemetryChannel.Test/TestFramework/Shared/TestEventListener.cs b/Test/ServerTelemetryChannel.Test/TestFramework/Shared/TestEventListener.cs index f0d1134845..5e0cf06357 100644 --- a/Test/ServerTelemetryChannel.Test/TestFramework/Shared/TestEventListener.cs +++ b/Test/ServerTelemetryChannel.Test/TestFramework/Shared/TestEventListener.cs @@ -1,6 +1,7 @@ namespace Microsoft.ApplicationInsights.Web.TestFramework { using System; + using System.Collections.Concurrent; using System.Collections.Generic; #if NET45 @@ -13,14 +14,15 @@ internal class TestEventListener : EventListener { - private readonly IList events; + private readonly ConcurrentQueue events; public TestEventListener() { - this.events = new List(); + this.events = new ConcurrentQueue(); + this.OnOnEventWritten = e => { - this.events.Add(e); + this.events.Enqueue(e); }; } @@ -28,12 +30,9 @@ public TestEventListener() public Action OnOnEventWritten { get; set; } - public IList Messages + public IEnumerable Messages { - get - { - return this.events; - } + get { return this.events; } } protected override void OnEventWritten(EventWrittenEventArgs eventData) From 9dd4b549cc6afedab1a9a650e88be72297f64f7f Mon Sep 17 00:00:00 2001 From: abaranch Date: Thu, 16 Jun 2016 15:52:34 -0700 Subject: [PATCH 15/30] Allow excluding types from sampling --- .../AdaptiveSamplingTelemetryProcessorTest.cs | 16 ++ ...etryProcessorChainBuilderExtensionsTest.cs | 124 ++++++++++++++ .../SamplingTelemetryProcessorTest.cs | 160 +++++++++++++++--- .../Shared.Tests/Shared.Tests.projitems | 1 + .../AdaptiveSamplingTelemetryProcessor.cs | 26 ++- .../TelemetryChannelEventSource.cs | 6 + .../Shared/SamplingTelemetryProcessor.cs | 111 ++++++++++-- .../TelemetryChannelBuilderExtensions.cs | 78 ++++++++- 8 files changed, 474 insertions(+), 48 deletions(-) create mode 100644 Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TelemetryProcessorChainBuilderExtensionsTest.cs diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/AdaptiveSamplingTelemetryProcessorTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/AdaptiveSamplingTelemetryProcessorTest.cs index 083309a67c..28fce4f990 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/AdaptiveSamplingTelemetryProcessorTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/AdaptiveSamplingTelemetryProcessorTest.cs @@ -3,7 +3,9 @@ using System; using System.Collections.Generic; using System.Diagnostics; + using System.Reflection; using System.Threading; + using Microsoft.ApplicationInsights.Channel; using Microsoft.ApplicationInsights.DataContracts; using Microsoft.ApplicationInsights.Extensibility; @@ -194,6 +196,20 @@ public void SamplingPercentageAdjustsForSpikyProductionRate() Assert.True(sentTelemetry.Count < targetItemCount + tolerance); } + [TestMethod] + public void AdaptiveSamplingSetsExcludedTypesOnInternalSamplingProcessor() + { + var tc = new TelemetryConfiguration { TelemetryChannel = new StubTelemetryChannel() }; + var channelBuilder = new TelemetryProcessorChainBuilder(tc); + channelBuilder.UseAdaptiveSampling(5, "request;"); + channelBuilder.Build(); + + var fieldInfo = typeof(AdaptiveSamplingTelemetryProcessor).GetField("samplingProcessor", BindingFlags.GetField | BindingFlags.Instance | BindingFlags.NonPublic); + SamplingTelemetryProcessor internalProcessor = (SamplingTelemetryProcessor) fieldInfo.GetValue(tc.TelemetryProcessorChain.FirstTelemetryProcessor); + + Assert.Equal("request;", internalProcessor.ExcludedTypes); + } + private void TraceSamplingPercentageEvaluation( double afterSamplingTelemetryItemRatePerSecond, double currentSamplingPercentage, diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TelemetryProcessorChainBuilderExtensionsTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TelemetryProcessorChainBuilderExtensionsTest.cs new file mode 100644 index 0000000000..c3fe249dd2 --- /dev/null +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TelemetryProcessorChainBuilderExtensionsTest.cs @@ -0,0 +1,124 @@ +namespace Microsoft.ApplicationInsights.WindowsServer.Channel.Implementation +{ + using System; + using Microsoft.ApplicationInsights.Extensibility; + using Microsoft.ApplicationInsights.Extensibility.Implementation; + using Microsoft.ApplicationInsights.Web.TestFramework; + using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel; + using Microsoft.VisualStudio.TestTools.UnitTesting; + + using Assert = Xunit.Assert; + + [TestClass] + public class TelemetryProcessorChainBuilderExtensionsTest + { + [TestMethod] + public void UseSamplingThrowsArgumentNullExceptionBuilderIsNull() + { + Assert.Throws(() => TelemetryProcessorChainBuilderExtensions.UseSampling(null, 5)); + } + + [TestMethod] + public void UseSamplingSetsAddsSamplingProcessorToTheChainWithCorrectPercentage() + { + var tc = new TelemetryConfiguration { TelemetryChannel = new StubTelemetryChannel() }; + var channelBuilder = new TelemetryProcessorChainBuilder(tc); + channelBuilder.UseSampling(5); + channelBuilder.Build(); + + Assert.Equal(5, ((SamplingTelemetryProcessor) tc.TelemetryProcessorChain.FirstTelemetryProcessor).SamplingPercentage); + } + + [TestMethod] + public void UseSamplingSetsAddsSamplingProcessorToTheChainWithCorrectExcludedTypes() + { + var tc = new TelemetryConfiguration { TelemetryChannel = new StubTelemetryChannel() }; + var channelBuilder = new TelemetryProcessorChainBuilder(tc); + channelBuilder.UseSampling(5, "request"); + channelBuilder.Build(); + + Assert.Equal(5, ((SamplingTelemetryProcessor)tc.TelemetryProcessorChain.FirstTelemetryProcessor).SamplingPercentage); + Assert.Equal("request", ((SamplingTelemetryProcessor)tc.TelemetryProcessorChain.FirstTelemetryProcessor).ExcludedTypes); + } + + [TestMethod] + public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChain() + { + var tc = new TelemetryConfiguration { TelemetryChannel = new StubTelemetryChannel() }; + var channelBuilder = new TelemetryProcessorChainBuilder(tc); + channelBuilder.UseAdaptiveSampling(); + channelBuilder.Build(); + + Assert.IsType(tc.TelemetryProcessorChain.FirstTelemetryProcessor); + } + + [TestMethod] + public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChainWithCorrectExcludedTypes() + { + var tc = new TelemetryConfiguration { TelemetryChannel = new StubTelemetryChannel() }; + var channelBuilder = new TelemetryProcessorChainBuilder(tc); + channelBuilder.UseAdaptiveSampling("request"); + channelBuilder.Build(); + + Assert.Equal("request", ((AdaptiveSamplingTelemetryProcessor)tc.TelemetryProcessorChain.FirstTelemetryProcessor).ExcludedTypes); + } + + [TestMethod] + public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChainWithCorrectMaxTelemetryItemsPerSecond() + { + var tc = new TelemetryConfiguration { TelemetryChannel = new StubTelemetryChannel() }; + var channelBuilder = new TelemetryProcessorChainBuilder(tc); + channelBuilder.UseAdaptiveSampling(5); + channelBuilder.Build(); + + Assert.Equal(5, ((AdaptiveSamplingTelemetryProcessor)tc.TelemetryProcessorChain.FirstTelemetryProcessor).MaxTelemetryItemsPerSecond); + } + + [TestMethod] + public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChainWithCorrectMaxTelemetryItemsPerSecondAndExcludedTypes() + { + var tc = new TelemetryConfiguration { TelemetryChannel = new StubTelemetryChannel() }; + var channelBuilder = new TelemetryProcessorChainBuilder(tc); + channelBuilder.UseAdaptiveSampling(5, "request"); + channelBuilder.Build(); + + Assert.Equal(5, ((AdaptiveSamplingTelemetryProcessor)tc.TelemetryProcessorChain.FirstTelemetryProcessor).MaxTelemetryItemsPerSecond); + Assert.Equal("request", ((AdaptiveSamplingTelemetryProcessor)tc.TelemetryProcessorChain.FirstTelemetryProcessor).ExcludedTypes); + } + + [TestMethod] + public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChainWithCorrectSettings() + { + SamplingPercentageEstimatorSettings settings = new SamplingPercentageEstimatorSettings + { + MaxSamplingPercentage = 13 + }; + AdaptiveSamplingPercentageEvaluatedCallback callback = (second, percentage, samplingPercentage, changed, estimatorSettings) => { }; + + var tc = new TelemetryConfiguration { TelemetryChannel = new StubTelemetryChannel() }; + var channelBuilder = new TelemetryProcessorChainBuilder(tc); + channelBuilder.UseAdaptiveSampling(settings, callback); + channelBuilder.Build(); + + Assert.Equal(13, ((AdaptiveSamplingTelemetryProcessor)tc.TelemetryProcessorChain.FirstTelemetryProcessor).MaxSamplingPercentage); + } + + [TestMethod] + public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChainWithCorrectSettingsAndExcludedTypes() + { + SamplingPercentageEstimatorSettings settings = new SamplingPercentageEstimatorSettings + { + MaxSamplingPercentage = 13 + }; + AdaptiveSamplingPercentageEvaluatedCallback callback = (second, percentage, samplingPercentage, changed, estimatorSettings) => { }; + + var tc = new TelemetryConfiguration { TelemetryChannel = new StubTelemetryChannel() }; + var channelBuilder = new TelemetryProcessorChainBuilder(tc); + channelBuilder.UseAdaptiveSampling(settings, callback, "request"); + channelBuilder.Build(); + + Assert.Equal(13, ((AdaptiveSamplingTelemetryProcessor)tc.TelemetryProcessorChain.FirstTelemetryProcessor).MaxSamplingPercentage); + Assert.Equal("request", ((AdaptiveSamplingTelemetryProcessor)tc.TelemetryProcessorChain.FirstTelemetryProcessor).ExcludedTypes); + } + } +} diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/SamplingTelemetryProcessorTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/SamplingTelemetryProcessorTest.cs index 60b9320a08..89d69e5f5a 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/SamplingTelemetryProcessorTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/SamplingTelemetryProcessorTest.cs @@ -7,7 +7,6 @@ using Microsoft.ApplicationInsights.Extensibility; using Microsoft.ApplicationInsights.Extensibility.Implementation; using Microsoft.ApplicationInsights.Web.TestFramework; - using Microsoft.ApplicationInsights.WindowsServer.Channel.Implementation; using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel; using Microsoft.VisualStudio.TestTools.UnitTesting; using Assert = Xunit.Assert; @@ -49,8 +48,10 @@ public void AllTelemetryIsSentWithDefaultSamplingRate() public void TelemetryItemHasSamplingPercentageSet() { var sentTelemetry = new List(); - var processor = new SamplingTelemetryProcessor(new StubTelemetryProcessor(null) { OnProcess = t => sentTelemetry.Add(t) }); - processor.SamplingPercentage = 20; + var processor = new SamplingTelemetryProcessor(new StubTelemetryProcessor(null) { OnProcess = t => sentTelemetry.Add(t) }) + { + SamplingPercentage = 20 + }; do { @@ -64,79 +65,188 @@ public void TelemetryItemHasSamplingPercentageSet() [TestMethod] public void DependencyTelemetryIsSubjectToSampling() { - TelemetryTypeSupportsSampling((telemetryProcessors) => telemetryProcessors.Process(new DependencyTelemetry())); + TelemetryTypeSupportsSampling(telemetryProcessors => telemetryProcessors.Process(new DependencyTelemetry())); } [TestMethod] public void EventTelemetryIsSubjectToSampling() { - TelemetryTypeSupportsSampling((telemetryProcessors) => telemetryProcessors.Process(new EventTelemetry("event"))); + TelemetryTypeSupportsSampling(telemetryProcessors => telemetryProcessors.Process(new EventTelemetry("event"))); } [TestMethod] public void ExceptionTelemetryIsSubjectToSampling() { - TelemetryTypeSupportsSampling((telemetryProcessors) => telemetryProcessors.Process(new ExceptionTelemetry(new Exception("exception")))); + TelemetryTypeSupportsSampling(telemetryProcessors => telemetryProcessors.Process(new ExceptionTelemetry(new Exception("exception")))); } [TestMethod] public void MetricTelemetryIsNotSubjectToSampling() { - TelemetryTypeDoesNotSupportSampling((telemetryProcessors) => telemetryProcessors.Process(new MetricTelemetry("metric", 1.0))); + TelemetryTypeDoesNotSupportSampling(telemetryProcessors => + { + telemetryProcessors.Process(new MetricTelemetry("metric", 1.0)); + return 1; + }); } [TestMethod] public void PageViewTelemetryIsSubjectToSampling() { - TelemetryTypeSupportsSampling((telemetryProcessors) => telemetryProcessors.Process(new PageViewTelemetry("page"))); + TelemetryTypeSupportsSampling(telemetryProcessors => telemetryProcessors.Process(new PageViewTelemetry("page"))); } [TestMethod] public void PerformanceCounterTelemetryIsNotSubjectToSampling() { TelemetryTypeDoesNotSupportSampling( - (telemetryProcessors) => telemetryProcessors.Process(new PerformanceCounterTelemetry("category", "counter", "instance", 1.0))); + telemetryProcessors => + { + telemetryProcessors.Process(new PerformanceCounterTelemetry("category", "counter", "instance", 1.0)); + return 1; + }); } [TestMethod] public void RequestTelemetryIsSubjectToSampling() { - TelemetryTypeSupportsSampling((telemetryProcessors) => telemetryProcessors.Process(new RequestTelemetry())); + TelemetryTypeSupportsSampling(telemetryProcessors => telemetryProcessors.Process(new RequestTelemetry())); } [TestMethod] public void SessionStateTelemetryIsNotSubjectToSampling() { - TelemetryTypeDoesNotSupportSampling((telemetryProcessors) => telemetryProcessors.Process(new SessionStateTelemetry())); + TelemetryTypeDoesNotSupportSampling(telemetryProcessors => + { + telemetryProcessors.Process(new SessionStateTelemetry()); + return 1; + }); } [TestMethod] public void TraceTelemetryIsSubjectToSampling() { - TelemetryTypeSupportsSampling((telemetryProcessors) => telemetryProcessors.Process(new TraceTelemetry("my trace"))); + TelemetryTypeSupportsSampling(telemetryProcessors => telemetryProcessors.Process(new TraceTelemetry("my trace"))); } - - private static void TelemetryTypeDoesNotSupportSampling(Action sendAction) + + [TestMethod] + public void RequestCanBeExcludedFromSampling() + { + TelemetryTypeDoesNotSupportSampling(telemetryProcessors => + { + telemetryProcessors.Process(new RequestTelemetry()); + return 1; + }, "request"); + } + + [TestMethod] + public void DependencyCanBeExcludedFromSampling() + { + TelemetryTypeDoesNotSupportSampling(telemetryProcessors => + { + telemetryProcessors.Process(new DependencyTelemetry()); + return 1; + }, + "dependency"); + } + + [TestMethod] + public void EventCanBeExcludedFromSampling() + { + TelemetryTypeDoesNotSupportSampling(telemetryProcessors => + { + telemetryProcessors.Process(new EventTelemetry()); + return 1; + }, + "event"); + } + + [TestMethod] + public void ExceptionCanBeExcludedFromSampling() + { + TelemetryTypeDoesNotSupportSampling(telemetryProcessors => + { + telemetryProcessors.Process(new ExceptionTelemetry()); + return 1; + }, + "exception"); + } + + [TestMethod] + public void TraceCanBeExcludedFromSampling() + { + TelemetryTypeDoesNotSupportSampling(telemetryProcessors => + { + telemetryProcessors.Process(new TraceTelemetry()); + return 1; + }, + "trace"); + } + + [TestMethod] + public void PageViewCanBeExcludedFromSampling() + { + TelemetryTypeDoesNotSupportSampling(telemetryProcessors => + { + telemetryProcessors.Process(new PageViewTelemetry()); + return 1; + }, + "pageview"); + } + + [TestMethod] + public void MultipleItemsCanBeExcludedFromSampling() + { + TelemetryTypeDoesNotSupportSampling( + telemetryProcessors => + { + telemetryProcessors.Process(new PageViewTelemetry()); + telemetryProcessors.Process(new RequestTelemetry()); + return 2; + }, + "pageview;request"); + } + + [TestMethod] + public void UnknownExcludedTypesAreIgnored() + { + TelemetryTypeSupportsSampling(telemetryProcessors => telemetryProcessors.Process(new TraceTelemetry("my trace")), "lala1;lala2,lala3"); + } + + [TestMethod] + public void IncorrectFormatDoesNotAffectCorrectExcludedTypes() + { + TelemetryTypeDoesNotSupportSampling( + telemetryProcessors => + { + telemetryProcessors.Process(new PageViewTelemetry()); + telemetryProcessors.Process(new RequestTelemetry()); + return 2; + }, + ";;;;;lala1;;;;;pageview;lala2;request;;;;;"); + } + + private static void TelemetryTypeDoesNotSupportSampling(Func sendAction, string excludedTypes = null) { - const int ItemsToGenerate = 100; const int SamplingPercentage = 10; var sentTelemetry = new List(); - var telemetryProcessorChainWithSampling = CreateTelemetryProcessorChainWithSampling(sentTelemetry, SamplingPercentage); + var telemetryProcessorChainWithSampling = CreateTelemetryProcessorChainWithSampling(sentTelemetry, SamplingPercentage, excludedTypes); - for (int i = 0; i < ItemsToGenerate; i++) + int generatedCount = 0; + for (int i = 0; i < 100; i++) { - sendAction.Invoke(telemetryProcessorChainWithSampling); + generatedCount += sendAction.Invoke(telemetryProcessorChainWithSampling); } - Assert.Equal(sentTelemetry.Count, ItemsToGenerate); + Assert.Equal(generatedCount, sentTelemetry.Count); } - private static void TelemetryTypeSupportsSampling(Action sendAction) + private static void TelemetryTypeSupportsSampling(Action sendAction, string excludedTypes = null) { const int ItemsToGenerate = 100; const int SamplingPercentage = 10; var sentTelemetry = new List(); - var telemetryProcessorChainWithSampling = CreateTelemetryProcessorChainWithSampling(sentTelemetry, SamplingPercentage); + var telemetryProcessorChainWithSampling = CreateTelemetryProcessorChainWithSampling(sentTelemetry, SamplingPercentage, excludedTypes); for (int i = 0; i < ItemsToGenerate; i++) { @@ -149,12 +259,12 @@ private static void TelemetryTypeSupportsSampling(Action sentTelemetry, double samplingPercentage) + private static TelemetryProcessorChain CreateTelemetryProcessorChainWithSampling(IList sentTelemetry, double samplingPercentage, string excludedTypes = null) { - var tc = new TelemetryConfiguration() {TelemetryChannel = new StubTelemetryChannel()}; + var tc = new TelemetryConfiguration {TelemetryChannel = new StubTelemetryChannel()}; var channelBuilder = new TelemetryProcessorChainBuilder(tc); - channelBuilder.UseSampling(samplingPercentage); - channelBuilder.Use((next) => new StubTelemetryProcessor(next) { OnProcess = (t) => sentTelemetry.Add(t) }); + channelBuilder.UseSampling(samplingPercentage, excludedTypes); + channelBuilder.Use(next => new StubTelemetryProcessor(next) { OnProcess = t => sentTelemetry.Add(t) }); channelBuilder.Build(); diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Shared.Tests.projitems b/Test/ServerTelemetryChannel.Test/Shared.Tests/Shared.Tests.projitems index 72ff641a17..45ec0fa33b 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Shared.Tests.projitems +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Shared.Tests.projitems @@ -35,6 +35,7 @@ + diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/AdaptiveSamplingTelemetryProcessor.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/AdaptiveSamplingTelemetryProcessor.cs index 2a88573a1a..6514de6ff0 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/AdaptiveSamplingTelemetryProcessor.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/AdaptiveSamplingTelemetryProcessor.cs @@ -15,22 +15,22 @@ public class AdaptiveSamplingTelemetryProcessor : ITelemetryProcessor, IDisposab /// /// Fixed-rate sampling telemetry processor. /// - private SamplingTelemetryProcessor samplingProcessor; - + private readonly SamplingTelemetryProcessor samplingProcessor; + /// - /// Sampling percentage estimator telemetry processor. + /// Sampling percentage estimator settings. /// - private SamplingPercentageEstimatorTelemetryProcessor estimatorProcessor; + private readonly SamplingPercentageEstimatorSettings estimatorSettings; /// - /// Sampling percentage estimator settings. + /// Callback invoked every time sampling percentage is evaluated. /// - private SamplingPercentageEstimatorSettings estimatorSettings; + private readonly AdaptiveSamplingPercentageEvaluatedCallback evaluationCallback; /// - /// Callback invoked every time sampling percentage is evaluated. + /// Sampling percentage estimator telemetry processor. /// - private AdaptiveSamplingPercentageEvaluatedCallback evaluationCallback; + private SamplingPercentageEstimatorTelemetryProcessor estimatorProcessor; /// /// Initializes a new instance of the class. @@ -60,6 +60,16 @@ public AdaptiveSamplingTelemetryProcessor( this.samplingProcessor = new SamplingTelemetryProcessor(this.estimatorProcessor); } + /// + /// Gets or sets a semicolon separated list of telemetry types that should not be sampled. + /// + public string ExcludedTypes + { + get { return this.samplingProcessor.ExcludedTypes; } + + set { this.samplingProcessor.ExcludedTypes = value; } + } + /// /// Gets or sets initial sampling percentage applied at the start /// of the process to dynamically vary the percentage. diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs index aed1d5dde4..9690a20d0a 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs @@ -30,6 +30,12 @@ public bool IsVerboseEnabled } } + [Event(3, Message = "Sampling skipped: {0}.", Level = EventLevel.Verbose)] + public void SamplingSkippedByType(string telemetryType, string appDomainName = "Incorrect") + { + this.WriteEvent(3, telemetryType ?? string.Empty, this.ApplicationName); + } + [Event(4, Message = "Backoff interval in seconds {0}.", Level = EventLevel.Verbose)] public void BackoffInterval(double intervalInSec, string appDomainName = "Incorrect") { diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/SamplingTelemetryProcessor.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/SamplingTelemetryProcessor.cs index 19bfda0968..dba9b7d717 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/SamplingTelemetryProcessor.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/SamplingTelemetryProcessor.cs @@ -1,6 +1,8 @@ namespace Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel { using System; + using System.Collections.Generic; + using System.Threading; using Extensibility.Implementation; using Microsoft.ApplicationInsights.Channel; using Microsoft.ApplicationInsights.DataContracts; @@ -13,6 +15,19 @@ /// public sealed class SamplingTelemetryProcessor : ITelemetryProcessor { + private const string DependencyTelemetryName = "Dependency"; + private const string EventTelemetryName = "Event"; + private const string ExceptionTelemetryName = "Exception"; + private const string PageViewTelemetryName = "PageView"; + private const string RequestTelemetryName = "Request"; + private const string TraceTelemetryName = "Trace"; + + private readonly char[] listSeparators = { ';' }; + + private HashSet excludedTypesHashSet; + + private string excludedTypesString; + /// /// Initializes a new instance of the class. /// Next TelemetryProcessor in call chain. @@ -26,8 +41,71 @@ public SamplingTelemetryProcessor(ITelemetryProcessor next) this.SamplingPercentage = 100.0; this.Next = next; + this.excludedTypesHashSet = new HashSet(); } - + + /// + /// Gets or sets a semicolon separated list of telemetry types that should not be sampled. + /// + public string ExcludedTypes + { + get + { + return this.excludedTypesString; + } + + set + { + this.excludedTypesString = value; + + HashSet newExcludedTypesHashSet = new HashSet(); + if (!string.IsNullOrEmpty(value)) + { + string[] splitList = value.Split(this.listSeparators, StringSplitOptions.RemoveEmptyEntries); + foreach (string item in splitList) + { + if (string.Compare(item, DependencyTelemetryName, StringComparison.OrdinalIgnoreCase) == 0) + { + newExcludedTypesHashSet.Add(typeof(DependencyTelemetry)); + continue; + } + + if (string.Compare(item, EventTelemetryName, StringComparison.OrdinalIgnoreCase) == 0) + { + newExcludedTypesHashSet.Add(typeof(EventTelemetry)); + continue; + } + + if (string.Compare(item, ExceptionTelemetryName, StringComparison.OrdinalIgnoreCase) == 0) + { + newExcludedTypesHashSet.Add(typeof(ExceptionTelemetry)); + continue; + } + + if (string.Compare(item, PageViewTelemetryName, StringComparison.OrdinalIgnoreCase) == 0) + { + newExcludedTypesHashSet.Add(typeof(PageViewTelemetry)); + continue; + } + + if (string.Compare(item, RequestTelemetryName, StringComparison.OrdinalIgnoreCase) == 0) + { + newExcludedTypesHashSet.Add(typeof(RequestTelemetry)); + continue; + } + + if (string.Compare(item, TraceTelemetryName, StringComparison.OrdinalIgnoreCase) == 0) + { + newExcludedTypesHashSet.Add(typeof(TraceTelemetry)); + continue; + } + } + } + + Interlocked.Exchange(ref this.excludedTypesHashSet, newExcludedTypesHashSet); + } + } + /// /// Gets or sets data sampling percentage (between 0 and 100) for all /// objects logged in this . @@ -51,23 +129,34 @@ public void Process(ITelemetry item) { if (this.SamplingPercentage < 100.0 - 1.0E-12) { - // set sampling percentage on telemetry item, current codebase assumes it is the only one updating SamplingPercentage. var samplingSupportingTelemetry = item as ISupportSampling; if (samplingSupportingTelemetry != null) { - samplingSupportingTelemetry.SamplingPercentage = this.SamplingPercentage; - } - - if (!this.IsSampledIn(item)) - { - if (TelemetryChannelEventSource.Log.IsVerboseEnabled) + var excludedTypesHashSetRef = this.excludedTypesHashSet; + if (excludedTypesHashSetRef.Count > 0 && excludedTypesHashSetRef.Contains(item.GetType())) { - TelemetryChannelEventSource.Log.ItemSampledOut(item.ToString()); + if (TelemetryChannelEventSource.Log.IsVerboseEnabled) + { + TelemetryChannelEventSource.Log.SamplingSkippedByType(item.ToString()); + } } + else + { + // set sampling percentage on telemetry item, current codebase assumes it is the only one updating SamplingPercentage. + samplingSupportingTelemetry.SamplingPercentage = this.SamplingPercentage; - TelemetryDebugWriter.WriteTelemetry(item, this.GetType().Name); - return; + if (!this.IsSampledIn(item)) + { + if (TelemetryChannelEventSource.Log.IsVerboseEnabled) + { + TelemetryChannelEventSource.Log.ItemSampledOut(item.ToString()); + } + + TelemetryDebugWriter.WriteTelemetry(item, this.GetType().Name); + return; + } + } } } diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/TelemetryChannelBuilderExtensions.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/TelemetryChannelBuilderExtensions.cs index 025e216da7..977604193b 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/TelemetryChannelBuilderExtensions.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/TelemetryChannelBuilderExtensions.cs @@ -1,5 +1,6 @@ namespace Microsoft.ApplicationInsights.Extensibility { + using System; using System.ComponentModel; using Microsoft.ApplicationInsights.Extensibility.Implementation; @@ -21,7 +22,28 @@ public static class TelemetryProcessorChainBuilderExtensions /// Instance of . public static TelemetryProcessorChainBuilder UseSampling(this TelemetryProcessorChainBuilder builder, double samplingPercentage) { - return builder.Use((next) => new SamplingTelemetryProcessor(next) { SamplingPercentage = samplingPercentage }); + if (builder == null) + { + throw new ArgumentNullException("builder"); + } + + return builder.Use(next => new SamplingTelemetryProcessor(next) { SamplingPercentage = samplingPercentage }); + } + + /// + /// Adds to the given + /// + /// Instance of + /// Sampling Percentage to configure. + /// Semicolon separated list of types that should not be sampled. + /// Instance of . + public static TelemetryProcessorChainBuilder UseSampling(this TelemetryProcessorChainBuilder builder, double samplingPercentage, string excludedTypes) + { + return builder.Use(next => new SamplingTelemetryProcessor(next) + { + SamplingPercentage = samplingPercentage, + ExcludedTypes = excludedTypes, + }); } /// @@ -31,7 +53,18 @@ public static TelemetryProcessorChainBuilder UseSampling(this TelemetryProcessor /// Instance of . public static TelemetryProcessorChainBuilder UseAdaptiveSampling(this TelemetryProcessorChainBuilder builder) { - return builder.Use((next) => new AdaptiveSamplingTelemetryProcessor(next)); + return builder.Use(next => new AdaptiveSamplingTelemetryProcessor(next)); + } + + /// + /// Adds to the + /// + /// Instance of + /// Semicolon separated list of types that should not be sampled. + /// Instance of . + public static TelemetryProcessorChainBuilder UseAdaptiveSampling(this TelemetryProcessorChainBuilder builder, string excludedTypes) + { + return builder.Use(next => new AdaptiveSamplingTelemetryProcessor(next) { ExcludedTypes = excludedTypes }); } /// @@ -42,7 +75,23 @@ public static TelemetryProcessorChainBuilder UseAdaptiveSampling(this TelemetryP /// Instance of . public static TelemetryProcessorChainBuilder UseAdaptiveSampling(this TelemetryProcessorChainBuilder builder, double maxTelemetryItemsPerSecond) { - return builder.Use((next) => new AdaptiveSamplingTelemetryProcessor(next) { MaxTelemetryItemsPerSecond = maxTelemetryItemsPerSecond }); + return builder.Use(next => new AdaptiveSamplingTelemetryProcessor(next) { MaxTelemetryItemsPerSecond = maxTelemetryItemsPerSecond }); + } + + /// + /// Adds to the + /// + /// Instance of + /// Maximum number of telemetry items to be generated on this application instance. + /// Semicolon separated list of types that should not be sampled. + /// Instance of . + public static TelemetryProcessorChainBuilder UseAdaptiveSampling(this TelemetryProcessorChainBuilder builder, double maxTelemetryItemsPerSecond, string excludedTypes) + { + return builder.Use(next => new AdaptiveSamplingTelemetryProcessor(next) + { + MaxTelemetryItemsPerSecond = maxTelemetryItemsPerSecond, + ExcludedTypes = excludedTypes, + }); } /// @@ -57,7 +106,28 @@ public static TelemetryProcessorChainBuilder UseAdaptiveSampling( SamplingPercentageEstimatorSettings settings, AdaptiveSamplingPercentageEvaluatedCallback callback) { - return builder.Use((next) => new AdaptiveSamplingTelemetryProcessor(settings, callback, next) { InitialSamplingPercentage = 100.0 / settings.EffectiveInitialSamplingRate }); + return builder.Use(next => new AdaptiveSamplingTelemetryProcessor(settings, callback, next) { InitialSamplingPercentage = 100.0 / settings.EffectiveInitialSamplingRate }); + } + + /// + /// Adds to the + /// + /// Instance of + /// Set of settings applicable to dynamic sampling percentage algorithm. + /// Callback invoked every time sampling percentage evaluation occurs. + /// Semicolon separated list of types that should not be sampled. + /// Instance of . + public static TelemetryProcessorChainBuilder UseAdaptiveSampling( + this TelemetryProcessorChainBuilder builder, + SamplingPercentageEstimatorSettings settings, + AdaptiveSamplingPercentageEvaluatedCallback callback, + string excludedTypes) + { + return builder.Use(next => new AdaptiveSamplingTelemetryProcessor(settings, callback, next) + { + InitialSamplingPercentage = 100.0 / settings.EffectiveInitialSamplingRate, + ExcludedTypes = excludedTypes, + }); } } } From 2f175205499532a481c8dbe7445d43968672bc27 Mon Sep 17 00:00:00 2001 From: abaranch Date: Thu, 16 Jun 2016 15:58:39 -0700 Subject: [PATCH 16/30] Update changelog --- CHANGELOG.md | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 7a852be2f5..e07c90c2e6 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,7 +5,8 @@ This changelog will be used to generate documentation on [release notes page](ht ## Version 2.2.0-beta1 -- Add ExceptionTelemetry.Message property. If it is provided it is used instead of Exception.Message property for the ounter-most exception. +- Add ExceptionTelemetry.Message property. If it is provided it is used instead of Exception.Message property for the ounter-most exception. +- Telemetry types can be exluded from sampling by specifing ExcludedTypes property. ## Version 2.1.0-beta4 - [Bug fix](https://github.com/Microsoft/ApplicationInsights-dotnet-server/issues/76) From 0d9197be6e1cf4a0b27785ddd7c82a2ac45f4d64 Mon Sep 17 00:00:00 2001 From: abaranch Date: Thu, 16 Jun 2016 16:14:04 -0700 Subject: [PATCH 17/30] Add parameters validation --- ...etryProcessorChainBuilderExtensionsTest.cs | 48 +++++++++++++++++++ .../TelemetryChannelBuilderExtensions.cs | 45 +++++++++++++++++ 2 files changed, 93 insertions(+) diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TelemetryProcessorChainBuilderExtensionsTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TelemetryProcessorChainBuilderExtensionsTest.cs index c3fe249dd2..757e5a7613 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TelemetryProcessorChainBuilderExtensionsTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TelemetryProcessorChainBuilderExtensionsTest.cs @@ -41,6 +41,12 @@ public void UseSamplingSetsAddsSamplingProcessorToTheChainWithCorrectExcludedTyp Assert.Equal("request", ((SamplingTelemetryProcessor)tc.TelemetryProcessorChain.FirstTelemetryProcessor).ExcludedTypes); } + [TestMethod] + public void UseAdaptiveSamplingThrowsArgumentNullExceptionBuilderIsNull() + { + Assert.Throws(() => TelemetryProcessorChainBuilderExtensions.UseAdaptiveSampling(null)); + } + [TestMethod] public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChain() { @@ -63,6 +69,12 @@ public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChainWithCorrec Assert.Equal("request", ((AdaptiveSamplingTelemetryProcessor)tc.TelemetryProcessorChain.FirstTelemetryProcessor).ExcludedTypes); } + [TestMethod] + public void UseAdaptiveSamplingWithMaxItemsParameterThrowsArgumentNullExceptionBuilderIsNull() + { + Assert.Throws(() => TelemetryProcessorChainBuilderExtensions.UseAdaptiveSampling(null, 5)); + } + [TestMethod] public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChainWithCorrectMaxTelemetryItemsPerSecond() { @@ -74,6 +86,12 @@ public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChainWithCorrec Assert.Equal(5, ((AdaptiveSamplingTelemetryProcessor)tc.TelemetryProcessorChain.FirstTelemetryProcessor).MaxTelemetryItemsPerSecond); } + [TestMethod] + public void UseAdaptiveSamplingWithMaxItemsAndExcludedTypesParametersThrowsArgumentNullExceptionBuilderIsNull() + { + Assert.Throws(() => TelemetryProcessorChainBuilderExtensions.UseAdaptiveSampling(null, 5, "request")); + } + [TestMethod] public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChainWithCorrectMaxTelemetryItemsPerSecondAndExcludedTypes() { @@ -86,6 +104,21 @@ public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChainWithCorrec Assert.Equal("request", ((AdaptiveSamplingTelemetryProcessor)tc.TelemetryProcessorChain.FirstTelemetryProcessor).ExcludedTypes); } + [TestMethod] + public void UseAdaptiveSamplingWithSettingsParameterThrowsArgumentNullExceptionBuilderIsNull() + { + Assert.Throws(() => TelemetryProcessorChainBuilderExtensions.UseAdaptiveSampling(null, null, null)); + } + + [TestMethod] + public void UseAdaptiveSamplingWithSettingsParameterThrowsArgumentNullExceptionSettingsIsNull() + { + var tc = new TelemetryConfiguration { TelemetryChannel = new StubTelemetryChannel() }; + var channelBuilder = new TelemetryProcessorChainBuilder(tc); + + Assert.Throws(() => channelBuilder.UseAdaptiveSampling(null, null)); + } + [TestMethod] public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChainWithCorrectSettings() { @@ -103,6 +136,21 @@ public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChainWithCorrec Assert.Equal(13, ((AdaptiveSamplingTelemetryProcessor)tc.TelemetryProcessorChain.FirstTelemetryProcessor).MaxSamplingPercentage); } + [TestMethod] + public void UseAdaptiveSamplingWithSettingsParameterAndExcludedTypesThrowsArgumentNullExceptionBuilderIsNull() + { + Assert.Throws(() => TelemetryProcessorChainBuilderExtensions.UseAdaptiveSampling(null, null, null, "request")); + } + + [TestMethod] + public void UseAdaptiveSamplingWithSettingsParameterAndExcludedTypesThrowsArgumentNullExceptionSettingsIsNull() + { + var tc = new TelemetryConfiguration { TelemetryChannel = new StubTelemetryChannel() }; + var channelBuilder = new TelemetryProcessorChainBuilder(tc); + + Assert.Throws(() => channelBuilder.UseAdaptiveSampling(null, null, "request")); + } + [TestMethod] public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChainWithCorrectSettingsAndExcludedTypes() { diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/TelemetryChannelBuilderExtensions.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/TelemetryChannelBuilderExtensions.cs index 977604193b..9f22b94224 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/TelemetryChannelBuilderExtensions.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/TelemetryChannelBuilderExtensions.cs @@ -39,6 +39,11 @@ public static TelemetryProcessorChainBuilder UseSampling(this TelemetryProcessor /// Instance of . public static TelemetryProcessorChainBuilder UseSampling(this TelemetryProcessorChainBuilder builder, double samplingPercentage, string excludedTypes) { + if (builder == null) + { + throw new ArgumentNullException("builder"); + } + return builder.Use(next => new SamplingTelemetryProcessor(next) { SamplingPercentage = samplingPercentage, @@ -53,6 +58,11 @@ public static TelemetryProcessorChainBuilder UseSampling(this TelemetryProcessor /// Instance of . public static TelemetryProcessorChainBuilder UseAdaptiveSampling(this TelemetryProcessorChainBuilder builder) { + if (builder == null) + { + throw new ArgumentNullException("builder"); + } + return builder.Use(next => new AdaptiveSamplingTelemetryProcessor(next)); } @@ -64,6 +74,11 @@ public static TelemetryProcessorChainBuilder UseAdaptiveSampling(this TelemetryP /// Instance of . public static TelemetryProcessorChainBuilder UseAdaptiveSampling(this TelemetryProcessorChainBuilder builder, string excludedTypes) { + if (builder == null) + { + throw new ArgumentNullException("builder"); + } + return builder.Use(next => new AdaptiveSamplingTelemetryProcessor(next) { ExcludedTypes = excludedTypes }); } @@ -75,6 +90,11 @@ public static TelemetryProcessorChainBuilder UseAdaptiveSampling(this TelemetryP /// Instance of . public static TelemetryProcessorChainBuilder UseAdaptiveSampling(this TelemetryProcessorChainBuilder builder, double maxTelemetryItemsPerSecond) { + if (builder == null) + { + throw new ArgumentNullException("builder"); + } + return builder.Use(next => new AdaptiveSamplingTelemetryProcessor(next) { MaxTelemetryItemsPerSecond = maxTelemetryItemsPerSecond }); } @@ -87,6 +107,11 @@ public static TelemetryProcessorChainBuilder UseAdaptiveSampling(this TelemetryP /// Instance of . public static TelemetryProcessorChainBuilder UseAdaptiveSampling(this TelemetryProcessorChainBuilder builder, double maxTelemetryItemsPerSecond, string excludedTypes) { + if (builder == null) + { + throw new ArgumentNullException("builder"); + } + return builder.Use(next => new AdaptiveSamplingTelemetryProcessor(next) { MaxTelemetryItemsPerSecond = maxTelemetryItemsPerSecond, @@ -106,6 +131,16 @@ public static TelemetryProcessorChainBuilder UseAdaptiveSampling( SamplingPercentageEstimatorSettings settings, AdaptiveSamplingPercentageEvaluatedCallback callback) { + if (builder == null) + { + throw new ArgumentNullException("builder"); + } + + if (settings == null) + { + throw new ArgumentNullException("settings"); + } + return builder.Use(next => new AdaptiveSamplingTelemetryProcessor(settings, callback, next) { InitialSamplingPercentage = 100.0 / settings.EffectiveInitialSamplingRate }); } @@ -123,6 +158,16 @@ public static TelemetryProcessorChainBuilder UseAdaptiveSampling( AdaptiveSamplingPercentageEvaluatedCallback callback, string excludedTypes) { + if (builder == null) + { + throw new ArgumentNullException("builder"); + } + + if (settings == null) + { + throw new ArgumentNullException("settings"); + } + return builder.Use(next => new AdaptiveSamplingTelemetryProcessor(settings, callback, next) { InitialSamplingPercentage = 100.0 / settings.EffectiveInitialSamplingRate, From 34cf669dfcb05e59cf90e754ad902e8edc3eaa24 Mon Sep 17 00:00:00 2001 From: abaranch Date: Thu, 16 Jun 2016 17:12:07 -0700 Subject: [PATCH 18/30] More unit tests --- .../TelemetryProcessorChainBuilderExtensionsTest.cs | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TelemetryProcessorChainBuilderExtensionsTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TelemetryProcessorChainBuilderExtensionsTest.cs index 757e5a7613..236aa56666 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TelemetryProcessorChainBuilderExtensionsTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TelemetryProcessorChainBuilderExtensionsTest.cs @@ -29,6 +29,12 @@ public void UseSamplingSetsAddsSamplingProcessorToTheChainWithCorrectPercentage( Assert.Equal(5, ((SamplingTelemetryProcessor) tc.TelemetryProcessorChain.FirstTelemetryProcessor).SamplingPercentage); } + [TestMethod] + public void UseSamplingWithExcluedTypesParameterThrowsArgumentNullExceptionBuilderIsNull() + { + Assert.Throws(() => TelemetryProcessorChainBuilderExtensions.UseSampling(null, 5, "request")); + } + [TestMethod] public void UseSamplingSetsAddsSamplingProcessorToTheChainWithCorrectExcludedTypes() { @@ -58,6 +64,12 @@ public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChain() Assert.IsType(tc.TelemetryProcessorChain.FirstTelemetryProcessor); } + [TestMethod] + public void UseAdaptiveSamplingWithExcludedTypesThrowsArgumentNullExceptionBuilderIsNull() + { + Assert.Throws(() => TelemetryProcessorChainBuilderExtensions.UseAdaptiveSampling(null, "request")); + } + [TestMethod] public void UseAdaptiveSamplingAddsAdaptiveSamplingProcessorToTheChainWithCorrectExcludedTypes() { From 71961e4a2f15f2121235bf01815842c25c7a136a Mon Sep 17 00:00:00 2001 From: abaranch Date: Tue, 21 Jun 2016 15:28:41 -0700 Subject: [PATCH 19/30] Small refactoring --- .../Shared/SamplingTelemetryProcessor.cs | 45 +++++-------------- 1 file changed, 12 insertions(+), 33 deletions(-) diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/SamplingTelemetryProcessor.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/SamplingTelemetryProcessor.cs index dba9b7d717..41d3ca0090 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/SamplingTelemetryProcessor.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/SamplingTelemetryProcessor.cs @@ -23,6 +23,7 @@ public sealed class SamplingTelemetryProcessor : ITelemetryProcessor private const string TraceTelemetryName = "Trace"; private readonly char[] listSeparators = { ';' }; + private readonly IDictionary allowedTypes; private HashSet excludedTypesHashSet; @@ -42,6 +43,15 @@ public SamplingTelemetryProcessor(ITelemetryProcessor next) this.SamplingPercentage = 100.0; this.Next = next; this.excludedTypesHashSet = new HashSet(); + this.allowedTypes = new Dictionary (6, StringComparer.OrdinalIgnoreCase) + { + { DependencyTelemetryName, typeof (DependencyTelemetry) }, + { EventTelemetryName, typeof (EventTelemetry) }, + { ExceptionTelemetryName, typeof (ExceptionTelemetry) }, + { PageViewTelemetryName, typeof (PageViewTelemetry) }, + { RequestTelemetryName, typeof (RequestTelemetry) }, + { TraceTelemetryName, typeof (TraceTelemetry) }, + }; } /// @@ -64,40 +74,9 @@ public string ExcludedTypes string[] splitList = value.Split(this.listSeparators, StringSplitOptions.RemoveEmptyEntries); foreach (string item in splitList) { - if (string.Compare(item, DependencyTelemetryName, StringComparison.OrdinalIgnoreCase) == 0) - { - newExcludedTypesHashSet.Add(typeof(DependencyTelemetry)); - continue; - } - - if (string.Compare(item, EventTelemetryName, StringComparison.OrdinalIgnoreCase) == 0) - { - newExcludedTypesHashSet.Add(typeof(EventTelemetry)); - continue; - } - - if (string.Compare(item, ExceptionTelemetryName, StringComparison.OrdinalIgnoreCase) == 0) - { - newExcludedTypesHashSet.Add(typeof(ExceptionTelemetry)); - continue; - } - - if (string.Compare(item, PageViewTelemetryName, StringComparison.OrdinalIgnoreCase) == 0) - { - newExcludedTypesHashSet.Add(typeof(PageViewTelemetry)); - continue; - } - - if (string.Compare(item, RequestTelemetryName, StringComparison.OrdinalIgnoreCase) == 0) - { - newExcludedTypesHashSet.Add(typeof(RequestTelemetry)); - continue; - } - - if (string.Compare(item, TraceTelemetryName, StringComparison.OrdinalIgnoreCase) == 0) + if (this.allowedTypes.ContainsKey(item)) { - newExcludedTypesHashSet.Add(typeof(TraceTelemetry)); - continue; + newExcludedTypesHashSet.Add(this.allowedTypes[item]); } } } From 6c377819daf047ade2049020e5ee47bb3c1fbd38 Mon Sep 17 00:00:00 2001 From: abaranch Date: Tue, 21 Jun 2016 15:33:55 -0700 Subject: [PATCH 20/30] Stylecop --- .../Shared/SamplingTelemetryProcessor.cs | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/SamplingTelemetryProcessor.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/SamplingTelemetryProcessor.cs index 41d3ca0090..e807a82c0f 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/SamplingTelemetryProcessor.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/SamplingTelemetryProcessor.cs @@ -43,14 +43,14 @@ public SamplingTelemetryProcessor(ITelemetryProcessor next) this.SamplingPercentage = 100.0; this.Next = next; this.excludedTypesHashSet = new HashSet(); - this.allowedTypes = new Dictionary (6, StringComparer.OrdinalIgnoreCase) + this.allowedTypes = new Dictionary(6, StringComparer.OrdinalIgnoreCase) { - { DependencyTelemetryName, typeof (DependencyTelemetry) }, - { EventTelemetryName, typeof (EventTelemetry) }, - { ExceptionTelemetryName, typeof (ExceptionTelemetry) }, - { PageViewTelemetryName, typeof (PageViewTelemetry) }, - { RequestTelemetryName, typeof (RequestTelemetry) }, - { TraceTelemetryName, typeof (TraceTelemetry) }, + { DependencyTelemetryName, typeof(DependencyTelemetry) }, + { EventTelemetryName, typeof(EventTelemetry) }, + { ExceptionTelemetryName, typeof(ExceptionTelemetry) }, + { PageViewTelemetryName, typeof(PageViewTelemetry) }, + { RequestTelemetryName, typeof(RequestTelemetry) }, + { TraceTelemetryName, typeof(TraceTelemetry) }, }; } From 0755ff6b3746ede4eeb33f5d1808caa787d6086e Mon Sep 17 00:00:00 2001 From: Sergey Kanzhelev Date: Tue, 21 Jun 2016 22:34:38 -0700 Subject: [PATCH 21/30] oss conduct --- README.md | 2 ++ 1 file changed, 2 insertions(+) diff --git a/README.md b/README.md index 07d7fb72e4..cb57685a32 100644 --- a/README.md +++ b/README.md @@ -68,6 +68,8 @@ Read about [how to use the API and see the results in the portal][api-overview]. We strongly welcome and encourage contributions to this project. Please read the [contributor's guide][ContribGuide] located in the ApplicationInsights-Home repository. If making a large change we request that you open an [issue][GitHubIssue] first. We follow the [Git Flow][GitFlow] approach to branching. +This project has adopted the [Microsoft Open Source Code of Conduct](https://opensource.microsoft.com/codeofconduct/). For more information see the [Code of Conduct FAQ](https://opensource.microsoft.com/codeofconduct/faq/) or contact [opencode@microsoft.com](mailto:opencode@microsoft.com) with any additional questions or comments. + [AILandingPage]: http://azure.microsoft.com/services/application-insights/ [api-overview]: https://azure.microsoft.com/documentation/articles/app-insights-api-custom-events-metrics/ [ContribGuide]: https://github.com/Microsoft/ApplicationInsights-Home/blob/master/CONTRIBUTING.md From 993ab21eee70c98081c0aabf35137fe840184eb8 Mon Sep 17 00:00:00 2001 From: abaranch Date: Tue, 5 Jul 2016 11:10:33 -0700 Subject: [PATCH 22/30] Add diagnostics event for backoff logic. --- .../Shared.Tests/Helpers/StubTransmitter.cs | 15 +- .../Helpers/TestableBackoffLogicManager.cs | 20 ++ .../Implementation/BackoffLogicManagerTest.cs | 248 ++++++++++++++++++ .../ErrorHandlingTransmissionPolicyTest.cs | 54 ++-- .../PartialSuccessTransmissionPolicyTest.cs | 12 +- .../TransmissionPolicyHelpersTest.cs | 111 -------- .../Shared.Tests/Shared.Tests.projitems | 3 +- .../Implementation/BackoffLogicManager.cs | 180 +++++++++++++ .../ErrorHandlingTransmissionPolicy.cs | 85 +++--- .../PartialSuccessTransmissionPolicy.cs | 67 ++--- .../TelemetryChannelEventSource.cs | 31 +++ .../ThrottlingTransmissionPolicy.cs | 75 ++---- .../Implementation/TransmissionPolicy.cs | 1 - .../TransmissionPolicyHelpers.cs | 106 -------- .../Shared/Implementation/Transmitter.cs | 18 +- .../Shared/Shared.projitems | 4 +- 16 files changed, 630 insertions(+), 400 deletions(-) create mode 100644 Test/ServerTelemetryChannel.Test/Shared.Tests/Helpers/TestableBackoffLogicManager.cs create mode 100644 Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs delete mode 100644 Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TransmissionPolicyHelpersTest.cs create mode 100644 src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs delete mode 100644 src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Helpers/StubTransmitter.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Helpers/StubTransmitter.cs index bb1c8fe2e6..b4b18cc9b3 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Helpers/StubTransmitter.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Helpers/StubTransmitter.cs @@ -3,10 +3,8 @@ using System; using System.Linq; using Microsoft.ApplicationInsights.Channel; + using Microsoft.ApplicationInsights.Channel.Implementation; using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Implementation; -#if NET45 - using TaskEx = System.Threading.Tasks.Task; -#endif internal class StubTransmitter : Transmitter { @@ -14,10 +12,19 @@ internal class StubTransmitter : Transmitter public Action OnEnqueue = transmission => { }; public Action OnInitialize = () => { }; + public Func OnGetBackOffTime = timeInMs => TimeSpan.FromMilliseconds(timeInMs); + public StubTransmitter() - : base(new StubTransmissionSender(), new StubTransmissionBuffer(), new StubTransmissionStorage(), Enumerable.Empty()) + : base(new StubTransmissionSender(), new StubTransmissionBuffer(), new StubTransmissionStorage(), Enumerable.Empty(), new BackoffLogicManager(TimeSpan.FromMinutes(30))) { + + } + + public StubTransmitter(BackoffLogicManager backoffLogicManager) + : base(new StubTransmissionSender(), new StubTransmissionBuffer(), new StubTransmissionStorage(), Enumerable.Empty(), backoffLogicManager) + { + } internal override void Initialize() diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Helpers/TestableBackoffLogicManager.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Helpers/TestableBackoffLogicManager.cs new file mode 100644 index 0000000000..d9f1ecc746 --- /dev/null +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Helpers/TestableBackoffLogicManager.cs @@ -0,0 +1,20 @@ +namespace Microsoft.ApplicationInsights.WindowsServer.Channel.Helpers +{ + using System; + using Microsoft.ApplicationInsights.Channel.Implementation; + + internal class TestableBackoffLogicManager : BackoffLogicManager + { + private readonly TimeSpan backoffInterval; + + public TestableBackoffLogicManager(TimeSpan backoffInterval, int defaultBackoffEnabledIntervalInMin = 30) : base(TimeSpan.FromMinutes(defaultBackoffEnabledIntervalInMin)) + { + this.backoffInterval = backoffInterval; + } + + protected override TimeSpan GetBackOffTime(string headerValue) + { + return this.backoffInterval; + } + } +} diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs new file mode 100644 index 0000000000..be5467bcd5 --- /dev/null +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs @@ -0,0 +1,248 @@ +namespace Microsoft.ApplicationInsights.WindowsServer.Channel.Implementation +{ + using System; +#if !NET40 + using System.Diagnostics.Tracing; +#endif + + using System.Globalization; + using System.Net; + using System.Linq; + + using Microsoft.ApplicationInsights.WindowsServer.Channel.Helpers; + +#if NET40 + using Microsoft.Diagnostics.Tracing; +#endif + + using Microsoft.VisualStudio.TestTools.UnitTesting; + + using Microsoft.ApplicationInsights.Channel; + using Microsoft.ApplicationInsights.Channel.Implementation; + using Microsoft.ApplicationInsights.Extensibility.Implementation; + using Microsoft.ApplicationInsights.Web.TestFramework; + using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Helpers; + using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Implementation; + + using Assert = Xunit.Assert; + + public class BackoffLogicManagerTest + { + [TestClass] + public class GetBackendResponse + { + public void ReturnNullIfArgumentIsNull() + { + var manager = new BackoffLogicManager(TimeSpan.Zero); + Assert.Null(manager.GetBackendResponse(null)); + } + + public void ReturnNullIfArgumentEmpty() + { + var manager = new BackoffLogicManager(TimeSpan.Zero); + Assert.Null(manager.GetBackendResponse(string.Empty)); + } + + public void IfContentCannotBeParsedNullIsReturned() + { + var manager = new BackoffLogicManager(TimeSpan.Zero); + Assert.Null(manager.GetBackendResponse("ab}{")); + } + + public void IfContentIsUnexpectedJsonNullIsReturned() + { + var manager = new BackoffLogicManager(TimeSpan.Zero); + Assert.Null(manager.GetBackendResponse("[1,2]")); + } + + public void BackendResponseIsReturnedForCorrectContent() + { + string content = BackendResponseHelper.CreateBackendResponse(100, 1, new[] {"206"}, 84); + + var manager = new BackoffLogicManager(TimeSpan.Zero); + var backendResponse = manager.GetBackendResponse(content); + + Assert.Equal(1, backendResponse.ItemsAccepted); + Assert.Equal(100, backendResponse.ItemsReceived); + Assert.Equal(1, backendResponse.Errors.Length); + Assert.Equal(84, backendResponse.Errors[0].Index); + Assert.Equal(206, backendResponse.Errors[0].StatusCode); + Assert.Equal("Explanation", backendResponse.Errors[0].Message); + } + } + + [TestClass] + public class ScheduleRestore + { + [TestMethod] + public void NoErrorDelayIsSameAsSlotDelay() + { + var manager = new BackoffLogicManager(TimeSpan.Zero); + manager.ScheduleRestore(string.Empty, () => null); + Assert.Equal(TimeSpan.FromSeconds(10), manager.CurrentDelay); + } + + [TestMethod] + public void FirstErrorDelayIsSameAsSlotDelay() + { + var manager = new BackoffLogicManager(TimeSpan.Zero); + manager.ConsecutiveErrors++; + manager.ScheduleRestore(string.Empty, () => null); + Assert.Equal(TimeSpan.FromSeconds(10), manager.CurrentDelay); + } + + [TestMethod] + public void UpperBoundOfDelayIsMaxDelay() + { + var manager = new BackoffLogicManager(TimeSpan.Zero) { ConsecutiveErrors = int.MaxValue }; + manager.ScheduleRestore(string.Empty, () => null); + Assert.InRange(manager.CurrentDelay, TimeSpan.FromSeconds(10), TimeSpan.FromSeconds(3600)); + } + + [TestMethod] + public void RetryAfterFromHeadersHasMorePriorityThanExponentialRetry() + { + WebHeaderCollection headers = new WebHeaderCollection(); + headers.Add("Retry-After", DateTimeOffset.UtcNow.AddSeconds(30).ToString("O")); + + var manager = new BackoffLogicManager(TimeSpan.Zero); + manager.ScheduleRestore(headers, () => null); + + Xunit.Assert.InRange(manager.CurrentDelay, TimeSpan.FromSeconds(20), TimeSpan.FromSeconds(30)); + } + + [TestMethod] + public void AssertIfDateParseErrorCausesDefaultDelay() + { + WebHeaderCollection headers = new WebHeaderCollection(); + headers.Add("Retry-After", "no one can parse me"); + + var manager = new BackoffLogicManager(TimeSpan.Zero); + manager.ScheduleRestore(headers, () => null); + Assert.Equal(TimeSpan.FromSeconds(10), manager.CurrentDelay); + } + + [TestMethod] + public void RetryAfterOlderThanNowCausesDefaultDelay() + { + // An old date + string retryAfterDateString = DateTime.Now.AddMinutes(-1).ToString("R", CultureInfo.InvariantCulture); + + WebHeaderCollection headers = new WebHeaderCollection(); + headers.Add("Retry-After", retryAfterDateString); + + var manager = new BackoffLogicManager(TimeSpan.Zero); + manager.ScheduleRestore(headers, () => null); + Assert.Equal(TimeSpan.FromSeconds(10), manager.CurrentDelay); + } + } + + [TestClass] + public class ReportDiagnosticMessage + { + [TestMethod] + public void ReportBackoffWriteMessageOnce() + { + using (var listener = new TestEventListener()) + { + const long AllKeywords = -1; + listener.EnableEvents(TelemetryChannelEventSource.Log, EventLevel.Error, (EventKeywords)AllKeywords); + + var manager = new BackoffLogicManager(TimeSpan.Zero); + manager.ReportBackoffEnabled(200); + manager.ReportBackoffEnabled(200); + + var traces = listener.Messages.ToList(); + + Assert.Equal(1, traces.Count); + Assert.Equal(2, traces[0].EventId); + } + } + + [TestMethod] + public void ReportBackoffWriteDoesNotLogMessagesBeforeIntervalPasses() + { + using (var listener = new TestEventListener()) + { + const long AllKeywords = -1; + listener.EnableEvents(TelemetryChannelEventSource.Log, EventLevel.Error, (EventKeywords)AllKeywords); + + var manager = new BackoffLogicManager(TimeSpan.FromSeconds(20)); + + manager.ReportBackoffEnabled(200); + manager.ReportBackoffEnabled(200); + + var traces = listener.Messages.ToList(); + + Assert.Equal(0, traces.Count); + } + } + + [TestMethod] + public void ReportBackoffWritesLogMessagesAfterIntervalPasses() + { + using (var listener = new TestEventListener()) + { + const long AllKeywords = -1; + listener.EnableEvents(TelemetryChannelEventSource.Log, EventLevel.Error, (EventKeywords)AllKeywords); + + var manager = new BackoffLogicManager(TimeSpan.FromMilliseconds(10)); + + System.Threading.Thread.Sleep(10); + + manager.ReportBackoffEnabled(200); + manager.ReportBackoffEnabled(200); + + var traces = listener.Messages.ToList(); + + Assert.Equal(1, traces.Count); + } + } + + [TestMethod] + public void ReportBackoffWriteIsLoggedAgainAfterReportDisabledWasCalled() + { + using (var listener = new TestEventListener()) + { + const long AllKeywords = -1; + listener.EnableEvents(TelemetryChannelEventSource.Log, EventLevel.Error, (EventKeywords)AllKeywords); + + var manager = new BackoffLogicManager(TimeSpan.Zero); + + manager.ReportBackoffEnabled(200); + manager.ReportBackoffEnabled(200); + + manager.ReportBackoffDisabled(); + manager.ReportBackoffDisabled(); + + manager.ReportBackoffEnabled(200); + manager.ReportBackoffEnabled(200); + + var traces = listener.Messages.ToList(); + Assert.Equal(3, traces.Count); + Assert.Equal(2, traces[0].EventId); + Assert.Equal(1, traces[1].EventId); + Assert.Equal(2, traces[2].EventId); + } + } + + [TestMethod] + public void DisableDoesNotLogMessageIfEnabledWasNotCalled() + { + using (var listener = new TestEventListener()) + { + const long AllKeywords = -1; + listener.EnableEvents(TelemetryChannelEventSource.Log, EventLevel.Error, (EventKeywords)AllKeywords); + + var manager = new BackoffLogicManager(TimeSpan.Zero); + + manager.ReportBackoffDisabled(); + manager.ReportBackoffDisabled(); + + var traces = listener.Messages.ToList(); + Assert.Equal(0, traces.Count); + } + } + } + } +} diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs index 75b2462aaf..4aed80e0a8 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/ErrorHandlingTransmissionPolicyTest.cs @@ -4,14 +4,12 @@ #if NET45 using System.Diagnostics.Tracing; #endif - using System.Collections.Generic; - using System.Collections.Specialized; - using System.Globalization; using System.Linq; using System.Net; using System.Threading; using System.Threading.Tasks; using Microsoft.ApplicationInsights.Channel; + using Microsoft.ApplicationInsights.Channel.Implementation; using Microsoft.ApplicationInsights.Extensibility.Implementation; using Microsoft.ApplicationInsights.WindowsServer.Channel.Helpers; using Microsoft.ApplicationInsights.Web.TestFramework; @@ -23,9 +21,6 @@ using Assert = Xunit.Assert; using System.Text; using System.IO; -#if NET45 - using TaskEx = System.Threading.Tasks.Task; -#endif public class ErrorHandlingTransmissionPolicyTest { @@ -36,16 +31,15 @@ public class HandleTransmissionSentEvent : ErrorHandlingTransmissionPolicyTest public void StopsTransmissionSendingWhenTransmissionTimesOut() { var policyApplied = new AutoResetEvent(false); - var transmitter = new StubTransmitter(); + var transmitter = new StubTransmitter(new TestableBackoffLogicManager(TimeSpan.FromSeconds(10))); transmitter.OnApplyPolicies = () => { policyApplied.Set(); }; - var policy = new TestableErrorHandlingTransmissionPolicy(); + var policy = new ErrorHandlingTransmissionPolicy(); policy.Initialize(transmitter); - policy.BackOffTime = TimeSpan.FromSeconds(10); transmitter.OnTransmissionSent(new TransmissionProcessedEventArgs(new StubTransmission(), CreateException(statusCode: 408))); Assert.True(policyApplied.WaitOne(100)); @@ -56,16 +50,15 @@ public void StopsTransmissionSendingWhenTransmissionTimesOut() public void ResumesTransmissionSenderAfterPauseDuration() { var policyApplied = new AutoResetEvent(false); - var transmitter = new StubTransmitter(); + var transmitter = new StubTransmitter(new TestableBackoffLogicManager(TimeSpan.FromMilliseconds(1))); transmitter.OnApplyPolicies = () => { policyApplied.Set(); }; - var policy = new TestableErrorHandlingTransmissionPolicy(); + var policy = new ErrorHandlingTransmissionPolicy(); policy.Initialize(transmitter); - policy.BackOffTime = TimeSpan.FromMilliseconds(1); transmitter.OnTransmissionSent(new TransmissionProcessedEventArgs(new StubTransmission(), CreateException(statusCode: 408))); Assert.True(policyApplied.WaitOne(100)); @@ -76,14 +69,11 @@ public void ResumesTransmissionSenderAfterPauseDuration() [TestMethod] public void KeepsTransmissionSenderPausedWhenAdditionalTransmissionsFail() { - var transmitter = new StubTransmitter(); - var policy = new TestableErrorHandlingTransmissionPolicy(); + var transmitter = new StubTransmitter(new TestableBackoffLogicManager(TimeSpan.FromMinutes(1))); + var policy = new ErrorHandlingTransmissionPolicy(); policy.Initialize(transmitter); - policy.BackOffTime = TimeSpan.FromMilliseconds(10); transmitter.OnTransmissionSent(new TransmissionProcessedEventArgs(new StubTransmission(), CreateException(statusCode: 408))); - - policy.BackOffTime = TimeSpan.FromMilliseconds(50); transmitter.OnTransmissionSent(new TransmissionProcessedEventArgs(new StubTransmission(), CreateException(statusCode: 408))); Thread.Sleep(TimeSpan.FromMilliseconds(30)); @@ -114,14 +104,14 @@ public void RetriesFailedTransmissionIfItsNumberOfAttemptsDidNotReachMaximum() public void RetriesFailedTransmissionInfinitely() { Transmission enqueuedTransmission = null; - var transmitter = new StubTransmitter(); + + var transmitter = new StubTransmitter(new TestableBackoffLogicManager(TimeSpan.FromMilliseconds(10))); transmitter.OnEnqueue = transmission => { enqueuedTransmission = transmission; }; - var policy = new TestableErrorHandlingTransmissionPolicy(); - policy.BackOffTime = TimeSpan.FromMilliseconds(10); + var policy = new ErrorHandlingTransmissionPolicy(); policy.Initialize(transmitter); var failedTransmission = new StubTransmission(); @@ -148,7 +138,7 @@ public void DoesNotRetrySuccessfulTransmission() transmitter.OnTransmissionSent(new TransmissionProcessedEventArgs(successfulTransmission)); Assert.Null(enqueuedTransmission); - Assert.Equal(0, policy.ConsecutiveErrors); + Assert.Equal(0, transmitter.BackoffLogicManager.ConsecutiveErrors); } [TestMethod] @@ -172,9 +162,9 @@ public void CatchesAndLogsAsynchronousExceptionsThrownByTransmitterWhenPausingTr [TestMethod, Timeout(1000)] public void CatchesAndLogsSynchronousExceptionsThrownByTransmitterWhenResumingTransmission() { - var policy = new TestableErrorHandlingTransmissionPolicy { BackOffTime = TimeSpan.FromMilliseconds(1) }; + var policy = new ErrorHandlingTransmissionPolicy(); var exception = CreateException(statusCode: 408); - var transmitter = new StubTransmitter(); + var transmitter = new StubTransmitter(new TestableBackoffLogicManager(TimeSpan.FromMilliseconds(1))); transmitter.OnApplyPolicies = () => { if (policy.MaxSenderCapacity == null) @@ -195,16 +185,12 @@ public void LogsAdditionalTracesIfResponseIsProvided() listener.EnableEvents(TelemetryChannelEventSource.Log, EventLevel.LogAlways, (EventKeywords)AllKeywords); Transmission enqueuedTransmission = null; - var transmitter = new StubTransmitter + var transmitter = new StubTransmitter (new BackoffLogicManager(TimeSpan.FromMilliseconds(10))) { OnEnqueue = transmission => { enqueuedTransmission = transmission; } }; - var policy = new TestableErrorHandlingTransmissionPolicy - { - BackOffTime = TimeSpan.FromMilliseconds(10) - }; - + var policy = new ErrorHandlingTransmissionPolicy(); policy.Initialize(transmitter); var failedTransmission = new StubTransmission(); @@ -261,15 +247,5 @@ private static WebException CreateException(int statusCode) return new WebException("Transmitter Error", null, WebExceptionStatus.UnknownError, mockWebResponse.Object); } } - - private class TestableErrorHandlingTransmissionPolicy : ErrorHandlingTransmissionPolicy - { - public TimeSpan BackOffTime { get; set; } - - protected override TimeSpan GetBackOffTime(NameValueCollection headers = null) - { - return this.BackOffTime; - } - } } } \ No newline at end of file diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/PartialSuccessTransmissionPolicyTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/PartialSuccessTransmissionPolicyTest.cs index 58ecb8c6a6..a4431630d7 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/PartialSuccessTransmissionPolicyTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/PartialSuccessTransmissionPolicyTest.cs @@ -2,9 +2,9 @@ { using System; using System.Collections.Generic; - using System.Globalization; using Microsoft.ApplicationInsights.Channel; + using Microsoft.ApplicationInsights.Channel.Implementation; using Microsoft.ApplicationInsights.DataContracts; using Microsoft.ApplicationInsights.Extensibility.Implementation; using Microsoft.ApplicationInsights.WindowsServer.Channel.Helpers; @@ -109,7 +109,7 @@ public void IfNumberOfRecievedItemsEqualsToNumberOfAcceptedErrorsListIsIgnored() transmitter.OnTransmissionSent(new TransmissionProcessedEventArgs(transmission, null, wrapper)); - Assert.Equal(0, policy.ConsecutiveErrors); + Assert.Equal(0, transmitter.BackoffLogicManager.ConsecutiveErrors); } [TestMethod] @@ -181,7 +181,7 @@ public void IfMultipleItemsAreRejectedNumberOfErrorsIsIncreasedByOne() transmitter.OnTransmissionSent(new TransmissionProcessedEventArgs(transmission, null, wrapper)); - Assert.Equal(1, policy.ConsecutiveErrors); + Assert.Equal(1, transmitter.BackoffLogicManager.ConsecutiveErrors); } [TestMethod] @@ -209,7 +209,7 @@ public void IfResponseIsBadJsonWeDoNotIncreaseErrorCount() transmitter.OnTransmissionSent(new TransmissionProcessedEventArgs(transmission, null, wrapper)); - Assert.Equal(0, policy.ConsecutiveErrors); + Assert.Equal(0, transmitter.BackoffLogicManager.ConsecutiveErrors); Assert.Equal(0, enqueuedTransmissions.Count); } @@ -243,7 +243,7 @@ public void IfIndexMoreThanNumberOfItemsInTransmissionIgnoreError() transmitter.OnTransmissionSent(new TransmissionProcessedEventArgs(transmission, null, wrapper)); - Assert.Equal(0, policy.ConsecutiveErrors); + Assert.Equal(0, transmitter.BackoffLogicManager.ConsecutiveErrors); Assert.Equal(0, enqueuedTransmissions.Count); } @@ -275,7 +275,7 @@ public void DoesNotSendTransmissionForUnsupportedCodes() transmitter.OnTransmissionSent(new TransmissionProcessedEventArgs(transmission, null, wrapper)); - Assert.Equal(0, policy.ConsecutiveErrors); + Assert.Equal(0, transmitter.BackoffLogicManager.ConsecutiveErrors); Assert.Equal(0, enqueuedTransmissions.Count); } } diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TransmissionPolicyHelpersTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TransmissionPolicyHelpersTest.cs deleted file mode 100644 index 25b0c65cb5..0000000000 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/TransmissionPolicyHelpersTest.cs +++ /dev/null @@ -1,111 +0,0 @@ -namespace Microsoft.ApplicationInsights.WindowsServer.Channel.Implementation -{ - using System; - using System.Globalization; - using System.Net; - using Microsoft.ApplicationInsights.Channel.Implementation; - using Microsoft.ApplicationInsights.WindowsServer.Channel.Helpers; - using Microsoft.VisualStudio.TestTools.UnitTesting; - using Assert = Xunit.Assert; - - [TestClass] - public class TransmissionPolicyHelpersTest - { - [TestClass] - public class GetBackendResponse - { - public void ReturnNullIfArgumentIsNull() - { - Assert.Null(TransmissionPolicyHelpers.GetBackendResponse(null)); - } - - public void ReturnNullIfArgumentEmpty() - { - Assert.Null(TransmissionPolicyHelpers.GetBackendResponse(string.Empty)); - } - - public void IfContentCannotBeParsedNullIsReturned() - { - Assert.Null(TransmissionPolicyHelpers.GetBackendResponse("ab}{")); - } - - public void IfContentIsUnexpectedJsonNullIsReturned() - { - Assert.Null(TransmissionPolicyHelpers.GetBackendResponse("[1,2]")); - } - - public void BackendResponseIsReturnedForCorrectContent() - { - string content = BackendResponseHelper.CreateBackendResponse(100, 1, new[] {"206"}, 84); - - var backendResponse = TransmissionPolicyHelpers.GetBackendResponse(content); - - Assert.Equal(1, backendResponse.ItemsAccepted); - Assert.Equal(100, backendResponse.ItemsReceived); - Assert.Equal(1, backendResponse.Errors.Length); - Assert.Equal(84, backendResponse.Errors[0].Index); - Assert.Equal(206, backendResponse.Errors[0].StatusCode); - Assert.Equal("Explanation", backendResponse.Errors[0].Message); - } - } - - [TestClass] - public class GetBackOffTime - { - [TestMethod] - public void NoErrorDelayIsSameAsSlotDelay() - { - TimeSpan delay = TransmissionPolicyHelpers.GetBackOffTime(0, new WebHeaderCollection()); - Assert.Equal(TimeSpan.FromSeconds(10), delay); - } - - [TestMethod] - public void FirstErrorDelayIsSameAsSlotDelay() - { - TimeSpan delay = TransmissionPolicyHelpers.GetBackOffTime(1, new WebHeaderCollection()); - Assert.Equal(TimeSpan.FromSeconds(10), delay); - } - - [TestMethod] - public void UpperBoundOfDelayIsMaxDelay() - { - TimeSpan delay = TransmissionPolicyHelpers.GetBackOffTime(int.MaxValue, new WebHeaderCollection()); - Assert.InRange(delay, TimeSpan.FromSeconds(10), TimeSpan.FromSeconds(3600)); - } - - [TestMethod] - public void RetryAfterFromHeadersHasMorePriorityThanExponentialRetry() - { - WebHeaderCollection headers = new WebHeaderCollection(); - headers.Add("Retry-After", DateTimeOffset.UtcNow.AddSeconds(30).ToString("O")); - - TimeSpan delay = TransmissionPolicyHelpers.GetBackOffTime(0, headers); - - Xunit.Assert.InRange(delay, TimeSpan.FromSeconds(20), TimeSpan.FromSeconds(30)); - } - - [TestMethod] - public void AssertIfDateParseErrorCausesDefaultDelay() - { - WebHeaderCollection headers = new WebHeaderCollection(); - headers.Add("Retry-After", "no one can parse me"); - - TimeSpan delay = TransmissionPolicyHelpers.GetBackOffTime(0, headers); - Assert.Equal(TimeSpan.FromSeconds(10), delay); - } - - [TestMethod] - public void RetryAfterOlderThanNowCausesDefaultDelay() - { - // An old date - string retryAfterDateString = DateTime.Now.AddMinutes(-1).ToString("R", CultureInfo.InvariantCulture); - - WebHeaderCollection headers = new WebHeaderCollection(); - headers.Add("Retry-After", retryAfterDateString); - - TimeSpan delay = TransmissionPolicyHelpers.GetBackOffTime(0, headers); - Assert.Equal(TimeSpan.FromSeconds(10), delay); - } - } - } -} diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Shared.Tests.projitems b/Test/ServerTelemetryChannel.Test/Shared.Tests/Shared.Tests.projitems index 45ec0fa33b..2cf778e965 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Shared.Tests.projitems +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Shared.Tests.projitems @@ -21,6 +21,7 @@ + @@ -39,7 +40,7 @@ - + diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs new file mode 100644 index 0000000000..4ae741123c --- /dev/null +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs @@ -0,0 +1,180 @@ +namespace Microsoft.ApplicationInsights.Channel.Implementation +{ + using System; + using System.Net; + using System.Threading.Tasks; + using System.Web.Script.Serialization; + + using Microsoft.ApplicationInsights.Extensibility.Implementation; + using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Implementation; + +#if CORE_PCL || NET45 || NET46 + using TaskEx = System.Threading.Tasks.Task; +#endif + + internal class BackoffLogicManager : IDisposable + { + private const int SlotDelayInSeconds = 10; + private const int MaxDelayInSeconds = 3600; + + private static readonly Random Random = new Random(); + private static readonly JavaScriptSerializer Serializer = new JavaScriptSerializer(); + + private readonly TimeSpan defaultBackoffEnabledReportingInterval; + + private TaskTimer pauseTimer = new TaskTimer { Delay = TimeSpan.FromSeconds(SlotDelayInSeconds) }; + private bool exponentialBackoffReported = false; + + public BackoffLogicManager(TimeSpan defaultBackoffEnabledReportingInterval) + { + this.defaultBackoffEnabledReportingInterval = defaultBackoffEnabledReportingInterval; + } + + /// + /// Gets or sets the number of consecutive errors SDK transmitter got so far while sending telemetry to backend. + /// + public int ConsecutiveErrors { get; set; } + + internal TimeSpan CurrentDelay + { + get { return this.pauseTimer.Delay; } + } + + public void ScheduleRestore(WebHeaderCollection headers, Func elapsedFunc) + { + // Back-off for the Delay duration and enable sending capacity + string retryAfterHeader = string.Empty; + if (headers != null) + { + retryAfterHeader = headers.Get("Retry-After"); + } + + this.ScheduleRestore(retryAfterHeader, elapsedFunc); + } + + public void ScheduleRestore(string retryAfterHeader, Func elapsedFunc) + { + // Back-off for the Delay duration and enable sending capacity + this.pauseTimer.Delay = this.GetBackOffTime(retryAfterHeader); + this.pauseTimer.Start(elapsedFunc); + } + + public BackendResponse GetBackendResponse(string responseContent) + { + BackendResponse backendResponse = null; + + try + { + if (!string.IsNullOrEmpty(responseContent)) + { + backendResponse = Serializer.Deserialize(responseContent); + } + } + catch (ArgumentException exp) + { + TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); + backendResponse = null; + } + catch (InvalidOperationException exp) + { + TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); + backendResponse = null; + } + + return backendResponse; + } + + public void ReportBackoffEnabled(int statusCode) + { + if (!this.exponentialBackoffReported && this.pauseTimer.Delay > this.defaultBackoffEnabledReportingInterval) + { + TelemetryChannelEventSource.Log.BackoffEnabled(this.pauseTimer.Delay.TotalMinutes, statusCode); + this.exponentialBackoffReported = true; + } + } + + public void ReportBackoffDisabled() + { + if (this.exponentialBackoffReported) + { + TelemetryChannelEventSource.Log.BackoffDisabled(); + this.exponentialBackoffReported = false; + } + } + + public void Dispose() + { + this.Dispose(true); + GC.SuppressFinalize(this); + } + + // Calculates the time to wait before retrying in case of an error based on + // http://en.wikipedia.org/wiki/Exponential_backoff + protected virtual TimeSpan GetBackOffTime(string headerValue) + { + TimeSpan retryAfterTimeSpan; + if (!this.TryParseRetryAfter(headerValue, out retryAfterTimeSpan)) + { + double delayInSeconds; + + if (this.ConsecutiveErrors <= 1) + { + delayInSeconds = SlotDelayInSeconds; + } + else + { + double backOffSlot = (Math.Pow(2, this.ConsecutiveErrors) - 1) / 2; + var backOffDelay = Random.Next(1, (int)Math.Min(backOffSlot * SlotDelayInSeconds, int.MaxValue)); + delayInSeconds = Math.Max(Math.Min(backOffDelay, MaxDelayInSeconds), SlotDelayInSeconds); + } + + TelemetryChannelEventSource.Log.BackoffTimeSetInSeconds(delayInSeconds); + retryAfterTimeSpan = TimeSpan.FromSeconds(delayInSeconds); + } + + TelemetryChannelEventSource.Log.BackoffInterval(retryAfterTimeSpan.TotalSeconds); + return retryAfterTimeSpan; + } + + private bool TryParseRetryAfter(string retryAfter, out TimeSpan retryAfterTimeSpan) + { + retryAfterTimeSpan = TimeSpan.FromSeconds(0); + + if (string.IsNullOrEmpty(retryAfter)) + { + return false; + } + + TelemetryChannelEventSource.Log.RetryAfterHeaderIsPresent(retryAfter); + + var now = DateTimeOffset.UtcNow; + DateTimeOffset retryAfterDate; + if (DateTimeOffset.TryParse(retryAfter, out retryAfterDate)) + { + if (retryAfterDate > now) + { + retryAfterTimeSpan = retryAfterDate - now; + return true; + } + + return false; + } + + TelemetryChannelEventSource.Log.TransmissionPolicyRetryAfterParseFailedWarning(retryAfter); + + return false; + } + + private void Dispose(bool disposing) + { + if (disposing) + { + if (this.pauseTimer != null) + { + this.pauseTimer.Dispose(); + this.pauseTimer = null; + } + } + } + } +} diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs index d07072e17e..55662b6b78 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs @@ -1,39 +1,31 @@ namespace Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Implementation { using System; - using System.Collections.Specialized; using System.IO; using System.Net; using System.Threading.Tasks; using Microsoft.ApplicationInsights.Channel.Implementation; - using Microsoft.ApplicationInsights.Extensibility.Implementation; #if NET45 using TaskEx = System.Threading.Tasks.Task; #endif - internal class ErrorHandlingTransmissionPolicy : TransmissionPolicy, IDisposable + internal class ErrorHandlingTransmissionPolicy : TransmissionPolicy { - private TaskTimer pauseTimer = new TaskTimer { Delay = TimeSpan.FromSeconds(TransmissionPolicyHelpers.SlotDelayInSeconds) }; - - public int ConsecutiveErrors { get; set; } + private BackoffLogicManager backoffLogicManager; public override void Initialize(Transmitter transmitter) { - base.Initialize(transmitter); - transmitter.TransmissionSent += this.HandleTransmissionSentEvent; - } + if (transmitter == null) + { + throw new ArgumentNullException(); + } - public void Dispose() - { - this.Dispose(true); - GC.SuppressFinalize(this); - } + this.backoffLogicManager = transmitter.BackoffLogicManager; - protected virtual TimeSpan GetBackOffTime(NameValueCollection headers) - { - return TransmissionPolicyHelpers.GetBackOffTime(this.ConsecutiveErrors, headers); + base.Initialize(transmitter); + transmitter.TransmissionSent += this.HandleTransmissionSentEvent; } private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEventArgs e) @@ -41,7 +33,8 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve var webException = e.Exception as WebException; if (webException != null) { - this.ConsecutiveErrors++; + // We do not send data very often so we do not care about locking the counter + this.backoffLogicManager.ConsecutiveErrors++; HttpWebResponse httpWebResponse = webException.Response as HttpWebResponse; if (httpWebResponse != null) { @@ -50,37 +43,43 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve webException.Message, (int)httpWebResponse.StatusCode, httpWebResponse.StatusDescription); + this.AdditionalVerboseTracing(httpWebResponse); switch (httpWebResponse.StatusCode) { - case (HttpStatusCode)408: - case (HttpStatusCode)503: - case (HttpStatusCode)500: - // Disable sending and buffer capacity (=EnqueueAsync will enqueue to the Storage) + case (HttpStatusCode)ResponseStatusCodes.RequestTimeout: + case (HttpStatusCode)ResponseStatusCodes.ServiceUnavailable: + case (HttpStatusCode)ResponseStatusCodes.InternalServerError: + // Disable sending and buffer capacity (Enqueue will enqueue to the Storage) this.MaxSenderCapacity = 0; this.MaxBufferCapacity = 0; this.LogCapacityChanged(); this.Apply(); - // Back-off for the Delay duration and enable sending capacity - this.pauseTimer.Delay = this.GetBackOffTime(httpWebResponse.Headers); - this.pauseTimer.Start(() => - { - this.MaxBufferCapacity = null; - this.MaxSenderCapacity = null; - this.LogCapacityChanged(); - this.Apply(); + this.backoffLogicManager.ReportBackoffEnabled((int)httpWebResponse.StatusCode); + this.Transmitter.Enqueue(e.Transmission); + + this.backoffLogicManager.ScheduleRestore( + httpWebResponse.Headers, + () => + { + this.MaxBufferCapacity = null; + this.MaxSenderCapacity = null; + this.LogCapacityChanged(); + this.Apply(); - return TaskEx.FromResult(null); - }); + this.backoffLogicManager.ReportBackoffDisabled(); - this.Transmitter.Enqueue(e.Transmission); + return TaskEx.FromResult(null); + }); break; } } else { + // We are loosing data here (we did not upload failed transaction back). + // We did not get response back. TelemetryChannelEventSource.Log.TransmissionSendingFailedWebExceptionWarning(e.Transmission.Id, webException.Message, (int)HttpStatusCode.InternalServerError, null); } } @@ -88,10 +87,10 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve { if (e.Exception != null) { + // We are loosing data here (we did not upload failed transaction back). + // We got unknown exception. TelemetryChannelEventSource.Log.TransmissionSendingFailedWarning(e.Transmission.Id, e.Exception.Message); } - - this.ConsecutiveErrors = 0; } } @@ -111,7 +110,7 @@ private void AdditionalVerboseTracing(HttpWebResponse httpResponse) if (!string.IsNullOrEmpty(response)) { - BackendResponse backendResponse = TransmissionPolicyHelpers.GetBackendResponse(response); + BackendResponse backendResponse = this.backoffLogicManager.GetBackendResponse(response); if (backendResponse != null && backendResponse.Errors != null) { @@ -132,18 +131,6 @@ private void AdditionalVerboseTracing(HttpWebResponse httpResponse) // This code is for tracing purposes only; it cannot not throw } } - } - - private void Dispose(bool disposing) - { - if (disposing) - { - if (this.pauseTimer != null) - { - this.pauseTimer.Dispose(); - this.pauseTimer = null; - } - } - } + } } } \ No newline at end of file diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs index ade16cc9c5..9839185b64 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs @@ -12,33 +12,39 @@ using TaskEx = System.Threading.Tasks.Task; #endif - internal class PartialSuccessTransmissionPolicy : TransmissionPolicy, IDisposable + internal class PartialSuccessTransmissionPolicy : TransmissionPolicy { - private TaskTimer pauseTimer = new TaskTimer { Delay = TimeSpan.FromSeconds(TransmissionPolicyHelpers.SlotDelayInSeconds) }; - - public int ConsecutiveErrors { get; set; } + private BackoffLogicManager backoffLogicManager; public override void Initialize(Transmitter transmitter) { + if (transmitter == null) + { + throw new ArgumentNullException(); + } + + this.backoffLogicManager = transmitter.BackoffLogicManager; + base.Initialize(transmitter); transmitter.TransmissionSent += this.HandleTransmissionSentEvent; } - public void Dispose() - { - this.Dispose(true); - GC.SuppressFinalize(this); - } - private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEventArgs args) { + if (args.Exception == null && args.Response == null) + { + // We succesfully sent transmittion + this.backoffLogicManager.ConsecutiveErrors = 0; + return; + } + if (args.Response != null && args.Response.StatusCode == ResponseStatusCodes.PartialSuccess) { string newTransmissions = this.ParsePartialSuccessResponse(args.Transmission, args); if (!string.IsNullOrEmpty(newTransmissions)) { - this.ConsecutiveErrors++; + this.backoffLogicManager.ConsecutiveErrors++; this.DelayFutureProcessing(args.Response); byte[] data = JsonSerializer.ConvertToByteArray(newTransmissions); @@ -51,6 +57,11 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve this.Transmitter.Enqueue(newTransmission); } + else + { + // We got 206 but there is no indication in response that something was not accepted. + this.backoffLogicManager.ConsecutiveErrors = 0; + } } } @@ -60,12 +71,11 @@ private string ParsePartialSuccessResponse(Transmission initialTransmission, Tra if (args != null && args.Response != null) { - backendResponse = TransmissionPolicyHelpers.GetBackendResponse(args.Response.Content); + backendResponse = this.backoffLogicManager.GetBackendResponse(args.Response.Content); } if (backendResponse == null) { - this.ConsecutiveErrors = 0; return null; } @@ -119,28 +129,19 @@ private void DelayFutureProcessing(HttpWebResponseWrapper response) this.Apply(); // Back-off for the Delay duration and enable sending capacity - this.pauseTimer.Delay = TransmissionPolicyHelpers.GetBackOffTime(this.ConsecutiveErrors, response.RetryAfterHeader); - this.pauseTimer.Start(() => - { - this.MaxBufferCapacity = null; - this.MaxSenderCapacity = null; - this.LogCapacityChanged(); - this.Apply(); + this.backoffLogicManager.ReportBackoffEnabled(206); - return TaskEx.FromResult(null); - }); - } + this.backoffLogicManager.ScheduleRestore( + response.RetryAfterHeader, + () => + { + this.MaxBufferCapacity = null; + this.MaxSenderCapacity = null; + this.LogCapacityChanged(); + this.Apply(); - private void Dispose(bool disposing) - { - if (disposing) - { - if (this.pauseTimer != null) - { - this.pauseTimer.Dispose(); - this.pauseTimer = null; - } - } + return TaskEx.FromResult(null); + }); } } } diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs index 9690a20d0a..2dd739e984 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs @@ -30,6 +30,26 @@ public bool IsVerboseEnabled } } + // Verbosity is Error - so it is always sent to portal; Keyword is Diagnostics so throttling is not applied. + [Event(1, + Message = "It is a diagnostics message. Backoff logic was disabled. Transmission will be resolved.", + Level = EventLevel.Error, + Keywords = Keywords.Diagnostics | Keywords.UserActionable)] + public void BackoffDisabled(string appDomainName = "Incorrect") + { + this.WriteEvent(1, this.ApplicationName); + } + + // Verbosity is Error - so it is always sent to portal; Keyword is Diagnostics so throttling is not applied. + [Event(2, + Message = "It is a diagnostics message. Backoff logic was enabled. Backoff internal exceeded {0} min. Last status code received from the backend was {1}.", + Level = EventLevel.Error, + Keywords = Keywords.Diagnostics | Keywords.UserActionable)] + public void BackoffEnabled(double intervalInMin, int statusCode, string appDomainName = "Incorrect") + { + this.WriteEvent(2, intervalInMin, statusCode, this.ApplicationName); + } + [Event(3, Message = "Sampling skipped: {0}.", Level = EventLevel.Verbose)] public void SamplingSkippedByType(string telemetryType, string appDomainName = "Incorrect") { @@ -297,6 +317,15 @@ public void ApplyPoliciesError(string exception, string appDomainName = "Incorre this.WriteEvent(45, exception ?? string.Empty, this.ApplicationName); } + [Event(46, Message = "Retry-After http header: '{0}'. Transmission will be stopped.", Level = EventLevel.Warning)] + public void RetryAfterHeaderIsPresent(string retryAfterHeader, string appDomainName = "Incorrect") + { + this.WriteEvent( + 46, + retryAfterHeader ?? string.Empty, + this.ApplicationName); + } + [Event(48, Message = "TransmissionFailedToStoreWarning. TransmissionId: {0}. Exception: {1}.", Level = EventLevel.Warning)] public void TransmissionFailedToStoreWarning(string transmissionId, string exception, string appDomainName = "Incorrect") { @@ -398,6 +427,8 @@ private string GetApplicationName() public sealed class Keywords { public const EventKeywords UserActionable = (EventKeywords)0x1; + + public const EventKeywords Diagnostics = (EventKeywords)0x2; } } } diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ThrottlingTransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ThrottlingTransmissionPolicy.cs index e8481a7ebb..440887019a 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ThrottlingTransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ThrottlingTransmissionPolicy.cs @@ -5,26 +5,24 @@ using System.Threading.Tasks; using Microsoft.ApplicationInsights.Channel.Implementation; - using Microsoft.ApplicationInsights.Extensibility.Implementation; #if NET45 using TaskEx = System.Threading.Tasks.Task; #endif - internal class ThrottlingTransmissionPolicy : TransmissionPolicy, IDisposable + internal class ThrottlingTransmissionPolicy : TransmissionPolicy { - private TaskTimer pauseTimer = new TaskTimer { Delay = TimeSpan.FromSeconds(TransmissionPolicyHelpers.SlotDelayInSeconds) }; - - public int ConsecutiveErrors { get; set; } - - public void Dispose() - { - this.Dispose(true); - GC.SuppressFinalize(this); - } + private BackoffLogicManager backoffLogicManager; public override void Initialize(Transmitter transmitter) { + if (transmitter == null) + { + throw new ArgumentNullException(); + } + + this.backoffLogicManager = transmitter.BackoffLogicManager; + base.Initialize(transmitter); transmitter.TransmissionSent += this.HandleTransmissionSentEvent; } @@ -34,44 +32,41 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve var webException = e.Exception as WebException; if (webException != null) { - this.ConsecutiveErrors++; - HttpWebResponse httpWebResponse = webException.Response as HttpWebResponse; if (httpWebResponse != null) { if (httpWebResponse.StatusCode == (HttpStatusCode)ResponseStatusCodes.ResponseCodeTooManyRequests || httpWebResponse.StatusCode == (HttpStatusCode)ResponseStatusCodes.ResponseCodeTooManyRequestsOverExtendedTime) { - this.pauseTimer.Delay = TransmissionPolicyHelpers.GetBackOffTime(this.ConsecutiveErrors, httpWebResponse.Headers); - TelemetryChannelEventSource.Log.ThrottlingRetryAfterParsedInSec(this.pauseTimer.Delay.TotalSeconds); + this.backoffLogicManager.ConsecutiveErrors++; this.MaxSenderCapacity = 0; - this.MaxBufferCapacity = - httpWebResponse.StatusCode == - (HttpStatusCode)ResponseStatusCodes.ResponseCodeTooManyRequestsOverExtendedTime ? (int?)0 : null; - this.MaxStorageCapacity = - httpWebResponse.StatusCode == - (HttpStatusCode)ResponseStatusCodes.ResponseCodeTooManyRequestsOverExtendedTime ? (int?)0 : null; + if (httpWebResponse.StatusCode == (HttpStatusCode)ResponseStatusCodes.ResponseCodeTooManyRequestsOverExtendedTime) + { + // We start loosing data! + this.MaxBufferCapacity = 0; + this.MaxStorageCapacity = 0; + } + else + { + this.MaxBufferCapacity = null; + this.MaxStorageCapacity = null; + } this.LogCapacityChanged(); - this.Apply(); - - // Back-off for the Delay duration and enable sending capacity - this.pauseTimer.Start(() => - { - this.ResetPolicy(); - return TaskEx.FromResult(null); - }); - this.Transmitter.Enqueue(e.Transmission); + + this.backoffLogicManager.ScheduleRestore( + httpWebResponse.Headers, + () => + { + this.ResetPolicy(); + return TaskEx.FromResult(null); + }); } } } - else - { - this.ConsecutiveErrors = 0; - } } private void ResetPolicy() @@ -82,17 +77,5 @@ private void ResetPolicy() this.LogCapacityChanged(); this.Apply(); } - - private void Dispose(bool disposing) - { - if (disposing) - { - if (this.pauseTimer != null) - { - this.pauseTimer.Dispose(); - this.pauseTimer = null; - } - } - } } } diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicy.cs index d1ed6d256e..514a3554f4 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicy.cs @@ -1,7 +1,6 @@ namespace Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Implementation { using System; - using System.Collections.Specialized; internal abstract class TransmissionPolicy { diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs deleted file mode 100644 index fb1267b7b1..0000000000 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TransmissionPolicyHelpers.cs +++ /dev/null @@ -1,106 +0,0 @@ -namespace Microsoft.ApplicationInsights.Channel.Implementation -{ - using System; - using System.Collections.Specialized; - using System.Web.Script.Serialization; - using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Implementation; - - internal static class TransmissionPolicyHelpers - { - public const int SlotDelayInSeconds = 10; - private const int MaxDelayInSeconds = 3600; - private static readonly Random Random = new Random(); - private static readonly JavaScriptSerializer Serializer = new JavaScriptSerializer(); - - public static BackendResponse GetBackendResponse(string responseContent) - { - BackendResponse backendResponse = null; - - try - { - if (!string.IsNullOrEmpty(responseContent)) - { - backendResponse = Serializer.Deserialize(responseContent); - } - } - catch (ArgumentException exp) - { - TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); - backendResponse = null; - } - catch (InvalidOperationException exp) - { - TelemetryChannelEventSource.Log.BreezeResponseWasNotParsedWarning(exp.Message, responseContent); - backendResponse = null; - } - - return backendResponse; - } - - // Calculates the time to wait before retrying in case of an error based on - // http://en.wikipedia.org/wiki/Exponential_backoff - public static TimeSpan GetBackOffTime(int consecutiveErrors, string headerValue) - { - TimeSpan retryAfterTimeSpan; - if (!TryParseRetryAfter(headerValue, out retryAfterTimeSpan)) - { - double delayInSeconds; - - if (consecutiveErrors <= 1) - { - delayInSeconds = SlotDelayInSeconds; - } - else - { - double backOffSlot = (Math.Pow(2, consecutiveErrors) - 1) / 2; - var backOffDelay = Random.Next(1, (int)Math.Min(backOffSlot * SlotDelayInSeconds, int.MaxValue)); - delayInSeconds = Math.Max(Math.Min(backOffDelay, MaxDelayInSeconds), SlotDelayInSeconds); - } - - TelemetryChannelEventSource.Log.BackoffTimeSetInSeconds(delayInSeconds); - retryAfterTimeSpan = TimeSpan.FromSeconds(delayInSeconds); - } - - TelemetryChannelEventSource.Log.BackoffInterval(retryAfterTimeSpan.TotalSeconds); - return retryAfterTimeSpan; - } - - public static TimeSpan GetBackOffTime(int consecutiveErrors, NameValueCollection headers) - { - string retryAfterHeader = string.Empty; - if (headers != null) - { - retryAfterHeader = headers.Get("Retry-After"); - } - - return GetBackOffTime(consecutiveErrors, retryAfterHeader); - } - - private static bool TryParseRetryAfter(string retryAfter, out TimeSpan retryAfterTimeSpan) - { - retryAfterTimeSpan = TimeSpan.FromSeconds(0); - - if (string.IsNullOrEmpty(retryAfter)) - { - return false; - } - - var now = DateTimeOffset.UtcNow; - DateTimeOffset retryAfterDate; - if (DateTimeOffset.TryParse(retryAfter, out retryAfterDate)) - { - if (retryAfterDate > now) - { - retryAfterTimeSpan = retryAfterDate - now; - return true; - } - - return false; - } - - TelemetryChannelEventSource.Log.TransmissionPolicyRetryAfterParseFailedWarning(retryAfter); - - return false; - } - } -} diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/Transmitter.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/Transmitter.cs index cd72dc6596..86fc70ae14 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/Transmitter.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/Transmitter.cs @@ -5,6 +5,7 @@ using System.Diagnostics.CodeAnalysis; using System.Linq; using Microsoft.ApplicationInsights.Channel; + using Microsoft.ApplicationInsights.Channel.Implementation; /// /// Implements throttled and persisted transmission of telemetry to Application Insights. @@ -15,6 +16,7 @@ internal class Transmitter : IDisposable internal readonly TransmissionBuffer Buffer; internal readonly TransmissionStorage Storage; private readonly IEnumerable policies; + private readonly BackoffLogicManager backoffLogicManager; private bool arePoliciesApplied; private int maxSenderCapacity; @@ -29,8 +31,10 @@ internal Transmitter( TransmissionSender sender = null, TransmissionBuffer transmissionBuffer = null, TransmissionStorage storage = null, - IEnumerable policies = null) + IEnumerable policies = null, + BackoffLogicManager backoffLogicManager = null) { + this.backoffLogicManager = backoffLogicManager ?? new BackoffLogicManager(TimeSpan.FromMinutes(30)); // TODO: 30 to params this.Sender = sender ?? new TransmissionSender(); this.Sender.TransmissionSent += this.HandleSenderTransmissionSentEvent; this.maxSenderCapacity = this.Sender.Capacity; @@ -95,6 +99,11 @@ public long MaxStorageCapacity } } + public BackoffLogicManager BackoffLogicManager + { + get { return this.backoffLogicManager; } + } + /// /// Releases resources used by this instance. /// @@ -287,7 +296,12 @@ private void Dispose(bool disposing) { policy.Dispose(); } - } + + if (this.backoffLogicManager != null) + { + this.backoffLogicManager.Dispose(); + } + } } } } diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Shared.projitems b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Shared.projitems index e7084dde47..cb8f5a8b14 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Shared.projitems +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Shared.projitems @@ -22,7 +22,8 @@ - + + @@ -41,7 +42,6 @@ - From 48a077f9acd386681d2f6fd1f14fcb36459a7e63 Mon Sep 17 00:00:00 2001 From: abaranch Date: Tue, 5 Jul 2016 15:12:20 -0700 Subject: [PATCH 23/30] Code review comments --- .../Implementation/BackoffLogicManagerTest.cs | 10 ++++++---- .../Implementation/TelemetryChannelEventSource.cs | 4 ++-- 2 files changed, 8 insertions(+), 6 deletions(-) diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs index be5467bcd5..8e41613598 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs @@ -17,11 +17,8 @@ using Microsoft.VisualStudio.TestTools.UnitTesting; - using Microsoft.ApplicationInsights.Channel; using Microsoft.ApplicationInsights.Channel.Implementation; - using Microsoft.ApplicationInsights.Extensibility.Implementation; using Microsoft.ApplicationInsights.Web.TestFramework; - using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Helpers; using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Implementation; using Assert = Xunit.Assert; @@ -31,33 +28,38 @@ public class BackoffLogicManagerTest [TestClass] public class GetBackendResponse { + [TestMethod] public void ReturnNullIfArgumentIsNull() { var manager = new BackoffLogicManager(TimeSpan.Zero); Assert.Null(manager.GetBackendResponse(null)); } + [TestMethod] public void ReturnNullIfArgumentEmpty() { var manager = new BackoffLogicManager(TimeSpan.Zero); Assert.Null(manager.GetBackendResponse(string.Empty)); } + [TestMethod] public void IfContentCannotBeParsedNullIsReturned() { var manager = new BackoffLogicManager(TimeSpan.Zero); Assert.Null(manager.GetBackendResponse("ab}{")); } + [TestMethod] public void IfContentIsUnexpectedJsonNullIsReturned() { var manager = new BackoffLogicManager(TimeSpan.Zero); Assert.Null(manager.GetBackendResponse("[1,2]")); } + [TestMethod] public void BackendResponseIsReturnedForCorrectContent() { - string content = BackendResponseHelper.CreateBackendResponse(100, 1, new[] {"206"}, 84); + string content = BackendResponseHelper.CreateBackendResponse(itemsReceived: 100, itemsAccepted: 1, errorCodes: new[] {"206"}, indexStartWith: 84); var manager = new BackoffLogicManager(TimeSpan.Zero); var backendResponse = manager.GetBackendResponse(content); diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs index 2dd739e984..9cff24ccd9 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs @@ -32,7 +32,7 @@ public bool IsVerboseEnabled // Verbosity is Error - so it is always sent to portal; Keyword is Diagnostics so throttling is not applied. [Event(1, - Message = "It is a diagnostics message. Backoff logic was disabled. Transmission will be resolved.", + Message = "Diagnostic message: backoff logic disabled, transmission will be resolved.", Level = EventLevel.Error, Keywords = Keywords.Diagnostics | Keywords.UserActionable)] public void BackoffDisabled(string appDomainName = "Incorrect") @@ -42,7 +42,7 @@ public void BackoffDisabled(string appDomainName = "Incorrect") // Verbosity is Error - so it is always sent to portal; Keyword is Diagnostics so throttling is not applied. [Event(2, - Message = "It is a diagnostics message. Backoff logic was enabled. Backoff internal exceeded {0} min. Last status code received from the backend was {1}.", + Message = "Diagnostic message: backoff logic was enabled. Backoff internal exceeded {0} min. Last status code received from the backend was {1}.", Level = EventLevel.Error, Keywords = Keywords.Diagnostics | Keywords.UserActionable)] public void BackoffEnabled(double intervalInMin, int statusCode, string appDomainName = "Incorrect") From 67984ea71f21154fc04fc10c983504b9a0edccdb Mon Sep 17 00:00:00 2001 From: abaranch Date: Tue, 5 Jul 2016 17:09:50 -0700 Subject: [PATCH 24/30] Do not update ConsecutiveErrors often --- .../Implementation/BackoffLogicManagerTest.cs | 51 ++++++++++++++++++- .../Implementation/BackoffLogicManager.cs | 48 ++++++++++++++++- .../ErrorHandlingTransmissionPolicy.cs | 1 - .../TelemetryChannelEventSource.cs | 6 +-- .../Shared/Implementation/Transmitter.cs | 2 +- 5 files changed, 100 insertions(+), 8 deletions(-) diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs index 8e41613598..f86662de5d 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs @@ -8,6 +8,8 @@ using System.Globalization; using System.Net; using System.Linq; + using System.Threading; + using System.Threading.Tasks; using Microsoft.ApplicationInsights.WindowsServer.Channel.Helpers; @@ -23,6 +25,10 @@ using Assert = Xunit.Assert; +#if NET45 + using TaskEx = System.Threading.Tasks.Task; +#endif + public class BackoffLogicManagerTest { [TestClass] @@ -66,7 +72,7 @@ public void BackendResponseIsReturnedForCorrectContent() Assert.Equal(1, backendResponse.ItemsAccepted); Assert.Equal(100, backendResponse.ItemsReceived); - Assert.Equal(1, backendResponse.Errors.Length); + Assert.Equal(1, backendResponse.Errors.Length); // Even though accepted number of items is 1 out of 99 we get only 1 error back. We do not expect same in production but SDK should handle it correctly. Assert.Equal(84, backendResponse.Errors[0].Index); Assert.Equal(206, backendResponse.Errors[0].StatusCode); Assert.Equal("Explanation", backendResponse.Errors[0].Message); @@ -246,5 +252,48 @@ public void DisableDoesNotLogMessageIfEnabledWasNotCalled() } } } + + [TestClass] + public class ConsecutiveErrors + { + [TestMethod] + public void DoNotIncrementConsecutiveErrorsMoreOftenThanOnceInminIntervalToUpdateConsecutiveErrors() + { + BackoffLogicManager manager = new BackoffLogicManager(TimeSpan.Zero, TimeSpan.FromDays(1)); + + Task[] tasks = new Task[10]; + for (int i = 0; i < 10; ++i) + { + tasks[i] = TaskEx.Run(() => manager.ConsecutiveErrors++); + } + + Task.WaitAll(tasks); + + Assert.Equal(1, manager.ConsecutiveErrors); + } + + [TestMethod] + public void IncrementConsecutiveErrorsAfterMinIntervalToUpdateConsecutiveErrorsPassed() + { + BackoffLogicManager manager = new BackoffLogicManager(TimeSpan.Zero, TimeSpan.FromMilliseconds(1)); + + manager.ConsecutiveErrors++; + Thread.Sleep(1); + manager.ConsecutiveErrors++; + + Assert.Equal(2, manager.ConsecutiveErrors); + } + + [TestMethod] + public void ConsecutiveErrorsCanAlwaysBeResetTo0() + { + BackoffLogicManager manager = new BackoffLogicManager(TimeSpan.Zero, TimeSpan.FromDays(1)); + + manager.ConsecutiveErrors++; + manager.ConsecutiveErrors = 0; + + Assert.Equal(0, manager.ConsecutiveErrors); + } + } } } diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs index 4ae741123c..73a67815c9 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs @@ -21,19 +21,59 @@ internal class BackoffLogicManager : IDisposable private static readonly JavaScriptSerializer Serializer = new JavaScriptSerializer(); private readonly TimeSpan defaultBackoffEnabledReportingInterval; + private readonly object lockConsecutiveErrors = new object(); private TaskTimer pauseTimer = new TaskTimer { Delay = TimeSpan.FromSeconds(SlotDelayInSeconds) }; private bool exponentialBackoffReported = false; - + private int consecutiveErrors; + private DateTimeOffset nextMinTimeToUpdateConsecutiveErrors = DateTimeOffset.MinValue; + private TimeSpan minIntervalToUpdateConsecutiveErrors; + public BackoffLogicManager(TimeSpan defaultBackoffEnabledReportingInterval) { this.defaultBackoffEnabledReportingInterval = defaultBackoffEnabledReportingInterval; + this.minIntervalToUpdateConsecutiveErrors = TimeSpan.FromSeconds(SlotDelayInSeconds); + } + + internal BackoffLogicManager(TimeSpan defaultBackoffEnabledReportingInterval, TimeSpan minIntervalToUpdateConsecutiveErrors) + : this(defaultBackoffEnabledReportingInterval) + { + // This constructor is used from unit tests + this.minIntervalToUpdateConsecutiveErrors = minIntervalToUpdateConsecutiveErrors; } /// /// Gets or sets the number of consecutive errors SDK transmitter got so far while sending telemetry to backend. /// - public int ConsecutiveErrors { get; set; } + public int ConsecutiveErrors + { + get { return this.consecutiveErrors; } + + set + { + lock (this.lockConsecutiveErrors) + { + if (value == 0) + { + this.consecutiveErrors = 0; + return; + } + + // Do not increase number of errors more often than minimum interval (SlotDelayInSeconds) + // since we have 3 senders and all of them most likely would fail if we have intermittent error + if (DateTimeOffset.UtcNow > this.nextMinTimeToUpdateConsecutiveErrors) + { + this.consecutiveErrors = value; + this.nextMinTimeToUpdateConsecutiveErrors = DateTimeOffset.UtcNow + this.minIntervalToUpdateConsecutiveErrors; + } + } + } + } + + /// + /// Last status code SDK received from the backend. + /// + public int LastStatusCode { get; set; } internal TimeSpan CurrentDelay { @@ -86,6 +126,8 @@ public BackendResponse GetBackendResponse(string responseContent) public void ReportBackoffEnabled(int statusCode) { + this.LastStatusCode = statusCode; + if (!this.exponentialBackoffReported && this.pauseTimer.Delay > this.defaultBackoffEnabledReportingInterval) { TelemetryChannelEventSource.Log.BackoffEnabled(this.pauseTimer.Delay.TotalMinutes, statusCode); @@ -95,6 +137,8 @@ public void ReportBackoffEnabled(int statusCode) public void ReportBackoffDisabled() { + this.LastStatusCode = 200; + if (this.exponentialBackoffReported) { TelemetryChannelEventSource.Log.BackoffDisabled(); diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs index 55662b6b78..00b3c5f971 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs @@ -33,7 +33,6 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve var webException = e.Exception as WebException; if (webException != null) { - // We do not send data very often so we do not care about locking the counter this.backoffLogicManager.ConsecutiveErrors++; HttpWebResponse httpWebResponse = webException.Response as HttpWebResponse; if (httpWebResponse != null) diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs index 9cff24ccd9..33b2b10fa4 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs @@ -287,10 +287,10 @@ public void TransmitterSenderSkipped(string transmissionId, string appDomainName this.WriteEvent(40, transmissionId ?? string.Empty, this.ApplicationName); } - [Event(41, Message = "TransmitterBufferSkipped. TransmissionId: {0}.", Level = EventLevel.Verbose)] - public void TransmitterBufferSkipped(string transmissionId, string appDomainName = "Incorrect") + [Event(41, Message = "TransmitterBufferSkipped. TransmissionId: {0}. Last backend status code: {1}. Current delay in sec: {2}.", Level = EventLevel.Verbose)] + public void TransmitterBufferSkipped(string transmissionId, int statusCode, double currentDelayInSeconds, string appDomainName = "Incorrect") { - this.WriteEvent(41, transmissionId, this.ApplicationName); + this.WriteEvent(41, transmissionId, statusCode, currentDelayInSeconds, this.ApplicationName); } [Event(42, Message = "TransmitterStorageSkipped. TransmissionId: {0}.", Level = EventLevel.Verbose)] diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/Transmitter.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/Transmitter.cs index 86fc70ae14..6b6e8696fc 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/Transmitter.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/Transmitter.cs @@ -146,7 +146,7 @@ internal virtual void Enqueue(Transmission transmission) return; } - TelemetryChannelEventSource.Log.TransmitterBufferSkipped(transmission.Id); + TelemetryChannelEventSource.Log.TransmitterBufferSkipped(transmission.Id, this.BackoffLogicManager.LastStatusCode, this.BackoffLogicManager.CurrentDelay.TotalSeconds); if (!this.Storage.Enqueue(transmissionGetter)) { From 2830ab33ae936b21e09f13383bb564977cd5d3fa Mon Sep 17 00:00:00 2001 From: abaranch Date: Wed, 6 Jul 2016 15:07:13 -0700 Subject: [PATCH 25/30] Stylecop --- .../Shared/Implementation/BackoffLogicManager.cs | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs index 73a67815c9..08194fc246 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs @@ -22,12 +22,12 @@ internal class BackoffLogicManager : IDisposable private readonly TimeSpan defaultBackoffEnabledReportingInterval; private readonly object lockConsecutiveErrors = new object(); + private readonly TimeSpan minIntervalToUpdateConsecutiveErrors; private TaskTimer pauseTimer = new TaskTimer { Delay = TimeSpan.FromSeconds(SlotDelayInSeconds) }; private bool exponentialBackoffReported = false; private int consecutiveErrors; private DateTimeOffset nextMinTimeToUpdateConsecutiveErrors = DateTimeOffset.MinValue; - private TimeSpan minIntervalToUpdateConsecutiveErrors; public BackoffLogicManager(TimeSpan defaultBackoffEnabledReportingInterval) { @@ -47,7 +47,10 @@ internal BackoffLogicManager(TimeSpan defaultBackoffEnabledReportingInterval, Ti /// public int ConsecutiveErrors { - get { return this.consecutiveErrors; } + get + { + return this.consecutiveErrors; + } set { @@ -71,7 +74,7 @@ public int ConsecutiveErrors } /// - /// Last status code SDK received from the backend. + /// Gets or sets the last status code SDK received from the backend. /// public int LastStatusCode { get; set; } From b0c62858ccbbb3bf90138c75f1ee32d44e5a1322 Mon Sep 17 00:00:00 2001 From: abaranch Date: Wed, 6 Jul 2016 16:12:42 -0700 Subject: [PATCH 26/30] Remove ConsecutiveErrors setter --- .../Implementation/BackoffLogicManagerTest.cs | 19 ++++--- .../Implementation/BackoffLogicManager.cs | 51 +++++++++---------- .../ErrorHandlingTransmissionPolicy.cs | 1 - .../PartialSuccessTransmissionPolicy.cs | 5 +- .../ThrottlingTransmissionPolicy.cs | 4 +- 5 files changed, 41 insertions(+), 39 deletions(-) diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs index f86662de5d..202ce29c93 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs @@ -94,7 +94,7 @@ public void NoErrorDelayIsSameAsSlotDelay() public void FirstErrorDelayIsSameAsSlotDelay() { var manager = new BackoffLogicManager(TimeSpan.Zero); - manager.ConsecutiveErrors++; + manager.ReportBackoffEnabled(500); manager.ScheduleRestore(string.Empty, () => null); Assert.Equal(TimeSpan.FromSeconds(10), manager.CurrentDelay); } @@ -102,8 +102,13 @@ public void FirstErrorDelayIsSameAsSlotDelay() [TestMethod] public void UpperBoundOfDelayIsMaxDelay() { - var manager = new BackoffLogicManager(TimeSpan.Zero) { ConsecutiveErrors = int.MaxValue }; + var manager = new BackoffLogicManager(TimeSpan.Zero, TimeSpan.Zero); + + PrivateObject wrapper = new PrivateObject(manager); + wrapper.SetField("consecutiveErrors", int.MaxValue); + manager.ScheduleRestore(string.Empty, () => null); + Assert.InRange(manager.CurrentDelay, TimeSpan.FromSeconds(10), TimeSpan.FromSeconds(3600)); } @@ -264,7 +269,7 @@ public void DoNotIncrementConsecutiveErrorsMoreOftenThanOnceInminIntervalToUpdat Task[] tasks = new Task[10]; for (int i = 0; i < 10; ++i) { - tasks[i] = TaskEx.Run(() => manager.ConsecutiveErrors++); + tasks[i] = TaskEx.Run(() => manager.ReportBackoffEnabled(500)); } Task.WaitAll(tasks); @@ -277,9 +282,9 @@ public void IncrementConsecutiveErrorsAfterMinIntervalToUpdateConsecutiveErrorsP { BackoffLogicManager manager = new BackoffLogicManager(TimeSpan.Zero, TimeSpan.FromMilliseconds(1)); - manager.ConsecutiveErrors++; + manager.ReportBackoffEnabled(500); Thread.Sleep(1); - manager.ConsecutiveErrors++; + manager.ReportBackoffEnabled(500); Assert.Equal(2, manager.ConsecutiveErrors); } @@ -289,8 +294,8 @@ public void ConsecutiveErrorsCanAlwaysBeResetTo0() { BackoffLogicManager manager = new BackoffLogicManager(TimeSpan.Zero, TimeSpan.FromDays(1)); - manager.ConsecutiveErrors++; - manager.ConsecutiveErrors = 0; + manager.ReportBackoffEnabled(500); + manager.ResetConsecutiveErrors(); Assert.Equal(0, manager.ConsecutiveErrors); } diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs index 08194fc246..977526fbe4 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs @@ -43,34 +43,11 @@ internal BackoffLogicManager(TimeSpan defaultBackoffEnabledReportingInterval, Ti } /// - /// Gets or sets the number of consecutive errors SDK transmitter got so far while sending telemetry to backend. + /// Gets the number of consecutive errors SDK transmitter got so far while sending telemetry to backend. /// public int ConsecutiveErrors { - get - { - return this.consecutiveErrors; - } - - set - { - lock (this.lockConsecutiveErrors) - { - if (value == 0) - { - this.consecutiveErrors = 0; - return; - } - - // Do not increase number of errors more often than minimum interval (SlotDelayInSeconds) - // since we have 3 senders and all of them most likely would fail if we have intermittent error - if (DateTimeOffset.UtcNow > this.nextMinTimeToUpdateConsecutiveErrors) - { - this.consecutiveErrors = value; - this.nextMinTimeToUpdateConsecutiveErrors = DateTimeOffset.UtcNow + this.minIntervalToUpdateConsecutiveErrors; - } - } - } + get { return this.consecutiveErrors; } } /// @@ -127,15 +104,37 @@ public BackendResponse GetBackendResponse(string responseContent) return backendResponse; } + /// + /// Sets ConsecutiveErrors to 0. + /// + public void ResetConsecutiveErrors() + { + lock (this.lockConsecutiveErrors) + { + this.consecutiveErrors = 0; + } + } + public void ReportBackoffEnabled(int statusCode) { this.LastStatusCode = statusCode; - + if (!this.exponentialBackoffReported && this.pauseTimer.Delay > this.defaultBackoffEnabledReportingInterval) { TelemetryChannelEventSource.Log.BackoffEnabled(this.pauseTimer.Delay.TotalMinutes, statusCode); this.exponentialBackoffReported = true; } + + lock (this.lockConsecutiveErrors) + { + // Do not increase number of errors more often than minimum interval (SlotDelayInSeconds) + // since we have 3 senders and all of them most likely would fail if we have intermittent error + if (DateTimeOffset.UtcNow > this.nextMinTimeToUpdateConsecutiveErrors) + { + this.consecutiveErrors++; + this.nextMinTimeToUpdateConsecutiveErrors = DateTimeOffset.UtcNow + this.minIntervalToUpdateConsecutiveErrors; + } + } } public void ReportBackoffDisabled() diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs index 00b3c5f971..1230ec7576 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ErrorHandlingTransmissionPolicy.cs @@ -33,7 +33,6 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve var webException = e.Exception as WebException; if (webException != null) { - this.backoffLogicManager.ConsecutiveErrors++; HttpWebResponse httpWebResponse = webException.Response as HttpWebResponse; if (httpWebResponse != null) { diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs index 9839185b64..d741347606 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/PartialSuccessTransmissionPolicy.cs @@ -34,7 +34,7 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve if (args.Exception == null && args.Response == null) { // We succesfully sent transmittion - this.backoffLogicManager.ConsecutiveErrors = 0; + this.backoffLogicManager.ResetConsecutiveErrors(); return; } @@ -44,7 +44,6 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve if (!string.IsNullOrEmpty(newTransmissions)) { - this.backoffLogicManager.ConsecutiveErrors++; this.DelayFutureProcessing(args.Response); byte[] data = JsonSerializer.ConvertToByteArray(newTransmissions); @@ -60,7 +59,7 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve else { // We got 206 but there is no indication in response that something was not accepted. - this.backoffLogicManager.ConsecutiveErrors = 0; + this.backoffLogicManager.ResetConsecutiveErrors(); } } } diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ThrottlingTransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ThrottlingTransmissionPolicy.cs index 440887019a..177753ed01 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ThrottlingTransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/ThrottlingTransmissionPolicy.cs @@ -38,8 +38,6 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve if (httpWebResponse.StatusCode == (HttpStatusCode)ResponseStatusCodes.ResponseCodeTooManyRequests || httpWebResponse.StatusCode == (HttpStatusCode)ResponseStatusCodes.ResponseCodeTooManyRequestsOverExtendedTime) { - this.backoffLogicManager.ConsecutiveErrors++; - this.MaxSenderCapacity = 0; if (httpWebResponse.StatusCode == (HttpStatusCode)ResponseStatusCodes.ResponseCodeTooManyRequestsOverExtendedTime) { @@ -55,6 +53,8 @@ private void HandleTransmissionSentEvent(object sender, TransmissionProcessedEve this.LogCapacityChanged(); this.Apply(); + + this.backoffLogicManager.ReportBackoffEnabled((int)httpWebResponse.StatusCode); this.Transmitter.Enqueue(e.Transmission); this.backoffLogicManager.ScheduleRestore( From 57825d5deb76083edb6b1cf963cce62bfd6e1f21 Mon Sep 17 00:00:00 2001 From: abaranch Date: Wed, 6 Jul 2016 16:15:42 -0700 Subject: [PATCH 27/30] Make LastStatusCode setter private --- .../Shared/Implementation/BackoffLogicManager.cs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs index 977526fbe4..9ed3bfb4d8 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs @@ -51,9 +51,9 @@ public int ConsecutiveErrors } /// - /// Gets or sets the last status code SDK received from the backend. + /// Gets the last status code SDK received from the backend. /// - public int LastStatusCode { get; set; } + public int LastStatusCode { get; private set; } internal TimeSpan CurrentDelay { From cdd886dcb83f10c574edd3693494ac6d7d61de03 Mon Sep 17 00:00:00 2001 From: abaranch Date: Wed, 6 Jul 2016 16:34:35 -0700 Subject: [PATCH 28/30] More tracing for NetworkAvailablity policy --- ...tworkAvailabilityTransmissionPolicyTest.cs | 4 ++-- .../NetworkAvailabilityTransmissionPolicy.cs | 19 ++++++++++++++----- .../TelemetryChannelEventSource.cs | 6 +++--- 3 files changed, 19 insertions(+), 10 deletions(-) diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/NetworkAvailabilityTransmissionPolicyTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/NetworkAvailabilityTransmissionPolicyTest.cs index eed3a285c0..b115185865 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/NetworkAvailabilityTransmissionPolicyTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/NetworkAvailabilityTransmissionPolicyTest.cs @@ -79,7 +79,7 @@ public void DoesNotSetMaxSenderAndBufferCapacitiesToZeroWhenNetworkIsAvailable() [TestMethod] public void DoesNotSetMaxSenderAndBufferCapacitiesToZeroWhenNetworkAvailabilityCheckFailsHopingThatTransmissionsThemselvesMaySucceed() { - var network = new StubNetwork { OnIsAvailable = () => { throw new Exception("NetworkInformationException"); } }; + var network = new StubNetwork { OnIsAvailable = () => { throw new SocketException(); } }; var policy = new NetworkAvailabilityTransmissionPolicy(network); policy.Initialize(new StubTransmitter()); @@ -168,7 +168,7 @@ public void HandlesExceptionsThrownByNetworkIsAvailable() const long AllKeywords = -1; listener.EnableEvents(TelemetryChannelEventSource.Log, EventLevel.Warning, (EventKeywords)AllKeywords); - var exception = new Exception("Socket Error"); + var exception = new SocketException(); var network = new StubNetwork { OnIsAvailable = () => { throw exception; } }; var policy = new NetworkAvailabilityTransmissionPolicy(network); policy.Initialize(new StubTransmitter()); diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/NetworkAvailabilityTransmissionPolicy.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/NetworkAvailabilityTransmissionPolicy.cs index 3d4dc027c9..e1ec7a2955 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/NetworkAvailabilityTransmissionPolicy.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/NetworkAvailabilityTransmissionPolicy.cs @@ -81,16 +81,25 @@ private void SetBufferAndSenderCapacity() private bool IsNetworkAvailable() { + bool result = true; try { - return this.network.IsAvailable(); + result = this.network.IsAvailable(); + if (!result) + { + TelemetryChannelEventSource.Log.NetworkIsNotAvailableWarning(); + } } - catch (Exception e) + catch (SocketException se) { - // Catch all exceptions because SocketException and NetworkInformationException are not defined on all platforms - TelemetryChannelEventSource.Log.NetworkIsNotAvailableWarning(e.ToString()); - return true; + TelemetryChannelEventSource.Log.SubscribeToNetworkFailureWarning(se.ToString()); + } + catch (NetworkInformationException nie) + { + TelemetryChannelEventSource.Log.SubscribeToNetworkFailureWarning(nie.ToString()); } + + return result; } private void Dispose(bool disposing) diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs index 33b2b10fa4..3f276c9078 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/TelemetryChannelEventSource.cs @@ -233,10 +233,10 @@ public void BackoffTimeSetInSeconds(double seconds, string appDomainName = "Inco this.WriteEvent(31, seconds, this.ApplicationName); } - [Event(32, Message = "NetworkIsNotAvailable: {0}", Level = EventLevel.Warning)] - public void NetworkIsNotAvailableWarning(string exception, string appDomainName = "Incorrect") + [Event(32, Message = "NetworkIsNotAvailable", Level = EventLevel.Warning)] + public void NetworkIsNotAvailableWarning(string appDomainName = "Incorrect") { - this.WriteEvent(32, exception ?? string.Empty, this.ApplicationName); + this.WriteEvent(32, this.ApplicationName); } [Event(33, Message = "StorageCapacityReset: {0}", Level = EventLevel.Verbose)] From 53df86e672823f5011c51e1130ed3fc2c905826f Mon Sep 17 00:00:00 2001 From: abaranch Date: Wed, 6 Jul 2016 17:09:12 -0700 Subject: [PATCH 29/30] Make default reporting interval configurable --- .../Implementation/BackoffLogicManagerTest.cs | 10 ++++++++++ .../ServerTelemetryChannelTest.cs | 15 ++++++++++++++ .../Implementation/BackoffLogicManager.cs | 14 ++++++++++--- .../Shared/Implementation/Transmitter.cs | 2 +- .../Shared/ServerTelemetryChannel.cs | 20 ++++++++++++++++++- 5 files changed, 56 insertions(+), 5 deletions(-) diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs index 202ce29c93..578d5ada81 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/Implementation/BackoffLogicManagerTest.cs @@ -31,6 +31,16 @@ public class BackoffLogicManagerTest { + [TestClass] + public class DefaultBackoffEnabledReportingInterval + { + [TestMethod] + public void DefaultReportingIntervalInMinIs30Min() + { + Assert.Equal(30, new BackoffLogicManager().DefaultBackoffEnabledReportingInterval.TotalMinutes); + } + } + [TestClass] public class GetBackendResponse { diff --git a/Test/ServerTelemetryChannel.Test/Shared.Tests/ServerTelemetryChannelTest.cs b/Test/ServerTelemetryChannel.Test/Shared.Tests/ServerTelemetryChannelTest.cs index 57a05e6d56..c68e296935 100644 --- a/Test/ServerTelemetryChannel.Test/Shared.Tests/ServerTelemetryChannelTest.cs +++ b/Test/ServerTelemetryChannel.Test/Shared.Tests/ServerTelemetryChannelTest.cs @@ -53,6 +53,21 @@ public void InitializesTransmitterWithNetworkAvailabilityPolicy() } } + [TestClass] + public class DefaultBackoffEnabledReportingInterval + { + [TestMethod] + public void DefaultBackoffEnabledReportingIntervalUpdatesBackoffLogicManager() + { + ServerTelemetryChannel channel = new ServerTelemetryChannel + { + DefaultBackoffEnabledReportingInterval = TimeSpan.FromHours(42) + }; + + Assert.Equal(channel.Transmitter.BackoffLogicManager.DefaultBackoffEnabledReportingInterval, TimeSpan.FromHours(42)); + } + } + [TestClass] public class DeveloperMode : ServerTelemetryChannelTest { diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs index 9ed3bfb4d8..f024d23bdf 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/BackoffLogicManager.cs @@ -16,11 +16,11 @@ internal class BackoffLogicManager : IDisposable { private const int SlotDelayInSeconds = 10; private const int MaxDelayInSeconds = 3600; + private const int DefaultBackoffEnabledReportingIntervalInMin = 30; private static readonly Random Random = new Random(); private static readonly JavaScriptSerializer Serializer = new JavaScriptSerializer(); - private readonly TimeSpan defaultBackoffEnabledReportingInterval; private readonly object lockConsecutiveErrors = new object(); private readonly TimeSpan minIntervalToUpdateConsecutiveErrors; @@ -29,9 +29,15 @@ internal class BackoffLogicManager : IDisposable private int consecutiveErrors; private DateTimeOffset nextMinTimeToUpdateConsecutiveErrors = DateTimeOffset.MinValue; + public BackoffLogicManager() + { + this.DefaultBackoffEnabledReportingInterval = TimeSpan.FromMinutes(DefaultBackoffEnabledReportingIntervalInMin); + this.minIntervalToUpdateConsecutiveErrors = TimeSpan.FromSeconds(SlotDelayInSeconds); + } + public BackoffLogicManager(TimeSpan defaultBackoffEnabledReportingInterval) { - this.defaultBackoffEnabledReportingInterval = defaultBackoffEnabledReportingInterval; + this.DefaultBackoffEnabledReportingInterval = defaultBackoffEnabledReportingInterval; this.minIntervalToUpdateConsecutiveErrors = TimeSpan.FromSeconds(SlotDelayInSeconds); } @@ -55,6 +61,8 @@ public int ConsecutiveErrors /// public int LastStatusCode { get; private set; } + public TimeSpan DefaultBackoffEnabledReportingInterval { get; set; } + internal TimeSpan CurrentDelay { get { return this.pauseTimer.Delay; } @@ -119,7 +127,7 @@ public void ReportBackoffEnabled(int statusCode) { this.LastStatusCode = statusCode; - if (!this.exponentialBackoffReported && this.pauseTimer.Delay > this.defaultBackoffEnabledReportingInterval) + if (!this.exponentialBackoffReported && this.pauseTimer.Delay > this.DefaultBackoffEnabledReportingInterval) { TelemetryChannelEventSource.Log.BackoffEnabled(this.pauseTimer.Delay.TotalMinutes, statusCode); this.exponentialBackoffReported = true; diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/Transmitter.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/Transmitter.cs index 6b6e8696fc..4dae27207e 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/Transmitter.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/Implementation/Transmitter.cs @@ -34,7 +34,7 @@ internal Transmitter( IEnumerable policies = null, BackoffLogicManager backoffLogicManager = null) { - this.backoffLogicManager = backoffLogicManager ?? new BackoffLogicManager(TimeSpan.FromMinutes(30)); // TODO: 30 to params + this.backoffLogicManager = backoffLogicManager ?? new BackoffLogicManager(); this.Sender = sender ?? new TransmissionSender(); this.Sender.TransmissionSent += this.HandleSenderTransmissionSentEvent; this.maxSenderCapacity = this.Sender.Capacity; diff --git a/src/TelemetryChannels/ServerTelemetryChannel/Shared/ServerTelemetryChannel.cs b/src/TelemetryChannels/ServerTelemetryChannel/Shared/ServerTelemetryChannel.cs index 08f4d09ad2..d4da88dc06 100644 --- a/src/TelemetryChannels/ServerTelemetryChannel/Shared/ServerTelemetryChannel.cs +++ b/src/TelemetryChannels/ServerTelemetryChannel/Shared/ServerTelemetryChannel.cs @@ -1,11 +1,12 @@ namespace Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel { using System; + using System.ComponentModel; using System.Threading.Tasks; using Microsoft.ApplicationInsights.Channel; using Microsoft.ApplicationInsights.Extensibility; using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel.Implementation; - + #if NET45 using TaskEx = System.Threading.Tasks.Task; #endif @@ -52,6 +53,23 @@ internal ServerTelemetryChannel(INetwork network, IApplicationLifecycle applicat this.isInitialized = false; } + /// + /// Gets or sets default interval after which diagnostics event will be logged if telemetry sending was disabled. + /// + [EditorBrowsable(EditorBrowsableState.Never)] + public TimeSpan DefaultBackoffEnabledReportingInterval + { + get + { + return this.Transmitter.BackoffLogicManager.DefaultBackoffEnabledReportingInterval; + } + + set + { + this.Transmitter.BackoffLogicManager.DefaultBackoffEnabledReportingInterval = value; + } + } + /// /// Gets or sets a value indicating whether developer mode of telemetry transmission is enabled. /// When developer mode is True, sends telemetry to Application Insights immediately From 1041a88667ae4cb7670a12e214c7f24cca894fe5 Mon Sep 17 00:00:00 2001 From: Anastasia Baranchenkova Date: Tue, 12 Jul 2016 11:20:07 -0700 Subject: [PATCH 30/30] Update CHANGELOG.md --- CHANGELOG.md | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index e07c90c2e6..7f92000cce 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,7 @@ This changelog will be used to generate documentation on [release notes page](ht - Add ExceptionTelemetry.Message property. If it is provided it is used instead of Exception.Message property for the ounter-most exception. - Telemetry types can be exluded from sampling by specifing ExcludedTypes property. +- ServerTelemetryChannel: changed backoff logic to be less aggressive, added diagnostics event when backoff logic kicks in and added more tracing. (Done to address issues when data stopps flowing till application gets restarted) ## Version 2.1.0-beta4 - [Bug fix](https://github.com/Microsoft/ApplicationInsights-dotnet-server/issues/76)