Inefficiency when reading large request bodies (e.g. uploads)

Consider an ASP.NET MVC action dealing with file uploads like below.

using var destination = new FileStream(path, FileMode.OpenOrCreate, FileAccess.Write, FileShare.None, 81920);
await Request.Body.CopyToAsync(destination, 81920);

The code above uses 80KB buffer for the reasons mentioned here https://github.com/dotnet/runtime/blob/release/5.0/src/libraries/System.Private.CoreLib/src/System/IO/Stream.cs#L33.

The code above will use about 3 or 4 times more CPU resources than the same code using .NET Framework System.Web. This is comparing CopyToAsync in .NET Core with CopyTo (synchronous) in .NET Framework. The async version used a lot of CPU in .NET Framework as well, but resorting to synchronous operations solved that with similar or better upload speeds. We can't (by default) use the synchronous version in .NET Core, though, and even when doing so by setting AllowSynchronousIO, it uses about the same amount of CPU resources as the async version.

I'm wondering if this might have to do with the pipe reader in .NET Core reading in 4KB chunks, compared to 16KB chunks in .NET Framework and System.Web.

I profiled the code while uploading a little more than half a GB of data. I can see that calls to FileStream.WriteCore indicate that the buffer size of 80KB is honored. I get around 6 500 writes (512MB / 80KB). The number of request body stream reads is a lot higher, though, and indicate a 4KB buffer limit causing overhead.

When running under IIS, the number of calls to Microsoft.AspNetCore.Server.IIS.NativeMethods.http_read_request_bytes is over 120 000 in my example and that is reflected in the number of thread-pool dispatch related calls.

I can reproduce the same issue with Kestrel, but with slightly different call stacks for reading the request body, of course. I haven't found a way of configuring the default buffer size of the pipe readers used.

Using FileOptions.Asynchronous when opening the file stream doesn't seem to make a lot of difference.

This issue could be related to dotnet/runtime#43480, although they are discussing general performance of pipes and in relation to writing the response.

