AspNetCore Mvc Controller keeps serializing IAsyncEnumerable after connection is closed

[fkreis]

Describe the bug

In #32483 (see also) a breaking change regarding the processing of IAsyncEnumerable was announced. I wanted to test the new behavior using preview version 6.0.100-preview.6.21355.2.

Observed behavior

At first glance, it works as expected and data is returned to the client even before the processing is terminated. However, adding Console.WriteLine reveals that the ASP keeps iterating over IAsyncEnumerable for serialization even a long time after the client has closed the connection. This puts unnecessary load on the server because the result of that processing will never be fetched.

Expected behavior

After the client closed the connection the server should stop processing and hence stop iterating over IAsyncEnumerable

To Reproduce

Server

The server exposes an endpoint "Loop" which returns a list of 100000 ints. Each time a single int is fetched it will be logged in the console with a counter and the current timestamp.

using Microsoft.AspNetCore.Mvc;
using System.Collections.Generic;
using System;

namespace dot_net_api_streaming.Controllers
{
    [ApiController]
    [Route("[controller]")]
    public class LoopController : ControllerBase
    {

        [HttpGet]
        public IAsyncEnumerable<int> Get()
        {
            return GetInfiniteInts();
        }

        private async IAsyncEnumerable<int> GetInfiniteInts()
        {
            int index = 0;
            while (index <100000)
            {
                Console.WriteLine($"{DateTime.Now}: {index}");
                yield return index++;
            }            

        }
    }
}

Output

Please note that the server is processing for about a minute when this endpoint is called.

8/13/2021 11:51:18 AM: 1
8/13/2021 11:51:18 AM: 2
[...]
8/13/2021 11:52:19 AM: 99998
8/13/2021 11:52:19 AM: 99999

Client

The Python client calls the server's exposed "Loop" endpoint, but only fetches the first 100 bytes and closes the connection afterwards. The client code terminates after about 100-200ms.

import urllib.request
import time
import ssl

request_url = 'https://localhost:5001/Loop'
ctx = ssl.create_default_context()
ctx.check_hostname = False
ctx.verify_mode = ssl.CERT_NONE
print(f"Start request {request_url}")
start = time.time()
f = urllib.request.urlopen(request_url, context=ctx)
print(f.read(100).decode('utf-8'))
end = time.time()
print("Completed in {}s".format(round(end - start, 3)))

Output

Please not the the client closes the connection after less than a second while the server before was processing for about a minute.

Start request https://localhost:5001/Loop
[0,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25,26,27,28,29,30,31,32,33,34,35,3
Completed in 0.107s

Exceptions (if any)

There are no exceptions. The logs reveal the unexpected bahvior.

Further technical details

.NET SDK (reflecting any global.json):
Version: 6.0.100-preview.6.21355.2
Commit: 7f8e0d76c0

Runtime Environment:
OS Name: ubuntu
OS Version: 20.04
OS Platform: Linux
RID: ubuntu.20.04-x64
Base Path: /home/USER/.dotnet/sdk/6.0.100-preview.6.21355.2/

Host (useful for support):
Version: 6.0.0-preview.6.21352.12
Commit: 770d630b28

.NET SDKs installed:
5.0.205 [/home/USER/.dotnet/sdk]
6.0.100-preview.6.21355.2 [/home/USER/.dotnet/sdk]

.NET runtimes installed:
Microsoft.AspNetCore.App 5.0.8 [/home/USER/.dotnet/shared/Microsoft.AspNetCore.App]
Microsoft.AspNetCore.App 6.0.0-preview.6.21355.2 [/home/USER/.dotnet/shared/Microsoft.AspNetCore.App]
Microsoft.NETCore.App 5.0.8 [/home/USER/.dotnet/shared/Microsoft.NETCore.App]
Microsoft.NETCore.App 6.0.0-preview.6.21352.12 [/home/USER/.dotnet/shared/Microsoft.NETCore.App]

[Vake93]

The way to do this is to pass in the CancellationToken into GetInfiniteInts method and decorate it with EnumeratorCancellation attribute.

using System.Runtime.CompilerServices;

var builder = WebApplication.CreateBuilder(args);
var app = builder.Build();

app.MapGet("/", (CancellationToken cancellationToken) => GetNumbersAsync(cancellationToken));

app.Run();

static async IAsyncEnumerable<int> GetNumbersAsync([EnumeratorCancellation]CancellationToken cancellationToken)
{
    for (int i = 0; i < int.MaxValue; i++)
    {
        if (cancellationToken.IsCancellationRequested)
        {
            break;
        }

        await Task.Delay(TimeSpan.FromMilliseconds(100));
        Console.WriteLine($"{DateTime.Now}: {i}");

        yield return i;
    }
}

[davidfowl]

We should fix this by passing the RequestAborted token to the call to SerializeAsync

[pranavkm]

Response.WriteAsJsonAsync also do this by default - pass the RequestAborted token if there isn't one specified - https://github.com/dotnet/aspnetcore/blob/main/src/Http/Http.Extensions/src/HttpResponseJsonExtensions.cs#L33

[davidfowl]

Yep, we should fix it in both places.

[Vake93]

Passing the RequestAborted token to WriteAsJsonAsync ends up in an error for me when the request is cancelled:

var builder = WebApplication.CreateBuilder(args);
var app = builder.Build();

app.MapGet("/", (HttpResponse res, CancellationToken cancellationToken) => res.WriteAsJsonAsync(GetNumbersAsync(), cancellationToken)); ;

app.Run();

static async IAsyncEnumerable<int> GetNumbersAsync()
{
    for (int i = 0; i < int.MaxValue; i++)
    {
        await Task.Delay(TimeSpan.FromMilliseconds(100));
        Console.WriteLine($"{DateTime.Now}: {i}");

        yield return i;
    }
}

fail: Microsoft.AspNetCore.Server.Kestrel[13]
      Connection id "0HMAUEFGC8F2R", Request id "0HMAUEFGC8F2R:00000002": An unhandled exception was thrown by the application.
      System.NotSupportedException: Specified method is not supported.
         at <Program>$.<<<Main>$>g__GetNumbersAsync|0_1>d.System.IAsyncDisposable.DisposeAsync() in Experiments.dll:token 0x6000015+0xe
         at System.Text.Json.WriteStack.<DisposePendingDisposablesOnExceptionAsync>g__DisposeFrame|19_0(IEnumerator collectionEnumerator, IAsyncDisposable asyncDisposable, Exception exception) in System.Text.Json.dll:token 0x6000458+0x2c
         at System.Text.Json.WriteStack.DisposePendingDisposablesOnExceptionAsync() in System.Text.Json.dll:token 0x6000455+0x19b
         at System.Text.Json.JsonSerializer.WriteAsyncCore[TValue](Stream utf8Json, TValue value, JsonTypeInfo jsonTypeInfo, CancellationToken cancellationToken) in System.Text.Json.dll:token 0x60003d4+0x36c
         at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger) in Microsoft.AspNetCore.Routing.dll:token 0x60000ab+0x5e
         at Microsoft.WebTools.BrowserLink.Net.BrowserLinkMiddleware.ExecuteWithFilterAsync(IHttpSocketAdapter injectScriptSocket, String requestId, HttpContext httpContext) in Microsoft.WebTools.BrowserLink.Net.dll:token 0x600000c+0x159
         at Microsoft.AspNetCore.Watch.BrowserRefresh.BrowserRefreshMiddleware.InvokeAsync(HttpContext context) in Microsoft.AspNetCore.Watch.BrowserRefresh.dll:token 0x6000016+0xd7
         at Microsoft.AspNetCore.Builder.Extensions.MapMiddleware.Invoke(HttpContext context) in Microsoft.AspNetCore.Http.Abstractions.dll:token 0x600008b+0x1ec
         at Microsoft.AspNetCore.Builder.Extensions.MapMiddleware.Invoke(HttpContext context) in Microsoft.AspNetCore.Http.Abstractions.dll:token 0x600008b+0x1ec
         at Microsoft.AspNetCore.Builder.Extensions.MapMiddleware.Invoke(HttpContext context) in Microsoft.AspNetCore.Http.Abstractions.dll:token 0x600008b+0x1ec
         at Microsoft.AspNetCore.Builder.Extensions.MapMiddleware.Invoke(HttpContext context) in Microsoft.AspNetCore.Http.Abstractions.dll:token 0x600008b+0x1ec
         at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application) in Microsoft.AspNetCore.Server.Kestrel.Core.dll:token 0x6000ac9+0x1b8

