Linux consumption cold start improvements. Part - 2

    Part 1 - https://github.com/Azure/azure-functions-host/pull/6408/files
    This change addresses the following improvments based on profiling

    1. Metrics publisher invokes expensive Process apis to collect memory metrics during cold start. Deferring this by 2 seconds moves it out of critical path.
    2. Some of the operations in specialization code path were not being jit-ed since the warmup specialization call doesn't invoke all the operations. This change decrypts the host assignment context, validates and downloads a fake Website-Run-From-Pkg url to jit HttpDownload calls. The fake url points to a local endpoint and the downloaded contents are ignored.

    Fixes #6407

Author: balag0

src/WebJobs.Script.WebHost/ContainerManagement/LinuxContainerInitializationHostService.cs

@@ -53,7 +53,7 @@ private async Task ApplyStartContextIfPresent()
                 var encryptedAssignmentContext = JsonConvert.DeserializeObject<EncryptedHostAssignmentContext>(startContext);
                 var assignmentContext = _startupContextProvider.SetContext(encryptedAssignmentContext);
 
-                bool success = _instanceManager.StartAssignment(assignmentContext, false);
+                bool success = _instanceManager.StartAssignment(assignmentContext);
                 _logger.LogInformation($"StartAssignment invoked (Success={success})");
             }
             else

src/WebJobs.Script.WebHost/Controllers/InstanceController.cs