Having spend a bunch of time with FileStream for writes (in the static files case), I can concur that some of the performance issue comes from the number of calls into FileStream.WriteAsync (there are some inefficiencies there) caused by the buffer size in Kestrel. Also as you identified, there's thread pool dispatch but I'm not sure how big of a problem that ends up being here (since data get coalesced, we don't dispatch per 4K chunk). The buffer size you pass in to CopyToAsync is ignored so it doesn't matter when you pass there Kestrel will copy it's internal 4K buffers into the target stream (FileStream in this case).

Have you tried writing a custom version of CopyToAsync that copies larger buffers? Basically copying into a bigger buffer (like 16K) and then doing bigger writes to the FileStream.

We should really get a benchmark for this. It's been too long 😄

PS: Async vs Sync here for writes won't matter unless the disk is hitting the queue length (or whatever backpressure mechanism you drive has). The difference shows up immediately on networked drives though so it does matter in lots of scenarios.

Thanks for your reply. Writing my own CopyTo method where I control the buffer size makes no difference, and I think this has to do with the fact that the size of my reads from the body stream doesn't affect the size of reads from the internal structure representing the request body. Profiling the code also indicates that there is a thread pool dispatch for every small read.

Here is a small repro that just reads the request body using an 80KB buffer:

using System;
using Microsoft.AspNetCore.Hosting;
using Microsoft.Extensions.Hosting;
using Microsoft.AspNetCore.Builder;

Host.CreateDefaultBuilder(args)
    .ConfigureWebHostDefaults(webBuilder => {
        webBuilder.Configure(app => {
            app.Use(async (context, next) => {

                var buffer = new byte[81920];
                while (await context.Request.Body.ReadAsync(new Memory<byte>(buffer)) > 0) { }
                await next();

            });
    })
    .ConfigureKestrel(options => options.Limits.MaxRequestBodySize = null);
})
.Build().Run();

Here is corresponding client code for sending a file:

using System.IO;
using System.Net.Http;

string url = args[0];
using var file = new FileStream(args[1], FileMode.Open, FileAccess.Read, FileShare.Read, 81920);

var request = new HttpRequestMessage(HttpMethod.Put, url) {
    Content = new StreamContent(file, 81920)
};
await new HttpClient().SendAsync(request);

Below is an excerpt of the profiling results from receiving 1.26 GB. I used 6.0.100-preview.3.21202.5. Note the number of dispatch calls.

73.19%   WorkerThreadStart  •  239,216* ms  •  16 calls  •  System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart
  ►67.44%   Wait  •  220,421* ms  •  316,232 calls  •  System.Threading.LowLevelLifoSemaphore.Wait(Int32, Boolean)
  5.60%   Dispatch  •  18,287 ms  •  314,186 calls  •  System.Threading.ThreadPoolWorkQueue.Dispatch
    ►2.77%   Execute  •  9,051 ms  •  4 calls  •  Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.IOQueue.Execute
    2.20%   MoveNext  •  7,188 ms  •  152,248 calls  •  System.Runtime.CompilerServices.AsyncTaskMethodBuilder+AsyncStateMachineBox`2.MoveNext(Thread)
      2.18%   RunFromThreadPoolDispatchLoop  •  7,141 ms  •  152,248 calls  •  System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(Thread, ExecutionContext, ContextCallback, Object)
        2.11%   MoveNext  •  6,896 ms  •  151,024 calls  •  Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody+<ReadAsyncInternal>d__9.MoveNext
          1.93%   SetResult  •  6,303 ms  •  151,024 calls  •  System.Runtime.CompilerServices.AsyncValueTaskMethodBuilder`1.SetResult(TResult)
            1.91%   TrySetResult  •  6,259 ms  •  151,024 calls  •  System.Threading.Tasks.Task`1.TrySetResult(TResult)
              1.88%   RunContinuations  •  6,154 ms  •  149,807 calls  •  System.Threading.Tasks.Task.RunContinuations(Object)
                1.85%   RunOrScheduleAction  •  6,037 ms  •  149,807 calls  •  System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(IAsyncStateMachineBox, Boolean)
                  1.80%   MoveNext  •  5,869 ms  •  149,772 calls  •  System.Runtime.CompilerServices.AsyncTaskMethodBuilder+AsyncStateMachineBox`2.MoveNext(Thread)
                    1.78%   RunInternal  •  5,825 ms  •  149,772 calls  •  System.Threading.ExecutionContext.RunInternal(ExecutionContext, ContextCallback, Object)
                      1.75%   MoveNext  •  5,735 ms  •  149,763 calls  •  Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream+<ReadAsyncInternal>d__29.MoveNext
                        1.45%   SetExistingTaskResult  •  4,737 ms  •  149,763 calls  •  System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.SetExistingTaskResult(Task, TResult)
                          1.44%   TrySetResult  •  4,700 ms  •  149,763 calls  •  System.Threading.Tasks.Task`1.TrySetResult(TResult)
                            1.41%   RunContinuations  •  4,615 ms  •  149,616 calls  •  System.Threading.Tasks.Task.RunContinuations(Object)
                              1.38%   RunOrScheduleAction  •  4,513 ms  •  149,616 calls  •  System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(IAsyncStateMachineBox, Boolean)
                                1.34%   MoveNext  •  4,381 ms  •  149,603 calls  •  System.Runtime.CompilerServices.AsyncTaskMethodBuilder+AsyncStateMachineBox`2.MoveNext(Thread)
                                  1.33%   RunInternal  •  4,343 ms  •  149,603 calls  •  System.Threading.ExecutionContext.RunInternal(ExecutionContext, ContextCallback, Object)
                                    1.31%   MoveNext  •  4,272 ms  •  149,596 calls  •  <Program>$+<>c+<<<Main>$>b__0_3>d.MoveNext
                                      ►1.07%   ReadAsync  •  3,484 ms  •  296,084 calls  •  Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.ReadAsync(Memory, CancellationToken)
                                      ►0.07%   AwaitUnsafeOnCompleted  •  240 ms  •  149,595 calls  •  System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AwaitUnsafeOnCompleted(ref TAwaiter, IAsyncStateMachineBox)
                                      ►0.03%   get_Body  •  99 ms  •  296,084 calls  •  Microsoft.AspNetCore.Http.DefaultHttpRequest.get_Body
                                      ►0.03%   GetStateMachineBox  •  89 ms  •  149,595 calls  •  System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.GetStateMachineBox(ref TStateMachine, ref Task)
                                      ►0.01%   SetExistingTaskResult  •  40 ms  •  1 call  •  System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.SetExistingTaskResult(Task, TResult)
                                       0.01%   IsInstanceOfClass  •  39 ms  •  299,295 calls  •  System.Runtime.CompilerServices.CastHelpers.IsInstanceOfClass(Void*, Object)
                                       0.01%   get_Request  •  36 ms  •  296,084 calls  •  Microsoft.AspNetCore.Http.DefaultHttpContext.get_Request
                                       0.01%   get_Body  •  35 ms  •  296,084 calls  •  Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.get_Body
                                       --- <cut> ---

Using synchronous reads with AllowSynchronousIO makes no difference. Neither does using the overload taking a byte array and a count.

Show me your implementation

The profiling results in my last comment are from the code I included there.

Here is the CopyTo implementation I mentioned. The version below is synchronous because I wanted to see if that changed the behavior.

var buffer = ArrayPool<byte>.Shared.Rent(81920);
try {
    int bytesRead;
    while ((bytesRead = Request.Body.Read(buffer.AsSpan())) != 0) {
        destination.Write(new ReadOnlySpan<byte>(buffer, 0, bytesRead));
    }
}
finally {
    ArrayPool<byte>.Shared.Return(buffer);
}

Synchronous IO from the ASP.NET Core side is MUCH worse, so definitely avoid that and it will make a difference even if you don't see it in your microbenchmark.

and I think this has to do with the fact that the size of my reads from the body stream doesn't affect the size of reads from the internal structure representing the request body

How many bytes are being read per call? Can you dump that out in your repro?

I assume this test is all on the local machine so everything is running as fast as possible?

Triage: We're planning on adding a benchmark to our perf infra for this scenario.

@avendel

I'll let @avendel answer about the repro details when he checks back since I haven't been directly involved, but I just want to add for clarity for the triage and benchmarking, that we first saw roughly a doubling of CPU usage on the reading side during performance testing on a proper multiserver setup with uploads and file system writes over the network. We were still fully async and hosting .NET Core 3.1 in-process IIS. After much head scratching small buffer IO with lots of context switching was basically where we was left standing.

So the synchronous stuff is just from further testing after the fact, and it can seemingly be reproduced across different hosting implementations and framework versions. Our expectation is that we'll find that the reads are 4096 bytes since that seems to align well with the IO implementation details of IISHttpContext and the corresponding Kestrel parts. But we may certainly be overlooking something.

I assume this is all on windows and it seems like you're measuring IIS not Kestrel?

Thanks for your reply. Writing my own CopyTo method where I control the buffer size makes no difference, and I think this has to do with the fact that the size of my reads from the body stream doesn't affect the size of reads from the internal structure representing the request body. Profiling the code also indicates that there is a thread pool dispatch for every small read.

I just wrote a sample (using Kestrel) and I got 81K reads (localhost), so it should definitely be faster than using CopyToAsync. I think it's important to understand the difference between the cost of the reads VS writes because they differ massively in both cases.

The cost of reads at the transport layer
- In Kestrel this maps the socket transport and the implementation of sockets in .NET
- In IIS this maps to the p-invokes into our IIS native module
- The buffer size is typically 4K here and we thread pool dispatch so we can continue reading while the application is also reading. This is why the application can see bigger than 4K chunks at a time.
The cost of reads at the application layer.
- How big are the chunks we get at the application layer?
The costs of the operation that happens after the read is completed (in this case, writing to the file stream)
- How much overhead is there per operation? The bigger the buffer the less times this operation happens. That's directly affected in this case by the size of the read at the application layer.

The cost includes CPU time and latency of the overall operation and they are affected by each of these discrete operations. As part of this investigation we'll want to narrow down and zoom in on exactly what we're trying to improve here. My assumption here is overall latency of the operation is what's most important, that is, how fast can we achieve a large file upload.

Doing some testing with IIS, I can confirm that the same technique doesn't seem to work as well but it does work with kestrel. I think that confirms the issue above. The slowness likely comes from the number of write operations due to the small size of the read operations. Using a bigger buffer does help a little bit as I get reads that vary between 4K and 64K but the batching isn't as effective as it is in the Kestrel case.

Kestrel's buffer slack on the transport size is 1MB (the amount it writes before pausing), and is configurable globally on the transport side. This setting in IIS is 64K and isn't configurable. Making that setting 1MB in IIS speeds up the overall upload by 50% on my machine.

I can also reproduce the thread pool dispatching and confirm that we're doing 1 per 4K read at the transport layer, but less at the application layer (as those 4K reads end up batched at the application).

I'll post more details later.

We had a custom WebHostBufferPolicySelector to avoid buffering large requests.

Can you share this?

Can you share this?

It was basically a variant of the idea from section 3 at https://www.strathweb.com/2012/09/dealing-with-large-files-in-asp-net-web-api/, but with slightly different criteria for choosing when to buffer. But I can assure that it didn't buffer the entire request content.

I'm just trying to remember what that code did https://github.com/aspnet/AspNetWebStack/blob/42991b3d2537b702736463f76a10a4fcf2ea44c9/src/System.Web.Http.WebHost/HttpControllerHandler.cs#L296

This is the relevant parts of the subtree of CopyTo from a profiling of uploading 1.27GB in three requests on IIS on .NET Framework:

92.56%   InternalCopyTo  •  4,354 ms  •  3 calls  •  System.IO.Stream.InternalCopyTo(Stream, Int32)
  73.93%   Read  •  3,477 ms  •  16,655 calls  •  System.Web.HttpBufferlessInputStream.Read(Byte[], Int32, Int32)
    72.45%   ReadEntityCoreSync  •  3,408 ms  •  83,245 calls  •  System.Web.Hosting.IIS7WorkerRequest.ReadEntityCoreSync(Byte[], Int32, Int32)
       69.79%   MgdReadEntityBody  •  3,283 ms  •  83,245 calls  •  System.Web.Hosting.UnsafeIISMethods.MgdReadEntityBody(IntPtr, Byte[], Int32, Int32, Boolean, out Int32, out IntPtr)
     0.11%   ReadEntityBody  •  5 ms  •  83,245 calls  •  System.Web.Hosting.IIS7WorkerRequest.ReadEntityBody(Byte[], Int32, Int32)
    ►0.02%   GetPreloadedContent  •  1 ms  •  16,655 calls  •  System.Web.HttpBufferlessInputStream.GetPreloadedContent(Byte[], ref Int32, ref Int32)
  18.25%   WriteCore  •  858 ms  •  16,649 calls  •  System.IO.FileStream.WriteCore(Byte[], Int32, Int32)

So the managed code seems to call into IIS and get 16KB per read (1.27GB / 83,245).

This is the subtree of ReadAsStreamAsync

0.01%   ReadAsStreamAsync  •  1 ms  •  3 calls  •  System.Net.Http.HttpContent.ReadAsStreamAsync
  0.01%   CreateContentReadStreamAsync  •  1 ms  •  3 calls  •  System.Web.Http.WebHost.HttpControllerHandler+LazyStreamContent.CreateContentReadStreamAsync
    0.01%   get_StreamContent  •  1 ms  •  3 calls  •  System.Web.Http.WebHost.HttpControllerHandler+LazyStreamContent.get_StreamContent
      ►0.00%   StreamContent..ctor  •  0 ms  •  3 calls  •  System.Net.Http.StreamContent..ctor(Stream, Int32)
      0.00%   GetBufferlessInputStream  •  0 ms  •  3 calls  •  System.Web.HttpRequestWrapper.GetBufferlessInputStream
        0.00%   GetInputStream  •  0 ms  •  3 calls  •  System.Web.HttpRequest.GetInputStream(Boolean, Boolean)
          ►0.00%   HttpBufferlessInputStream..ctor  •  0 ms  •  3 calls  •  System.Web.HttpBufferlessInputStream..ctor(HttpContext, Boolean, Boolean)
          ►0.00%   EnsureHasNotTransitionedToWebSocket  •  0 ms  •  3 calls  •  System.Web.HttpRequest.EnsureHasNotTransitionedToWebSocket
      ►0.00%   <GetStreamContent>b__1  •  0 ms  •  3 calls  •  System.Web.Http.WebHost.HttpControllerHandler+<>c__DisplayClass18_0.<GetStreamContent>b__1
    ►0.00%   CreateContentReadStreamAsync  •  0 ms  •  3 calls  •  System.Net.Http.StreamContent.CreateContentReadStreamAsync

But as you mentioned before, the behavior of FileStream is of course also relevant. I noticed e.g. dotnet/runtime#25905 which might affect upload speeds when creating the file stream for async IO.

Any updates on that? Workaround maybe?

This issue is still present on .NET 7, when reading data from the HttpRequestStream the read times are very high.

Doing the opposite, by returning a stream via Results.Stream, the read times are normal.

@arielmoraes

@arielmoraes do you have a detailed analysis like @avendel did? What are you measuring and can you provide us with a sample?

Very high CPU (100% all time of copy) usage when I use CopyToAsync of a request body to a FileStream (very slow too) but when I use CopyTo, it's very quick and CPU is not impacted.
In .Net 7 Web API.
Don't know if it's related.

@Safirion

@Safirion do you have a sample and instructions on how to reproduce it?

I am currently profiling issue why asp is spending ~1000ms of time before hitting controller method when larger payload is used (~10MB). This is API endpoint that accept JSON with base64 encoded data. I was able to fix/workaround this issue by switching type declared for API model from byte byte[] to Memory<byte>.

Reproducer:
Using asp net 8.0 and WebApi controller POST method accepting these types.

SLOW (~1000ms)

public class InputRequestByteArray
{
    public byte[] ImgData { get; set; }
}

FAST (~50ms)

public class InputRequestMemory
{
    public Memory<byte> ImgData { get; set; }
}

I tried to so some profiling and when using InputRequestByteArray -> 97% of time was spent in System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart.

Is this expected behavior ? Because to me it seems like a 🐛
Thanks.

Navigation Menu

Repository navigation

Inefficiency when reading large request bodies (e.g. uploads) #32467

4 remaining items

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Inefficiency when reading large request bodies (e.g. uploads) #32467

Description

Activity

davidfowl commented on May 6, 2021

avendel commented on May 7, 2021

davidfowl commented on May 7, 2021

avendel commented on May 7, 2021

davidfowl commented on May 7, 2021

BrennanConroy commented on May 7, 2021

ow-- commented on May 7, 2021

davidfowl commented on May 8, 2021

davidfowl commented on May 8, 2021

4 remaining items

davidfowl commented on May 11, 2021

avendel commented on May 11, 2021

davidfowl commented on May 11, 2021

avendel commented on May 11, 2021

tshcherban commented on Jul 19, 2022

arielmoraes commented on Dec 8, 2022

davidfowl commented on Dec 12, 2022

Safirion commented on Jan 8, 2023

davidfowl commented on Jan 8, 2023

Temppus commented on Feb 7, 2025

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions