Web API XML POST requests working in 2.1 but not in 3.1

[cmhernandezdel]

Describe the bug

Web API POST requests sending a XML file over HTTP are working in ASP Net Core 2.1 project, but not in ASP Net Core 3.1 project with the same code, with the latter throwing a Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: "Unexpected end of request content."

To Reproduce

This is happening with Hikvision security cameras, so I am not sure about the source, but it should be reproducible with any application that sends "application/xml" bodies over HTTP.

1. Download the source code at https://github.com/cmhernandezdel/TestEndpointSafire
2. Run the TestEndpointAspNetCore2 project.
3. Post a XML (application/xml content type) file to http://:7050. It is encouraged to POST from another origin, since this is how the bug happened in the first place (I cannot reproduce it with Postman).
4. You should see an output that looks similar to this in console:

<?xml version="1.0" encoding="UTF-8"?>
<EventNotificationAlert version="1.0" xmlns="urn:psialliance-org">
<protocolType>HTTP</protocolType>
<channelID>1</channelID>
<dateTime>2020-07-31T10:29:38+01:00</dateTime>
<activePostCount>1</activePostCount>
<eventType>PeopleCounting</eventType>
<eventState>active</eventState>
<eventDescription>peopleCounting alarm</eventDescription>
<channelName>Camera 01</channelName>
<peopleCounting>
<statisticalMethods>realTime</statisticalMethods>
<RealTime>
<time>2020-07-31T10:29:38+01:00</time>
</RealTime>
<enter>1365</enter>
<exit>1329</exit>
<regionsID>1</regionsID>
</peopleCounting>
<childCounting>
<enter>798</enter>
<exit>791</exit>
</childCounting>
</EventNotificationAlert>

5. Kill the TestEndpointAspNetCore2 project.
6. Run the TestEndpointAspNetCore3 project.
7. Post a XML (application/xml content type) file to http://:7050. It is encouraged to POST from another origin, since this is how the bug happened in the first place (I cannot reproduce it with Postman).
8. You should see an exception, with an output that looks similar to this in console:

fail: Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware[1]
      An unhandled exception has occurred while executing the request.
Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content.                       at Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException.Throw(RequestRejectionReason reason)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody.ReadAsyncInternal(CancellationToken cancellationToken)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.ReadAsyncInternal(Memory`1 buffer, CancellationToken cancellationToken)
   at System.IO.StreamReader.ReadBufferAsync(CancellationToken cancellationToken)                                          at System.IO.StreamReader.ReadToEndAsyncInternal()
   at TestEndpointAspNetCore3.Controllers.SafireController.PostSafire() in C:\Users\chernandez\Desktop\TestEndpointAspNetCore3\TestEndpointAspNetCore3\Controllers\SafireController.cs:line 21
   at lambda_method(Closure , Object )
   at Microsoft.Extensions.Internal.ObjectMethodExecutorAwaitable.Awaiter.GetResult()                                      at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.AwaitableResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeActionMethodAsync>g__Awaited|12_0(ControllerActionInvoker invoker, ValueTask`1 actionResultValueTask)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeNextActionFilterAsync>g__Awaited|10_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeInnerFilterAsync()
--- End of stack trace from previous location where exception was thrown ---
   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__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope)
   at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)
   at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(HttpContext context)

Exceptions (if any)

Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content.

Further technical details

• This is happening in ASP Net Core 3.1.
• The error was found in Visual Studio Community 2019, version 16.4.5, in Windows 10.

[Tratcher]

Note in your 2.x code CORS isn't run for the API request because it's placed after UseMvc. Try reversing that.

Also, I suggest capturing debug level logs for both apps.

[cmhernandezdel]

Thanks for your quick response.

It is working either way in 2.x code. The problem is with 3.x code.

I've set debug level logging for the 3.x app, according to the docs, but I see exactly the same in console. When a request is received, a BadHttpRequestException is thrown with the message "Unexpected end of request content".

Updated code is in the repo I linked in the OP.

[Tratcher]