@@ -39,34 +39,26 @@ public async Task<IActionResult> Assign([FromBody] EncryptedHostAssignmentContex
         {
             _logger.LogDebug($"Starting container assignment for host : {Request?.Host}. ContextLength is: {encryptedAssignmentContext.EncryptedContext?.Length}");
 
-            bool succeeded = false;
-            if (!encryptedAssignmentContext.IsWarmup)
-            {
-                var assignmentContext = _startupContextProvider.SetContext(encryptedAssignmentContext);
-
-                // before starting the assignment we want to perform as much
-                // up front validation on the context as possible
-                string error = await _instanceManager.ValidateContext(assignmentContext, encryptedAssignmentContext.IsWarmup);
-                if (error != null)
-                {
-                    return StatusCode(StatusCodes.Status400BadRequest, error);
-                }
-
-                // Wait for Sidecar specialization to complete before returning ok.
-                // This shouldn't take too long so ok to do this sequentially.
-                error = await _instanceManager.SpecializeMSISidecar(assignmentContext, encryptedAssignmentContext.IsWarmup);
-                if (error != null)
-                {
-                    return StatusCode(StatusCodes.Status500InternalServerError, error);
-                }
+            var assignmentContext = _startupContextProvider.SetContext(encryptedAssignmentContext);
 
-                succeeded = _instanceManager.StartAssignment(assignmentContext, encryptedAssignmentContext.IsWarmup);
+            // before starting the assignment we want to perform as much
+            // up front validation on the context as possible
+            string error = await _instanceManager.ValidateContext(assignmentContext);
+            if (error != null)
+            {
+                return StatusCode(StatusCodes.Status400BadRequest, error);
             }
-            else
+
+            // Wait for Sidecar specialization to complete before returning ok.
+            // This shouldn't take too long so ok to do this sequentially.
+            error = await _instanceManager.SpecializeMSISidecar(assignmentContext);
+            if (error != null)
             {
-                succeeded = true;
+                return StatusCode(StatusCodes.Status500InternalServerError, error);
             }
 
+            var succeeded = _instanceManager.StartAssignment(assignmentContext);
+
             return succeeded
                 ? Accepted()
                 : StatusCode(StatusCodes.Status409Conflict, "Instance already assigned");

src/WebJobs.Script.WebHost/Management/IInstanceManager.cs

@@ -11,10 +11,10 @@ public interface IInstanceManager
     {
         IDictionary<string, string> GetInstanceInfo();
 
-        Task<string> ValidateContext(HostAssignmentContext assignmentContext, bool isWarmup);
+        Task<string> ValidateContext(HostAssignmentContext assignmentContext);
 
-        bool StartAssignment(HostAssignmentContext assignmentContext, bool isWarmup);
+        bool StartAssignment(HostAssignmentContext assignmentContext);
 
-        Task<string> SpecializeMSISidecar(HostAssignmentContext assignmentContext, bool isWarmup);
+        Task<string> SpecializeMSISidecar(HostAssignmentContext assignmentContext);
     }
 }

src/WebJobs.Script.WebHost/Management/InstanceManager.cs

@@ -46,9 +46,10 @@ public InstanceManager(IOptionsFactory<ScriptApplicationHostOptions> optionsFact
             _optionsFactory = optionsFactory ?? throw new ArgumentNullException(nameof(optionsFactory));
         }
 
-        public async Task<string> SpecializeMSISidecar(HostAssignmentContext context, bool isWarmup)
+        public async Task<string> SpecializeMSISidecar(HostAssignmentContext context)
         {
-            if (isWarmup)
+            // No cold start optimization needed for side car scenarios
+            if (context.IsWarmupRequest)
             {
                 return null;
             }
@@ -89,16 +90,19 @@ public async Task<string> SpecializeMSISidecar(HostAssignmentContext context, bo
             return null;
         }
 
-        public bool StartAssignment(HostAssignmentContext context, bool isWarmup)
+        public bool StartAssignment(HostAssignmentContext context)
         {
             if (!_webHostEnvironment.InStandbyMode)
             {
                 _logger.LogError("Assign called while host is not in placeholder mode");
                 return false;
             }
 
-            if (isWarmup)
+            if (context.IsWarmupRequest)
             {
+                // Based on profiling download code jit-ing holds up cold start.
+                // Pre-jit to avoid paying the cost later.
+                Task.Run(async () => await Download(context.GetRunFromPkgContext()));
                 return true;
             }
             else if (_assignmentContext == null)
@@ -134,16 +138,11 @@ public bool StartAssignment(HostAssignmentContext context, bool isWarmup)
             }
         }
 
-        public async Task<string> ValidateContext(HostAssignmentContext assignmentContext, bool isWarmup)
+        public async Task<string> ValidateContext(HostAssignmentContext assignmentContext)
         {
-            if (isWarmup)
-            {
-                return null;
-            }
-
-            _logger.LogInformation($"Validating host assignment context (SiteId: {assignmentContext.SiteId}, SiteName: '{assignmentContext.SiteName}')");
+            _logger.LogInformation($"Validating host assignment context (SiteId: {assignmentContext.SiteId}, SiteName: '{assignmentContext.SiteName}'. IsWarmup: '{assignmentContext.IsWarmupRequest}')");
             RunFromPackageContext pkgContext = assignmentContext.GetRunFromPkgContext();
-            _logger.LogInformation($"Will be using {pkgContext.EnvironmentVariableName} app setting as zip url");
+            _logger.LogInformation($"Will be using {pkgContext.EnvironmentVariableName} app setting as zip url. IsWarmup: '{assignmentContext.IsWarmupRequest}')");
 
             if (pkgContext.IsScmRunFromPackage())
             {
@@ -154,7 +153,7 @@ public async Task<string> ValidateContext(HostAssignmentContext assignmentContex
             {
                 // In AppService, ZipUrl == 1 means the package is hosted in azure files.
                 // Otherwise we expect zipUrl to be a blobUri to a zip or a squashfs image
-                (var error, var contentLength) = await ValidateBlobPackageContext(pkgContext.Url);
+                (var error, var contentLength) = await ValidateBlobPackageContext(pkgContext);
                 if (string.IsNullOrEmpty(error))
                 {
                     assignmentContext.PackageContentLength = contentLength;
@@ -172,8 +171,12 @@ public async Task<string> ValidateContext(HostAssignmentContext assignmentContex
             }
         }
 
-        private async Task<(string, long?)> ValidateBlobPackageContext(string blobUri)
+        private async Task<(string, long?)> ValidateBlobPackageContext(RunFromPackageContext context)
         {
+            string blobUri = context.Url;
+            string eventName = context.IsWarmUpRequest
+                ? MetricEventNames.LinuxContainerSpecializationZipHeadWarmup
+                : MetricEventNames.LinuxContainerSpecializationZipHead;
             string error = null;
             HttpResponseMessage response = null;
             long? contentLength = null;
@@ -186,7 +189,7 @@ await Utility.InvokeWithRetriesAsync(async () =>
                     {
                         try
                         {
-                            using (_metricsLogger.LatencyEvent(MetricEventNames.LinuxContainerSpecializationZipHead))
+                            using (_metricsLogger.LatencyEvent(eventName))
                             {
                                 var request = new HttpRequestMessage(HttpMethod.Head, blobUri);
                                 response = await _client.SendAsync(request);
@@ -199,7 +202,7 @@ await Utility.InvokeWithRetriesAsync(async () =>
                         }
                         catch (Exception e)
                         {
-                            _logger.LogError(e, $"{MetricEventNames.LinuxContainerSpecializationZipHead} failed");
+                            _logger.LogError(e, $"{eventName} failed");
                             throw;
                         }
                     }, maxRetries: 2, retryInterval: TimeSpan.FromSeconds(0.3)); // Keep this less than ~1s total
@@ -208,7 +211,7 @@ await Utility.InvokeWithRetriesAsync(async () =>
             catch (Exception e)
             {
                 error = $"Invalid zip url specified (StatusCode: {response?.StatusCode})";
-                _logger.LogError(e, "ValidateContext failed");
+                _logger.LogError(e, $"ValidateContext failed. IsWarmupRequest = {context.IsWarmUpRequest}");
             }
 
             return (error, contentLength);
@@ -372,25 +375,28 @@ private async Task<string> Download(RunFromPackageContext pkgContext)
             if (pkgContext.PackageContentLength != null && pkgContext.PackageContentLength > 100 * 1024 * 1024)
             {
                 _logger.LogInformation($"Downloading zip contents from '{cleanedUrl}' using aria2c'");
-                AriaDownload(tmpPath, fileName, zipUri);
+                AriaDownload(tmpPath, fileName, zipUri, pkgContext.IsWarmUpRequest);
             }
             else
             {
                 _logger.LogInformation($"Downloading zip contents from '{cleanedUrl}' using httpclient'");
-                await HttpClientDownload(filePath, zipUri);
+                await HttpClientDownload(filePath, zipUri, pkgContext.IsWarmUpRequest);
             }
 
             return filePath;
         }
 
-        private async Task HttpClientDownload(string filePath, Uri zipUri)
+        private async Task HttpClientDownload(string filePath, Uri zipUri, bool isWarmupRequest)
         {
             HttpResponseMessage response = null;
             await Utility.InvokeWithRetriesAsync(async () =>
             {
                 try
                 {
-                    using (_metricsLogger.LatencyEvent(MetricEventNames.LinuxContainerSpecializationZipDownload))
+                    var downloadMetricName = isWarmupRequest
+                        ? MetricEventNames.LinuxContainerSpecializationZipDownloadWarmup
+                        : MetricEventNames.LinuxContainerSpecializationZipDownload;
+                    using (_metricsLogger.LatencyEvent(downloadMetricName))
                     {
                         var request = new HttpRequestMessage(HttpMethod.Get, zipUri);
                         response = await _client.SendAsync(request, HttpCompletionOption.ResponseHeadersRead);
@@ -403,31 +409,36 @@ await Utility.InvokeWithRetriesAsync(async () =>
                     _logger.LogError(e, error);
                     throw;
                 }
-                _logger.LogInformation($"{response.Content.Headers.ContentLength} bytes downloaded");
+                _logger.LogInformation($"{response.Content.Headers.ContentLength} bytes downloaded. IsWarmupRequest = {isWarmupRequest}");
             }, 2, TimeSpan.FromSeconds(0.5));
 
-            using (_metricsLogger.LatencyEvent(MetricEventNames.LinuxContainerSpecializationZipWrite))
+            using (_metricsLogger.LatencyEvent(isWarmupRequest ? MetricEventNames.LinuxContainerSpecializationZipWriteWarmup : MetricEventNames.LinuxContainerSpecializationZipWrite))
             {
                 using (var content = await response.Content.ReadAsStreamAsync())
                 using (var stream = new FileStream(filePath, FileMode.Create, FileAccess.Write, FileShare.None, bufferSize: 4096, useAsync: true))
                 {
                     await content.CopyToAsync(stream);
                 }
-                _logger.LogInformation($"{response.Content.Headers.ContentLength} bytes written");
+                _logger.LogInformation($"{response.Content.Headers.ContentLength} bytes written. IsWarmupRequest = {isWarmupRequest}");
             }
         }
 
-        private void AriaDownload(string directory, string fileName, Uri zipUri)
+        private void AriaDownload(string directory, string fileName, Uri zipUri, bool isWarmupRequest)
         {
-            (string stdout, string stderr, int exitCode) = RunBashCommand($"aria2c --allow-overwrite -x12 -d {directory} -o {fileName} '{zipUri}'", MetricEventNames.LinuxContainerSpecializationZipDownload);
+            var metricName = isWarmupRequest
+                ? MetricEventNames.LinuxContainerSpecializationZipDownloadWarmup
+                : MetricEventNames.LinuxContainerSpecializationZipDownload;
+            (string stdout, string stderr, int exitCode) = RunBashCommand(
+                $"aria2c --allow-overwrite -x12 -d {directory} -o {fileName} '{zipUri}'",
+                metricName);
             if (exitCode != 0)
             {
                 var msg = $"Error downloading package. stdout: {stdout}, stderr: {stderr}, exitCode: {exitCode}";
                 _logger.LogError(msg);
                 throw new InvalidOperationException(msg);
             }
             var fileInfo = FileUtility.FileInfoFromFileName(Path.Combine(directory, fileName));
-            _logger.LogInformation($"{fileInfo.Length} bytes downloaded");
+            _logger.LogInformation($"{fileInfo.Length} bytes downloaded. IsWarmupRequest = {isWarmupRequest}");
         }
 
         private async Task UnpackPackage(string filePath, string scriptPath, RunFromPackageContext pkgContext)

src/WebJobs.Script.WebHost/Metrics/LinuxContainerMetricsPublisher.cs

@@ -33,6 +33,7 @@ public class LinuxContainerMetricsPublisher : IMetricsPublisher
 
         private readonly TimeSpan _memorySnapshotInterval = TimeSpan.FromMilliseconds(1000);
         private readonly TimeSpan _metricPublishInterval = TimeSpan.FromMilliseconds(30 * 1000);
+        private readonly TimeSpan _timerStartDelay = TimeSpan.FromSeconds(2);
         private readonly IOptionsMonitor<StandbyOptions> _standbyOptions;
         private readonly IDisposable _standbyOptionsOnChangeSubscription;
         private readonly string _requestUri;
@@ -251,8 +252,8 @@ public void Initialize()
         public void Start()
         {
             Initialize();
-            _processMonitorTimer = new Timer(OnProcessMonitorTimer, null, TimeSpan.Zero, _memorySnapshotInterval);
-            _metricsPublisherTimer = new Timer(OnFunctionMetricsPublishTimer, null, TimeSpan.Zero, _metricPublishInterval);
+            _processMonitorTimer = new Timer(OnProcessMonitorTimer, null, _timerStartDelay, _memorySnapshotInterval);
+            _metricsPublisherTimer = new Timer(OnFunctionMetricsPublishTimer, null, _timerStartDelay, _metricPublishInterval);
 
             _logger.LogInformation(string.Format("Starting metrics publisher for container : {0}. Publishing endpoint is {1}", _containerName, _requestUri));
         }

src/WebJobs.Script.WebHost/Models/EncryptedHostAssignmentContext.cs

@@ -1,7 +1,6 @@
 // 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 Newtonsoft.Json;
 
 namespace Microsoft.Azure.WebJobs.Script.WebHost.Models
@@ -10,8 +9,5 @@ public class EncryptedHostAssignmentContext
     {
         [JsonProperty("encryptedContext")]
         public string EncryptedContext { get; set; }
-
-        [JsonProperty("isWarmup")]
-        public bool IsWarmup { get; set; }
     }
 }

src/WebJobs.Script.WebHost/Models/HostAssignmentContext.cs

@@ -6,7 +6,6 @@
 using System.Linq;
 using Microsoft.Extensions.Logging;
 using Newtonsoft.Json;
-using Newtonsoft.Json.Linq;
 
 namespace Microsoft.Azure.WebJobs.Script.WebHost.Models
 {
@@ -36,6 +35,13 @@ public class HostAssignmentContext
         [JsonProperty("Secrets")]
         public FunctionAppSecrets Secrets { get; set; }
 
+        // This will be true for dummy specialization calls to pre-jit specialization code.
+        // For warmup requests the Run-From-Pkg appsetting will point to a local endpoint that
+        // returns 200 to ensure downloading app contents succeeds.
+        // All the other fields will be empty.
+        [JsonProperty("isWarmupRequest")]
+        public bool IsWarmupRequest { get; set; }
+
         public long? PackageContentLength { get; set; }
 
         public string AzureFilesConnectionString
@@ -55,29 +61,29 @@ public RunFromPackageContext GetRunFromPkgContext()
             {
                 return new RunFromPackageContext(EnvironmentSettingNames.AzureWebsiteRunFromPackage,
                     Environment[EnvironmentSettingNames.AzureWebsiteRunFromPackage],
-                    PackageContentLength);
+                    PackageContentLength, IsWarmupRequest);
             }
             else if (Environment.ContainsKey(EnvironmentSettingNames.AzureWebsiteAltZipDeployment))
             {
                 return new RunFromPackageContext(EnvironmentSettingNames.AzureWebsiteAltZipDeployment,
                     Environment[EnvironmentSettingNames.AzureWebsiteAltZipDeployment],
-                    PackageContentLength);
+                    PackageContentLength, IsWarmupRequest);
             }
             else if (Environment.ContainsKey(EnvironmentSettingNames.AzureWebsiteZipDeployment))
             {
                 return new RunFromPackageContext(EnvironmentSettingNames.AzureWebsiteZipDeployment,
                     Environment[EnvironmentSettingNames.AzureWebsiteZipDeployment],
-                    PackageContentLength);
+                    PackageContentLength, IsWarmupRequest);
             }
             else if (Environment.ContainsKey(EnvironmentSettingNames.ScmRunFromPackage))
             {
                 return new RunFromPackageContext(EnvironmentSettingNames.ScmRunFromPackage,
                     Environment[EnvironmentSettingNames.ScmRunFromPackage],
-                    PackageContentLength);
+                    PackageContentLength, IsWarmupRequest);
             }
             else
             {
-                return new RunFromPackageContext(string.Empty, string.Empty, PackageContentLength);
+                return new RunFromPackageContext(string.Empty, string.Empty, PackageContentLength, IsWarmupRequest);
             }
         }
 

src/WebJobs.Script.WebHost/Models/RunFromPackageContext.cs

@@ -10,11 +10,12 @@ namespace Microsoft.Azure.WebJobs.Script.WebHost.Models
 {
     public class RunFromPackageContext
     {
-        public RunFromPackageContext(string envVarName, string url, long? packageContentLength)
+        public RunFromPackageContext(string envVarName, string url, long? packageContentLength, bool isWarmupRequest)
         {
             EnvironmentVariableName = envVarName;
             Url = url;
             PackageContentLength = packageContentLength;
+            IsWarmUpRequest = isWarmupRequest;
         }
 
         public string EnvironmentVariableName { get; set; }
@@ -23,6 +24,8 @@ public RunFromPackageContext(string envVarName, string url, long? packageContent
 
         public long? PackageContentLength { get; set; }
 
+        public bool IsWarmUpRequest { get; }
+
         public bool IsScmRunFromPackage()
         {
             return string.Equals(EnvironmentVariableName, EnvironmentSettingNames.ScmRunFromPackage,