Hello I am trying to implement an integration with an Apex application and users cant login the second time when there is already a session of the user in keycloak, its crashing but if I add the prompt parameter (which is optional) to “login” or “consent” it works.
In the browser I have a 502 to the following request. (its a 502 because its behind a nginx proxy and the keycloak service crash but I cant find an error in the logs). Everything is in a dev environment. What is going on? Any idea? suggestion? Any link that may help me. Thanks
Request:
https://test.com/realms/portal/protocol/openid-connect/auth?response_type=code&client_id=APEX-TEST&scope=openid+profile+email+phone&redirect_uri=https://g4d097.us-ashburn-1.oraclecloudapps.com/ords/apex_authentication.callback&state=7Wrh6fZF48FeZcvbdwLsTrSmjEqMfSYQIyhI1RS1HueRbXmRrSu7o4c7P5nax68a1llPur8XC8b_pDDX0tDjn9hMRHlQl_S88d_0HhlyvrOXcdDjtgS7rLjEadc_FEH78xgYy42DGsSw9EJ2uIXhzdYH5iLrYi4hHe1wPYFRjDtT1rmuQLSS3OBIYUp1ECYHGHvgK21Hjxqmc6qkp6ZWDw
Expected answer: redirect to
https://g4d097.us-ashburn-1.oraclecloudapps.com/ords/apex_authentication.callback?state=7Wrh6fZF48FeZcvbdwLsTrSmjEqMfSYQIyhI1RS1HueRbXmRrSu7o4c7P5nax68a1llPur8XC8b_pDDX0tDjn9hMRHlQl_S88d_0HhlyvrOXcdDjtgS7rLjEadc_FEH78xgYy42DGsSw9EJ2uIXhzdYH5iLrYi4hHe1wPYFRjDtT1rmuQLSS3OBIYUp1ECYHGHvgK21Hjxqmc6qkp6ZWDw&session_state=c55238cf-c62b-4f6e-ba2d-021dcff1f7b4&code=92817552-0849-4da5-b721-7cda7402c433.c55238cf-c62b-4f6e-ba2d-021dcff1f7b4.04a75b69-e041-46ea-b957-2b98dc6c5b4e
Logs:
2023-11-15 12:43:20,149 DEBUG [io.quarkus.vertx.http.runtime.ForwardedParser] (executor-thread-235) Recalculated absoluteURI to https://test.com/realms/portal/protocol/openid-connect/auth?response_type=code&client_id=APEX-TEST&scope=openid+profile+email+phone&redirect_uri=https ://g4d097.us-ashburn-1.oraclecloudapps.com/ords/apex_authentication.callback&state=7Wrh6fZF48FeZcvbdwLsTrSmjEqMfSYQIyhI1RS1HueRbXmRrSu7o4c7P5nax68a1llPur8XC8b_pDDX0tDjn9hMRHlQl_S88d_0HhlyvrOXcdDjtgS7rLjEadc_FEH78xgYy42DGsSw9EJ2uIXhzdYH5iLrYi4hHe1wPYFRjDtT1rmuQLSS3OBIYUp1ECYHGHvgK21Hjxqmc6qkp6ZWDw
2023-11-15 12:43:20,150 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (executor-thread-235) `hibernate.connection.provider_disables_autocommit` was enabled. This setting should only be enabled when you are certain that the Connections given to Hibernate by the ConnectionProvider have auto-commit disabled. Enabling this setting when the Connections do not have auto-commit disabled will lead to Hibernate executing SQL operations outside of any JDBC/SQL transaction.
2023-11-15 12:43:20,150 DEBUG [org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl] (executor-thread-235) Hibernate RegisteredSynchronization successfully registered with JTA platform
2023-11-15 12:43:20,151 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-235) new JtaTransactionWrapper
2023-11-15 12:43:20,151 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-235) was existing? true
2023-11-15 12:43:20,151 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (executor-thread-235) `hibernate.connection.provider_disables_autocommit` was enabled. This setting should only be enabled when you are certain that the Connections given to Hibernate by the ConnectionProvider have auto-commit disabled. Enabling this setting when the Connections do not have auto-commit disabled will lead to Hibernate executing SQL operations outside of any JDBC/SQL transaction.
2023-11-15 12:43:20,151 DEBUG [org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl] (executor-thread-235) Hibernate RegisteredSynchronization successfully registered with JTA platform
2023-11-15 12:43:20,153 DEBUG [org.keycloak.protocol.oidc.endpoints.AuthorizationEndpointChecker] (executor-thread-235) PKCE non-supporting Client
2023-11-15 12:43:20,153 DEBUG [org.keycloak.services.util.CookieHelper] (executor-thread-235) AUTH_SESSION_ID cookie found in the request header
2023-11-15 12:43:20,153 DEBUG [org.keycloak.services.util.CookieHelper] (executor-thread-235) AUTH_SESSION_ID cookie found in the cookie field
2023-11-15 12:43:20,153 DEBUG [org.keycloak.services.util.CookieHelper] (executor-thread-235) AUTH_SESSION_ID cookie found in the request header
2023-11-15 12:43:20,153 DEBUG [org.keycloak.services.util.CookieHelper] (executor-thread-235) AUTH_SESSION_ID cookie found in the cookie field
2023-11-15 12:43:20,155 DEBUG [org.keycloak.services.managers.AuthenticationSessionManager] (executor-thread-235) Found AUTH_SESSION_ID cookie with value fb603645-63ff-434b-b75a-8f588059ac0d
2023-11-15 12:43:20,155 DEBUG [org.keycloak.models.sessions.infinispan.InfinispanUserSessionProvider] (executor-thread-235) getUserSessionWithPredicate(fb603645-63ff-434b-b75a-8f588059ac0d): remote cache not available
2023-11-15 12:43:20,156 DEBUG [org.keycloak.protocol.AuthorizationEndpointBase] (executor-thread-235) Sent request to authz endpoint. We don't have root authentication session with ID 'fb603645-63ff-434b-b75a-8f588059ac0d' but we have userSession.Re-created root authentication session with same ID. Client is: APEX-TEST . New authentication session tab ID: HmY_mbtKY28
2023-11-15 12:43:20,157 DEBUG [org.keycloak.authentication.AuthenticationProcessor] (executor-thread-235) AUTHENTICATE
2023-11-15 12:43:20,157 DEBUG [org.keycloak.authentication.AuthenticationProcessor] (executor-thread-235) AUTHENTICATE ONLY
2023-11-15 12:43:20,157 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (executor-thread-235) processFlow: browser
2023-11-15 12:43:20,158 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (executor-thread-235) check execution: 'auth-cookie', requirement: 'ALTERNATIVE'
2023-11-15 12:43:20,158 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (executor-thread-235) authenticator: auth-cookie
2023-11-15 12:43:20,158 DEBUG [org.keycloak.authentication.AuthenticationSelectionResolver] (executor-thread-235) Going through the flow 'browser' for adding executions
2023-11-15 12:43:20,158 DEBUG [org.keycloak.authentication.AuthenticationSelectionResolver] (executor-thread-235) Going through the flow 'forms' for adding executions
2023-11-15 12:43:20,158 DEBUG [org.keycloak.authentication.AuthenticationSelectionResolver] (executor-thread-235) Selections when trying execution 'auth-cookie' : [ authSelection - auth-cookie, authSelection - identity-provider-redirector, authSelection - auth-username-password-form]
2023-11-15 12:43:20,158 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (executor-thread-235) invoke authenticator.authenticate: auth-cookie
2023-11-15 12:43:20,159 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (executor-thread-235) authenticator SUCCESS: auth-cookie
2023-11-15 12:43:20,159 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (executor-thread-235) Authentication successful of the top flow 'browser'
2023-11-15 12:43:20,160 DEBUG [org.keycloak.services.managers.AuthenticationSessionManager] (executor-thread-235) Removing authSession 'fb603645-63ff-434b-b75a-8f588059ac0d'. Expire restart cookie: true
2023-11-15 12:43:20,162 DEBUG [org.hibernate.event.internal.AbstractSaveEventListener] (executor-thread-235) Generated identifier: ca70b1ff-8872-4159-8d95-e8b2ec811ecd, using strategy: org.hibernate.id.Assigned
2023-11-15 12:43:20,164 DEBUG [org.keycloak.services.managers.AuthenticationManager] (executor-thread-235) Create login cookie - name: KEYCLOAK_IDENTITY, path: /realms/portal/, max-age: -1
2023-11-15 12:43:20,164 DEBUG [org.keycloak.services.managers.AuthenticationManager] (executor-thread-235) Expiring remember me cookie
2023-11-15 12:43:20,164 DEBUG [org.keycloak.services.managers.AuthenticationManager] (executor-thread-235) Expiring cookie: KEYCLOAK_REMEMBER_ME path: /realms/portal/
2023-11-15 12:43:20,165 DEBUG [org.keycloak.protocol.oidc.OIDCLoginProtocol] (executor-thread-235) redirectAccessCode: state: 7Wrh6fZF48FeZcvbdwLsTrSmjEqMfSYQIyhI1RS1HueRbXmRrSu7o4c7P5nax68a1llPur8XC8b_pDDX0tDjn9hMRHlQl_S88d_0HhlyvrOXcdDjtgS7rLjEadc_FEH78xgYy42DGsSw9EJ2uIXhzdYH5iLrYi4hHe1wPYFRjDtT1rmuQLSS3OBIYUp1ECYHGHvgK21Hjxqmc6qkp6ZWDw
2023-11-15 12:43:20,165 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-235) JtaTransactionWrapper commit
2023-11-15 12:43:20,165 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Brute Force Protector) new JtaTransactionWrapper
2023-11-15 12:43:20,165 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (executor-thread-235) Processing flush-time cascades
2023-11-15 12:43:20,165 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Brute Force Protector) was existing? false
2023-11-15 12:43:20,165 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (executor-thread-235) Dirty checking collections
2023-11-15 12:43:20,165 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (executor-thread-235) Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
2023-11-15 12:43:20,165 DEBUG [org.keycloak.services.managers.DefaultBruteForceProtector] (Brute Force Protector) user myuser@gmail.com successfully logged in, clearing all failures
2023-11-15 12:43:20,165 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (executor-thread-235) Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2023-11-15 12:43:20,165 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Brute Force Protector) JtaTransactionWrapper commit
2023-11-15 12:43:20,165 DEBUG [org.hibernate.internal.util.EntityPrinter] (executor-thread-235) Listing entities:
2023-11-15 12:43:20,165 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Brute Force Protector) JtaTransactionWrapper end
2023-11-15 12:43:20,165 DEBUG [org.hibernate.internal.util.EntityPrinter] (executor-thread-235) org.keycloak.events.jpa.EventEntity{clientId=APEX-TEST, realmId=9ed73d03-81b4-4ded-ba2c-97693110d411, ipAddress=199.199.199.199, id=ca70b1ff-8872-4159-8d95-e8b2ec811ecd, sessionId=fb603645-63ff-434b-b75a-8f588059ac0d, time=1700063000161, error=null, type=LOGIN,
userId=664f1c85-5c19-48dc-98e6-bdc2e7e54ba4, detailsJson={"auth_method":"openid-connect","auth_type":"code","response_type":"code","redirect_uri":"https://g4d097.us-ashburn-1.oraclecloudapps.com/ords/apex_authentication.callback","consent":"no_consent_required","code_id":"fb603645-63ff-434b-b75a-8f588059ac0d","response_mode":"query","username":"myuser@gmail.com"}}
2023-11-15 12:43:20,166 DEBUG [org.hibernate.SQL] (executor-thread-235) insert into EVENT_ENTITY (CLIENT_ID, DETAILS_JSON, ERROR, IP_ADDRESS, REALM_ID, SESSION_ID, EVENT_TIME, TYPE, USER_ID, ID) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2023-11-15 12:43:20,166 DEBUG [org.mariadb.jdbc.client.impl.StandardClient] (executor-thread-235) execute query: set autocommit=0
2023-11-15 12:43:20,169 DEBUG [org.mariadb.jdbc.message.server.OkPacket] (executor-thread-235) System variable change: autocommit = OFF
2023-11-15 12:43:20,169 DEBUG [org.mariadb.jdbc.client.impl.StandardClient] (executor-thread-235) execute query: XA START 0x00000000000000000000FFFFC0A8824A00008E3F65539891000066EC717561726B7573,0x00000000000000000000FFFFC0A8824A00008E3F65539891000066F00000000000000000,0x20005
2023-11-15 12:43:20,169 DEBUG [org.mariadb.jdbc.client.impl.StandardClient] (executor-thread-235) execute query: insert into EVENT_ENTITY (CLIENT_ID, DETAILS_JSON, ERROR, IP_ADDRESS, REALM_ID, SESSION_ID, EVENT_TIME, TYPE, USER_ID, ID) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2023-11-15 12:43:20,173 DEBUG [org.hibernate.engine.transaction.internal.TransactionImpl] (executor-thread-235) On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2023-11-15 12:43:20,174 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (executor-thread-235) Initiating JDBC connection release from beforeTransactionCompletion
2023-11-15 12:43:20,174 DEBUG [org.mariadb.jdbc.client.impl.StandardClient] (executor-thread-235) execute query: XA END 0x00000000000000000000FFFFC0A8824A00008E3F65539891000066EC717561726B7573,0x00000000000000000000FFFFC0A8824A00008E3F65539891000066F00000000000000000,0x20005
2023-11-15 12:43:20,174 DEBUG [org.mariadb.jdbc.client.impl.StandardClient] (executor-thread-235) execute query: XA COMMIT 0x00000000000000000000FFFFC0A8824A00008E3F65539891000066EC717561726B7573,0x00000000000000000000FFFFC0A8824A00008E3F65539891000066F00000000000000000,0x20005 ONE PHASE
2023-11-15 12:43:20,177 DEBUG [org.mariadb.jdbc.client.impl.StandardClient] (executor-thread-235) execute query: set autocommit=1
2023-11-15 12:43:20,177 DEBUG [org.mariadb.jdbc.message.server.OkPacket] (executor-thread-235) System variable change: autocommit = ON
2023-11-15 12:43:20,177 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (executor-thread-235) Initiating JDBC connection release from afterTransaction
2023-11-15 12:43:20,178 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-235) JtaTransactionWrapper end
2023-11-15 12:43:20,178 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-235) JtaTransactionWrapper resuming suspended
2023-11-15 12:43:20,178 DEBUG [org.keycloak.events] (executor-thread-235) type=LOGIN, realmId=9ed73d03-81b4-4ded-ba2c-97693110d411, clientId=APEX-TEST, userId=664f1c85-5c19-48dc-98e6-bdc2e7e54ba4, ipAddress=192.199.199.199, auth_method=openid-connect, auth_type=code, response_type=code, redirect_uri=https://g4d097.us-ashburn-1.oraclecloudapps.com/ords/apex_authentication.callback, consent=no_consent_required, code_id=fb603645-63ff-434b-b75a-8f588059ac0d, response_mode=query, username=myuser@gmail.com, authSessionParentId=fb603645-63ff-434b-b75a-8f588059ac0d, authSessionTabId=HmY_mbtKY28
2023-11-15 12:43:20,179 DEBUG [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (executor-thread-235) HHH000420: Closing un-released batch
2023-11-15 12:43:20,180 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-235) JtaTransactionWrapper commit
2023-11-15 12:43:20,180 DEBUG [org.hibernate.engine.transaction.internal.TransactionImpl] (executor-thread-235) On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2023-11-15 12:43:20,180 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (executor-thread-235) Initiating JDBC connection release from beforeTransactionCompletion
2023-11-15 12:43:20,180 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (executor-thread-235) Initiating JDBC connection release from afterTransaction
2023-11-15 12:43:20,180 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-235) JtaTransactionWrapper end