This is the line that you should change to Debug:
"Microsoft": "Information"
https://github.com/cmhernandezdel/TestEndpointSafire/blob/e3c95355cc74621d4c892213c9655db810394df8/TestEndpointAspNetCore3/TestEndpointAspNetCore3/appsettings.Development.json#L5

[cmhernandezdel]

Thanks for pointing me in the right direction, I completely overlooked that.

Here are some logs for a few requests:

dbug: Microsoft.Extensions.Hosting.Internal.Host[1]
      Hosting starting
dbug: Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer[2]
      Failed to locate the development https certificate at '(null)'.
info: Microsoft.Hosting.Lifetime[0]
      Now listening on: http://[::]:7050
dbug: Microsoft.AspNetCore.Hosting.Diagnostics[0]
      Loaded hosting startup assembly TestEndpointAspNetCore3
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Development
info: Microsoft.Hosting.Lifetime[0]
      Content root path: C:\Users\chernandez\Desktop\TestEndpointSafire\TestEndpointAspNetCore3\TestEndpointAspNetCore3
dbug: Microsoft.Extensions.Hosting.Internal.Host[2]
      Hosting started
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM1OBCCL41ML" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM1OBCCL41ML" started.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM1OBCCL41MM" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM1OBCCL41ML" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM1OBCCL41MM" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM1OBCCL41MM" started.
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM1OBCCL41ML" disconnecting.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM1OBCCL41MM" sending FIN because: "The client closed the connection."
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM1OBCCL41ML" sending FIN because: "The client closed the connection."
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM1OBCCL41MM" disconnecting.
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM1OBCCL41ML" stopped.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 POST http://172.16.10.105/api/testsafire application/xml; charset="UTF-8" 875
dbug: Microsoft.AspNetCore.HostFiltering.HostFilteringMiddleware[0]
      Wildcard detected, all requests with hosts will be allowed.
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/api/testsafire'
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)' with route pattern 'api/testsafire' is valid for the request path '/api/testsafire'
dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)'
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)'
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ModelBinderFactory[12]
      Registered model binder providers, in the following order: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BinderTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ServicesModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.HeaderModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.FloatingPointTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.EnumTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.CancellationTokenModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ByteArrayModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.FormFileModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.FormCollectionModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.KeyValuePairModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.DictionaryModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ArrayModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.CollectionModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ComplexTypeModelBinderProvider
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "PostSafire", controller = "Safire"}. Executing controller action with signature System.Threading.Tasks.Task PostSafire() on controller TestEndpointAspNetCore3.Controllers.SafireController (TestEndpointAspNetCore3).
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of authorization filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of resource filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of action filters (in the following order): Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000), Microsoft.AspNetCore.Mvc.Infrastructure.ModelStateInvalidFilter (Order: -2000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of exception filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of result filters (in the following order): Microsoft.AspNetCore.Mvc.Infrastructure.ClientErrorResultFilter (Order: -2000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Executing controller factory for controller TestEndpointAspNetCore3.Controllers.SafireController (TestEndpointAspNetCore3)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed controller factory for controller TestEndpointAspNetCore3.Controllers.SafireController (TestEndpointAspNetCore3)
dbug: Microsoft.AspNetCore.Server.Kestrel[25]
      Connection id "0HM1OBCCL41MM", Request id "0HM1OBCCL41MM:00000001": started reading request body.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3) in 317.6723ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)'
