aspnetcore: Request not being aborted after closing the connection is causing high CPU
Is there an existing issue for this?
- I have searched the existing issues
Describe the bug
We experience an issue with unresponsiveness of RavenDB server (https://github.com/ravendb/ravendb) after a set of certain operations is cancelled. The operations in question are the streaming of query results (https://ravendb.net/docs/article-page/5.4/csharp/client-api/session/querying/how-to-stream-query-results).
The client application is creating 100 tasks and each of them is getting 2M records from a database. Under the covers each creates an HTTP request. The server handles the requests in a streaming manner and writes the results to HttpContext.Response.
The relevant server side code is here: https://github.com/ravendb/ravendb/blob/917bbe60b099cd710de1f04cd27be8442251f790/src/Raven.Server/Documents/Handlers/Streaming/StreamingHandler.cs#L227-L267
Kestrel configuration: https://github.com/ravendb/ravendb/blob/917bbe60b099cd710de1f04cd27be8442251f790/src/Raven.Server/RavenServer.cs#L185
When the streaming queries are handled have the following utilization:
- ~100 of connections (“18384” is pid of Raven.Server process):
C:\Users\arek>netstat -ano | find /c "18384"
112
- The CPU is 20% - 60% on my end (it’s 12-core machine, 32GB of memory)
- It’s ~9GB of managed memory
ravendb> stats
Showing stats, press any key to close...
working set | native mem | managed mem | mmap size
* 10.57 GBytes | 29 MBytes | 9.29 GBytes | 4.54 GBytes
The issue
The issue is happening once the client app is closed, Then we have very high CPU and memory usage is increasing. The server becomes unresponsive. After attaching the debugger we can see that the query results are still being written to the response (the underling stream is Microsoft.AspNetCore.ResponseCompression.ResponseCompressionBody) and all operations continue as usual. We have a cancellation token hooked up to HttpContext.RequestAborted but it’s not cancelled:
https://github.com/ravendb/ravendb/blob/917bbe60b099cd710de1f04cd27be8442251f790/src/Raven.Server/Documents/DatabaseRequestHandler.cs#L140
- The number of connections drops immediately:
C:\Users\arek>netstat -ano | find /c "18384"
12
- CPU usage is over 90%
- The process started to consume additional 2GB of managed memory
ravendb> stats
Showing stats, press any key to close...
working set | native mem | managed mem | mmap size
* 12.64 GBytes | 28.29 MBytes | 11.45 GBytes | 4.54 GBytes
After some time (once all streaming operations completes I believe) the CPU get back to normal.
Expected Behavior
- The cancellation token
HttpContext.RequestAbortedshould be cancelled if the underlying connection no longer exists - We expected to get some error on attempt to flush (we use default
KestrelServerOptions.Limits.MaxResponseBufferSizewhich is 64KB) so we would stop the operation. Instead it appears to write to the memory so fast that it causes very high CPU usage.
Steps To Reproduce
-
checkout branch https://github.com/arekpalinski/ravendb/tree/streaming-issue
-
start
Raven.Serverproject -
create a database named
test -
go to the database and import below .ravendump file (https://ravendb.net/docs/article-page/5.4/csharp/studio/database/tasks/import-data/import-data-file):
-
run project
Tryoutswhich will create the actual requests -
stop it by pressing
q
We have reproduce it locally on Win11. But the same was experienced on WinServer2022 and Ubuntu 22.04.
Exceptions (if any)
No response
.NET Version
7.0.14
Anything else?
No response
About this issue
- Original URL
- State: open
- Created 7 months ago
- Comments: 17 (10 by maintainers)
It doesn’t reproduce the same log commands as the example above, but if you have high CPU usage, the tasks are still running even if Netstats shows that sockets are closed. If you comment out the
CpuUsagefrom theStreamingControllerand useThread.Sleep, tasks should end pretty soon.Repro can be found here: https://github.com/maciejaszyk/ravendb/tree/KestrelReproduction/Reproduction
The same is experienced on .net 8.0:
We can even see with the usage of
netstatthat there is no connection for the port57886:Below is a sample stacktrace which shows that the query streaming operation is continuing its execution at the time when the connection no longer exists:
Then we can chek in the debugger that the underlying HTTP context’s
RequestAbortedtoken doesn’t indicate the cancellation:This is the first time we noticed an issue like that. I don’t know if this is new dotnet 7.0 behavior.