request processing slows down on concurrent requests.

Request handling extremely slows down on concurrent requests

[Route("Test")]
public class TestController : Controller {
        [HttpGet("DoNothingGet")]
        public void DoNothingGet() { }
}

Against above controller, I tested concurrent request using shell script below

for i in {1..50}
do
curl -X GET "http://localhost:5000/Test/DoNothingGet" -H "Host: 127.0.0.1:5000" -H "X-Debug: true" -H "User-Agent: Terminal" -d "[0, 0]" &
done

For sequential request, there's almost no delay for processing requests. consuming about 1~5ms per request. but For concurrent request, handling time varies from 100ms ~ 2000ms

There's light middleware attached for logging execution time.

public class ProcessingTimeLoggingMiddleware
    {
        readonly RequestDelegate _next;
        readonly ILogger<RequestLoggingMiddleware> _logger;

        public ProcessingTimeLoggingMiddleware(
            RequestDelegate next,
            ILogger<RequestLoggingMiddleware> logger
        )
        {
            _logger = logger;
            _next = next;
        }

        public async Task Invoke(HttpContext context)
        {
            _logger.LogInformation("Start Middleware");
            var sw = Stopwatch.StartNew();

            await _next.Invoke(context);

            sw.Stop();

            _logger.LogInformation(LoggingEvents.RequestProcessingTime,
                "Processing {Path} [{StatusCode}] took {ElapsedTime}ms.",
                context.Request.Path, context.Response.StatusCode, sw.ElapsedMilliseconds
            );
        }
    }

Below are collected logs for slow request. (one of 50 requests. others also have similar logs)

March 29th 2018, 15:50:20.286 Microsoft.AspNetCore.Hosting.Internal.WebHost 
Request starting HTTP/1.1 GET http://127.0.0.1:5000/Test/DoNothingGet application/x-www-form-urlencoded 6

March 29th 2018, 15:50:20.412 Server.Middlewares.RequestLoggingMiddleware 
Start Middleware

March 29th 2018, 15:50:21.445 Server.Middlewares.RequestLoggingMiddleware 
Processing /Test/DoNothingGet [200] took 830ms

March 29th 2018, 15:50:22.439 Microsoft.AspNetCore.Hosting.Internal.WebHost 
Request finished in 2166.119ms

I tried manipulating ThreadPool.SetMinThreads and KestrelServerOptions.Limits.MaxConcurrentConnection but nothing had any effect.

Environment data

<PackageReference Include="Microsoft.AspNetCore.Hosting" Version="2.0.0" />
    <PackageReference Include="Microsoft.AspNetCore.Mvc" Version="2.1.0-preview1-final" />
    <PackageReference Include="Microsoft.AspNetCore.Owin" Version="2.0.0" />
    <PackageReference Include="Microsoft.AspNetCore.Server.Kestrel" Version="2.0.0" />

Product Information:
 Version:            2.1.4
 Commit SHA-1 hash:  5e8add2190

Runtime Environment:
 OS Name:     Mac OS X
 OS Version:  10.13
 OS Platform: Darwin
 RID:         osx.10.12-x64
 Base Path:   /usr/local/share/dotnet/sdk/2.1.4/

Microsoft .NET Core Shared Framework Host

  Version  : 2.0.5
  Build    : 17373eb129b3b05aa18ece963f8795d65ef8ea54

dotnet / sdk

request processing slows down on concurrent requests. #9237

Environment data