fail: Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware[1]
      An unhandled exception has occurred while executing the request.
Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content.
   at Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException.Throw(RequestRejectionReason reason)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody.ReadAsyncInternal(CancellationToken cancellationToken)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.ReadAsyncInternal(Memory`1 buffer, CancellationToken cancellationToken)
   at System.IO.StreamReader.ReadBufferAsync(CancellationToken cancellationToken)
   at System.IO.StreamReader.ReadToEndAsyncInternal()
   at TestEndpointAspNetCore3.Controllers.SafireController.PostSafire() in C:\Users\chernandez\Desktop\TestEndpointSafire\TestEndpointAspNetCore3\TestEndpointAspNetCore3\Controllers\SafireController.cs:line 21
   at lambda_method(Closure , Object )
   at Microsoft.Extensions.Internal.ObjectMethodExecutorAwaitable.Awaiter.GetResult()
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.AwaitableResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeActionMethodAsync>g__Awaited|12_0(ControllerActionInvoker invoker, ValueTask`1 actionResultValueTask)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeNextActionFilterAsync>g__Awaited|10_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeInnerFilterAsync()
--- End of stack trace from previous location where exception was thrown ---
   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 Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(HttpContext context)
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 560.893ms 500 text/plain
dbug: Microsoft.AspNetCore.Server.Kestrel[26]
      Connection id "0HM1OBCCL41MM", Request id "0HM1OBCCL41MM:00000001": done reading request body.
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM1OBCCL41MM" stopped.
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM1OBCCL41MN" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM1OBCCL41MN" started.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM1OBCCL41MN" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM1OBCCL41MO" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM1OBCCL41MN" sending FIN because: "The client closed the connection."
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM1OBCCL41MN" disconnecting.
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM1OBCCL41MN" stopped.
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM1OBCCL41MO" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM1OBCCL41MO" started.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM1OBCCL41MO" sending FIN because: "The client closed the connection."
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM1OBCCL41MO" disconnecting.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 POST http://172.16.10.105/api/testsafire application/xml; charset="UTF-8" 828
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/api/testsafire'
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)' with route pattern 'api/testsafire' is valid for the request path '/api/testsafire'
dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)'
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)'
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "PostSafire", controller = "Safire"}. Executing controller action with signature System.Threading.Tasks.Task PostSafire() on controller TestEndpointAspNetCore3.Controllers.SafireController (TestEndpointAspNetCore3).
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of authorization filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of resource filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of action filters (in the following order): Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000), Microsoft.AspNetCore.Mvc.Infrastructure.ModelStateInvalidFilter (Order: -2000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of exception filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of result filters (in the following order): Microsoft.AspNetCore.Mvc.Infrastructure.ClientErrorResultFilter (Order: -2000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Executing controller factory for controller TestEndpointAspNetCore3.Controllers.SafireController (TestEndpointAspNetCore3)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed controller factory for controller TestEndpointAspNetCore3.Controllers.SafireController (TestEndpointAspNetCore3)
dbug: Microsoft.AspNetCore.Server.Kestrel[25]
      Connection id "0HM1OBCCL41MO", Request id "0HM1OBCCL41MO:00000001": started reading request body.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3) in 290.8187ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)'
