Enable kernel response buffering for HTTP.sys server

[wdls22]

I deploy an ASP.NET Core Service in Service Fabric in Azure.
I tried Kestrel and Http.sys as server and using Response compression.
I found if I use Http.sys as server and usign Response compression, static file download is very slow It will cost more than 1 minutes to doanload a 1.6mb JS file.
If I use Kestrel, this issue will not happen. If I use http.sys without Response compression, it also did not happen.
So maybe something wrong with Http.sys and Response compression?

I tried it on ASP.Net 2.2 and 3.0, it can repro in both environments.

To Reproduce

Building an ASP.NET Core Service with Http.sys as server (using https),
Using "app.UseResponseCompression();" to compress the static file response. Then deploy it to Azure Service Fabric with 5 nodes.

Using browsers to open website. It will take a long time to download static files.
If using Kestrel or Http.sys without compression, it will not happen.
And if I run this service on my local machine, it will never happen Whatever combination.

Screenshots

[Tratcher]

Does it make a difference if you use http vs https?

This is most likely an issue with buffering (or the lack thereof) between response compression and HttpSys. Kestrel has what we call a write-behind buffer for the response body, so most write operations complete immediately and then the server aggregates them on a background thread when writing to the network. HttpSys doesn't do this, every write waits for the data to get fully flushed to the network layer before unblocking the app for the next write. This is mainly a problem if you're doing multiple small writes, you would see lots of small TCP packets on the wire. StaticFiles should be doing fairly large writes though, unless response compression is breaking them up?

Using Wireshark to capture the TCP traffic for HttpSys and Kestrel would be a good place to start. Then we can see how efficiently they're flushing to the network.

[udlose]

any update on this problem?

[Tratcher]

We've had few reports and are not currently investigating this. If you can provide additional details that would help us prioritize it.

Using Wireshark to capture the TCP traffic for HttpSys and Kestrel would be a good place to start. Then we can see how efficiently they're flushing to the network.

[dalir-bajelani]

16KB js file download take 25 seconds to response from server!

[ghost]

We've moved this issue to the Backlog milestone. This means that it is not going to be worked on for the coming release. We will reassess the backlog following the current release and consider this item at that time. To learn more about our issue management process and to have better expectation regarding different types of issues you can read our Triage Process.

[t-auer]

I have seen a similar behavior a few days ago on Windows Server. Serving Static files with multiple users became very slow. It seems to me that this is due to threadpool starvation (on .net FW 4.8). The number of used threads in the threadpool increased approximately by 1 per second with the server being idle, and after some time there were enough threads that the server started working again.

When using .net core 3.1 I found that requesting 12 static files shows about 70 items completed in ThreadPool when using no compression, but > 3.500 items completed when using compression.

[Tratcher]

Are any active threads blocked on sync IO? That's the usual cause of threadpool starvation.

[t-auer]

Threads blocked on I/O: not that I am aware of (I did not see anything in VS debugger) - I reduced my test program up to the point that it does nothing except starting http.Sys and providing static files (load is generated with VS load testing) - in addition it has a thread that writes available threads of the threadpool to the console every 5 seconds. The test pogram has NLog configured for Logging.

Maybe the following code segments are helpfull:

  private static IWebHost BuildWebHost(string serverUrl, string[] args) =>
            new WebHostBuilder()
            .ConfigureAppConfiguration((hostingContext, config) =>
            {
                config
                    .SetBasePath(Path.GetDirectoryName(Assembly.GetExecutingAssembly().Location))
                    .AddInMemoryCollection(new Dictionary<string, string>
                    {
                            { "WebConfig:JwtBearerIssuer", ConfigurationManager.AppSettings["jwtBearerIssuer"] },
                            { "WebConfig:JwtBearerIssuerKey", ConfigurationManager.AppSettings["jwtBearerIssuerKey"] }
                    })
                    .AddXmlFile("MyConfig.xml", false, false)
                    .AddCommandLine(args);
            })
         .ConfigureServices(services =>
         {
             services.AddHttpClient();
             services.AddResponseCompression();
             services.AddCors();
         })
         .ConfigureLogging((hostingContext, logging) =>
         {
             logging.ClearProviders();
         })
         .UseStartup<StartupFW>()
         .UseNLog()
         .UseContentRoot(Path.GetDirectoryName(Assembly.GetExecutingAssembly().Location))
         .UseWebRoot(Path.Combine(Path.GetDirectoryName(Assembly.GetExecutingAssembly().Location), "MyClientDir"))
         .UseUrls(serverUrl)
#if DEBUG
                .UseEnvironment("Development")
#endif
            .UseHttpSys(options =>
                {
                    options.Authentication.AllowAnonymous = true;
                    options.Authentication.Schemes =
                        Microsoft.AspNetCore.Server.HttpSys.AuthenticationSchemes.NTLM |
                        Microsoft.AspNetCore.Server.HttpSys.AuthenticationSchemes.Negotiate;
                    options.MaxRequestBodySize = null;
                })            
         .Build();

