Random model validation errors occur during POST request when Request.ContentLength exceeds 4096.

[RomanTymchyshyn]

I get the following error, when executing my POST request:

{
  "errors": {
    "string[216]": [
      "Unexpected character encountered while parsing value: S. Path 'string[216]', line 1, position 3808."
    ],
    "string[216].string": [
      "The input was not valid."
    ]
  },
  "type": "https://tools.ietf.org/html/rfc7231#section-6.5.1",
  "title": "One or more validation errors occurred.",
  "status": 400,
  "traceId": "00-a8a345166aff6f41a0b3b59526a20044-12f52af2db5e0748-00"
}

Sometimes error looks like this (request is similar, it just has more or fewer strings in it). See the request below.

{
  "errors": {
    "strings[216]": [
      "The input was not valid.",
      "Unexpected character encountered while parsing value: S. Path 'strings[216]', line 1, position 3810.",
      "Unexpected character encountered while parsing value: o. Path 'strings[216]', line 1, position 3810."
    ],
    "strings[216].strings": [
      "Infinite loop detected from error handling. Path 'strings[216]', line 1, position 3810."
    ]
  },
  "type": "https://tools.ietf.org/html/rfc7231#section-6.5.1",
  "title": "One or more validation errors occurred.",
  "status": 400,
  "traceId": "00-d3e8019bfcf3fe4888488ab0438f3910-8626179ab7e6e94a-00"
}

I created the following sample controller and model to reproduce the issue:

[ApiController]
[Route("api/[controller]")]
public class TestController: ControllerBase
{
    [HttpPost("post")]
    public IActionResult Post(Model model)
    {
        return Ok();
    }
}

public class Model
{
    public string[] Strings { get; set; }
}

This is the request I use: https://jsonblob.com/faf7720e-0559-11ea-a4bb-cf0a978731bb
There is an array strings with 235 strings in it. The interesting part is that it works with 230 strings.
I noticed, that with 235 it exceeds 4096 ContentLength.
Do you have such limits anywhere?

However, if I do manual deserialization of request body it works fine:

[ApiController]
[Route("api/[controller]")]
public class TestController: ControllerBase
{
    [HttpPost("post")]
    public async Task<IActionResult> Post()
    {
        var model = await DeserializeInputStream<Model>(Request.Body);
        return Ok();
    }

    protected static async Task<T> DeserializeInputStream<T>(Stream body)
    {
        var jsonRequest = await new StreamReader(body).ReadToEndAsync();
        return JsonConvert.DeserializeObject<T>(jsonRequest);
    }
}

public class Model
{
    public string[] Strings { get; set; }
}

We use version 3.0.
Also, we use AddNewtonsoftJson and EnableBuffering.

[javiercn]

@RomanTymchyshyn thanks for contacting us.

@pranavkm Do you have any thoughts?

[pranavkm]

@RomanTymchyshyn could you share a minimal app that reproduces the issue? I tried recreating an app based on what you wrote and I did not see any the error. I do see these two errors crop up if I have malformed JSON input. For instance, if I post this payload (note the missing quotes around the second string):

{
  "strings": [
    "Some string 0",
    Some string 1
 ]
}

I get this:

{
"errors": {
"strings[0]": [
  "Unexpected character encountered while parsing value: S. Path 'strings[0]', line 4, position 5.",
  "Unexpected character encountered while parsing value: o. Path 'strings[0]', line 4, position 6.",
  "Unexpected character encountered while parsing value: m. Path 'strings[0]', line 4, position 6."
],
"strings[0].strings": [
  "Infinite loop detected from error handling. Path 'strings[0]', line 4, position 6."
],
},
"type": "https://tools.ietf.org/html/rfc7231#section-6.5.1",
"title": "One or more validation errors occurred.",
"status": 400,
"traceId": "|edf23a06-4c51e57cfd5cce01."
}

which looks pretty close to the error you posted.

FYI @JamesNK, here's the stack trace I get for the infinite loop detected error:

Newtonsoft.Json.JsonSerializationException
  HResult=0x80131500
  Message=Infinite loop detected from error handling. Path 'strings[0]', line 4, position 6.
  Source=Newtonsoft.Json
  StackTrace:
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.PopulateList(IList list, JsonReader reader, JsonArrayContract contract, JsonProperty containerProperty, String id)

  This exception was originally thrown at this call stack:
	Newtonsoft.Json.JsonTextReader.ReadStringValue(Newtonsoft.Json.ReadType)
	Newtonsoft.Json.JsonTextReader.ReadAsString()
	Newtonsoft.Json.JsonReader.ReadForType(Newtonsoft.Json.Serialization.JsonContract, bool)
	Newtonsoft.Json.Serialization.JsonSerializerInternalReader.PopulateList(System.Collections.IList, Newtonsoft.Json.JsonReader, Newtonsoft.Json.Serialization.JsonArrayContract, Newtonsoft.Json.Serialization.JsonProperty, string)

