BindJson crashes Kestrel on Azure

[dsincl12]

Took me hours to figure this one out but I finally found the error: "Concurrent reads or writes not allowed." That's what Kestrel crashes with on Azure when BindJson is called more than once. I had severe issues with my "real" application and in the end just copy and pasted submitCar from the BindJson example and got the same error.

The first call to an endpoint with BindJson always goes through but subsequent calls returns "502 - Web server received an invalid response while acting as a gateway or proxy server." or "HTTP Error 502.3 - Bad Gateway The specified CGI application encountered an error and the server terminated the process." This is just Kestrel crashing with the error mentioned above.

Locally everything works just fine and I have no issues at all.

[dawedawe]

I can reproduce this. For me, this also only happens on Azure. Here's a stack trace.

2017-11-08 06:01:44.423 +00:00 [Error] Giraffe.Middleware.GiraffeErrorHandlerMiddleware: An unhandled exception has occurred while executing the request.

System.NullReferenceException: Object reference not set to an instance of an object.

at System.IO.StreamReader.IsPreamble()

at System.IO.StreamReader.d__65.MoveNext()

--- End of stack trace from previous location where exception was thrown ---

at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()

at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)

at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)

at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()

at System.IO.StreamReader.d__61.MoveNext()

--- End of stack trace from previous location where exception was thrown ---

at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()

at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)

at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)

at Giraffe.HttpContextExtensions.HttpContext-BindJson@62-1.Invoke(Unit unitVar0)

at Giraffe.TaskBuilder.StepStateMachine`1.nextAwaitable()

--- End of stack trace from previous location where exception was thrown ---

at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()

at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)

at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)

at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()

at BikeShed.HttpHandlers.postBikeHandler@28-3.Invoke(Unit unitVar0) in d:\a\1\s\BikeShed\HttpHandlers.fs:line 28

at Giraffe.TaskBuilder.StepStateMachine`1.nextAwaitable()

--- End of stack trace from previous location where exception was thrown ---

at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()

at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)

at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)

at Giraffe.HttpHandlers.chooseHttpFunc@92-1.Invoke(Unit unitVar0)

at Giraffe.TaskBuilder.StepStateMachine`1.nextAwaitable()

--- End of stack trace from previous location where exception was thrown ---

at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()

at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)

at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)

at Giraffe.HttpHandlers.chooseHttpFunc@92-1.Invoke(Unit unitVar0)

at Giraffe.TaskBuilder.StepStateMachine`1.nextAwaitable()

--- End of stack trace from previous location where exception was thrown ---

at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()

at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)

at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)

at Giraffe.Middleware.Invoke@38-5.Invoke(Unit unitVar0)

