Kestrel stops serving https (http2) requests after reboot under load

[dv00d00]

Describe the bug

I am running Kestrel as an edge server in the Digital Ocean ( Ubuntu Docker 5:19.03.1~3 on 18.04) via docker-compose

version: '3.5'
services:

  db:
    build: ./docker/db
    command: ["--default-authentication-plugin=mysql_native_password", "--character-set-server=utf8"]
    volumes:
      - dotnet_db_data:/var/lib/mysql
    networks:
      - default
    restart: always
        
  dotnet:
    depends_on:
      - db
    build: .
    environment:
      ASPNETCORE_URLS: "http://+:80;https://+:443"
      ASPNETCORE_ENVIRONMENT: Production
      APPLICATION_NAME: "${APPLICATION_NAME}"
    volumes:
      - ./docker/dotnet_certs:/etc/dotnet_certs
    networks:
      - default
    ports:
      - "80:80"
      - "443:443"
    restart: always

volumes:
  dotnet_db_data: {}

networks:
  default:
    driver: bridge

The container is built with mcr.microsoft.com/dotnet/core/sdk:3.1 and mcr.microsoft.com/dotnet/core/aspnet:3.1

I am using Compression and ResponseCaching middlewares in the request pipeline.

        public void ConfigureServices(IServiceCollection services)
        {
            var deployment = DeploymentResolver.Resolve(Environment, Configuration);
            services.AddSingleton<Deployment>(deployment);
            
            services.AddHttpContextAccessor();
            services.TryAddScoped<IUserAgentService, UserAgentService>();
            services.TryAddScoped<IDeviceService, DeviceService>();

            var mvc = services.AddMvc(options =>
            {
                options.CacheProfiles.Add(DefinedCacheProfiles.Default, new CacheProfile
                {
                    VaryByHeader = DefinedCacheProfiles.PlatformDetectHeader,
                    Duration = 60 * 5
                });

                if (Environment.IsStaging())
                {
                    options.Filters.Add(new BasicAuth("test"));
                }
            })
            .AddJsonOptions(options => options.JsonSerializerOptions.PropertyNamingPolicy = null); ;

            if (Environment.IsDevelopment())
            {
                mvc.AddRazorRuntimeCompilation();
            }

            services.AddDbContext<TrackDbContext>(options =>
            {
                options.UseMySql(Configuration.GetConnectionString("DefaultConnection"),
                    mysql =>
                    {
                        mysql.ServerVersion(new Version(8, 0, 16), ServerType.MySql);
                        mysql.MigrationsHistoryTable("migrations_history");
                    });
            });

            services.AddResponseCaching(options => { options.UseCaseSensitivePaths = false; });
            services.AddMemoryCache(options => { });
            
            services.AddHttpClient();
            services.RemoveAll<IHttpMessageHandlerBuilderFilter>();
           
            services.Configure<GzipCompressionProviderOptions>(options =>
            {
                options.Level = CompressionLevel.Optimal;
            });

            services.AddResponseCompression(options =>
            {
                options.EnableForHttps = true;
                options.MimeTypes = new[]
                {
                    "application/atom+xml",
                    "application/javascript",
                    "application/json",
                    "application/ld+json",
                    "application/manifest+json",
                    "application/rss+xml",
                    "application/vnd.geo+json",
                    "application/vnd.ms-fontobject",
                    "application/x-font-ttf",
                    "application/x-web-app-manifest+json",
                    "application/xhtml+xml",
                    "application/xml",
                    "font/opentype",
                    "font/woff2",
                    "image/bmp",
                    "image/svg+xml",
                    "image/x-icon",
                    "text/html",
                    "text/cache-manifest",
                    "text/css",
                    "text/plain",
                    "text/vcard",
                    "text/vnd.rim.location.xloc",
                    "text/vtt",
                    "text/x-component",
                    "text/x-cross-domain-policy",
                };

                options.Providers.Add<BrotliCompressionProvider>();
                options.Providers.Add<GzipCompressionProvider>();
            });

            if (!Environment.IsDevelopment())
            {
                services.AddFluffySpoonLetsEncrypt(new LetsEncryptOptions
                {
                    Email =  "[email protected]", 
                    UseStaging = false, 
                    Domains = new[] { deployment.DNS },
                    TimeUntilExpiryBeforeRenewal = TimeSpan.FromDays(30), 
                    TimeAfterIssueDateBeforeRenewal = TimeSpan.FromDays(7), 
                    CertificateSigningRequest = new CsrInfo(),
                    KeyAlgorithm = KeyAlgorithm.ES256,
                });
                
                services.AddFluffySpoonLetsEncryptFileCertificatePersistence("//etc/dotnet_certs/main");
                services.AddFluffySpoonLetsEncryptMemoryChallengePersistence();
            }
        }

        public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
        {
            if (!env.IsProduction())
            {
                app.UseDeveloperExceptionPage();
                app.UseDatabaseErrorPage();
            }

            app.UseFluffySpoonLetsEncrypt();
            
            app.UseHsts();
            app.UseHttpsRedirection();
            app.UseStatusCodePagesWithReExecute("/status/{0}");
            
            app.Use((context, next) =>
            {
                context.SetEndpoint(null);
                return next();
            });
            
            app.Map("/metrics", metricsApp =>
            {
                const string userName = "monitoring";
                const string password = "long-and-secure-password-for-monitoring-2";
                var valid = "Basic " + Convert.ToBase64String(Encoding.UTF8.GetBytes(userName + ":" + password));

                metricsApp.Use((context, next) =>
                {
                    if (context.Request.Headers["Authorization"] == valid)
                    {
                        return next();
                    }

                    context.Response.Headers["WWW-Authenticate"] = "Basic";
                    context.Response.StatusCode = (int) HttpStatusCode.Unauthorized;
                    return Task.CompletedTask;
                });
                
                metricsApp.UseMetricServer("");
            });
            
            app.UseResponseCompression();

            var cacheValue = $"public, max-age={30 * 24 * 60 * 60}";
            app.UseStaticFiles(new StaticFileOptions
            {
                OnPrepareResponse = ctx => { 
                    ctx.Context.Response.Headers.Append("Cache-Control", cacheValue); 
                }
            });

            app.UseRouting();
            
            app.UseHttpMetrics(options =>
            {
                options.InProgress.Enabled = false;
            });
            
            app.Use(DetectDevice);
            
            app.UseResponseCaching();

            app.UseEndpoints(endpoints => { endpoints.MapControllers(); });
        }