Inner Exception 1:
JsonReaderException: Unexpected character encountered while parsing value: o. Path 'strings[0]', line 4, position 6.

[RomanTymchyshyn]

@pranavkm, here is the app reproducing the issue.

It appears that this middleware is the cause of the issue.
It enables buffering, reads the body and resets it to the beginning.

Am I using it the way it's not supposed to be used?

The weird part is that in this small app I had to increase the request size to get it failing.
Even weirder part is that sometimes I get this error:

System.InvalidOperationException: Synchronous operations are disallowed. Call ReadAsync or set AllowSynchronousIO to true instead.
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.Read(Byte[] buffer, Int32 offset, Int32 count)
   at Microsoft.AspNetCore.WebUtilities.FileBufferingReadStream.Read(Byte[] buffer, Int32 offset, Int32 count)
   at Microsoft.AspNetCore.WebUtilities.HttpRequestStreamReader.ReadIntoBuffer()
   at Microsoft.AspNetCore.WebUtilities.HttpRequestStreamReader.Read(Char[] buffer, Int32 index, Int32 count)
   at Newtonsoft.Json.JsonTextReader.ReadData(Boolean append, Int32 charsRequired)
   at Newtonsoft.Json.JsonTextReader.ParseValue()
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.HandleError(JsonReader reader, Boolean readPastError, Int32 initialDepth)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.PopulateObject(Object newObject, JsonReader reader, JsonObjectContract contract, JsonProperty member, String id)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.CreateObject(JsonReader reader, Type objectType, JsonContract contract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerMember, Object existingValue)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.Deserialize(JsonReader reader, Type objectType, Boolean checkAdditionalContent)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Mvc.Formatters.NewtonsoftJsonInputFormatter.ReadRequestBodyAsync(InputFormatterContext context, Encoding encoding)
   at Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinder.BindModelAsync(ModelBindingContext bindingContext)
   at Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder.BindModelAsync(ActionContext actionContext, IModelBinder modelBinder, IValueProvider valueProvider, ParameterDescriptor parameter, ModelMetadata metadata, Object value)
   at Microsoft.AspNetCore.Mvc.Controllers.ControllerBinderDelegateProvider.<>c__DisplayClass0_0.<<CreateBinderDelegate>g__Bind|0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeInnerFilterAsync>g__Awaited|13_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeFilterPipelineAsync>g__Awaited|19_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Logged|17_1(ResourceInvoker invoker)
   at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)
   at ModelValidationErrorSample.Middleware.RequestResponseLoggingMiddleware.Invoke(HttpContext context) in C:\Users\romant\source\repos\ModelValidationErrorSample\Middleware\RequestResponseLoggingMiddleware.cs:line 33
   at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(HttpContext context)

And sometimes it even succeeds.
But in the larger app it fails 100% of the time with the request I provided in the description.
It looks like something is not awaited properly, but middleware seems to await every task.

Sorry in advance if it's my mistake.

[RomanTymchyshyn]

@pranavkm, I updated the provided sample to use factory activated IMiddleware and it still reproduces.
Now I'm really confused...

BTW, is there any difference in using Invoke/InvokeAsync methods when using conventional middleware?

[RomanTymchyshyn]

Ok, found the problem, next code in the middleware does not read the body to the end

var buffer = new byte[Convert.ToInt32(request.ContentLength)];
var read = await request.Body.ReadAsync(buffer, 0, buffer.Length);
var requestBody = Encoding.UTF8.GetString(buffer);

Returned number of bytes is less than the requested number of bytes (buffer.Length).
And if you try to read it again, you will succeed.

So I changed my code to this and now it works as expected:

var requestBody = await new StreamReader(request.Body).ReadToEndAsync();

However, from the documentation for ReadAsync method:

<returns>
A task that represents the asynchronous read operation.

The value of the <paramref name="TResult" /> parameter contains the total number of bytes read into the buffer.

The result value can be less than the number of bytes requested
if the number of bytes currently available is less than the requested number,
or it can be 0 (zero) if the end of the stream has been reached.
</returns>

Since I was able to read the stream to the end after first ReadAsync, it's clear that the number of bytes currently available was NOT less than the requested number (buffer.Length).

So, is it a bug in FileBufferingReadStream or is it incomplete documentation and ReadAsync can return number of bytes less than requested even if there are more bytes in the stream?

[javiercn]

So, is it a bug in FileBufferingReadStream or is it incomplete documentation and ReadAsync can return number of bytes less than requested even if there are more bytes in the stream?

I think the stream, being a network stream gets updated internally. Think of it this way, if it has 100 bytes in the buffer and you ask for 200, it will give you back 100 without waiting. If it doesn't have any bit available (or determines it would give you too few bytes, it will yield until it receives enough data and then give that back to you.

It can be that even in that case doesn't give you what you asked for. It's up to the stream implementation to decide how to do that.

Hope that helps.

[RomanTymchyshyn]

Ok, thanks! Sorry for wasting your time.