Received successful OpenID Connect callback but user is not registered (identity exist) #1002

TaSiya · 2021-01-22T08:50:29Z

TaSiya
Jan 22, 2021

Describe bug

When I login with an existing identity in kratos, I get that the user already exist. I get this because it goes through the registration flow after successful login with hydra but kratos says Received successful OpenID Connect callback but user is not registered, then registration hook starts the registration flow.

Reproducing the bug

Login using hydra as the provider
fill form in consent app
login and accept the consent scopes

Expected behavior

I expect to be logged in as the user/identity instead of trying to create the identity again. I do get the correct values from the claims requested.

Configuration

I always have the email for testing purposes

oidc.hydra.jsonnet

local claims = {
  email_verified: false
} + std.extVar('claims');

{
  identity: {
    traits: {
      email: claims.email
    },
  },
}

kratos.yml

#...
methods:
    password:
      enabled: false
    oidc:
      enabled: true
      config:
        providers:
          - id: hydra
            provider: generic
            mapper_url: file:///etc/config/kratos/oidc.hydra.jsonnet
            client_id: client-id
            client_secret: this-is-the-secret
            scope:
              - profile
              - openid
            issuer_url: http://my-issuer.com/
            requested_claims:
              userinfo:
                email:
                  essential: true
#...

Answered by TaSiya

Jan 25, 2021

@aeneasr @vinckr I managed to resolve the issue.

solution

I was creating the subject every time a user login even if it is the same user. Hence, after removing that and used the subject in the database. The login flow worked.

I hope I am making sense.

View full answer

aeneasr · 2021-01-22T11:04:38Z

aeneasr
Jan 22, 2021
Maintainer

When I login with an existing identity in kratos, I get that the user already exist. I get this because it goes through the registration flow after successful login with hydra but kratos says Received successful OpenID Connect callback but user is not registered, then registration hook starts the registration flow.

I don't quite follow, could you please elaborate? Thanks!

7 replies

TaSiya Jan 22, 2021
Author

yes thats correct @vinckr

aeneasr Jan 22, 2021
Maintainer

Can you please provide some logs with full debugging enabled LOG_LEVEL=trace and also include one or more ID Tokens issued by ORY Hydra.

Please also tell us which versions you use of both systems.

TaSiya Jan 22, 2021
Author

Hydra: v1.8.5
Kratos : latest

Note: I am using ngrok since I could not resolve this issue #937 with docker networking.

logs

