[keycloak-user] invalid_grant (Code not valid) error

Philip Lowman philip at yhbt.com
Fri Jul 26 19:31:58 EDT 2019


Hi,

I'm playing around with integrating KeyCloak 6.0.1 with the Tomcat 8 Adapter
<https://www.keycloak.org/docs/latest/securing_apps/index.html#_tomcat_adapter>
(Open ID Connect).

I'm running into a problem where the Tomcat adapter redirects to KeyCloak
just fine, authentication in Keycloak works, and it redirects back to the
application, but subsequently the Tomcat adapter gets a 400 error response
from the Keycloak server trying to turn the Access Code into a Token.

The error returned from Keycloak is:
       {"error":"invalid_grant","error_description":"Code not valid"}

Here's the code that is logging an error.  The error isn't intermittent,
happens on every request.

protected AuthChallenge resolveCode(String code) {
...
try {
  String httpSessionId = this.deployment.getTokenStore() ==
TokenStore.SESSION ? this.reqAuthenticator.changeHttpSessionId(true) :
null;
  tokenResponse =
ServerRequest.invokeAccessCodeToToken(this.deployment, code,
this.strippedOauthParametersRequestUri, httpSessionId);
} catch (HttpFailure var6) {
  log.error("failed to turn code into token");
  log.error("status from server: " + var6.getStatus());

I've grabbed TRACE logs for org.keycloak category on the server and
included them below, but don't see a smoking gun.

I suspect I have something misconfigured somewhere in Keycloak, as this is
my first time configuring this.
Just wondering if anyone has some suggestions for what I should be doing to
troubleshoot this further?

Thanks!


keycloak.json  (effectively copy/paste from KeyCloak Admin UI)

{
  "realm" : "myrealm",
  "auth-server-url" : "http://myhost.example.org:8080/auth",
  "ssl-required" : "external",
  "resource" : "myclient",
  "verify-token-audience" : true,
  "credentials" : {
    "secret" : "a41c8c84-ac43-43ae-bf9a-0241e24ce56f"
  },
  "use-resource-role-mappings": true,
  "confidential-port" : 0
}


keycloak server.log w/org.keyloak at TRACE
            <logger category="org.keycloak">
                <level name="TRACE"/>
            </logger>

2019-07-26 18:11:26,865 TRACE [org.keycloak.events] (default task-1) type=
*LOGIN*, realmId=308af72f-9f89-4fae-a583-b508d07b521a, clientId=myclient,
userId=19c4c859-e062-4528-b176-3a17caf443af, ipAddress=10.192.226.126,
auth_method=openid-connect, auth_type=code, redirect_uri=
http://localhost:7700/myapp/Foo.do, consent=no_consent_required,
code_id=9634b07b-6191-4a09-85b3-507ff9dcead1, username=myuser, requestUri=
http://myhost.example.org:8080/auth/realms/myrealm/login-actions/authenticate?session_code=jPGBXUCBH0K8dRZshxAbngFZYkXN2w3fkQgA0f2Sczg&execution=4ca897a0-89ef-406c-a889-55e71275643e&client_id=myclient&tab_id=SeyomGlfpSQ,
cookies=[KC_RESTART=eyJhbGciOiJIUzI1NiIsInR5cCIgOiAiSldUIiwia2lkIiA6ICIyZjc5NzQyZS1jZTA1LTQ3ZGEtYmFhZS05ZTkwMmMyYWUzYmYifQ.eyJjaWQiOiJXVG5BIiwicHR5Ijoib3BlbmlkLWNvbm5lY3QiLCJydXJpIjoiaHR0cDovL2xvY2FsaG9zdDo3NzAwL3dvcmtmb3JjZS9Ib21lLmRvP2FjdGlvbj1zdGFydCIsImFjdCI6IkFVVEhFTlRJQ0FURSIsIm5vdGVzIjp7InNjb3BlIjoib3BlbmlkIiwiaXNzIjoiaHR0cDovL3VzNGxhdGNhczAwMS51c2Rldi53ZnNhYXMubmV0OjgwODAvYXV0aC9yZWFsbXMvcGxvd21hbiIsInJlc3BvbnNlX3R5cGUiOiJjb2RlIiwiY29kZV9jaGFsbGVuZ2VfbWV0aG9kIjoicGxhaW4iLCJyZWRpcmVjdF91cmkiOiJodHRwOi8vbG9jYWxob3N0Ojc3MDAvd29ya2ZvcmNlL0hvbWUuZG8_YWN0aW9uPXN0YXJ0Iiwic3RhdGUiOiIyYzIwYzM0OC04M2Q0LTQ3YzQtOWZlOS0yZWUzZTE5ZjFjNDMiLCJjbGllbnRfcmVxdWVzdF9wYXJhbV9sb2dpbiI6InRydWUifX0.lol6rrM0GZpLxNY8tbMwPQt8_HBPnDSqHzGKvHU9zeY,
AUTH_SESSION_ID=9634b07b-6191-4a09-85b3-507ff9dcead1.myhost]
2019-07-26 18:11:26,865 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,865 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:26,865 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,865 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:26,865 TRACE [org.keycloak.keys.DefaultKeyManager]
(default task-1) Active key found: realm=myrealm
kid=2f79742e-ce05-47da-baae-9e902c2ae3bf algorithm=HS256 use=SIG
2019-07-26 18:11:26,865 DEBUG
[org.keycloak.services.managers.AuthenticationManager] (default task-1)
Create login cookie - name: KEYCLOAK_IDENTITY, path: /auth/realms/myrealm/,
max-age: -1
2019-07-26 18:11:26,866 DEBUG
[org.keycloak.services.managers.AuthenticationManager] (default task-1)
Expiring remember me cookie
2019-07-26 18:11:26,866 DEBUG
[org.keycloak.services.managers.AuthenticationManager] (default task-1)
Expiring cookie: KEYCLOAK_REMEMBER_ME path: /auth/realms/myrealm/
2019-07-26 18:11:26,866 DEBUG
[org.keycloak.protocol.oidc.OIDCLoginProtocol] (default task-1)
redirectAccessCode: state: 2c20c348-83d4-47c4-9fe9-2ee3e19f1c43
2019-07-26 18:11:26,866 DEBUG
[org.keycloak.models.sessions.infinispan.InfinispanCodeToTokenStoreProviderFactory]
(default task-1) Not having remote stores. Using normal cache
'actionTokens' for single-use cache of code
2019-07-26 18:11:26,866 DEBUG
[org.keycloak.transaction.JtaTransactionWrapper] (default task-1)
JtaTransactionWrapper  commit
2019-07-26 18:11:26,867 DEBUG
[org.keycloak.transaction.JtaTransactionWrapper] (default task-1)
JtaTransactionWrapper end
2019-07-26 18:11:26,867 TRACE
[org.keycloak.connections.jpa.DefaultJpaConnectionProvider] (default
task-1) DefaultJpaConnectionProvider close()
2019-07-26 18:11:26,982 DEBUG
[org.keycloak.transaction.JtaTransactionWrapper] (default task-1) new
JtaTransactionWrapper
2019-07-26 18:11:26,982 DEBUG
[org.keycloak.transaction.JtaTransactionWrapper] (default task-1) was
existing? false
2019-07-26 18:11:26,982 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
realm by name cache hit: myrealm
2019-07-26 18:11:26,982 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
by id cache hit: myrealm
2019-07-26 18:11:26,984 DEBUG
[org.keycloak.authentication.AuthenticationProcessor] (default task-1)
AUTHENTICATE CLIENT
2019-07-26 18:11:26,985 TRACE
[org.keycloak.authentication.ClientAuthenticationFlow] (default task-1)
Using executions for client authentication:
[abb870f0-a067-47db-8ff9-38812ccfadb0,
29a6449f-2624-461d-ae61-a099a4086428, ed974344-8b7c-4ff8-85ea-c61289ef23f0,
1ddbb0e6-5e92-45e6-b8fd-a82ba6b2b0a9]
2019-07-26 18:11:26,985 DEBUG
[org.keycloak.authentication.ClientAuthenticationFlow] (default task-1)
client authenticator: client-secret
2019-07-26 18:11:26,985 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
client by name cache hit: myclient
2019-07-26 18:11:26,985 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
client by id cache hit: myclient
2019-07-26 18:11:26,985 DEBUG
[org.keycloak.authentication.ClientAuthenticationFlow] (default task-1)
client authenticator SUCCESS: client-secret
2019-07-26 18:11:26,985 DEBUG
[org.keycloak.authentication.ClientAuthenticationFlow] (default task-1)
Client myclient authenticated by client-secret
2019-07-26 18:11:26,985 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
by id cache hit: myrealm
2019-07-26 18:11:26,985 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
client by id cache hit: myclient
2019-07-26 18:11:26,985 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
by id cache hit: myrealm
2019-07-26 18:11:26,985 DEBUG
[org.keycloak.models.sessions.infinispan.InfinispanUserSessionProvider]
(default task-1)
getUserSessionWithPredicate(9634b07b-6191-4a09-85b3-507ff9dcead1): found in
local cache
2019-07-26 18:11:26,985 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
client by id cache hit: myclient
2019-07-26 18:11:26,985 TRACE
[org.keycloak.protocol.oidc.utils.OAuth2CodeParser] (default task-1)
Successfully verified code '124e5aba-eb17-4eee-b435-6faf7aaf92ae'. User
session: '9634b07b-6191-4a09-85b3-507ff9dcead1', client:
'd6cce783-5559-48c1-b1b8-7f20d2fcf166'
2019-07-26 18:11:26,985 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,985 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,986 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:26,986 DEBUG
[org.keycloak.protocol.oidc.endpoints.TokenEndpoint] (default task-1)
Adapter Session '562F91F71B1FFDABD7E0EE2761BA03CE-n1' saved in
ClientSession for client 'myclient'. Host is 'mybox'
2019-07-26 18:11:26,986 TRACE
[org.keycloak.connections.jpa.DefaultJpaConnectionProviderFactory] (default
task-1) Create JpaConnectionProvider
2019-07-26 18:11:26,986 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
client by id cache hit: myclient
2019-07-26 18:11:26,987 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,987 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:26,992 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,992 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:26,992 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,992 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:26,992 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:26,993 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:27,021 TRACE [org.keycloak.keys.DefaultKeyManager]
(default task-1) Active key found: realm=myrealm
kid=YWkA3p3uFbmG1gsE_9bUAVCz0K_vZjkU8U4Q-WeN4Do algorithm=RS256 use=SIG
2019-07-26 18:11:27,023 TRACE [org.keycloak.keys.DefaultKeyManager]
(default task-1) Active key found: realm=myrealm
kid=YWkA3p3uFbmG1gsE_9bUAVCz0K_vZjkU8U4Q-WeN4Do algorithm=RS256 use=SIG
2019-07-26 18:11:27,025 TRACE [org.keycloak.keys.DefaultKeyManager]
(default task-1) Active key found: realm=myrealm
kid=2f79742e-ce05-47da-baae-9e902c2ae3bf algorithm=HS256 use=SIG
2019-07-26 18:11:27,025 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:27,025 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:27,025 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
getuserById 19c4c859-e062-4528-b176-3a17caf443af
2019-07-26 18:11:27,025 TRACE
[org.keycloak.models.cache.infinispan.UserCacheSession] (default task-1)
return managedusers
2019-07-26 18:11:27,025 TRACE [org.keycloak.events] (default task-1) type=
*CODE_TO_TOKEN*, realmId=308af72f-9f89-4fae-a583-b508d07b521a,
clientId=myclient, userId=19c4c859-e062-4528-b176-3a17caf443af,
ipAddress=10.192.226.126, client_session_host=mybox,
token_id=0773e6dc-8da1-4241-9fa8-081e95916042,
grant_type=authorization_code, refresh_token_type=Refresh, scope='openid
profile email', client_session_state=562F91F71B1FFDABD7E0EE2761BA03CE-n1,
refresh_token_id=57801953-87a2-4d3e-a4fb-5d91f2ed262f,
code_id=9634b07b-6191-4a09-85b3-507ff9dcead1,
client_auth_method=client-secret, requestUri=
http://myhost.example.org:8080/auth/realms/myrealm/protocol/openid-connect/token,
cookies=[]
2019-07-26 18:11:27,025 TRACE [org.keycloak.services.resources.Cors]
(default task-1) No origin header ignoring
2019-07-26 18:11:27,026 DEBUG
[org.keycloak.transaction.JtaTransactionWrapper] (default task-1)
JtaTransactionWrapper  commit
2019-07-26 18:11:27,026 DEBUG
[org.keycloak.transaction.JtaTransactionWrapper] (default task-1)
JtaTransactionWrapper end
2019-07-26 18:11:27,037 TRACE
[org.keycloak.connections.jpa.DefaultJpaConnectionProvider] (default
task-1) DefaultJpaConnectionProvider close()
2019-07-26 18:11:27,409 DEBUG
[org.keycloak.transaction.JtaTransactionWrapper] (default task-1) new
JtaTransactionWrapper
2019-07-26 18:11:27,409 DEBUG
[org.keycloak.transaction.JtaTransactionWrapper] (default task-1) was
existing? false
2019-07-26 18:11:27,410 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
realm by name cache hit: myrealm
2019-07-26 18:11:27,410 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
by id cache hit: myrealm
2019-07-26 18:11:27,410 TRACE
[org.keycloak.protocol.oidc.endpoints.AuthorizationEndpoint] (default
task-1) Processing @GET request
2019-07-26 18:11:27,410 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
client by name cache hit: myclient
2019-07-26 18:11:27,410 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
client by id cache hit: myclient
2019-07-26 18:11:27,410 DEBUG
[org.keycloak.protocol.oidc.endpoints.AuthorizationEndpoint] (default
task-1) PKCE non-supporting Client
2019-07-26 18:11:27,410 DEBUG
[org.keycloak.services.managers.AuthenticationSessionManager] (default
task-1) Not found AUTH_SESSION_ID cookie
2019-07-26 18:11:27,410 DEBUG
[org.keycloak.services.managers.AuthenticationSessionManager] (default
task-1) Not found AUTH_SESSION_ID cookie
2019-07-26 18:11:27,410 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: ADD on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,410 DEBUG
[org.keycloak.services.managers.AuthenticationSessionManager] (default
task-1) Set AUTH_SESSION_ID cookie with value
93ca18a6-fea5-42d5-bad9-125fd97906af.myhost
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.protocol.AuthorizationEndpointBase] (default task-1) Sent
request to authz endpoint. Created new root authentication session with ID
'93ca18a6-fea5-42d5-bad9-125fd97906af' . Client: myclient . New
authentication session tab ID: uG3knkEjbEE
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
client by id cache hit: myclient
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
client by id cache hit: myclient
2019-07-26 18:11:27,411 TRACE [org.keycloak.keys.DefaultKeyManager]
(default task-1) Active key found: realm=myrealm
kid=2f79742e-ce05-47da-baae-9e902c2ae3bf algorithm=HS256 use=SIG
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.authentication.AuthenticationProcessor] (default task-1)
AUTHENTICATE
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.authentication.AuthenticationProcessor] (default task-1)
AUTHENTICATE ONLY
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
client by id cache hit: myclient
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
processFlow
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
check execution: auth-cookie requirement: ALTERNATIVE
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
authenticator: auth-cookie
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
invoke authenticator.authenticate: auth-cookie
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.services.managers.AuthenticationManager] (default task-1)
Could not find cookie: KEYCLOAK_IDENTITY
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
authenticator ATTEMPTED: auth-cookie
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
check execution: auth-spnego requirement: DISABLED
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
execution is processed
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
check execution: identity-provider-redirector requirement: ALTERNATIVE
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
authenticator: identity-provider-redirector
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
invoke authenticator.authenticate: identity-provider-redirector
2019-07-26 18:11:27,411 TRACE
[org.keycloak.authentication.authenticators.browser.IdentityProviderAuthenticator]
(default task-1) No default provider set or kc_idp_hint query parameter
provided
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
authenticator ATTEMPTED: identity-provider-redirector
2019-07-26 18:11:27,411 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
check execution: null requirement: ALTERNATIVE
2019-07-26 18:11:27,411 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
execution is flow
2019-07-26 18:11:27,412 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
processFlow
2019-07-26 18:11:27,412 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
check execution: auth-username-password-form requirement: REQUIRED
2019-07-26 18:11:27,412 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
authenticator: auth-username-password-form
2019-07-26 18:11:27,412 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
invoke authenticator.authenticate: auth-username-password-form
2019-07-26 18:11:27,412 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,412 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,412 TRACE
[org.keycloak.models.cache.infinispan.RealmCacheSession] (default task-1)
client by id cache hit: myclient
2019-07-26 18:11:27,416 DEBUG
[org.keycloak.authentication.DefaultAuthenticationFlow] (default task-1)
authenticator CHALLENGE: auth-username-password-form
2019-07-26 18:11:27,416 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,416 TRACE
[org.keycloak.models.sessions.infinispan.InfinispanKeycloakTransaction]
(default task-1) Adding cache operation: REPLACE on
93ca18a6-fea5-42d5-bad9-125fd97906af
2019-07-26 18:11:27,416 DEBUG
[org.keycloak.transaction.JtaTransactionWrapper] (default task-1)
JtaTransactionWrapper  commit
2019-07-26 18:11:27,416 DEBUG
[org.keycloak.transaction.JtaTransactionWrapper] (default task-1)
JtaTransactionWrapper end


-- 
Philip Lowman


More information about the keycloak-user mailing list