fail: Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware[1]
      An unhandled exception has occurred while executing the request.
Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content.
   at Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException.Throw(RequestRejectionReason reason)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody.ReadAsyncInternal(CancellationToken cancellationToken)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.ReadAsyncInternal(Memory`1 buffer, CancellationToken cancellationToken)
   at System.IO.StreamReader.ReadBufferAsync(CancellationToken cancellationToken)
   at System.IO.StreamReader.ReadToEndAsyncInternal()
   at TestEndpointAspNetCore3.Controllers.SafireController.PostSafire() in C:\Users\chernandez\Desktop\TestEndpointSafire\TestEndpointAspNetCore3\TestEndpointAspNetCore3\Controllers\SafireController.cs:line 21
   at lambda_method(Closure , Object )
   at Microsoft.Extensions.Internal.ObjectMethodExecutorAwaitable.Awaiter.GetResult()
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.AwaitableResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeActionMethodAsync>g__Awaited|12_0(ControllerActionInvoker invoker, ValueTask`1 actionResultValueTask)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeNextActionFilterAsync>g__Awaited|10_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeInnerFilterAsync()
--- End of stack trace from previous location where exception was thrown ---
   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 Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(HttpContext context)
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 363.1332ms 500 text/plain
dbug: Microsoft.AspNetCore.Server.Kestrel[26]
      Connection id "0HM1OBCCL41MO", Request id "0HM1OBCCL41MO:00000001": done reading request body.
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM1OBCCL41MO" stopped.
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM1OBCCL41MP" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM1OBCCL41MP" started.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM1OBCCL41MQ" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM1OBCCL41MP" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM1OBCCL41MP" sending FIN because: "The client closed the connection."
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM1OBCCL41MQ" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM1OBCCL41MP" disconnecting.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM1OBCCL41MQ" started.
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM1OBCCL41MP" stopped.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM1OBCCL41MQ" sending FIN because: "The client closed the connection."
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM1OBCCL41MQ" disconnecting.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 POST http://172.16.10.105/api/testsafire application/xml; charset="UTF-8" 828
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/api/testsafire'
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)' with route pattern 'api/testsafire' is valid for the request path '/api/testsafire'
dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)'
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)'
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "PostSafire", controller = "Safire"}. Executing controller action with signature System.Threading.Tasks.Task PostSafire() on controller TestEndpointAspNetCore3.Controllers.SafireController (TestEndpointAspNetCore3).
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of authorization filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of resource filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of action filters (in the following order): Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000), Microsoft.AspNetCore.Mvc.Infrastructure.ModelStateInvalidFilter (Order: -2000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of exception filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of result filters (in the following order): Microsoft.AspNetCore.Mvc.Infrastructure.ClientErrorResultFilter (Order: -2000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Executing controller factory for controller TestEndpointAspNetCore3.Controllers.SafireController (TestEndpointAspNetCore3)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed controller factory for controller TestEndpointAspNetCore3.Controllers.SafireController (TestEndpointAspNetCore3)
dbug: Microsoft.AspNetCore.Server.Kestrel[25]
      Connection id "0HM1OBCCL41MQ", Request id "0HM1OBCCL41MQ:00000001": started reading request body.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3) in 417.3645ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)'
