Block Detected in Web API while writing output

[spenceclark]

I have a pretty standard dotnet Web API which returns JSON. All standard framework stuff.

I am getting this in my logs everytime the size of the response goes above a certain level. For example I can call an API with parameters that causes it to return a few records and I don't get the message. But then the same API with parameters that cause it to return 50 records I get the warning - in fact this same warning is reported hundreds of times at once.

As the stack trace seems to be entirely inside the MVC framework code, it doesn't seem like I can do anything about it.

Has anyone else seen this? As it stands it is creating too much noise in the log to be able to identify real problems.

warn: Ben.Diagnostics.BlockingMonitor[6]
      Blocking method has been invoked and blocked, this can lead to threadpool starvation.
         at System.IO.FileStream.Write(Byte[] array, Int32 offset, Int32 count)
         at Microsoft.AspNetCore.WebUtilities.PagedByteBuffer.MoveTo(Stream stream)
         at Microsoft.AspNetCore.WebUtilities.FileBufferingWriteStream.Write(Byte[] buffer, Int32 offset, Int32 count)
         at Microsoft.AspNetCore.WebUtilities.HttpResponseStreamWriter.Write(Char value)
         at Newtonsoft.Json.JsonTextWriter.WritePropertyName(String name, Boolean escape)
         at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeObject(JsonWriter writer, Object value, JsonObjectContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
         at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeList(JsonWriter writer, IEnumerable values, JsonArrayContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
         at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeObject(JsonWriter writer, Object value, JsonObjectContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
         at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeList(JsonWriter writer, IEnumerable values, JsonArrayContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
         at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeObject(JsonWriter writer, Object value, JsonObjectContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
         at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.Serialize(JsonWriter jsonWriter, Object value, Type objectType)
         at Newtonsoft.Json.JsonSerializer.SerializeInternal(JsonWriter jsonWriter, Object value, Type objectType)
         at Microsoft.AspNetCore.Mvc.Formatters.NewtonsoftJsonOutputFormatter.WriteResponseBodyAsync(OutputFormatterWriteContext context, Encoding selectedEncoding)
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
         at Microsoft.AspNetCore.Mvc.Formatters.NewtonsoftJsonOutputFormatter.WriteResponseBodyAsync(OutputFormatterWriteContext context, Encoding selectedEncoding)
         at Microsoft.AspNetCore.Mvc.Formatters.TextOutputFormatter.WriteAsync(OutputFormatterWriteContext context)
         at Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor.ExecuteAsync(ActionContext context, ObjectResult result)
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeResultAsync>g__Logged|21_0(ResourceInvoker invoker, IActionResult result)
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeResultAsync>g__Logged|21_0(ResourceInvoker invoker, IActionResult result)
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.ResultNext[TFilter,TFilterAsync](State& next, Scope& scope, Object& state, Boolean& isCompleted)
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeNextResultFilterAsync[TFilter,TFilterAsync]()
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.ResultNext[TFilter,TFilterAsync](State& next, Scope& scope, Object& state, Boolean& isCompleted)
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeNextResultFilterAsync[TFilter,TFilterAsync]()
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeNextResultFilterAwaitedAsync[TFilter,TFilterAsync]()
         at Microsoft.AspNetCore.Mvc.Filters.ActionFilterAttribute.OnResultExecutionAsync(ResultExecutingContext context, ResultExecutionDelegate next)
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
         at Microsoft.AspNetCore.Mvc.Filters.ActionFilterAttribute.OnResultExecutionAsync(ResultExecutingContext context, ResultExecutionDelegate next)
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.ResultNext[TFilter,TFilterAsync](State& next, Scope& scope, Object& state, Boolean& isCompleted)
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeNextResultFilterAsync[TFilter,TFilterAsync]()
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.ResultNext[TFilter,TFilterAsync](State& next, Scope& scope, Object& state, Boolean& isCompleted)
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeResultFilters()
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next(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 System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
         at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.MoveNext(Thread threadPoolThread)
         at System.Runtime.CompilerServices.TaskAwaiter.<>c.<OutputWaitEtwEvents>b__12_0(Action innerContinuation, Task innerTask)
         at System.Threading.ExecutionContext.RunForThreadPoolUnsafe[TState](ExecutionContext executionContext, Action`1 callback, TState& state)
         at System.Threading.ThreadPoolWorkQueue.Dispatch()```

[spenceclark]

OK its seems to be specific to Newtonsoft - I switched my JSON serialisation from Newtonsoft to the new System.Text.Json implementation and I no longer get those warnings.

[spenceclark]

Hmmm, System.Text.Json has too many other shortcomings for me to migrate to it for now. Having to revert to Newtonsoft and live with the potential blocking.

Would be interested to hear if anyone else has this problem.

[spenceclark]

Ah - JamesNK/Newtonsoft.Json#1193 - Ben, it looks like you already raised the issue of async serialisation in Newtonsoft, and its never going to happen.

[spenceclark]

https://github.com/dotnet/aspnetcore/blob/v3.1.11/src/Mvc/Mvc.NewtonsoftJson/src/NewtonsoftJsonOutputFormatter.cs

This appears to be where it is happening inside MVC - Its strange, I have AllowSynchronousIO turned off so the framework should actually stop if it detects sync writes to output stream.

[webprofusion-chrisc]

Hi, I just found the exact same thing. Upgrading from .net core 3.1 to .net 5 seems to have fixed it(?)

[spenceclark]

Hi, I just found the exact same thing. Upgrading from .net core 3.1 to .net 5 seems to have fixed it(?)

Ah ok. Upgrade is on my roadmap soon at least. But did it fix it, or did it silently switch you from Newtonsoft to System.Text.Json?

[webprofusion-chrisc]

I don't think it can switch us automatically, we're using JsonConvert.SerializeObject. It also seemed to fixed an issue on linux where we were encountering 'thread exhaustion' when lots of people hit our API.

Excuse the code, it's 10 years old: https://github.com/openchargemap/ocm-system/blob/0a7a52d85e4671b42b0b5ed52cb958be3068ed51/API/OCM.Net/OCM.API.Web/Compatibility/OutputProviders/JSONOutputProvider.cs#L20