The issue was not appearing before we have started receiving increased volume of traffic (eg before 1 rps after 8 rps).

Deployment process loads latest commit from repo, builds container on the host and launches new instance docker-compose -f prod.yml up -d --build

This process restarts the running Kestrel container and after the restart, newly started instance is not handling any requests.

Cpu is low during this period (normal avg 10%, broken avg 10%).

After a series of reboots server starts to handle requests again.

To Reproduce

I am able to consistently reproduce the issues with the syntetic traffic on our staging env:

    class Program
    {
        private static readonly string[] Urls = new[]
        {
            "https://server.com/homepage",
            "https://server.com/homepage2",
            "https://server.com/homepage3",
            
        };
        
        static async Task Main(string[] args)
        {
            for (int i = 0; i < 50; i++)
            {
                Go(i + 1);
            }

            Console.ReadLine();
        }
        
        static async Task Go(int id)
        {
            Console.WriteLine("Running: " + id);
            var random = new Random();

            while (true)
            {
                try
                {
                    var httpClient = new HttpClient();
                    var request = new HttpRequestMessage(HttpMethod.Get, Urls[random.Next(Urls.Length)] );
                    request.Headers.Authorization = new AuthenticationHeaderValue("Basic", "YWRtaW46bG9uZy1hbmQtc2VjdXJlLXBhc3N3b3JkLWZvci1hZG1pbjI=");
                    var response = await httpClient.SendAsync(request, HttpCompletionOption.ResponseContentRead);
                    var str = await response.Content.ReadAsStringAsync();
                    // Console.WriteLine("OK");
                }
                catch (Exception e)
                {
                    Console.WriteLine(e.Message);
                    
                    if (e.Message.Contains("SSL"))
                        Console.WriteLine(e.ToString());
                    // await Task.Delay(10);
                }
            }
        }
    }

While the fake load is running I am shutting the stack down and bringing it up again. Repro rate is around 90%

Further technical details

• ASP.NET Core version: 3.1
• Include the output of dotnet --info:

Host (useful for support):
  Version: 3.1.1
  Commit:  a1388f194c

.NET Core SDKs installed:
  No SDKs were found.