[davidfowl]

Here's the pattern we use for sending files

aspnetcore/src/Http/Http.Extensions/src/SendFileResponseExtensions.cs

Lines 142 to 153 in ff51fd7

	private static async Task SendFileAsyncCore(HttpResponse response, string fileName, long offset, long? count, CancellationToken cancellationToken = default)
	{
	var useRequestAborted = !cancellationToken.CanBeCanceled;
	var localCancel = useRequestAborted ? response.HttpContext.RequestAborted : cancellationToken;
	var sendFile = response.HttpContext.Features.Get<IHttpResponseBodyFeature>()!;
	try
	{
	await sendFile.SendFileAsync(fileName, offset, count, localCancel);
	}
	catch (OperationCanceledException) when (useRequestAborted) { }
	}

. Same technique applies here.

[Vake93]

Here's the pattern we use for sending files

aspnetcore/src/Http/Http.Extensions/src/SendFileResponseExtensions.cs

Lines 142 to 153 in ff51fd7

	private static async Task SendFileAsyncCore(HttpResponse response, string fileName, long offset, long? count, CancellationToken cancellationToken = default)
	{
	var useRequestAborted = !cancellationToken.CanBeCanceled;
	var localCancel = useRequestAborted ? response.HttpContext.RequestAborted : cancellationToken;
	var sendFile = response.HttpContext.Features.Get<IHttpResponseBodyFeature>()!;
	try
	{
	await sendFile.SendFileAsync(fileName, offset, count, localCancel);
	}
	catch (OperationCanceledException) when (useRequestAborted) { }
	}

. Same technique applies here.

So a empty catch block? 😊
The exception here isn't due to the task cancellation right?

[davidfowl]

The exception is only caught if it's an implicit cancellation, that is, if the token you passed in isn't the one that fired.

[Vake93]

Ah... Got it; if you pass the CancellationToken you need to handle the OperationCanceledException, else this (framework) handles it.
But still, my question is the above threw a System.NotSupportedException, not a OperationCanceledException.

[davidfowl]

I have no idea why that is, it looks like a bug...

cc @steveharter @eiriktsarpalis @layomia

[eiriktsarpalis]

Related to dotnet/runtime#51176 (comment). Compiler-generated async enumerators will throw NotSupportedException if an attempt is made to dispose them while a MoveNextAsync() task is pending completion. It would seem like STJ is doing this when serialization is cancelled due to a cancellation token firing. It's a bug and we need to fix it.

[fkreis]

Thanks everyone for looking into this!
I am looking forward to further updates 🙂