fail: Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware[1]
      An unhandled exception has occurred while executing the request.
Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content.
   at Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException.Throw(RequestRejectionReason reason)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody.ReadAsyncInternal(CancellationToken cancellationToken)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.ReadAsyncInternal(Memory`1 buffer, CancellationToken cancellationToken)
   at System.IO.StreamReader.ReadBufferAsync(CancellationToken cancellationToken)
   at System.IO.StreamReader.ReadToEndAsyncInternal()
   at TestEndpointAspNetCore3.Controllers.SafireController.PostSafire() in C:\Users\chernandez\Desktop\TestEndpointSafire\TestEndpointAspNetCore3\TestEndpointAspNetCore3\Controllers\SafireController.cs:line 21
   at lambda_method(Closure , Object )
   at Microsoft.Extensions.Internal.ObjectMethodExecutorAwaitable.Awaiter.GetResult()
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.AwaitableResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeActionMethodAsync>g__Awaited|12_0(ControllerActionInvoker invoker, ValueTask`1 actionResultValueTask)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeNextActionFilterAsync>g__Awaited|10_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeInnerFilterAsync()
--- End of stack trace from previous location where exception was thrown ---
   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 Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(HttpContext context)
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 499.1506ms 500 text/plain
dbug: Microsoft.AspNetCore.Server.Kestrel[26]
      Connection id "0HM1OBCCL41MQ", Request id "0HM1OBCCL41MQ:00000001": done reading request body.
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM1OBCCL41MQ" stopped.
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM1OBCCL41MR" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM1OBCCL41MR" started.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM1OBCCL41MR" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM1OBCCL41MR" sending FIN because: "The client closed the connection."
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM1OBCCL41MR" disconnecting.
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM1OBCCL41MR" stopped.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM1OBCCL41MS" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM1OBCCL41MS" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM1OBCCL41MS" started.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM1OBCCL41MS" sending FIN because: "The client closed the connection."
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM1OBCCL41MS" disconnecting.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 POST http://172.16.10.105/api/testsafire application/xml; charset="UTF-8" 828
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/api/testsafire'
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)' with route pattern 'api/testsafire' is valid for the request path '/api/testsafire'
dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)'
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)'
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "PostSafire", controller = "Safire"}. Executing controller action with signature System.Threading.Tasks.Task PostSafire() on controller TestEndpointAspNetCore3.Controllers.SafireController (TestEndpointAspNetCore3).
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of authorization filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of resource filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of action filters (in the following order): Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000), Microsoft.AspNetCore.Mvc.Infrastructure.ModelStateInvalidFilter (Order: -2000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of exception filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of result filters (in the following order): Microsoft.AspNetCore.Mvc.Infrastructure.ClientErrorResultFilter (Order: -2000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Executing controller factory for controller TestEndpointAspNetCore3.Controllers.SafireController (TestEndpointAspNetCore3)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed controller factory for controller TestEndpointAspNetCore3.Controllers.SafireController (TestEndpointAspNetCore3)
dbug: Microsoft.AspNetCore.Server.Kestrel[25]
      Connection id "0HM1OBCCL41MS", Request id "0HM1OBCCL41MS:00000001": started reading request body.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3) in 249.5785ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'TestEndpointAspNetCore3.Controllers.SafireController.PostSafire (TestEndpointAspNetCore3)'
fail: Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware[1]
      An unhandled exception has occurred while executing the request.
Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content.
   at Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException.Throw(RequestRejectionReason reason)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody.ReadAsyncInternal(CancellationToken cancellationToken)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.ReadAsyncInternal(Memory`1 buffer, CancellationToken cancellationToken)
   at System.IO.StreamReader.ReadBufferAsync(CancellationToken cancellationToken)
   at System.IO.StreamReader.ReadToEndAsyncInternal()
   at TestEndpointAspNetCore3.Controllers.SafireController.PostSafire() in C:\Users\chernandez\Desktop\TestEndpointSafire\TestEndpointAspNetCore3\TestEndpointAspNetCore3\Controllers\SafireController.cs:line 21
   at lambda_method(Closure , Object )
   at Microsoft.Extensions.Internal.ObjectMethodExecutorAwaitable.Awaiter.GetResult()
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.AwaitableResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeActionMethodAsync>g__Awaited|12_0(ControllerActionInvoker invoker, ValueTask`1 actionResultValueTask)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeNextActionFilterAsync>g__Awaited|10_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeInnerFilterAsync()
--- End of stack trace from previous location where exception was thrown ---
   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 Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(HttpContext context)
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 305.8977ms 500 text/plain
dbug: Microsoft.AspNetCore.Server.Kestrel[26]
      Connection id "0HM1OBCCL41MS", Request id "0HM1OBCCL41MS:00000001": done reading request body.
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM1OBCCL41MS" stopped.

[BrennanConroy]

Can you enable ConnectionLogging for your endpoint and provide the logs?
https://docs.microsoft.com/aspnet/core/fundamentals/servers/kestrel?view=aspnetcore-3.1#connection-logging

Since it'll be long could you paste it in a GitHub gist.

[cmhernandezdel]

I got something different this time. I don't know if I enabled the ConnectionLogging properly for the endpoint, but I guess so since I got it to log things. You can check my updated code and here is the gist with the logs:

https://gist.github.com/cmhernandezdel/22fc4d1dfb2ecbd66e4a205d19054b2a

You can see that the xml messages are being shown in the logs when doing this.

[Tratcher]

Hmm, there are no exceptions in that new log?

[cmhernandezdel]

Yeah, it's kinda weird.

Here you have logs when I comment out the line listenOptions.UseConnectionLogging():
https://gist.github.com/cmhernandezdel/4ad1d2425c454ed8025f3d3d080c973f

And here you have logs when I actually write that line:
https://gist.github.com/cmhernandezdel/31626e0d9c8e4a0bcd84e86b5476f747

As you can see, for some reason it raises an exception in the former case, but not in the latter. These both are with just ONE event received, as in I closed the app after receiving one event from the CCTV camera.

[cmhernandezdel]

To add a little more info, I tried with another camera that sends a JSON, and those are working fine, so the problem lies with XML.

Here are the logs for the JSON camera:
https://gist.github.com/cmhernandezdel/cbc2c5cc98030077b6a8e91d3069a4b4