invalid_code error during OIDC login

[Мартынов Илья]

Hello! I have OIDC client with standard authorization code flow. Sometimes code-to-token request fails with invalid_code. Looks like user session cannot be found in infinispan. Any ideas?

"28-04-2021 15:57:38,806 DEBUG [default task-35] org.keycloak.services.resources.IdentityBrokerService Performing local authentication for user [org.keycloak.models.cache.infinispan.UserAdapter@7d94770f]. " "28-04-2021 15:57:38,808 DEBUG [default task-35] org.keycloak.storage.user.OssUserStorageProvider getUserById: f:f0913d1b-3a6b-421b-8c5b-c3e33aa6edf8:7256 " "28-04-2021 15:57:38,814 DEBUG [default task-35] org.keycloak.locale.DefaultLocaleUpdaterProvider Updating locale cookie to en " "28-04-2021 15:57:38,815 DEBUG [default task-35] org.keycloak.storage.user.OssUserStorageProvider getUserById: f:f0913d1b-3a6b-421b-8c5b-c3e33aa6edf8:7256 " "28-04-2021 15:57:38,825 DEBUG [default task-35] org.keycloak.services.managers.AuthenticationSessionManager Removing authSession 'b351daf6-c19c-415f-9c10-3b79d7b6ded4'. Expire restart cookie: true " "28-04-2021 15:57:38,827 DEBUG [default task-35] org.keycloak.services.util.CookieHelper Could not find cookie KEYCLOAK_SESSION, trying KEYCLOAK_SESSION_LEGACY " "28-04-2021 15:57:38,829 DEBUG [default task-35] org.keycloak.services.managers.AuthenticationManager Create login cookie - name: KEYCLOAK_IDENTITY, path: /auth/realms/sr25/, max-age: -1 " "28-04-2021 15:57:38,830 DEBUG [default task-35] org.keycloak.services.managers.AuthenticationManager Expiring remember me cookie " "28-04-2021 15:57:38,830 DEBUG [default task-35] org.keycloak.services.managers.AuthenticationManager Expiring cookie: KEYCLOAK_REMEMBER_ME path: /auth/realms/sr25/ " "28-04-2021 15:57:38,831 DEBUG [default task-35] org.keycloak.protocol.oidc.OIDCLoginProtocol redirectAccessCode: state: PjhRdC1Lg0PLJ14krJ3jbw== " "28-04-2021 15:57:38,840 DEBUG [default task-35] org.keycloak.events.log.JBossLoggingEventListenerProvider type=LOGIN, realmId=sr25, clientId=arm, userId=f:f0913d1b-3a6b-421b-8c5b-c3e33aa6edf8:7256, ipAddress=80.200.216.219, identity_provider=IMOnline, response_type=code, consent=no_consent_required, identity_provider_identity=00u666504gfIossdg357, code_id=b351daf6-c19c-415f-9c10-3b79d7b6ded4, username=1100005751510255, response_mode=query, authSessionParentId=b351daf6-c19c-415f-9c10-3b79d7b6ded4, authSessionTabId=xayN1QL8sbY " "28-04-2021 15:57:38,900 DEBUG [Timer-2] org.keycloak.services.scheduled.ScheduledTaskRunner Executed scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$1941/0x0000000101a66040 " "28-04-2021 15:57:38,899 DEBUG [Timer-2] org.keycloak.models.sessions.infinispan.changes.sessions.PersisterLastSessionRefreshStore Updating 0 userSessions with lastSessionRefresh: 1619625398 " "28-04-2021 15:57:38,909 DEBUG [default task-29626] org.keycloak.authentication.AuthenticationProcessor AUTHENTICATE CLIENT " "28-04-2021 15:57:38,909 DEBUG [default task-29626] org.keycloak.authentication.ClientAuthenticationFlow client authenticator: client-secret " "28-04-2021 15:57:38,909 DEBUG [default task-29626] org.keycloak.authentication.ClientAuthenticationFlow client authenticator SUCCESS: client-secret " "28-04-2021 15:57:38,910 DEBUG [default task-29626] org.keycloak.authentication.ClientAuthenticationFlow Client arm authenticated by client-secret " "28-04-2021 15:57:38,911 WARN [default task-29626] org.keycloak.events.log.JBossLoggingEventListenerProvider type=CODE_TO_TOKEN_ERROR, realmId=sr25, clientId=arm, userId=null, ipAddress=51.124.54.210, error=invalid_code, grant_type=authorization_code, code_id=b351daf6-c19c-415f-9c10-3b79d7b6ded4, client_auth_method=client-secret "

[Мартынов Илья]

Ok, I've found the root cause. Call for token was scheduled on 2nd keycloak replica and there was no infinispan synchronization between replicas. User session was not found on 2nd replica.