sql: Scan error on column index 13, name \"login_challenge\": unsupported Scan, storing driver.Value type <nil> into type *string #1240
Comments
|
Did you upgrade recently? Maybe missed SQL migrations?
… On 16. Dec 2018, at 23:22, es-lab ***@***.***> wrote:
Describe the bug
OAuth flow breaks after a while. Currently unknown how to reproduce. But for some reason it breaks for a user & client specifically.
What happens visually is:
the client requests authorization
hydra redirects on login provider
login provider gets skip true and accepts login request and redirect on redirectTo value received from hydra
on accessing the link to hydra it gets the error *sql: Scan error on column index 13, name "login_challenge": unsupported Scan, storing driver.Value type into type string and redirects to client with error The error is unrecognizable
To Reproduce
Still do not know.
Expected behavior
To not break.
Screenshots
Logs of hydra of a complete OAuth flow:
time="2018-12-15T10:14:48Z" level=info msg="started handling request" method=GET remote=remote_ip_here request="/oauth2/auth?client_id=client_id_here&scope=offline&response_type=code&redirect_uri=https://client_host_here/oauth/redirect&state=23b00222-ef52-40df-aa07-4dc19330ebe0&ui_locales=en"
time="2018-12-15T10:14:48Z" level=info msg="completed handling request" measure#https://hydra_host_here/.latency=5613845 method=GET remote=remote_ip_here request="/oauth2/auth?client_id=client_id_here&scope=offline&response_type=code&redirect_uri=https://client_host_here/oauth/redirect&state=23b00222-ef52-40df-aa07-4dc19330ebe0&ui_locales=en"
status=302 text_status=Found took=5.613845ms
time="2018-12-15T10:14:48Z" level=info msg="started handling request" method=GET remote="172.18.0.13:43830" request=/oauth2/auth/requests/login/cf015261732444469bc3670643235896
time="2018-12-15T10:14:48Z" level=info msg="completed handling request" measure#https://hydra_host_here/.latency=4867655 method=GET remote="172.18.0.13:43830" request=/oauth2/auth/requests/login/cf015261732444469bc3670643235896 status=200 text_status=OK took=4.867655ms
time="2018-12-15T10:15:03Z" level=info msg="started handling request" method=GET remote="172.18.0.13:43830" request=/oauth2/auth/requests/login/cf015261732444469bc3670643235896
time="2018-12-15T10:15:03Z" level=info msg="completed handling request" measure#https://hydra_host_here/.latency=4808050 method=GET remote="172.18.0.13:43830" request=/oauth2/auth/requests/login/cf015261732444469bc3670643235896 status=200 text_status=OK took=4.80805ms
time="2018-12-15T10:15:03Z" level=info msg="started handling request" method=PUT remote="172.18.0.13:43830" request=/oauth2/auth/requests/login/cf015261732444469bc3670643235896/accept
time="2018-12-15T10:15:03Z" level=info msg="completed handling request" measure#https://hydra_host_here/.latency=6392958 method=PUT remote="172.18.0.13:43830" request=/oauth2/auth/requests/login/cf015261732444469bc3670643235896/accept status=200 text_status=OK took=6.392958ms
time="2018-12-15T10:15:03Z" level=info msg="started handling request" method=GET remote=remote_ip_here request="/oauth2/auth?client_id=client_id_here&login_verifier=797c33b6f64b452facead47aca386127&redirect_uri=https%3A%2F%2Fclient_host_here%2Foauth%2Fredirect&response_type=code&scope=offline&state=23b00222-ef52-40df-aa07-4dc19330ebe0&ui_locales=en"
time="2018-12-15T10:15:03Z" level=error msg="An error occurred" error="sql: Scan error on column index 13, name \"login_challenge\": unsupported Scan, storing driver.Value type <nil> into type *string"
time="2018-12-15T10:15:03Z" level=info msg="completed handling request" measure#https://hydra_host_here/.latency=14863933 method=GET remote=remote_ip_here request="/oauth2/auth?client_id=client_id_here&login_verifier=797c33b6f64b452facead47aca386127&redirect_uri=https%3A%2F%2Fclient_host_here%2Foauth%2Fredirect&response_type=code&scope=offline&state=23b00222-ef52-40df-aa07-4dc19330ebe0&ui_locales=en" status=302 text_status=Found took=14.863933ms
Version:
Environment: Docker Compose
Version oryd/hydra:v1.0.0-rc.5_oryOS.10 (happend on oryd/hydra:v1.0.0-rc.2_oryOS.9 too)
Access Token type: jwt
Additional context
Thought that the problem might be that I did not handled correctly 409 conflicts of login challenges, but even after proper logging and errors handling I still get the issue.
Tried to delete the data from tables with tokens and all the others excluding clients and migrations tables, everything started working properly, and then again it did break for some user/client. For the same user but other clients it still works.
To mention that the clients are first party apps that do not request audiences and scopes (it does request offline scope though), the consent logic authorizes the client with all its pre-defined scopes and audiences. May this be the problem? Do I need to allow to the client just its requested scopes and audiences?
Client details
{
"audience": [
"some_audience_here"
],
"client_id": "client_id_here",
"grant_types": [
"authorization_code",
"refresh_token"
],
"jwks": {},
"redirect_uris": [
"https://client_host_here/oauth/redirect",
"http://another_client_host_here/oauth/redirect"
],
"response_types": [
"code"
],
"scope": "offline oauth_auto_consent",
"subject_type": "public",
"token_endpoint_auth_method": "none",
"userinfo_signed_response_alg": "none"
}
oauth_auto_consent is used by the consent provider to check if it should skip consent and allow automatically for some clients. In this case it allows automatically for this clients. But the same happens for other clients and it works perfectly.
THIS NEEDS A SOLUTION ASAP
—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub, or mute the thread.
|
|
@aeneasr The last 3 weeks it was just integration of hydra in an existing system. I started with version oryd/hydra:v1.0.0-rc.2_oryOS.9 initially, sql migration did ran successfully from the first time. Then came a lot of clients create/update/delete/recreate because of development/prototyping of different use-cases. There was also a change to the Access Token type from the time I started. Could this change the way migrations run, and that now that it's jwt it expects some different schema/indexes? Also, I still can not reproduce this on my localhost, the current issues happens on a staging (https) environment. I did the upgrade to oryd/hydra:v1.0.0-rc.5_oryOS.10 3 days ago, just though it may solve the issue, but it did not. SQL migrations did run successfully though. What I did not try to do is a clean install of hydra db. I will try this one and hope to come back with more useful info. |
|
What database are you using? Exact version please.
The JWT strategy is, as noted, in beta and not the primary/recommended way, but it should obviously not break stuff.
The error is proper weird because <nil> is actually assignable to *string. That’s the whole point of *nil 🤔
… On 17. Dec 2018, at 07:43, es-lab ***@***.***> wrote:
@aeneasr The last 3 weeks it was just integration of hydra in an existing system. I started with version oryd/hydra:v1.0.0-rc.2_oryOS.9 initially, sql migration did ran successfully from the first time.
Then came a lot of clients create/update/delete/recreate because of development/prototyping of different use-cases.
There was also a change to the Access Token type from the time I started. Could this change the way migrations run, and that now that it's jwt it expects some different schema/indexes?
Also, I still can not reproduce this on my localhost, the current issues happens on a staging (https) environment.
I did the upgrade to oryd/hydra:v1.0.0-rc.5_oryOS.10 3 days ago, just though it may solve the issue, but it did not. SQL migrations did run successfully though.
What I did not try to do is a clean install of hydra. I will try this one and hope to come back with more useful info.
—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub, or mute the thread.
|
|
I'm using postgres 9.6 |
|
I've just done a clean db installation. Here are the outputs: Migration output First deploy after migration output Command used to create clients It works now, but as I said, I don't know how to reproduce and don't know if/when it will reappear now. |
|
@aeneasr I've reproduced it!! Finally!! Steps to reproduce:
Now this user can never authorize the clientY again. It gets redirected back to the client with /oauth/redirect?error=error&error_description=The+error+is+unrecognizable. If you delete the consent for the user/clientY from the table the client will be authorized successfully and it will work fine. |
|
@aeneasr I think there are some other ways to get to the issue, but I've found these way to get to it consistently, I've also noticed that this does not happen if in the database already exists a consent for the user/client, it somehow does not query the one with the NULL login_challenge and it does not fail. |
|
Thank you for reproducing this! I’ll push & publish a fix tomorrow
… On 17. Dec 2018, at 18:36, es-lab ***@***.***> wrote:
@aeneasr I think there are some other ways to get to the issue, but I've found these way to get to it consistently, I've also noticed that this does not happen if in the database already exists a consent for the user/client, it somehow does not query the one with the NULL login_challenge and it does not fail.
—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub, or mute the thread.
|
Closes #1240 Signed-off-by: aeneasr <aeneas@ory.sh>
|
This should work now, could you also check to make sure? :) |
|
Currently unreleased, on master, if you need help with that LMK |
|
@aeneasr It works! Thank you! |
|
Yes, this will be rc.6, I won't be able to release it today as there are a couple more things that need to be solved, but it should be out by latest end of week. |
Describe the bug
OAuth flow breaks after a while. Currently unknown how to reproduce. But for some reason it breaks for a user & client specifically.
What happens visually is:
To Reproduce
Still do not know.
Expected behavior
To not break.
Screenshots
Logs of hydra of a complete OAuth flow:
Version:
Additional context
Thought that the problem might be that I did not handled correctly 409 conflicts of login challenges, but even after proper logging and errors handling I still get the issue.
Tried to delete the data from tables with tokens and all the others excluding clients and migrations tables, everything started working properly, and then again it did break for some user/client. For the same user but other clients it still works.
To mention that the clients are first party apps that do not request audiences and scopes (it does request offline scope though), the consent logic authorizes the client with all its pre-defined scopes and audiences. May this be the problem? Do I need to allow to the client just its requested scopes and audiences?
Client details
oauth_auto_consent is used by the consent provider to check if it should skip consent and allow automatically for some clients. In this case it allows automatically for this clients. But the same happens for other clients and it works perfectly.
THIS NEEDS A SOLUTION ASAP
The text was updated successfully, but these errors were encountered: