Http timeouts handling

[damienbr]

We are facing a weird behavior in our production environment.
When a user tries to use a refresh_token in order to get a new access_token, sometimes, the DB is slow and it timeouts are triggered.
The problem is the refresh_token is deleted from the database while the new access_token hasn't been sent back to the client.
So the credentials are just lost.

When a request in hydra is taking too much time (apparently, when it takes more than 10secs), hydra logs says that it returns a 200 but the client is receiving a 502.
I have read here that the read timeout is configured to 10 seconds, which seems to be match our issues but the behavior seems weird as hydra logs says it's a 200 while it returns a 502.
If I'm not mistaking, this use case is when the DefaultWriteTimeout fires.
Could you precise if hydra should rollback the query when it happens? In this case, it doesn't seem to happen.

Unfortunately, this happens on a sensitive business case: when a user tries to use a refresh case. In that scenario, the refresh_token gets used by the hydra process while the token isn't returned to the client and the client has perform a new oauth flow.

We are using hydra 1.10.7

here is the log

hydra-sandbox_1 | {"http_request": {"method":"POST","path":"/oauth2/token","query":null,"remote":"172.27.0.254:46524","scheme":"https"},"http_response":{},"size":157,"status":200,"text_status":"OK","took":38091602516},"level":"info","msg":"completed handling request","time":"2022-06-08T09:15:02Z"}

kong_1 [error] 37#0: *57023 SSL_read() failed (SSL: error:1408F119:SSL routines:ssl3_get_record:decryption failed or bad record mac) while reading response header from upstream, client: 172.27.0.12, server: kong, request: "POST /oauth2/token HTTP/1.1", upstream: "https://172.27.0.11:4444/oauth2/token", host: "hydra-sandbox"

[damienbr]

When I lower the client timeout for the service calling hydra, I have another behavior:
Hydra returns a 401 when the connection is cut by the client and deletes the refresh_token.
So the credentials are lost also.
Wouldn't that make sense to have rollbacks happening in those situations?

The client calls hydra

Elixir.MyClient.HydraPublicClient post to https://public-hydra/oauth2/token
Hydra receives the requests

{"http_request":{"path":"/oauth2/token"},"level":"info","msg":"started handling request","time":"2022-06-08T13:06:34Z"}

The client close the connection because of timeout

Elixir.MyClient.HydraPublicClient post to https://public-hydra/oauth2/token took 506.936ms.

Elixir.MyClient.HydraPublicClient failed to call '/oauth2/token' due to '%HTTPoison.Error{id: nil, reason: :timeout}'

Hydra replies with a 401

{"audience":"application","error":{"debug":"timeout: context canceled","message":"invalid_client","reason":"","status":"Unauthorized","status_code":401},"level":"info","msg":"access denied","service_name":"ORY Hydra","service_version":"v1.10.7","time":"2022-06-08T13:06:34Z"}

{"http_response":{"size":200,"status":401,"text_status":"Unauthorized","took":500993983},"level":"info","msg":"completed handling request","time":"2022-06-08T13:06:34Z"}

Then the client retries

Elixir.MyClient.HydraPublicClient post to https://public-hydra/oauth2/token

Hydra returns a 400 because the refresh token is gone

{"http_request":{"path":"/oauth2/token"},"level":"info","msg":"started handling request","time":"2022-06-08T13:07:22Z"}

{"audience":"application","error":{"debug":"The refresh token has not been found: not_found","message":"invalid_grant","reason":"","status":"Bad Request","status_code":400},"level":"info","msg":"access denied","service_name":"ORY Hydra","service_version":"v1.10.7","time":"2022-06-08T13:07:22Z"}

{"http_request":{"size":333,"status":400,"text_status":"Bad Request","took":80777129},"level":"info","msg":"completed handling request","time":"2022-06-08T13:07:22Z"}

[aeneasr]

Thank you for the question and sorry for the slow response. Do you know why the refresh request is taking so long and the database is so slow? Is an index missing?

[vinckr]

Hey @damienbr, just checking in if your problem still persists.
I will mark this as answered for now, but feel free to come back to the discussion any time.
Thanks a ton 🐝