microsoft
System.InvalidOperationException: Reading is already in progress.
Hi, we have encountered below exception in our microservice serving as reverse proxy:
"MessageTemplate": "Connection id \"{ConnectionId}\", Request id \"{TraceIdentifier}\": An unhandled exception was thrown by the application.",
"RenderedMessage": "Connection id \"0HN7I0DFFRG93\", Request id \"0HN7I0DFFRG93:0000008C\": An unhandled exception was thrown by the application.",
"Exception": "Microsoft.AspNetCore.Connections.ConnectionAbortedException: The connection was aborted by the application.\n ---> System.InvalidOperationException: Reading is already in progress.\n at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1MessageBody.OnConsumeAsync()\n --- End of inner exception stack trace ---"
I have found several issues related to this topic:
- https://github.com/dotnet/aspnetcore/issues/33409
- https://github.com/microsoft/reverse-proxy/pull/1071
- https://github.com/dotnet/aspnetcore/issues/17840
The last one is suggesting that the reason may be invalid handling of reading request body. In our scenario there were no such operations (also buffering was not enabled). The only manipulation on body was as follows:
var originalBodyStream = context.Response.Body;
// Decorator counting bytes written to the stream
await using var monitoringStream = new Decorator(originalBodyStream);
try
{
context.Response.Body = monitoringStream;
await next(context);
await LogRequest();
}
catch (Exception)
{
// Error handling
}
finally
{
//Reassigning according to this advice: https://github.com/microsoft/reverse-proxy/issues/2385
context.Response.Body = originalBodyStream;
}
LogRequest is designed to log incoming request with optional logging of body. This option is however currently disabled. The only action taken is context.Response.Body = originalBodyStream;. What could be a cause of above exception and how could we prevent it?
We are currently using Yarp.ReverseProxy in 2.0.1 version (not updated because of https://github.com/microsoft/reverse-proxy/issues/2631).
What does the implementation of Decorator look like?
Are you able to create a minimal runnable repro sample?
internal class Decorator : Stream
{
private readonly Stream innerStream;
public long BytesWritten { get; private set; }
public override bool CanRead => false;
public override bool CanSeek => false;
public override bool CanWrite => innerStream.CanWrite;
public override long Length => innerStream.Length;
public override long Position { get => innerStream.Position; set => throw new NotSupportedException(); }
public Decorator(Stream innerStream) => this.innerStream = innerStream;
public override ValueTask WriteAsync(ReadOnlyMemory<byte> buffer, CancellationToken cancellationToken = default)
{
BytesWritten += buffer.Length;
return innerStream.WriteAsync(buffer, cancellationToken);
}
public override Task FlushAsync(CancellationToken cancellationToken) => innerStream.FlushAsync(cancellationToken);
public override void Flush() => throw new NotSupportedException();
public override void Write(byte[] buffer, int offset, int count) => throw new NotSupportedException();
public override Task WriteAsync(byte[] buffer, int offset, int count, CancellationToken cancellationToken) => throw new NotSupportedException();
public override int Read(byte[] buffer, int offset, int count) => throw new NotSupportedException();
public override Task<int> ReadAsync(byte[] buffer, int offset, int count, CancellationToken cancellationToken) => throw new NotSupportedException();
public override ValueTask<int> ReadAsync(Memory<byte> buffer, CancellationToken cancellationToken = default) => throw new NotSupportedException();
public override long Seek(long offset, SeekOrigin origin) => throw new NotSupportedException();
public override void SetLength(long value) => throw new NotSupportedException();
}
In case of reproduction, unfortunately I am not able to do it. This error occurs on once in a million requests (literally).
Are you able to collect the full stack trace for the exception (ex.ToString() in that catch block)?
That might give a hint for where things are going wrong.
I am not sure where to do it. This exception was thrown either before or after my pipeline, above middelware was mentioned only because it works with request body. Exception was not thrown there or in any of my middelwares (I assume that because there are no other logs that should be produced by my application in such case). Source context of that error is: "SourceContext": "Microsoft.AspNetCore.Server.Kestrel".
BTW ex.ToString() should produce more info that error logged with Serilog?
BTW ex.ToString() should produce more info that error logged with Serilog?
From the message you've shared it looked like it may have only been including the top-most exception information, but looking into https://github.com/dotnet/aspnetcore/issues/17840 more, that may just be all the info that's available at the time.
This sounds like a bug in ASP.NET Core, not much we can do about it in YARP. YARP itself isn't using the request body pipe directly, and from your description neither are you. It's possible this is just an error handling issue during cancellation.