From 5df91e0e6a23b08db0ff37ecdf803c7a145bda1b Mon Sep 17 00:00:00 2001 From: Brett Samblanet Date: Wed, 24 Jul 2019 14:26:57 -0700 Subject: [PATCH] [AppInsights] delaying QuickPulse initialization to help with cold start --- .../ApplicationInsightsLoggerOptions.cs | 8 ++++ ...tionInsightsServiceCollectionExtensions.cs | 43 ++++++++++------- .../QuickPulseInitializationScheduler.cs | 48 +++++++++++++++++++ .../ApplicationInsightsEndToEndTests.cs | 15 +++--- 4 files changed, 91 insertions(+), 23 deletions(-) create mode 100644 src/Microsoft.Azure.WebJobs.Logging.ApplicationInsights/QuickPulseInitializationScheduler.cs diff --git a/src/Microsoft.Azure.WebJobs.Logging.ApplicationInsights/ApplicationInsightsLoggerOptions.cs b/src/Microsoft.Azure.WebJobs.Logging.ApplicationInsights/ApplicationInsightsLoggerOptions.cs index 7768a5d28..28c447646 100644 --- a/src/Microsoft.Azure.WebJobs.Logging.ApplicationInsights/ApplicationInsightsLoggerOptions.cs +++ b/src/Microsoft.Azure.WebJobs.Logging.ApplicationInsights/ApplicationInsightsLoggerOptions.cs @@ -1,6 +1,7 @@ // Copyright (c) .NET Foundation. All rights reserved. // Licensed under the MIT License. See License.txt in the project root for license information. +using System; using Microsoft.ApplicationInsights.SnapshotCollector; using Microsoft.ApplicationInsights.WindowsServer.Channel.Implementation; using Microsoft.Azure.WebJobs.Hosting; @@ -31,6 +32,12 @@ public class ApplicationInsightsLoggerOptions : IOptionsFormatter /// public string QuickPulseAuthenticationApiKey { get; set; } + /// + /// Gets or sets the time to delay Quick Pulse (Live Metrics) initialization. Delaying this initialization + /// can result in decreased application startup time. Default value is 15 seconds. + /// + public TimeSpan QuickPulseInitializationDelay { get; set; } = TimeSpan.FromSeconds(15); + /// /// Gets or sets flag that enables Kudu performance counters collection. /// https://github.com/projectkudu/kudu/wiki/Perf-Counters-exposed-as-environment-variables. @@ -98,6 +105,7 @@ public string Format() { nameof(SnapshotConfiguration), snapshot }, { nameof(EnablePerformanceCountersCollection), EnablePerformanceCountersCollection}, { nameof(HttpAutoCollectionOptions), httpOptions}, + { nameof(QuickPulseInitializationDelay), QuickPulseInitializationDelay } }; return options.ToString(Formatting.Indented); diff --git a/src/Microsoft.Azure.WebJobs.Logging.ApplicationInsights/Extensions/ApplicationInsightsServiceCollectionExtensions.cs b/src/Microsoft.Azure.WebJobs.Logging.ApplicationInsights/Extensions/ApplicationInsightsServiceCollectionExtensions.cs index 8f9a949a4..e7d37c414 100644 --- a/src/Microsoft.Azure.WebJobs.Logging.ApplicationInsights/Extensions/ApplicationInsightsServiceCollectionExtensions.cs +++ b/src/Microsoft.Azure.WebJobs.Logging.ApplicationInsights/Extensions/ApplicationInsightsServiceCollectionExtensions.cs @@ -14,8 +14,8 @@ using Microsoft.ApplicationInsights.Extensibility.Implementation.ApplicationId; using Microsoft.ApplicationInsights.Extensibility.PerfCounterCollector; using Microsoft.ApplicationInsights.Extensibility.PerfCounterCollector.QuickPulse; -using Microsoft.ApplicationInsights.SnapshotCollector; using Microsoft.ApplicationInsights.Extensibility.W3C; +using Microsoft.ApplicationInsights.SnapshotCollector; using Microsoft.ApplicationInsights.WindowsServer; using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel; using Microsoft.Azure.WebJobs.Logging.ApplicationInsights; @@ -57,13 +57,18 @@ public static IServiceCollection AddApplicationInsights(this IServiceCollection services.AddSingleton(); services.AddSingleton(); - + services.AddSingleton(); + services.AddSingleton(provider => { ApplicationInsightsLoggerOptions options = provider.GetService>().Value; if (options.EnablePerformanceCountersCollection) { - return new PerformanceCollectorModule(); + return new PerformanceCollectorModule + { + // Disabling this can improve cold start times + EnableIISExpressPerformanceCounters = false + }; } return NullTelemetryModule.Instance; @@ -132,7 +137,7 @@ public static IServiceCollection AddApplicationInsights(this IServiceCollection var activeConfig = TelemetryConfiguration.Active; if (!string.IsNullOrEmpty(options.InstrumentationKey) && - string.IsNullOrEmpty(activeConfig.InstrumentationKey)) + string.IsNullOrEmpty(activeConfig.InstrumentationKey)) { activeConfig.InstrumentationKey = options.InstrumentationKey; } @@ -158,22 +163,22 @@ public static IServiceCollection AddApplicationInsights(this IServiceCollection provider.GetServices(), provider.GetServices(), appIdProvider, - filterOptions); + filterOptions, + provider.GetService()); return config; }); services.AddSingleton(provider => - { - TelemetryConfiguration configuration = provider.GetService(); - TelemetryClient client = new TelemetryClient(configuration); + { + TelemetryConfiguration configuration = provider.GetService(); + TelemetryClient client = new TelemetryClient(configuration); - ISdkVersionProvider versionProvider = provider.GetService(); - client.Context.GetInternalContext().SdkVersion = versionProvider?.GetSdkVersion(); + ISdkVersionProvider versionProvider = provider.GetService(); + client.Context.GetInternalContext().SdkVersion = versionProvider?.GetSdkVersion(); - return client; - } - ); + return client; + }); services.AddSingleton(); @@ -215,7 +220,8 @@ private static void SetupTelemetryConfiguration( IEnumerable telemetryInitializers, IEnumerable telemetryModules, IApplicationIdProvider applicationIdProvider, - LoggerFilterOptions filterOptions) + LoggerFilterOptions filterOptions, + QuickPulseInitializationScheduler delayer) { if (options.InstrumentationKey != null) { @@ -249,9 +255,14 @@ private static void SetupTelemetryConfiguration( { quickPulseModule.AuthenticationApiKey = options.QuickPulseAuthenticationApiKey; } - } - module.Initialize(configuration); + // QuickPulse can have a startup performance hit, so delay its initialization. + delayer.ScheduleInitialization(() => module.Initialize(configuration), options.QuickPulseInitializationDelay); + } + else + { + module.Initialize(configuration); + } } QuickPulseTelemetryProcessor quickPulseProcessor = null; diff --git a/src/Microsoft.Azure.WebJobs.Logging.ApplicationInsights/QuickPulseInitializationScheduler.cs b/src/Microsoft.Azure.WebJobs.Logging.ApplicationInsights/QuickPulseInitializationScheduler.cs new file mode 100644 index 000000000..7b62ab4f3 --- /dev/null +++ b/src/Microsoft.Azure.WebJobs.Logging.ApplicationInsights/QuickPulseInitializationScheduler.cs @@ -0,0 +1,48 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using System.Threading; +using System.Threading.Tasks; + +namespace Microsoft.Azure.WebJobs.Logging.ApplicationInsights +{ + // We need to be able to delay initialization in Functions for cold start, + // so perform this initialization in a service that can handle cancellation. + internal class QuickPulseInitializationScheduler : IDisposable + { + private readonly CancellationTokenSource _cts = new CancellationTokenSource(); + private bool _disposed = false; + private object _lock = new object(); + + public void ScheduleInitialization(Action initialization, TimeSpan delay) + { + Task.Delay(delay, _cts.Token) + .ContinueWith(_ => + { + lock (_lock) + { + if (!_disposed) + { + initialization(); + } + } + }, + TaskContinuationOptions.OnlyOnRanToCompletion); + } + + public void Dispose() + { + lock (_lock) + { + if (!_disposed) + { + _cts.Cancel(); + _cts.Dispose(); + + _disposed = true; + } + } + } + } +} \ No newline at end of file diff --git a/test/Microsoft.Azure.WebJobs.Host.EndToEndTests/ApplicationInsights/ApplicationInsightsEndToEndTests.cs b/test/Microsoft.Azure.WebJobs.Host.EndToEndTests/ApplicationInsights/ApplicationInsightsEndToEndTests.cs index 9e3054bbf..5e3a55e37 100644 --- a/test/Microsoft.Azure.WebJobs.Host.EndToEndTests/ApplicationInsights/ApplicationInsightsEndToEndTests.cs +++ b/test/Microsoft.Azure.WebJobs.Host.EndToEndTests/ApplicationInsights/ApplicationInsightsEndToEndTests.cs @@ -85,6 +85,7 @@ private IHost ConfigureHost(LogLevel minLevel = LogLevel.Information, HttpAutoCo { o.InstrumentationKey = _mockApplicationInsightsKey; o.HttpAutoCollectionOptions = httpOptions; + o.QuickPulseInitializationDelay = TimeSpan.FromSeconds(1); }); }) .ConfigureServices(services => @@ -465,10 +466,10 @@ public async Task ApplicationInsights_HttpRequestTrackingByAIAutoCollector(strin request.Headers.Add("traceparent", "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"); var mockHttpContext = new DefaultHttpContext(); - mockHttpContext.Connection.RemoteIpAddress = new IPAddress(new byte[] {1, 2, 3, 4}); + mockHttpContext.Connection.RemoteIpAddress = new IPAddress(new byte[] { 1, 2, 3, 4 }); // simulate functions behavior to set request on the scope - using (var _ = logger.BeginScope(new Dictionary { ["MS_HttpRequest"] = mockHttpContext.Request})) + using (var _ = logger.BeginScope(new Dictionary { ["MS_HttpRequest"] = mockHttpContext.Request })) { await client.SendAsync(request); } @@ -489,7 +490,7 @@ await TestHelpers.Await(() => Assert.True(functionRequest.Duration.TotalMilliseconds >= functionDuration); Assert.Equal("1.2.3.4", functionRequest.Context.Location.Ip); Assert.Equal("http://localhost/some/path", functionRequest.Url.ToString()); - + ValidateRequest( functionRequest, testName, @@ -665,7 +666,7 @@ await TestHelpers.Await(() => } } } - + // Test Functions [NoAutomaticTrigger] public static void TestApplicationInsightsInformation(string input, TraceWriter trace, ILogger logger) @@ -719,7 +720,7 @@ public static void TestApplicationInsightsExplicitCall(ILogger logger) TelemetryClient telemetryClient = new TelemetryClient(); // use TelemetryConfiguration.Active telemetryClient.TrackEvent("custom event"); } - + [NoAutomaticTrigger] public static void TestApplicationInsightsDisposeRequestsModule(string input, ILogger logger) { @@ -1012,7 +1013,7 @@ private static void ValidateRequest(RequestTelemetry telemetry, string operation } private static void ValidateSdkVersion(ITelemetry telemetry, string prefix = null) - { + { Assert.StartsWith($"{prefix}webjobs:", telemetry.Context.GetInternalContext().SdkVersion); } @@ -1106,7 +1107,7 @@ public void Configure(IApplicationBuilder app, AspNetCore.Hosting.IHostingEnviro try { - await Host.GetJobHost().CallAsync(methodInfo, new {input = "input"}); + await Host.GetJobHost().CallAsync(methodInfo, new { input = "input" }); } catch {