.NET Core runtimes installed:
  Microsoft.AspNetCore.App 3.1.1 [/usr/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 3.1.1 [/usr/share/dotnet/shared/Microsoft.NETCore.App]

[Tratcher]

What do the server logs say?
https://docs.microsoft.com/en-us/aspnet/core/fundamentals/logging/?view=aspnetcore-3.1#configuration

[dv00d00]

Whenever I was able to reproduce this behavior the only logs I was getting was the default startup output:

dotnet_1  | warn: Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository[60]
dotnet_1  |       Storing keys in a directory '/root/.aspnet/DataProtection-Keys' that may not be persisted outside of the container. Protected data will be unavailable when container is destroyed.
dotnet_1  | info: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[0]
dotnet_1  |       User profile is available. Using '/root/.aspnet/DataProtection-Keys' as key repository; keys will not be encrypted at rest.
dotnet_1  | info: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[58]
dotnet_1  |       Creating key {51e563a9-e6ff-427c-9345-e2c20042d581} with creation date 2020-04-24 20:48:20Z, activation date 2020-04-24 20:48:20Z, and expiration date 2020-07-23 20:48:20Z.
dotnet_1  | warn: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[35]
dotnet_1  |       No XML encryptor configured. Key {51e563a9-e6ff-427c-9345-e2c20042d581} may be persisted to storage in unencrypted form.
dotnet_1  | info: Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository[39]
dotnet_1  |       Writing data to file '/root/.aspnet/DataProtection-Keys/key-51e563a9-e6ff-427c-9345-e2c20042d581.xml'.
dotnet_1  | info: Microsoft.Hosting.Lifetime[0]
dotnet_1  |       Now listening on: http://[::]:80
dotnet_1  | info: Microsoft.Hosting.Lifetime[0]
dotnet_1  |       Now listening on: https://[::]:443
dotnet_1  | info: FluffySpoon.AspNet.LetsEncrypt.Certes.ILetsEncryptRenewalService[0]
dotnet_1  |       Application started
dotnet_1  | info: Microsoft.Hosting.Lifetime[0]
dotnet_1  |       Application started. Press Ctrl+C to shut down.
dotnet_1  | info: Microsoft.Hosting.Lifetime[0]
dotnet_1  |       Hosting environment: Staging
dotnet_1  | info: Microsoft.Hosting.Lifetime[0]
dotnet_1  |       Content root path: /app
dotnet_1  | info: FluffySpoon.AspNet.LetsEncrypt.Certificates.CertificateProvider[0]
dotnet_1  |       Checking to see if in-memory LetsEncrypt certificate needs renewal.
dotnet_1  | info: FluffySpoon.AspNet.LetsEncrypt.Certificates.CertificateProvider[0]
dotnet_1  |       Checking to see if existing LetsEncrypt certificate has been persisted and is valid.
dotnet_1  | info: FluffySpoon.AspNet.LetsEncrypt.Certificates.CertificateProvider[0]
dotnet_1  |       A persisted non-expired LetsEncrypt certificate was found and will be used.

and a several minutes of silence after

On a very rare occasion, I was getting

failed to receive a heartbeat in 1 second, looks like a threadpool starvation ( I was not able to copy the actual message yet)

I have disabled caching middleware and now getting the issue 100% of the time. (Will publish debug level logs in a moment)

So looks like a bunch of HTTP client (50 in my case) simultaneously sending 50 requests, if cache is not populated all of those requests are hitting some sort of lock contention.

There is a screenshot of the lock contention graphs from the production box which is running fine now:

[Tratcher]

Ah, that's progress. A process dump or attaching a debugger would be what you need to see where those threads are stuck.

[dv00d00]

Debug level logs

``` dotnet_1 | warn: Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository[60] dotnet_1 | Storing keys in a directory '/root/.aspnet/DataProtection-Keys' that may not be persisted outside of the container. Protected data will be unavailable when container is destroyed. dotnet_1 | info: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[0] dotnet_1 | User profile is available. Using '/root/.aspnet/DataProtection-Keys' as key repository; keys will not be encrypted at rest. dotnet_1 | dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.DefaultKeyResolver[53] dotnet_1 | Repository contains no viable default key. Caller should generate a key with immediate activation. dotnet_1 | dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.KeyRingProvider[57] dotnet_1 | Policy resolution states that a new key should be added to the key ring. dotnet_1 | info: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[58] dotnet_1 | Creating key {6550b92f-a449-4cb0-8a66-feb84141dd52} with creation date 2020-04-24 20:58:45Z, activation date 2020-04-24 20:58:45Z, and expiration date 2020-07-23 20:58:45Z. dotnet_1 | dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[32] dotnet_1 | Descriptor deserializer type for key {6550b92f-a449-4cb0-8a66-feb84141dd52} is 'Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ConfigurationModel.AuthenticatedEncryptorDescriptorDeserializer, Microsoft.AspNetCore.DataProtection, Version=3.1.3.0, Culture=neutral, PublicKeyToken=adb9793829ddae60'. dotnet_1 | dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[34] dotnet_1 | No key escrow sink found. Not writing key {6550b92f-a449-4cb0-8a66-feb84141dd52} to escrow. dotnet_1 | warn: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[35] dotnet_1 | No XML encryptor configured. Key {6550b92f-a449-4cb0-8a66-feb84141dd52} may be persisted to storage in unencrypted form. dotnet_1 | info: Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository[39] dotnet_1 | Writing data to file '/root/.aspnet/DataProtection-Keys/key-6550b92f-a449-4cb0-8a66-feb84141dd52.xml'. dotnet_1 | dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[23] dotnet_1 | Key cache expiration token triggered by 'CreateNewKey' operation. dotnet_1 | dbug: Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository[37] dotnet_1 | Reading data from file '/root/.aspnet/DataProtection-Keys/key-6550b92f-a449-4cb0-8a66-feb84141dd52.xml'. dotnet_1 | dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[18] dotnet_1 | Found key {6550b92f-a449-4cb0-8a66-feb84141dd52}. dotnet_1 | dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.DefaultKeyResolver[13] dotnet_1 | Considering key {6550b92f-a449-4cb0-8a66-feb84141dd52} with expiration date 2020-07-23 20:58:45Z as default key. dotnet_1 | dbug: Microsoft.AspNetCore.DataProtection.TypeForwardingActivator[0] dotnet_1 | Forwarded activator type request from Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ConfigurationModel.AuthenticatedEncryptorDescriptorDeserializer, Microsoft.AspNetCore.DataProtection, Version=3.1.3.0, Culture=neutral, PublicKeyToken=adb9793829ddae60 to Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ConfigurationModel.AuthenticatedEncryptorDescriptorDeserializer, Microsoft.AspNetCore.DataProtection, Culture=neutral, PublicKeyToken=adb9793829ddae60 dotnet_1 | dbug: Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ManagedAuthenticatedEncryptorFactory[11] dotnet_1 | Using managed symmetric algorithm 'System.Security.Cryptography.Aes'. db_1 | 2020-04-24T20:58:46.046834Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Socket: '/var/run/mysqld/mysqlx.sock' bind-address: '::' port: 33060 dotnet_1 | dbug: Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ManagedAuthenticatedEncryptorFactory[10] dotnet_1 | Using managed keyed hash algorithm 'System.Security.Cryptography.HMACSHA256'. dotnet_1 | dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.KeyRingProvider[2] dotnet_1 | Using key {6550b92f-a449-4cb0-8a66-feb84141dd52} as the default key. dotnet_1 | dbug: Microsoft.AspNetCore.DataProtection.Internal.DataProtectionHostedService[0] dotnet_1 | Key ring with default key {6550b92f-a449-4cb0-8a66-feb84141dd52} was loaded during application startup. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer[2] dotnet_1 | Failed to locate the development https certificate at '(null)'. dotnet_1 | info: Microsoft.Hosting.Lifetime[0] dotnet_1 | Now listening on: http://[::]:80 dotnet_1 | info: Microsoft.Hosting.Lifetime[0] dotnet_1 | Now listening on: https://[::]:443 dotnet_1 | dbug: Microsoft.AspNetCore.Hosting.Diagnostics[0] dotnet_1 | Loaded hosting startup assembly WebApplication dotnet_1 | info: FluffySpoon.AspNet.LetsEncrypt.Certes.ILetsEncryptRenewalService[0] dotnet_1 | Application started dotnet_1 | info: Microsoft.Hosting.Lifetime[0] dotnet_1 | Application started. Press Ctrl+C to shut down. dotnet_1 | info: Microsoft.Hosting.Lifetime[0] dotnet_1 | Hosting environment: Staging dotnet_1 | info: Microsoft.Hosting.Lifetime[0] dotnet_1 | Content root path: /app dotnet_1 | dbug: Microsoft.Extensions.Hosting.Internal.Host[2] dotnet_1 | Hosting started dotnet_1 | info: FluffySpoon.AspNet.LetsEncrypt.Certificates.CertificateProvider[0] dotnet_1 | Checking to see if in-memory LetsEncrypt certificate needs renewal. dotnet_1 | info: FluffySpoon.AspNet.LetsEncrypt.Certificates.CertificateProvider[0] dotnet_1 | Checking to see if existing LetsEncrypt certificate has been persisted and is valid. dotnet_1 | info: FluffySpoon.AspNet.LetsEncrypt.Certificates.CertificateProvider[0] dotnet_1 | A persisted non-expired LetsEncrypt certificate was found and will be used. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5B" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5C" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5D" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5E" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5F" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5G" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5H" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5B" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5C" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5D" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5E" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5F" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5G" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5H" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5I" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5J" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5K" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5L" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5M" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5N" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5O" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5P" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5Q" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5R" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5S" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5T" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5U" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G5V" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G60" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G61" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G62" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G63" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G64" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G65" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G66" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G67" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G68" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G69" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6A" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6B" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6C" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6D" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6E" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6F" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6G" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6H" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6I" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6J" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6K" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6L" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6M" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6N" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6O" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6P" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6Q" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6R" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6S" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5I" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5J" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5K" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5L" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5M" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5N" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5O" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5P" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5Q" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5G" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5R" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5S" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5I" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5T" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5U" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G5V" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G60" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G61" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G62" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G63" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G64" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5Q" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G65" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5R" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G66" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G67" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G68" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G69" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5V" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6A" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6B" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6C" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6D" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G63" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6E" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6F" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6G" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6H" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6I" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6J" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G69" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6K" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6A" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6L" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6B" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6M" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6N" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6O" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6P" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6Q" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6G" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6R" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6S" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6I" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5C" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5B" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5D" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5F" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5E" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5H" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6J" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6T" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6U" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G6V" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G70" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G71" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G72" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G73" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G74" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G75" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G76" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G77" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5J" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5K" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5L" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5M" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5N" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5O" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5P" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5S" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5T" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G5U" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G60" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G61" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G62" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G64" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G65" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G66" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G67" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G68" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6C" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6D" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6E" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6F" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6H" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6T" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6U" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6K" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G6V" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G70" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G71" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G72" started. ^Adotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G73" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G74" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G75" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G76" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G77" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G78" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G79" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7A" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7B" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7C" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7D" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7E" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7F" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7G" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7H" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7I" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7J" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7K" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7L" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7M" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7N" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7O" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7P" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7Q" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7R" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7S" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7T" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7U" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G7V" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G80" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G81" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G82" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G83" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G84" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G85" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G86" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[39] dotnet_1 | Connection id "0HLV8I93V3G87" accepted. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6L" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6N" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6M" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6O" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6P" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6Q" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6R" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6S" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G6T" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G78" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G79" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7A" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G70" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7B" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7C" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G71" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7D" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G72" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7E" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G73" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7F" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G74" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7G" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7H" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7I" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G77" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7J" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G78" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7K" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7L" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7M" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7N" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7O" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7P" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7Q" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7R" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7S" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7T" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7U" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G7L" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G7V" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G7M" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G80" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G81" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G82" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G7O" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G83" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G7P" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G84" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G85" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G7R" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G86" started. dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7] dotnet_1 | Connection id "0HLV8I93V3G7S" sending FIN because: "The connection was aborted by the application via ConnectionContext.Abort()." dotnet_1 | dbug: Microsoft.AspNetCore.Server.Kestrel[1] dotnet_1 | Connection id "0HLV8I93V3G87" started. ```

[dv00d00]

I will try to repro on my dev box under the debugger, will attempt to get dump out of container it that won't work

[Tratcher]

Weird, those connections don't even show that they've received any requests. Are those supposed to be https? Is it having trouble getting the FluffySpoon cert for the ssl channel?

[dv00d00]

Those are https indeed.

FluffySpoon is a lets encrypt cert renewal middleware, it got the certificate into a static variable before the server started listening to requests. ( according to logs at least )
(https://github.com/ffMathy/FluffySpoon.AspNet.LetsEncrypt/blob/master/src/FluffySpoon.AspNet.LetsEncrypt/KestrelOptionsSetup.cs)

I was not able to reproduce exact behavior locally, neither attach debugger to a remote docker container.

I did run damn thing under the profiler (windows, development). When a fresh instance is struck with 100 or so requests, there is a huge lock contention over entity framework context GetModel

then query cache hitting the fan

I am quite new at reading it though, I will try to grab proper trace from the thing in the docker, would appreciate any advice on how to do it.

[dv00d00]

Managed to collect trace
trace.zip

[dv00d00]

I've added reverse proxy in front of Kestrel.

Got a decent amount of metrics, change is very obvious.

Cpu from VM:

Network from VM:

Cpu from .net metrics:

GC allocations:

Lock contention:

A brief history of changes:

1. Change of VM (1 core 2 GB Ram -> 2 cores 4 GB Ram)
2. Reverse proxy added
   I've removed static files, compression, hsts, https redirection middlewares from Kestrel.
   Added UseForwardedHeaders.
   Changed hack for response caching (previously I was adding extra request header, now I am overwriting UserAgent)
   Turned off https.

[davidfowl]

@dv00d00 it sounds like you have a typical sync over async issue where your thread pool is being starved. It's likely caused by something in process blocking, if you're willing to, I'd like to help you debug this issue. To verify that it might indeed be thread pool starvation can you run dotnet counters inside of your container on the application that having this problem? The counters to look at would be the thread pool queue count.

[dv00d00]

@davidfowl will do. Are we interested in just my code or the whole setup which was experiencing thread pool starvation? (I assume the whole setup).

I've attached a graph of lock contention above, it shows a significant drop after I've removed some of middlewares from pipeline.

[davidfowl]

@davidfowl will do. Are we interested in just my code or the whole setup which was experiencing thread pool starvation? (I assume the whole setup).

Yes, I'm interesting in a couple of things:

• What components are "slow" here. Do you have anything blocking threads? Is it the lock contention?
• Between a dump and a trace, what things tools can we build to improve the diagnostics of these cases (we're working on a few specific async aware diagnostics tools that I want to try out on your scenario).

If you remove the load balancer and also removed the middleware does it improve things or did it still get stuck? Also do you have a process dump when things are stuck? (don't share it here, it has sensitive information).

[dv00d00]

@davidfowl

Due to the thread blocking: I am almost certain that there are no blocking calls (I am awaiting every async method or clear usage of lock instructions). The app is pretty simple, a bunch of controllers with views, some API calls via IHttpClientFactory. Views are a bit involved though, a lot of partials, some usage of ICompositeViewEngine.GetView here and there and that is basically it.

Full package list

<PackageReference Include="FluffySpoon.AspNet.LetsEncrypt" Version="1.146.0" />
<PackageReference Include="Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore" Version="3.1.3" />
<PackageReference Include="Microsoft.AspNetCore.Mvc.Razor.RuntimeCompilation" Version="3.1.3" />
<PackageReference Include="Serilog.AspNetCore" Version="3.2.0" />
<PackageReference Include="Serilog.Sinks.Loggly" Version="5.4.0" />
<PackageReference Include="prometheus-net.AspNetCore" Version="3.5.0" />
<PackageReference Include="prometheus-net.DotNetRuntime" Version="3.3.1" />
<PackageReference Include="Microsoft.EntityFrameworkCore.Design" Version="3.1.3" />
<PackageReference Include="Pomelo.EntityFrameworkCore.MySql" Version="3.1.1" />

Due to the tools, I've never had to deal with such in-depth performance profiling yet, dotnet-dump was impressive, PerfView is awful. In theory, something that would throw on calling Task.GetResult could be useful in debug mode.

I've managed to collect counters from the repro env, which is in exact shape when it happened in production. A few observations are if I will hit an with a single request from the browser before launching a load upon it, everything is slow (I've disabled cache) but works. The issue appears only if I hit the app with ~50 simultaneous requests from the load gen in the header of this issue.

[counter.zip](https://github.com/dotnet/aspnetcore/files/4534079/counter.zip)

thanks for working with me on Saturday

[dv00d00]

counter.zip

[dv00d00]

For this counter log, I've collected metrics from the case when I initially hit the app with a bunch of requests. I've stopped load, waited till I was able to get success and then launched another test run.

[dv00d00]

Due to the dump, any advice on how and when to get it ?

[davidfowl]

Due to the thread blocking: I am almost certain that there are no blocking calls (I am awaiting every async method or clear usage of lock instructions)

Libraries you are using might not be as diligent as you are.

Due to the tools, I've never had to deal with such in-depth performance profiling yet, dotnet-dump was impressive, PerfView is awful. In theory, something that would throw on calling Task.GetResult could be useful in debug mode.

Visual Studio also supports nettrace files! 😄

I've managed to collect counters from the repro env, which is in exact shape when it happened in production. A few observations are if I will hit an with a single request from the browser before launching a load upon it, everything is slow (I've disabled cache) but works. The issue appears only if I hit the app with ~50 simultaneous requests from the load gen in the header of this issue.

Thats very interesting it sounds like an the threadpool might be bombarded and requests are queued not being dequeued because there's a low number of threads to begin with. That usually only matters when blocking but it could also be due to things like Parallel.For/Foreach etc.

Due to the dump, any advice on how and when to get it ?

If you can reproduce it on demand in production, you need to add the dotnet dump tool to your container image so that you can exec into the container and capture it. Is that possible?

[dv00d00]

I am able to reproduce this thing easily, so dump is 100% possible

I've visualized metrics:

ThreadPool Queue Length

Lock contention

[dv00d00]

Due to the temp solution, can anyone validate this:

Some sort of initialization is happening during the first HTTP request to the server. This initialization requires a lock. If the uninitialized server is getting a bunch of requests it will spawn a thread for each, normally only a thread per core will be used.

A bunch of threads waiting to be dispatched crush cpu, nothing happens at this stage.

A regular page on my site is referencing ~15 static assets. During a peak, if I deploy a new version, it will start processing tcp traffic across previously active and new users.

If I somehow massage the server before exposing it to the world it might help. Docker health check might work if I will send a bunch of requests (sequentially) on the server before exposing it.

[davidfowl]

I am able to reproduce this thing easily, so dump is 100% possible

Perfect, can you get a dump? In your docker file, if you're doing a multi-statge build you can use the build stage to install the dotnet dump tool then copy it over to the runtime image. After you do that, you should be able to exec into the container and run dotnet-dump on the tool to capture it inside of the container. I'd recommand capturing the dump an looking at it inside of the container since that's easier.

Then run dotnet-dump analyze {dumpfile} to get the repl and run:

clrstack -all

That'll show all managed stacks. Paste the output in here.

[davidfowl]

This is what you can put in your docker file to install the tools (assuming you're doing a multi-stage build)

FROM mcr.microsoft.com/dotnet/core/sdk:3.1 AS build-env

RUN dotnet tool install dotnet-dump --tool-path /tools
RUN dotnet tool install dotnet-counters --tool-path /tools
RUN dotnet tool install dotnet-trace --tool-path /tools

WORKDIR /app

# Build runtime image
FROM mcr.microsoft.com/dotnet/core/aspnet:3.1

COPY --from=build-env /tools /tools

[dv00d00]

Got it
stack.txt

[dv00d00]

looks like System.Net.Http.TLSCertificateExtensions.BuildNewChain blocks

[davidfowl]

Yep https://github.com/dotnet/runtime/blob/dbc7fc6ec8d3812cef5eee5d0a9492e0c1fc37e1/src/libraries/System.Security.Cryptography.X509Certificates/src/Internal/Cryptography/Pal.Unix/CertificateAssetDownloader.cs#L99-L124

This has plagued several issues now and it might be time to discuss an alternative. I'm not even sure its possible to work around 😢 .

Look @bartonjs its our friend again 😄.

• Hang in x509certificate build chain when using a Let's Encrypt cert. runtime#24527
• Denial of service when using X509 certificates runtime#31664

PS: @dv00d00 excellent debugging.

[dv00d00]

Well..., 🛡️

Does it mean do not use Kestrel as an edge server until SslStream is fixed for Unix? Any chance it will be fixed as a prerequisite for YARP?

I took a brief look at the source code for ssl stream, does it download cert for request Kestrel handles?

I mean maybe there is a way to cache it somehow before starting port listening?

This did not work:

            var bytes = await File.ReadAllBytesAsync("//etc/dotnet_certs/main_Site");
            using (var cert = new X509Certificate2(bytes, "FluffySpoon"))
            using (var chain = new X509Chain(true))
            {
                
                chain.Build(cert);
            }

Thanks for replies on weekend @davidfowl

[davidfowl]

@dv00d00 Are you willing to try something out for me? I want to see if there's a workaround we can document and I want you to try again.

[dv00d00]

Sure, still have a repro branch by my side @davidfowl

[davidfowl]

We're going to need to make a change to FluffySpoonLetsEncrypt.

[davidfowl]

I'm looking for an extensibility point in the APIs. Basically what I want you to try is building the cert chain whenever a certificate is retrieved on the background thread.

Do you know if there's a way to hook in and get the certificate before it gets passed to Kestrel? I see some ways but it requires wrapping a service.

[dv00d00]

I'm ok with including FluffySpoonLetsEncrypt as a project reference, we can use the raw cert file it creates without it being involved at all. If the workaround works I'll submit a fix pr to the https://github.com/ffMathy/FluffySpoon.AspNet.LetsEncrypt repo

[davidfowl]

OK so this logic that you wrote here:

#21183 (comment)

You basically need to replicate that but I would copy this logic:

https://github.com/dotnet/runtime/blob/4f84429fb44801b841c052505935a3cd14da18e2/src/libraries/Common/src/System/Net/Http/TlsCertificateExtensions.cs#L77-L97

var chain = new X509Chain();
chain.ChainPolicy.VerificationFlags = X509VerificationFlags.AllFlags;
chain.ChainPolicy.RevocationFlag = X509RevocationFlag.ExcludeRoot;
chain.ChainPolicy.RevocationMode = X509RevocationMode.NoCheck;

// We're not doing anything client side
// if (includeClientApplicationPolicy)
// {
//    chain.ChainPolicy.ApplicationPolicy.Add(s_clientCertOidInst);
//}

if (chain.Build(certificate))
{
    return chain;
}
else
{
    chain.Dispose();
    return null;
}

Run this code here https://github.com/ffMathy/FluffySpoon.AspNet.LetsEncrypt/blob/02b617896e2ab394cb185a77b9d6f48abe6e5e12/src/FluffySpoon.AspNet.LetsEncrypt/Certificates/CertificateProvider.cs#L80

After getting the cert, Build the chain here.

[davidfowl]

It seems like there's a race condition in this library on startup where the cert could be null (or maybe I'm missing something...)

[dv00d00]

Oh wow it actually worked!

I've disabled fluffyspoon (services and middleware). The cert was already persisted to disk. I've added this method to Program.cs

        private static async Task<X509Certificate2> Build()
        {
            var bytes = await File.ReadAllBytesAsync("//etc/dotnet_certs/main_Site");
            var certificate = new X509Certificate2(bytes, "FluffySpoon");
            var chain = new X509Chain
            {
                ChainPolicy =
                {
                    VerificationFlags = X509VerificationFlags.AllFlags,
                    RevocationFlag = X509RevocationFlag.ExcludeRoot,
                    RevocationMode = X509RevocationMode.NoCheck
                }
            };
            
            if (chain.Build(certificate))
            {
                return certificate;
            }
            else
            {
                chain.Dispose();
                return null;
            }
        }

The used it

            var hostBuilder = Host.CreateDefaultBuilder(args)
                .ConfigureWebHostDefaults(webBuilder =>
                {
                    webBuilder
                        .ConfigureKestrel(options =>
                        {
                            options.Limits.KeepAliveTimeout = TimeSpan.FromSeconds(60);
                            options.ConfigureHttpsDefaults(o =>
                            {
                                o.ServerCertificate = cert;
                            });
                        })
                        .UseStartup<Startup>()
                        .UseSerilog();
                });

10/10 reboots under load were able to handle requests. Slower than expected, but ramping up to full speed in 20 seconds or so. The entity framework produces a lot of lock contention I believe.

When commented out

            var chain = new X509Chain
            {
                ChainPolicy =
                {
                    VerificationFlags = X509VerificationFlags.AllFlags,
                    RevocationFlag = X509RevocationFlag.ExcludeRoot,
                    RevocationMode = X509RevocationMode.NoCheck
                }
            };
            
            if (chain.Build(certificate))
            {
                return certificate;
            }
            else
            {
                chain.Dispose();
                return null;
            }
        }

server was not able to process any requests.

[davidfowl]

Nice! Are you going to send a PR to FluffySpoon

[dv00d00]

Yep, would appreciate your review tbh.

[dv00d00]

I am also curious about what was going on with thread pool starvation in my case. Am I right saying that all requests on a fresh/unvalidated certificate ended up querying cert status from LetsEncrypt servers and starved threadpool?

Or the certificate checks were made on a per request basis?

[davidfowl]

Am I right saying that all requests on a fresh/unvalidated certificate ended up querying cert status from LetsEncrypt servers and starved threadpool?

Even though the full chain is being requested we still validate it but this is what happens:

• We get a pfx file with the full cert chain
• We feed that cert into X509Certificate2 type which only grabs the first https cert not the full chain (we don't have a way to represent the validated chain)
• The logic then tries to download the full cert chain (per connection!), it does this synchronously.
• It caches the cert chain on disk, which is ephemeral inside of the container....

All badness.

[dv00d00]

Thanks for the review guys, both PRs (natemcmaster/LettuceEncrypt#81 and ffMathy/FluffySpoon.AspNet.EncryptWeMust#71) are merged and will be released soon. I am not aware of any other community projects aimed at acme cert providers.

This whole story rendered that SSL could be tricky and assuming that SslStream internals will change in the future this could lead to other similar issues.

Idk, I'd be happy to see support from the dotnet team on the LestsEncrypt side. Having SSL benchmarks with popular community libs is a great starting point as @davidfowl suggested. Dotnet foundation membership is better. Builtin support is best imo.

This issue could be closed I believe.

Really interested if there will be any further steps and if I can help somehow.

This was a wild ride.

[davidfowl]

This whole story rendered that SSL could be tricky and assuming that SslStream internals will change in the future this could lead to other similar issues.

Yes this great issue investigation spawned a set of work that I have tracked here #21512. 5.0 should have this situation dramatically improved.

@bartonjs is our certificate crypto export and we're looking at ways to represent a "pre-validated" certificate chain for these scenarios to avoid this in the future.

[BrennanConroy]

@davidfowl Do we believe this issue can be closed now for 5.0?

[davidfowl]

Sorta, but I need to merge this #24935 for it to be done done

[davidfowl]

Closing this as the major bug as been addressed here. Will follow up with this change #24935 later