9:50 a.m.
After upgrading to version 1.9.1 we’ve started to get rejections from keycloak.js while
getting token based on code.
If we enter base url (http://example.com <http://example.com/>) then the app works
fine, login is successful and token is retrieved.
Unfortunately when entering this child page
(https://example.com/?redirect_fragment=/asset-library/card-view/
<https://example.com/?redirect_fragment=/asset-library/card-view/> - it is sent from
javascript with redirect_fragment encoded, but in keycloak logs it’s visible with this
fragment decoded) we get error 400 while getting token after succesful login and obtaining
the code. The precise response is:
{"error_description":"Incorrect
redirect_uri","error":"invalid_grant”}
Why is that? In valid redirects uri in keycloak we have (just in case):
- https://example.com <https://example.com/>*
- https://example.com <https://example.com/>/*
- https://example.com/?redirect_fragment=/asset-library/card-view/
<https://example.com/?redirect_fragment=/asset-library/card-view/>
- https://example.com/?redirect_fragment=%2Fasset-library%2Fcard-view%2F
<https://example.com/?redirect_fragment=/asset-library/card-view/>
- http://example.com <http://example.com/>*
- http://example.com <http://example.com/>/*
- http://example.com/?redirect_fragment=/asset-library/card-view/
<http://example.com/?redirect_fragment=/asset-library/card-view/>
- http://example.com/?redirect_fragment=%2Fasset-library%2Fcard-view%2F
<http://example.com/?redirect_fragment=/asset-library/card-view/>
Here are the logs of succesful log in with redirect URI beeing http://example.com
<http://example.com/> :
11:38:47,934 DEBUG
[org.jboss.jca.core.connectionmanager.pool.validator.ConnectionValidator]
(ConnectionValidator) Notifying pools, interval: 30000
11:38:47,935 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(ConnectionValidator) Checking for connection within frequency
11:38:47,936 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(ConnectionValidator) Returning for connection within frequency
11:38:47,937 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(ConnectionValidator) Checking for connection within frequency
11:38:47,938 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(ConnectionValidator) Returning for connection within frequency
11:38:47,938 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(ConnectionValidator) Checking for connection within frequency
11:38:49,335 DEBUG [org.springframework.boot.context.web.OrderedRequestContextFilter]
(default task-14) Bound request context to thread: HttpServletRequestImpl [ GET
/auth/realms/xxxxxx/protocol/openid-connect/auth ]
11:38:49,336 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-14)
RESTEASY002315: PathInfo: /realms/xxxxxx/protocol/openid-connect/auth
11:38:49,348 DEBUG [org.keycloak.services] (default task-14) AUTHENTICATE
11:38:49,357 DEBUG [org.keycloak.services] (default task-14) AUTHENTICATE ONLY
11:38:49,358 DEBUG [org.keycloak.services] (default task-14) processFlow
11:38:49,358 DEBUG [org.keycloak.services] (default task-14) check execution: auth-cookie
requirement: ALTERNATIVE
11:38:49,358 DEBUG [org.keycloak.services] (default task-14) authenticator: auth-cookie
11:38:49,359 DEBUG [org.keycloak.services] (default task-14) invoke
authenticator.authenticate
11:38:49,360 DEBUG [org.keycloak.services] (default task-14) token active - active: true,
issued-at: 1,461,152,319, not-before: 0
11:38:49,361 DEBUG [org.keycloak.services] (default task-14) authenticator SUCCESS:
auth-cookie
11:38:49,361 DEBUG [org.keycloak.services] (default task-14) check execution: auth-spnego
requirement: DISABLED
11:38:49,361 DEBUG [org.keycloak.services] (default task-14) execution is processed
11:38:49,362 DEBUG [org.keycloak.services] (default task-14) check execution: null
requirement: ALTERNATIVE
11:38:49,362 DEBUG [org.keycloak.services] (default task-14) Skip alternative execution
11:38:49,362 DEBUG [org.keycloak.services] (default task-14) Using full scope for client
11:38:49,363 DEBUG [org.keycloak.events] (default task-14) type=LOGIN, realmId=xxxxxx,
clientId=api, userId=64e2ec92-a6ee-4705-a8b3-adebe9c3c816, ipAddress=172.17.0.1,
auth_method=openid-connect, auth_type=code, response_type=code,
redirect_uri=https://example.com/ <https://example.com/>;,
consent=no_consent_required, code_id=1e564327-4775-4cbc-8e15-c3b553bc7585,
response_mode=fragment, username=xxxxxx
11:38:49,384 DEBUG [org.keycloak.services] (default task-14) Create login cookie - name:
KEYCLOAK_IDENTITY, path: /auth/realms/xxxxxx, max-age: -1
11:38:49,385 DEBUG [org.keycloak.services] (default task-14) redirectAccessCode: state:
0ecc910f-b0d2-4b9f-80ae-105c2dc28644
11:38:49,387 DEBUG [org.springframework.boot.context.web.OrderedRequestContextFilter]
(default task-14) Cleared thread-bound request context: HttpServletRequestImpl [ GET
/auth/realms/xxxxxx/protocol/openid-connect/auth ]
11:38:50,139 DEBUG [org.springframework.boot.context.web.OrderedRequestContextFilter]
(default task-6) Bound request context to thread: HttpServletRequestImpl [ POST
/auth/realms/xxxxxx/protocol/openid-connect/token ]
11:38:50,140 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-6)
RESTEASY002315: PathInfo: /realms/xxxxxx/protocol/openid-connect/token
11:38:50,147 DEBUG [org.keycloak.services] (default task-6) AUTHENTICATE CLIENT
11:38:50,148 DEBUG [org.keycloak.services] (default task-6) client authenticator:
client-secret
11:38:50,148 DEBUG [org.keycloak.services] (default task-6) client authenticator SUCCESS:
client-secret
11:38:50,149 DEBUG [org.keycloak.services] (default task-6) Client api authenticated by
client-secret
11:38:50,178 DEBUG [org.keycloak.events] (default task-6) type=CODE_TO_TOKEN,
realmId=xxxxxx, clientId=api, userId=64e2ec92-a6ee-4705-a8b3-adebe9c3c816,
ipAddress=172.17.0.1, token_id=dd46b7cd-6233-4881-8fe1-96e4ed087b37,
grant_type=authorization_code, refresh_token_type=Refresh,
refresh_token_id=0751e640-397d-45d7-a799-485a0573f20a,
code_id=1e564327-4775-4cbc-8e15-c3b553bc7585, client_auth_method=client-secret
11:38:50,182 DEBUG [org.springframework.boot.context.web.OrderedRequestContextFilter]
(default task-6) Cleared thread-bound request context: HttpServletRequestImpl [ POST
/auth/realms/xxxxxx/protocol/openid-connect/token ]
11:38:50,353 DEBUG [org.springframework.boot.context.web.OrderedRequestContextFilter]
(default task-10) Bound request context to thread: HttpServletRequestImpl [ GET
/auth/realms/xxxxxx/protocol/openid-connect/userinfo ]
11:38:50,354 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-10)
RESTEASY002315: PathInfo: /realms/xxxxxx/protocol/openid-connect/userinfo
11:38:50,356 DEBUG [org.keycloak.events] (default task-10) type=USER_INFO_REQUEST,
realmId=xxxxxx, clientId=api, userId=64e2ec92-a6ee-4705-a8b3-adebe9c3c816,
ipAddress=172.17.0.1, auth_method=validate_access_token, username=xxxxxx
11:38:50,358 DEBUG [org.springframework.boot.context.web.OrderedRequestContextFilter]
(default task-10) Cleared thread-bound request context: HttpServletRequestImpl [ GET
/auth/realms/xxxxxx/protocol/openid-connect/userinfo ]
And here are the logs of failed login with redirect URI being
https://example.com/?redirect_fragment=/asset-library/card-view/
<https://example.com/?redirect_fragment=/asset-library/card-view/>;:
11:37:15,360 DEBUG [org.springframework.boot.context.web.OrderedRequestContextFilter]
(default task-7) Bound request context to thread: HttpServletRequestImpl [ GET
/auth/realms/xxxxxx/protocol/openid-connect/auth ]
11:37:15,361 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-7)
RESTEASY002315: PathInfo: /realms/xxxxxx/protocol/openid-connect/auth
11:37:15,366 DEBUG [org.keycloak.services] (default task-7) AUTHENTICATE
11:37:15,367 DEBUG [org.keycloak.services] (default task-7) AUTHENTICATE ONLY
11:37:15,367 DEBUG [org.keycloak.services] (default task-7) processFlow
11:37:15,368 DEBUG [org.keycloak.services] (default task-7) check execution: auth-cookie
requirement: ALTERNATIVE
11:37:15,368 DEBUG [org.keycloak.services] (default task-7) authenticator: auth-cookie
11:37:15,369 DEBUG [org.keycloak.services] (default task-7) invoke
authenticator.authenticate
11:37:15,371 DEBUG [org.keycloak.services] (default task-7) token active - active: true,
issued-at: 1,461,152,203, not-before: 0
11:37:15,373 DEBUG [org.keycloak.services] (default task-7) authenticator SUCCESS:
auth-cookie
11:37:15,374 DEBUG [org.keycloak.services] (default task-7) check execution: auth-spnego
requirement: DISABLED
11:37:15,374 DEBUG [org.keycloak.services] (default task-7) execution is processed
11:37:15,375 DEBUG [org.keycloak.services] (default task-7) check execution: null
requirement: ALTERNATIVE
11:37:15,375 DEBUG [org.keycloak.services] (default task-7) Skip alternative execution
11:37:15,376 DEBUG [org.keycloak.services] (default task-7) Using full scope for client
11:37:15,377 DEBUG [org.keycloak.events] (default task-7) type=LOGIN, realmId=xxxxxx,
clientId=api, userId=64e2ec92-a6ee-4705-a8b3-adebe9c3c816, ipAddress=172.17.0.1,
auth_method=openid-connect, auth_type=code, response_type=code,
redirect_uri=https://example.com/?redirect_fragment=/asset-library/card-v...
<https://example.com/?redirect_fragment=/asset-library/card-view/>;,
consent=no_consent_required, code_id=a47d3089-699e-4bc5-811c-e4a45655994a,
response_mode=fragment, username=xxxxxx
11:37:15,397 DEBUG [org.keycloak.services] (default task-7) Create login cookie - name:
KEYCLOAK_IDENTITY, path: /auth/realms/xxxxxx, max-age: -1
11:37:15,398 DEBUG [org.keycloak.services] (default task-7) redirectAccessCode: state:
0e2f72bc-14a4-46f8-8169-c55c85a50830
11:37:15,398 DEBUG [org.springframework.boot.context.web.OrderedRequestContextFilter]
(default task-7) Cleared thread-bound request context: HttpServletRequestImpl [ GET
/auth/realms/xxxxxx/protocol/openid-connect/auth ]
11:37:16,148 DEBUG [org.springframework.boot.context.web.OrderedRequestContextFilter]
(default task-13) Bound request context to thread: HttpServletRequestImpl [ POST
/auth/realms/xxxxxx/protocol/openid-connect/token ]
11:37:16,148 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-13)
RESTEASY002315: PathInfo: /realms/xxxxxx/protocol/openid-connect/token
11:37:16,150 DEBUG [org.keycloak.services] (default task-13) AUTHENTICATE CLIENT
11:37:16,150 DEBUG [org.keycloak.services] (default task-13) client authenticator:
client-secret
11:37:16,151 DEBUG [org.keycloak.services] (default task-13) client authenticator SUCCESS:
client-secret
11:37:16,151 DEBUG [org.keycloak.services] (default task-13) Client api authenticated by
client-secret
11:37:16,151 WARN [org.keycloak.events] (default task-13) type=CODE_TO_TOKEN_ERROR,
realmId=xxxxxx, clientId=api, userId=64e2ec92-a6ee-4705-a8b3-adebe9c3c816,
ipAddress=172.17.0.1, error=invalid_code, grant_type=authorization_code,
code_id=a47d3089-699e-4bc5-811c-e4a45655994a, client_auth_method=client-secret
11:37:16,153 DEBUG [org.springframework.boot.context.web.OrderedRequestContextFilter]
(default task-13) Cleared thread-bound request context: HttpServletRequestImpl [ POST
/auth/realms/xxxxxx/protocol/openid-connect/token ]
11:37:17,928 DEBUG
[org.jboss.jca.core.connectionmanager.pool.validator.ConnectionValidator]
(ConnectionValidator) Notifying pools, interval: 30000
11:37:17,928 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(ConnectionValidator) Checking for connection within frequency