and:

       public void Configure(IApplicationBuilder app, IHostingEnvironment env)
        {
            if (env.IsDevelopment())
            {
                app.UseDeveloperExceptionPage();
            }

            app
                .UseCors()               
                .UseStatusCodePages()
                .UseFileServer()
                .UseResponseCompression() // COMMENTING THIS LINE ELIMINATES THE PERFORMANCE PROBLEM
                .UseAuthentication()
                .UseWebSockets(new WebSocketOptions
                {
                    KeepAliveInterval = TimeSpan.FromHours(24) 
                });

and:

            var config = new LoggingConfiguration();

            // targets
            // Console
            var consoleTarget = new ColoredConsoleTarget("console")
            {
                Layout = "${message}"
            };
            consoleTarget.RowHighlightingRules.Add(new ConsoleRowHighlightingRule
            {
                Condition = ConditionParser.ParseExpression("level == LogLevel.Error"),
                ForegroundColor = ConsoleOutputColor.Red
            });
            consoleTarget.RowHighlightingRules.Add(new ConsoleRowHighlightingRule
            {
                Condition = ConditionParser.ParseExpression("level == LogLevel.Warn"),
                ForegroundColor = ConsoleOutputColor.Yellow
            });
            config.AddTarget(consoleTarget);

            var generalFileTarget = new FileTarget("generalfile")
            {
                Layout = "${message}",
                FileName = "${var:logdir}TEST_LOG.txt",
                ArchiveDateFormat = "yyyyMMddHHmmss",
                ArchiveNumbering = ArchiveNumberingMode.DateAndSequence,
                CreateDirs = true,
                EnableArchiveFileCompression = true,
                KeepFileOpen = true,
                ConcurrentWrites = true,
                OpenFileCacheTimeout = 30
            };
            config.AddTarget(generalFileTarget);
            // rules            
            config.AddRuleForAllLevels(consoleTarget, "consolelogger", true);
            config.AddRuleForAllLevels(generalFileTarget, "generalfilelogger", true);
            config.AddRule(LogLevel.Info, LogLevel.Fatal, consoleTarget, "*");
            config.AddRule(LogLevel.Info, LogLevel.Fatal, generalFileTarget, "*");
            // variables
            config.Variables.Add("logdir", new SimpleLayout(""));
            LogManager.Configuration = config;

[Tratcher]

The next thing I wanted to try was counting the number and size of write operations with and without compression. My theory is that compression does a lot of small writes. This could be measured either with a wireshark trace looking at the http chunk sizes, or by wrapping the response body stream to add per write logs.

Want to give that a try?

[t-auer]

It took me some time to get back to this topic, but in the meantime I have tested using a wrapper on the response body stream: Without UseResponseCompression I do not see any write on the body stream, but with UseResponseCompression I see 3 writes when requesting a static file.

[Tratcher]

Thanks @t-auer.

Without UseResponseCompression I do not see any write on the body stream

Because the stream is bypassed for the SendFileAsync API. The data gets sent as a single write.

but with UseResponseCompression I see 3 writes when requesting a static file.

That's not as noisy as I was expecting. How big is each write? And how big is the total file before and after compression?

A few other things that might make this combination slower:

• Chunked is used instead of Content-Length, and the chunk terminator isn't sent until the end of the app pipeline so anything that delays pipeline cleanup could affect it.
• Compression similarly needs to flush some data as the middleware pipeline unwinds.

There's not much you can do about either of those, they're part of the basic design.

[t-auer]

Hello Tratcher,

thanks for your detailled explanation. but I still think that the design is not ok. I completely understand that compresssion takes some time and thus makes the server slower.

However, if there is load on the server, threadpool starvation occurs, and this should not happen and - in my opinion - this is a major design issue.

You should be able to reproduce this behaviour by creating a simple server and then putting load on it using VS Studio load testing.

[Tratcher]

Threadpool starvation? Load should not cause starvation, only blocking operations should do that. Do you see any stacks that indicate blocking operations?

[Tratcher]

FYI I do think there's room for improvement here since we don't see these perf issues with Kestrel (or at least not that anyone has complained about?).

[ghost]

Thanks for contacting us.
We're moving this issue to the Next sprint planning milestone for future evaluation / consideration. We will evaluate the request when we are planning the work for the next milestone. To learn more about what to expect next and how this issue will be handled you can read more about our triage process here.

[ghost]

We've moved this issue to the Backlog milestone. This means that it is not going to be worked on for the coming release. We will reassess the backlog following the current release and consider this item at that time. To learn more about our issue management process and to have better expectation regarding different types of issues you can read our Triage Process.

[adityamandaleeka]

Triage: we need a good test for this that shows the impact of the change.

[abatishchev]

+@avparuch who might be interested in perf improvements in https.sys

[LaurensVergote]

Crosspost from grpc/grpc-dotnet#1971:
A small project demonstrating this issue can be found here:
https://github.com/LaurensVergote/HttpSysLaggyPerformance

[adityamandaleeka]

This has now made it to 6.0 and 7.0 for June servicing (#48072 and #48073).

[mgravell]

This is merged for full release in net8