at Giraffe.TaskBuilder.StepStateMachine`1.nextAwaitable()

--- End of stack trace from previous location where exception was thrown ---

at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()

at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)

at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)

at Giraffe.Middleware.Invoke@63-8.Invoke(Unit unitVar0)

at Giraffe.TaskBuilder.tryWith[a](FSharpFunc2 step, FSharpFunc2 catch)

[dsincl12]

Tried using BindModel<>() to see if it made any difference. Same issue with that one as well.

[dsincl12]

This is the exception I get, a bit different than the one @dawedawe got:

Concurrent reads or writes are not supported. -- at Microsoft.AspNetCore.Server.Kestrel.Internal.System.IO.Pipelines.PipeCompletion.ThrowFailed() at Microsoft.AspNetCore.Server.Kestrel.Internal.System.IO.Pipelines.Pipe.GetResult(ReadResult& result) at Microsoft.AspNetCore.Server.Kestrel.Internal.System.IO.Pipelines.Pipe.Microsoft.AspNetCore.Server.Kestrel.Internal.System.IO.Pipelines.IReadableBufferAwaiter.GetResult() at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.MessageBody.d22.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.FrameRequestStream.d21.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.ConfiguredTaskAwaitable1.ConfiguredTaskAwaiter.GetResult() at System.IO.StreamReader.<ReadBufferAsync>d__65.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.ConfiguredTaskAwaitable1.ConfiguredTaskAwaiter.GetResult() at System.IO.StreamReader.d__61.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Giraffe.HttpContextExtensions.HttpContext-BindJson@62-1.Invoke(Unit unitVar0) at Giraffe.TaskBuilder.StepStateMachine1.nextAwaitable() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.ConfiguredTaskAwaitable1.ConfiguredTaskAwaiter.GetResult() at Sarakin.App.handlePostBankReportUpdate@93-6.Invoke(Unit unitVar0) in C:\Users\David Sinclair\Playground\FSharp\Sarakin\Program.fs:line 93 at Giraffe.TaskBuilder.tryWith[a](FSharpFunc2 step, FSharpFunc2 catch)

[dsincl12]

I've submitted a pull request with a fix for this issue.

[dustinmoris]

Hi, I would like to understand the issue a bit better first. Why does this happen only on Azure? Why would someone call BindJson more than once during a request? There is only one HTTP body per request which can be bound to a model and as far as I know it's not possible to read the body more than once anyways without storing the body in a cache after the first read so that subsequent reads can access the cached value rather than attempting to read from a closed stream again. Am I misunderstanding here something?

[dsincl12]

Maybe I wasn't clear enough. It is not that BindJson is called "twice", one time after the other in the same request. It is the subsequent requests that are failing. Why this only happens on Azure I don't know.

[dustinmoris]

Oh.. that is very odd indeed... BindJson is (or at least should) be entirely stateless, so I don't see why the synchronous version of ReadToEnd fixes the issue. Can this be reproduced in Azure with a regular ASP.NET Core app which makes use of ReadToEndAsync() without using Giraffe?

[dustinmoris]

Sorry, I know you already provided a PR for this, but changing the ReadToEnd method from async to sync might have a negative impact for a lot of other applications and I can't just merge it without better understanding the underlying issue. Let's get down to the bottom of this and then let's take action.

[dsincl12]

No worries, I needed this to get my app running in production anyway.

[gerardtoconnor]

very strange, seems like some sort of dangling reference although doesn't explain why works locally and fails in Azure.

@dsincl12 would you be able to share the handler pipeline code that has the BindJson call so we can investigate further (obviously substituting any sensitive data)?

On a side note, we probably can remove the ReadToEnd all together as it is converting UTF-8 to .net string and then parsing it ... when JsonSerializer can itself accept a StreamReader and read the stream directly into the class fields. This might fix the problem but even if it doesn't, it is the more efficient, GC friendly way to parse, especially when large JSON objects are going to force temp strings on to the LOH unnecessarily.

[dsincl12]

Sure, here's one of them:

` let handlePostBankReportUpdate = fun (next : HttpFunc) (ctx : HttpContext) -> task { let! bankReportUpdate = ctx.BindJson()

        let current = deserializeJson<Statistics> statistics

        let newStatistics = {
            TotalPayoutMonth = current.TotalPayoutMonth + bankReportUpdate.Amount;
            TotalPayoutToday = current.TotalPayoutToday + bankReportUpdate.Amount;
        }

        do! updateStatistics newStatistics

        let message = 
            { BankId = bankReportUpdate.BankId;
            Amount = bankReportUpdate.Amount;
            TotalPayoutMonth = newStatistics.TotalPayoutMonth;
            TotalPayoutToday = newStatistics.TotalPayoutToday }

        for socket in sockets do
            try
                do! sendMessage socket (serializeJson message)
            with
                | _ -> sockets <- removeSocket sockets socket

        return! next ctx
    }
`

[hakonrossebo]

I've struggled with the same issue for a few hours before I found this issue. It works fine in local development on IIS Express, but fails when running on IIS (with https) on the test server.

[gerardtoconnor]

@dsincl12 thanks for sharing the snippet, seems in most cases the issue relates to the read stream being disposed of too early before the binding complete (the return of the Task to middleware pipeline closing it out).

I have sent in a PR #141 to bind Json using stream rather than string so may help while not compromising async, feel free to test if you like. still, need to get to the bottem of why stream being disposed of.

    member this.BindJson<'T>() =
            let body = this.Request.Body
            use sr = new StreamReader(body, true)
            use jr = new JsonTextReader(sr)
            let serializer = JsonSerializer()
            serializer.Deserialize<'T>(jr);

[dustinmoris]

A new version is on its way --> v0.1.0-beta-300 - hope this fixes the issue for you in the meanwhile.

[gerardtoconnor]

Has anyone tested this issue on released v0.1.0-beta-300 ? is the exception still being raised? @dsincl12 @dawedawe

[dawedawe]

For me, the issue is fixed with v0.1.0-beta-300. Thanks everyone!

[gerardtoconnor]

Sweet, thanks for letting us know, this is also a lot more efficient way of parsing so everyone's a winner

[dustinmoris]

Closing as this has been fixed and I believe it was related to #186