actix / actix-extras

A collection of additional crates supporting the actix and actix-web frameworks.
https://actix.rs
Apache License 2.0
776 stars 199 forks source link

AuthenticationMiddleware was called already panic #10

Closed dneuhaeuser-zalando closed 4 years ago

dneuhaeuser-zalando commented 4 years ago

We are observing that our actix-web application occasionally panics under a lot of contention with the message "AuthenticationMiddleware was called already". This seems to come from here https://github.com/actix/actix-web-httpauth/blob/v0.4.0/src/middleware.rs#L184

We have recently migrated to actix-web 2.0 and actix-web-httpauth 0.4. We haven't observed this before the migration.

As this doesn't happen for all requests, there seems to be some race condition either within actix-web or actix-web-httpauth that causes this.

We use bearer token authorization and within the validation function, to validate the token, we just perform an HTTP request with reqwest and depending on the result return Ok or Err.

stiiifff commented 4 years ago

@dneuhaeuser-zalando Do you use a blocking operation in one of your handlers ? I had the same issue and it came from the fact I was using the web::block helper function from actix-web in an async handler ...

dneuhaeuser-zalando commented 4 years ago

Yes and no. We don't use web::block. However we are performing database queries with diesel and those are of course blocking. (Not ideal, I know. We should change it at some point.)

robjtede commented 4 years ago

@dneuhaeuser-zalando can you provide us with a minimal reproduction program so we can trace the cause of the panic.

To be clear, web::block is non-blocking; its purpose is to run blocking code asynchronously on a background thread pool.

stiiifff commented 4 years ago

@robjtede re. web::blocking being non-blocking, that was my understanding ... but its use somehow lead to panics described in this issue. It would happen systematically if just 2 requests would arrive in //.

I replaced the use of web::block by an async move { ... } block and no more panics. For testing, I simply used apache bench (e.g. ab -c 10 -n 100 http://127.0.0.1:8080/).

boydjohnson commented 4 years ago

It looks to be inherent in the contract between poll_ready and call. The implementation of Service in actix-web-httpauth assumes that poll_ready and call won't be called at the same time: https://github.com/actix/actix-extras/blob/6b5215d43995af3a8eacc8505738cd689dd54833/actix-web-httpauth/src/middleware.rs#L183-L185

This doesn't seem to be true given the comments on Service: https://github.com/actix/actix-net/blob/a5c185e80e56d44ea88b4485729abdefb08b1c2a/actix-service/src/lib.rs#L95

This repo has code that reproduces the panic: https://github.com/boydjohnson/actix-example.

I have a commit that uses the futures::lock::Mutex that wraps the service and first calls poll on the lock and then poll_ready on the service. I would make a PR if it is wanted. https://github.com/boydjohnson/actix-extras/commit/43f7fcf3cca5e2345963317b0c96e761707721ca ----- EDIT 05-10-2020 ----- I think the above mentioned commit is not right and the commit by @stiiiifff https://github.com/stiiifff/actix-extras/commit/a8f142d965903277f175c0f61579c0a0445ce9a4 that swaps out the Mutex for a RefCell is the right way to go. ----- EDIT later 05-10-2020 ---- The commit by @stiiiifff https://github.com/stiiifff/actix-extras/commit/a8f142d965903277f175c0f61579c0a0445ce9a4 on further testing gives an intermittent BorrowRefError. I have a commit that tries a different futures aware lock: https://github.com/boydjohnson/actix-extras/commit/5d2cdf117324c73b7a14b960a185330edf86b1d7 that is promising.

stiiifff commented 4 years ago

@boydjohnson Thx for further looking into this, I still have some intermittent errors in my project due to this issue. I will try out your proposed fix.

boydjohnson commented 4 years ago

I have had good luck with the debug-2 branch on github.com/boydjohnson/actix-extras for about a month without a panic and without a deadlock. I am going to make a PR with this branch today. @stiiifff did you try the debug-2 branch at github.com/boydjohnson/actix-extras?

boydjohnson commented 4 years ago

Here is the backtrace of the panic with debug symbols on. https://gist.github.com/boydjohnson/8ab7d1aa1aadc9562ec50e67a3107fa6.

-- Edited this comment so as not to have a long back trace in the thread.

cetra3 commented 4 years ago

@dneuhaeuser-zalando There is a PR active by @boydjohnson that should address your issue.

Are you able to test that the PR solves your issue?

stiiifff commented 4 years ago

As mentioned in the PR, it looks good on my end as well.