consent_1         | POST /consent 302 43.448 ms - 904
hydra_1           | time=2021-01-22T12:29:46Z level=info msg=started handling request http_request=map[headers:map[accept:text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9 accept-encoding:gzip, deflate accept-language:en-ZA,en;q=0.9 cache-control:max-age=0 cookie:oauth2_authentication_csrf_insecure=MTYxMTMxODU2OXxEdi1CQkFFQ180SUFBUkFCRUFBQVB2LUNBQUVHYzNSeWFXNW5EQVlBQkdOemNtWUdjM1J5YVc1bkRDSUFJR0V6TURaa09UbGhPVGhpTWpRd05XVmhPR1kxTURSalltSmtaalprTUdGanwrcgYkP-GMWDO427HTcnklQyu8rsRBX18LCKZC-9bYSg==; oauth2_consent_csrf_insecure=MTYxMTMxODU3NnxEdi1CQkFFQ180SUFBUkFCRUFBQVB2LUNBQUVHYzNSeWFXNW5EQVlBQkdOemNtWUdjM1J5YVc1bkRDSUFJREJpWVRFM1pXWTVaalkyTlRSa1pqQmhZMkZtWXpNek5UVXdObVJoWldSaXwPV5-EhjNrA5rcP8HOEFUNrorHixq4zxGyqhj06It6sg== referer:http://127.0.0.1:3005/ user-agent:Mozilla/5.0 (Macintosh; Intel Mac OS X 11_1_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.141 Safari/537.36 x-forwarded-for:196.223.229.245] host:82c0b986a473.ngrok.io method:GET path:/oauth2/auth query:claims=%7B%22userinfo%22%3A%7B%22email%22%3A%7B%22essential%22%3Atrue%7D%2C%22sub%22%3A%7B%22essential%22%3Atrue%7D%7D%7D&client_id=myaccount&consent_verifier=633c9ca7b0324f2ba8127feb7f7a05a4&redirect_uri=http%3A%2F%2F127.0.0.1%3A4433%2Fself-service%2Fmethods%2Foidc%2Fcallback%2Fjd&response_type=code&scope=profile+openid&state=1e33511e-a4ae-4991-baf6-06466bf3c5b5 remote:172.20.0.1:58600 scheme:http]
hydra_1           | time=2021-01-22T12:29:46Z level=info msg=completed handling request http_request=map[headers:map[accept:text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9 accept-encoding:gzip, deflate accept-language:en-ZA,en;q=0.9 cache-control:max-age=0 cookie:oauth2_authentication_csrf_insecure=MTYxMTMxODU2OXxEdi1CQkFFQ180SUFBUkFCRUFBQVB2LUNBQUVHYzNSeWFXNW5EQVlBQkdOemNtWUdjM1J5YVc1bkRDSUFJR0V6TURaa09UbGhPVGhpTWpRd05XVmhPR1kxTURSalltSmtaalprTUdGanwrcgYkP-GMWDO427HTcnklQyu8rsRBX18LCKZC-9bYSg==; oauth2_consent_csrf_insecure=MTYxMTMxODU3NnxEdi1CQkFFQ180SUFBUkFCRUFBQVB2LUNBQUVHYzNSeWFXNW5EQVlBQkdOemNtWUdjM1J5YVc1bkRDSUFJREJpWVRFM1pXWTVaalkyTlRSa1pqQmhZMkZtWXpNek5UVXdObVJoWldSaXwPV5-EhjNrA5rcP8HOEFUNrorHixq4zxGyqhj06It6sg== referer:http://127.0.0.1:3005/ user-agent:Mozilla/5.0 (Macintosh; Intel Mac OS X 11_1_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.141 Safari/537.36 x-forwarded-for:196.223.229.245] host:82c0b986a473.ngrok.io method:GET path:/oauth2/auth query:claims=%7B%22userinfo%22%3A%7B%22email%22%3A%7B%22essential%22%3Atrue%7D%2C%22sub%22%3A%7B%22essential%22%3Atrue%7D%7D%7D&client_id=myaccount&consent_verifier=633c9ca7b0324f2ba8127feb7f7a05a4&redirect_uri=http%3A%2F%2F127.0.0.1%3A4433%2Fself-service%2Fmethods%2Foidc%2Fcallback%2Fjd&response_type=code&scope=profile+openid&state=1e33511e-a4ae-4991-baf6-06466bf3c5b5 remote:172.20.0.1:58600 scheme:http] http_response=map[status:302 text_status:Found took:32.4135ms]
hydra_1           | time=2021-01-22T12:29:47Z level=info msg=started handling request http_request=map[headers:map[accept-encoding:gzip user-agent:Go-http-client/1.1 x-forwarded-for:196.223.229.245] host:82c0b986a473.ngrok.io method:GET path:/.well-known/openid-configuration query:<nil> remote:172.20.0.1:58596 scheme:http]
hydra_1           | time=2021-01-22T12:29:47Z level=info msg=completed handling request http_request=map[headers:map[accept-encoding:gzip user-agent:Go-http-client/1.1 x-forwarded-for:196.223.229.245] host:82c0b986a473.ngrok.io method:GET path:/.well-known/openid-configuration query:<nil> remote:172.20.0.1:58596 scheme:http] http_response=map[status:200 text_status:OK took:2.0989ms]
hydra_1           | time=2021-01-22T12:29:47Z level=info msg=started handling request http_request=map[headers:map[accept-encoding:gzip user-agent:Go-http-client/1.1 x-forwarded-for:196.223.229.245] host:82c0b986a473.ngrok.io method:POST path:/oauth2/token query:<nil> remote:172.20.0.1:58596 scheme:http]
hydra_1           | time=2021-01-22T12:29:48Z level=info msg=completed handling request http_request=map[headers:map[accept-encoding:gzip user-agent:Go-http-client/1.1 x-forwarded-for:196.223.229.245] host:82c0b986a473.ngrok.io method:POST path:/oauth2/token query:<nil> remote:172.20.0.1:58596 scheme:http] http_response=map[status:200 text_status:OK took:234.3981ms]
hydra_1           | time=2021-01-22T12:29:48Z level=info msg=started handling request http_request=map[headers:map[accept-encoding:gzip user-agent:Go-http-client/1.1 x-forwarded-for:196.223.229.245] host:82c0b986a473.ngrok.io method:GET path:/.well-known/jwks.json query:<nil> remote:172.20.0.1:58596 scheme:http]
hydra_1           | time=2021-01-22T12:29:48Z level=info msg=completed handling request http_request=map[headers:map[accept-encoding:gzip user-agent:Go-http-client/1.1 x-forwarded-for:196.223.229.245] host:82c0b986a473.ngrok.io method:GET path:/.well-known/jwks.json query:<nil> remote:172.20.0.1:58596 scheme:http] http_response=map[status:200 text_status:OK took:4.0986ms]
kratos_1          | time=2021-01-22T12:29:48Z level=debug msg=Received successful OpenID Connect callback but user is not registered. Re-initializing registration flow now. func=github.com/ory/kratos/selfservice/strategy/oidc.(*Strategy).processLogin file=/home/ory/selfservice/strategy/oidc/strategy_login.go:53 audience=application provider=jd service_name=kratos service_version= subject=qEVjjvhkVuASwzTMz3vk2R4Rrdamc+4=
kratos_1          | time=2021-01-22T12:29:48Z level=debug msg=OpenID Connect Jsonnet mapper completed. func=github.com/ory/kratos/selfservice/strategy/oidc.(*Strategy).processRegistration file=/home/ory/selfservice/strategy/oidc/strategy_registration.go:116 audience=application http_request=map[headers:map[accept:text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9 accept-encoding:gzip, deflate, br accept-language:en-ZA,en;q=0.9 cache-control:max-age=0 cookie:my-account.sid=s%3AnsqbJL1jLtda9KlHOmLcdPUNZlax4c6P.jBpeaBE2EOB8Xv846kJ6JnsSK9xqUFIMzxfwyx4%2B5MA; csrf_token=rkW/IrydAmnAY3vTkfP2jDNXUiXOlkgZBGeKDB/nJMg=; ory_kratos_continuity=MTYxMTMxODU2OHxEdi1CQkFFQ180SUFBUkFCRUFBQVhfLUNBQUVHYzNSeWFXNW5EQ01BSVc5eWVWOXJjbUYwYjNOZmIybGtZMTloZFhSb1gyTnZaR1ZmYzJWemMybHZiZ1p6ZEhKcGJtY01KZ0FrWldFM05UazRaall0TkdSaVppMDBNakJrTFRsa1ptVXRabVptTUdSaE5ETXhOamRrfA7Fw8mVAOaZra2NNrTXxRTrm7u7fKwjJGrdNdEykfzf; _csrf=JeAXPp2ajxiCpoMpa4O2M6i3; consent.app.sid=s%3AEzOW89HrcY0BWKpVv7LYiU22KSfNQn59.cStZ1yc9GUfIOsmOxsfBDCh9SLm0oRtUoJfaK98KtoA referer:http://127.0.0.1:3005/ user-agent:Mozilla/5.0 (Macintosh; Intel Mac OS X 11_1_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.141 Safari/537.36] host:127.0.0.1:4433 method:GET path:/self-service/methods/oidc/callback/jd query:code=ct3a90nA_sdCoOLaA9h__UXshkdM1nVxB6UhpWNAwe8.1XBiadKDaR3fVK3igNFnLgOMGxIJAI2ajaXI5yBZHq8&scope=profile%20openid&state=1e33511e-a4ae-4991-baf6-06466bf3c5b5 remote:172.20.0.1:57250 scheme:http] mapper_jsonnet_output={
kratos_1          |    "identity": {
kratos_1          |       "traits": {
kratos_1          |          "email": "[email protected]"
kratos_1          |       }
kratos_1          |    }
kratos_1          | }
kratos_1          |  mapper_jsonnet_url=file:///etc/config/kratos/oidc.jd.jsonnet oidc_claims=&{http://82c0b986a473.ngrok.io/ qEVjjvhkVuASwzTMz3vk2R4Rrdamc+4=           [email protected] false      false 0} oidc_provider=jd service_name=kratos service_version=
kratos_1          | time=2021-01-22T12:29:49Z level=debug msg=Running PostRegistrationPrePersistHooks. func=github.com/ory/kratos/selfservice/flow/registration.(*HookExecutor).PostRegistrationHook file=/home/ory/selfservice/flow/registration/hook.go:91 audience=application flow_method=oidc http_request=map[headers:map[accept:text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9 accept-encoding:gzip, deflate, br accept-language:en-ZA,en;q=0.9 cache-control:max-age=0 cookie:my-account.sid=s%3AnsqbJL1jLtda9KlHOmLcdPUNZlax4c6P.jBpeaBE2EOB8Xv846kJ6JnsSK9xqUFIMzxfwyx4%2B5MA; csrf_token=rkW/IrydAmnAY3vTkfP2jDNXUiXOlkgZBGeKDB/nJMg=; ory_kratos_continuity=MTYxMTMxODU2OHxEdi1CQkFFQ180SUFBUkFCRUFBQVhfLUNBQUVHYzNSeWFXNW5EQ01BSVc5eWVWOXJjbUYwYjNOZmIybGtZMTloZFhSb1gyTnZaR1ZmYzJWemMybHZiZ1p6ZEhKcGJtY01KZ0FrWldFM05UazRaall0TkdSaVppMDBNakJrTFRsa1ptVXRabVptTUdSaE5ETXhOamRrfA7Fw8mVAOaZra2NNrTXxRTrm7u7fKwjJGrdNdEykfzf; _csrf=JeAXPp2ajxiCpoMpa4O2M6i3; consent.app.sid=s%3AEzOW89HrcY0BWKpVv7LYiU22KSfNQn59.cStZ1yc9GUfIOsmOxsfBDCh9SLm0oRtUoJfaK98KtoA referer:http://127.0.0.1:3005/ user-agent:Mozilla/5.0 (Macintosh; Intel Mac OS X 11_1_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.141 Safari/537.36] host:127.0.0.1:4433 method:GET path:/self-service/methods/oidc/callback/jd query:code=ct3a90nA_sdCoOLaA9h__UXshkdM1nVxB6UhpWNAwe8.1XBiadKDaR3fVK3igNFnLgOMGxIJAI2ajaXI5yBZHq8&scope=profile%20openid&state=1e33511e-a4ae-4991-baf6-06466bf3c5b5 remote:172.20.0.1:57250 scheme:http] identity_id=92b29608-ec73-48d1-9741-085ff1776ebc service_name=kratos service_version=
postgres_1        | 2021-01-22 12:29:49.019 UTC [374] ERROR:  duplicate key value violates unique constraint "identity_verifiable_addresses_status_via_uq_idx"
postgres_1        | 2021-01-22 12:29:49.019 UTC [374] DETAIL:  Key (via, value)=(email, [email protected]) already exists.
postgres_1        | 2021-01-22 12:29:49.019 UTC [374] STATEMENT:  INSERT INTO "identity_verifiable_addresses" ("created_at", "id", "identity_id", "status", "updated_at", "value", "verified", "verified_at", "via") VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9)
postgres_1        | 2021-01-22 12:29:49.019 UTC [374] ERROR:  current transaction is aborted, commands ignored until end of transaction block
postgres_1        | 2021-01-22 12:29:49.019 UTC [374] STATEMENT:  deallocate "pgx_38"
kratos_1          | time=2021-01-22T12:29:49Z level=info msg=Encountered self-service flow error. func=github.com/ory/kratos/selfservice/flow/registration.(*ErrorHandler).WriteFlowError file=/home/ory/selfservice/flow/registration/error.go:79 audience=audit error=map[message:I[#/] S[] an account with the same identifier (email, phone, username, ...) exists already trace:
kratos_1          | github.com/ory/kratos/schema.NewDuplicateCredentialsError
kratos_1          | 	/home/ory/schema/errors.go:96

aeneasr Jan 22, 2021
Maintainer

Looks like the subject of the ID Token (qEVjjvhkVuASwzTMz3vk2R4Rrdamc+4=) is not the value of the first login attempt

TaSiya Jan 25, 2021
Author

@aeneasr to be honest, I don't quite understand what you mean. Sorry if this is an obvious thing but I spent some time over the weekend and today to understand but still I don't. There is only 1 subject that I see and if it is different. Do you have any ideas what I am doing wrong?

thank you for support :)

TaSiya · 2021-01-25T13:34:01Z

TaSiya
Jan 25, 2021
Author

@aeneasr @vinckr I managed to resolve the issue.

solution

I was creating the subject every time a user login even if it is the same user. Hence, after removing that and used the subject in the database. The login flow worked.

I hope I am making sense.

1 reply

aeneasr Jan 25, 2021
Maintainer

Yes, that was what I was trying to say - congratulations!

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Received successful OpenID Connect callback but user is not registered (identity exist) #1002

{{title}}

Replies: 2 comments 8 replies

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

Select a reply

Received successful OpenID Connect callback but user is not registered (identity exist) #1002

TaSiya Jan 22, 2021

Replies: 2 comments · 8 replies

aeneasr Jan 22, 2021 Maintainer

TaSiya Jan 22, 2021 Author

aeneasr Jan 22, 2021 Maintainer

TaSiya Jan 22, 2021 Author

aeneasr Jan 22, 2021 Maintainer

TaSiya Jan 25, 2021 Author

TaSiya Jan 25, 2021 Author

aeneasr Jan 25, 2021 Maintainer

TaSiya
Jan 22, 2021

Replies: 2 comments 8 replies

aeneasr
Jan 22, 2021
Maintainer

TaSiya Jan 22, 2021
Author

aeneasr Jan 22, 2021
Maintainer

TaSiya Jan 22, 2021
Author

aeneasr Jan 22, 2021
Maintainer

TaSiya Jan 25, 2021
Author

TaSiya
Jan 25, 2021
Author

aeneasr Jan 25, 2021
Maintainer