search

Captain-P-Goldfish / scim-for-keycloak

a third party module that extends keycloak by SCIM functionality
BSD 3-Clause "New" or "Revised" License
183 stars 47 forks source link

scim-for-keycloak-kc-18-b1 error: Cannot invoke "javax.persistence.EntityManagerFactory.createEntityManager(javax.persistence.SynchronizationType)" because "emf" is null #59

Closed annasarte closed 1 year ago

annasarte commented 1 year ago

Hello, I have keycloak version 18.0.2. I have installed the scim-for-keycloak-kc-18-b1 plugin per the instructions listed on https://github.com/Captain-P-Goldfish/scim-for-keycloak. (By the way, the readme says the artifact from scim-for-keycloak-server/target is an EAR file but in reality it is a jar file.) When I try to start keycloak after installing the provider, I get an error and keycloak fails to start:

2022-08-17 17:58:35,994 ERROR [org.keycloak.quarkus.runtime.cli.ExecutionExceptionHandler] (main) ERROR: Failed to start server in (development) mode 2022-08-17 17:58:35,994 ERROR [org.keycloak.quarkus.runtime.cli.ExecutionExceptionHandler] (main) ERROR: Cannot invoke "javax.persistence.EntityManagerFactory.createEntityManager(javax.persistence.SynchronizationType)" because "emf" is null

kc.sh show-config output is this:

Current Mode: development Runtime Configuration: kc.cache = local (PersistedConfigSource) kc.config.args = show-config (SysPropConfigSource) kc.db = mysql (PropertiesConfigSource[source=file:/Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/bin/./../conf/keycloak.conf]) kc.db-password = ******* (PropertiesConfigSource[source=file:/Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/bin/./../conf/keycloak.conf]) kc.db-url = jdbc:mysql://localhost:3306/annakeycloak (PropertiesConfigSource[source=file:/Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/bin/./../conf/keycloak.conf]) kc.db-username = root (PropertiesConfigSource[source=file:/Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/bin/./../conf/keycloak.conf]) kc.health-enabled = true (PropertiesConfigSource[source=file:/Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/bin/./../conf/keycloak.conf]) kc.home.dir = ./../ (SysPropConfigSource) kc.http-enabled = false (PropertiesConfigSource[source=jar:file:///Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/lib/lib/main/org.keycloak.keycloak-quarkus-server-18.0.2.jar!/META-INF/keycloak.conf]) kc.http-relative-path = / (PersistedConfigSource) kc.log-console-output = default (PropertiesConfigSource[source=jar:file:///Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/lib/lib/main/org.keycloak.keycloak-quarkus-server-18.0.2.jar!/META-INF/keycloak.conf]) kc.log-file = ./../data/log/keycloak.log (PropertiesConfigSource[source=jar:file:///Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/lib/lib/main/org.keycloak.keycloak-quarkus-server-18.0.2.jar!/META-INF/keycloak.conf]) kc.metrics-enabled = true (PropertiesConfigSource[source=file:/Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/bin/./../conf/keycloak.conf]) kc.profile = dev (PersistedConfigSource) kc.provider.file.scim-for-keycloak-kc-18-b1.jar.last-modified = 1660782036013 (PersistedConfigSource) kc.quarkus-properties-enabled = false (PersistedConfigSource) kc.show.config = none (SysPropConfigSource) kc.version = 18.0.2 (SysPropConfigSource) Any ideas on how I can solve this problem? Thanks in advance.

Captain-P-Goldfish commented 1 year ago

Hi, I am not able to reproduce exactly the same error. But I can reproduce a similiar problem that is related to the keycloaks cache-implementation. Your config uses cache=local this is producing a similiar error on my side. If set to cache=ispn (which is the default) everything works fine here.

annasarte commented 1 year ago

I see. I am using keycloak in development mode for now so I can test this in development. But cache-local is the default for development mode per https://www.keycloak.org/server/caching. Are you able to get this plugin to work in development mode? A colleague told me that he was able to get it to work in dev mode on keycloak v 16 but he has the same issue now with your plugin that we upgraded to v 18.0.2.

annasarte commented 1 year ago

Hello again Pascal. I was able to get my cache configured to be ispn. Here is show-config ( I am not starting in development mode anymore, I am in production mode):

{627}:> ./kc.sh show-config
Current Mode: none
Runtime Configuration:
    kc.cache =  ispn (PersistedConfigSource)
    kc.config.args =  show-config (SysPropConfigSource)
    kc.db =  mysql (PropertiesConfigSource[source=file:/Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/bin/./../conf/keycloak.conf])
    kc.db-password =  ******* (PropertiesConfigSource[source=file:/Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/bin/./../conf/keycloak.conf])
    kc.db-url =  jdbc:mysql://localhost:3306/annakeycloak (PropertiesConfigSource[source=file:/Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/bin/./../conf/keycloak.conf])
    kc.db-username =  root (PropertiesConfigSource[source=file:/Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/bin/./../conf/keycloak.conf])
    kc.health-enabled =  true (PropertiesConfigSource[source=file:/Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/bin/./../conf/keycloak.conf])
    kc.home.dir =  ./../ (SysPropConfigSource)
    kc.hostname =  localhost (PropertiesConfigSource[source=file:/Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/bin/./../conf/keycloak.conf])
    kc.hostname-strict-https =  false (PropertiesConfigSource[source=file:/Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/bin/./../conf/keycloak.conf])
    kc.http-enabled =  true (PropertiesConfigSource[source=file:/Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/bin/./../conf/keycloak.conf])
    kc.http-relative-path =  / (PersistedConfigSource)
    kc.log-console-output =  default (PropertiesConfigSource[source=jar:file:///Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/lib/lib/main/org.keycloak.keycloak-quarkus-server-18.0.2.jar!/META-INF/keycloak.conf])
    kc.log-file =  ./../data/log/keycloak.log (PropertiesConfigSource[source=jar:file:///Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/lib/lib/main/org.keycloak.keycloak-quarkus-server-18.0.2.jar!/META-INF/keycloak.conf])
    kc.metrics-enabled =  true (PropertiesConfigSource[source=file:/Users/annanicotera/Documents/Anna/tools/keycloak-18.0.2/bin/./../conf/keycloak.conf])
    kc.provider.file.scim-for-keycloak-kc-18-b1.jar.last-modified =  1661194649613 (PersistedConfigSource)
    kc.quarkus-properties-enabled =  false (PersistedConfigSource)
    kc.show.config =  none (SysPropConfigSource)
    kc.version =  18.0.2 (SysPropConfigSource)

After building with the provider for this scim-for-keycloak plugin, the error is the same complaining about "emf". being null. Here is the verbose log with stacktrace to see if it will help you identify the issue:

2022-08-22 12:04:37,420 ERROR [org.keycloak.quarkus.runtime.cli.ExecutionExceptionHandler] (main) ERROR: Failed to start server in (production) mode
2022-08-22 12:04:37,420 ERROR [org.keycloak.quarkus.runtime.cli.ExecutionExceptionHandler] (main) Error details:: java.lang.NullPointerException: Cannot invoke "javax.persistence.EntityManagerFactory.createEntityManager(javax.persistence.SynchronizationType)" because "emf" is null
        at org.keycloak.quarkus.runtime.storage.database.jpa.AbstractJpaConnectionProviderFactory.createEntityManager(AbstractJpaConnectionProviderFactory.java:109)
        at org.keycloak.quarkus.runtime.storage.database.jpa.QuarkusJpaConnectionProviderFactory.create(QuarkusJpaConnectionProviderFactory.java:104)
        at org.keycloak.quarkus.runtime.storage.database.jpa.QuarkusJpaConnectionProviderFactory.create(QuarkusJpaConnectionProviderFactory.java:88)
        at org.keycloak.services.DefaultKeycloakSession.getProvider(DefaultKeycloakSession.java:316)
        at org.keycloak.models.jpa.JpaRealmProviderFactory.create(JpaRealmProviderFactory.java:64)
        at org.keycloak.models.jpa.JpaRealmProviderFactory.create(JpaRealmProviderFactory.java:40)
        at org.keycloak.services.DefaultKeycloakSession.getProvider(DefaultKeycloakSession.java:316)
        at org.keycloak.services.DefaultKeycloakSession.realmLocalStorage(DefaultKeycloakSession.java:228)
        at org.keycloak.models.cache.infinispan.RealmCacheSession.getRealmDelegate(RealmCacheSession.java:149)
        at org.keycloak.models.cache.infinispan.RealmCacheSession.getRealmsStream(RealmCacheSession.java:480)
        at de.captaingoldfish.scim.sdk.keycloak.provider.RealmRoleInitializer.setupRealmAccess(RealmRoleInitializer.java:102)
        at org.keycloak.models.utils.KeycloakModelUtils.runJobInTransaction(KeycloakModelUtils.java:242)
        at de.captaingoldfish.scim.sdk.keycloak.provider.RealmRoleInitializer.initializeRoles(RealmRoleInitializer.java:49)
        at de.captaingoldfish.scim.sdk.keycloak.provider.ScimEndpointProviderFactory.postInit(ScimEndpointProviderFactory.java:62)
Captain-P-Goldfish commented 1 year ago

I need to take a deeper look into this issue. And since I do not get the same error as you do I am not sure if this will ultimately resolve your problem if I find a solution for mine.

annasarte commented 1 year ago

Thanks Pascal. Let me know if you need anything else from me. And as I mentioned, maybe there is something that needs to be added to the readme, as I noticed the instructions do not quite match the artifacts (ex: readme mentioned an EAR file but there is only a scim-for-keycloak-server/target/scim-for-keycloak-kc-18-b1.jar).

Captain-P-Goldfish commented 1 year ago

I did not look too deep into the issue because I was pretty much confused that it works if I activate the debug option:

kc.bat --verbose start-dev <- fails with

2022-08-24 18:40:53,271 ERROR [org.keycloak.quarkus.runtime.cli.ExecutionExceptionHandler] (main) ERROR: Failed to start server in (development) mode
2022-08-24 18:40:53,271 ERROR [org.keycloak.quarkus.runtime.cli.ExecutionExceptionHandler] (main) Error details:: java.lang.NullPointerException
    at org.keycloak.quarkus.runtime.storage.database.jpa.AbstractJpaConnectionProviderFactory.createEntityManager(AbstractJpaConnectionProviderFactory.java:109)
    at org.keycloak.quarkus.runtime.storage.database.jpa.QuarkusJpaConnectionProviderFactory.create(QuarkusJpaConnectionProviderFactory.java:104)
    at org.keycloak.quarkus.runtime.storage.database.jpa.QuarkusJpaConnectionProviderFactory.create(QuarkusJpaConnectionProviderFactory.java:88)
    at org.keycloak.services.DefaultKeycloakSession.getProvider(DefaultKeycloakSession.java:316)
    at org.keycloak.models.jpa.JpaRealmProviderFactory.create(JpaRealmProviderFactory.java:64)
    at org.keycloak.models.jpa.JpaRealmProviderFactory.create(JpaRealmProviderFactory.java:40)
    at org.keycloak.services.DefaultKeycloakSession.getProvider(DefaultKeycloakSession.java:316)
    at org.keycloak.services.DefaultKeycloakSession.realmLocalStorage(DefaultKeycloakSession.java:228)
    at org.keycloak.models.cache.infinispan.RealmCacheSession.getRealmDelegate(RealmCacheSession.java:149)
    at org.keycloak.models.cache.infinispan.RealmCacheSession.getRealmsStream(RealmCacheSession.java:480)
    at de.captaingoldfish.scim.sdk.keycloak.provider.RealmRoleInitializer.setupRealmAccess(RealmRoleInitializer.java:102)
    at org.keycloak.models.utils.KeycloakModelUtils.runJobInTransaction(KeycloakModelUtils.java:242)
    at de.captaingoldfish.scim.sdk.keycloak.provider.RealmRoleInitializer.initializeRoles(RealmRoleInitializer.java:49)
    at de.captaingoldfish.scim.sdk.keycloak.provider.ScimEndpointProviderFactory.postInit(ScimEndpointProviderFactory.java:62)
    at org.keycloak.quarkus.runtime.integration.QuarkusKeycloakSessionFactory.init(QuarkusKeycloakSessionFactory.java:96)
    at org.keycloak.quarkus.runtime.integration.jaxrs.QuarkusKeycloakApplication.initializeKeycloakSessionFactory(QuarkusKeycloakApplication.java:68)
    at org.keycloak.quarkus.runtime.integration.jaxrs.QuarkusKeycloakApplication.startup(QuarkusKeycloakApplication.java:49)
    at org.keycloak.quarkus.runtime.integration.QuarkusLifecycleObserver.onStartupEvent(QuarkusLifecycleObserver.java:37)
    at org.keycloak.quarkus.runtime.integration.QuarkusLifecycleObserver_Observer_onStartupEvent_b0e82415b143738dc1f986a5fa4668e83d0a5dea.notify(Unknown Source)
    at io.quarkus.arc.impl.EventImpl$Notifier.notifyObservers(EventImpl.java:320)
    at io.quarkus.arc.impl.EventImpl$Notifier.notify(EventImpl.java:302)
    at io.quarkus.arc.impl.EventImpl.fire(EventImpl.java:73)
    at io.quarkus.arc.runtime.ArcRecorder.fireLifecycleEvent(ArcRecorder.java:128)
    at io.quarkus.arc.runtime.ArcRecorder.handleLifecycleEvents(ArcRecorder.java:97)
    at io.quarkus.deployment.steps.LifecycleEventsBuildStep$startupEvent1144526294.deploy_0(Unknown Source)
    at io.quarkus.deployment.steps.LifecycleEventsBuildStep$startupEvent1144526294.deploy(Unknown Source)
    at io.quarkus.runner.ApplicationImpl.doStart(Unknown Source)
    at io.quarkus.runtime.Application.start(Application.java:101)
    at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:103)
    at io.quarkus.runtime.Quarkus.run(Quarkus.java:67)
    at org.keycloak.quarkus.runtime.KeycloakMain.start(KeycloakMain.java:86)
    at org.keycloak.quarkus.runtime.cli.command.AbstractStartCommand.run(AbstractStartCommand.java:34)
    at picocli.CommandLine.executeUserObject(CommandLine.java:1939)
    at picocli.CommandLine.access$1300(CommandLine.java:145)
    at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2358)
    at picocli.CommandLine$RunLast.handle(CommandLine.java:2352)
    at picocli.CommandLine$RunLast.handle(CommandLine.java:2314)
    at picocli.CommandLine$AbstractParseResultHandler.execute(CommandLine.java:2179)
    at picocli.CommandLine$RunLast.execute(CommandLine.java:2316)
    at picocli.CommandLine.execute(CommandLine.java:2078)
    at org.keycloak.quarkus.runtime.cli.Picocli.parseAndRun(Picocli.java:88)
    at org.keycloak.quarkus.runtime.KeycloakMain.main(KeycloakMain.java:77)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at io.quarkus.bootstrap.runner.QuarkusEntryPoint.doRun(QuarkusEntryPoint.java:60)
    at io.quarkus.bootstrap.runner.QuarkusEntryPoint.main(QuarkusEntryPoint.java:31)

but

kc.bat --verbose start-dev --debug

works like a charm...

Does this fix your problem? If not I need more information in how to reproduce your problem since I am obviously not able to debug it since it works with remote-debugging enabled XD

annasarte commented 1 year ago

I'll look into this once I get back to the office in a couple of weeks. Thank you Pascal.

Sent from Yahoo Mail for iPhone

On Wednesday, August 24, 2022, 9:43 AM, Pascal Knüppel @.***> wrote:

I did not look too deep into the issue because I was pretty much confused that it works if I activate the debug option:

kc.bat --verbose start-dev <- fails with 2022-08-24 18:40:53,271 ERROR [org.keycloak.quarkus.runtime.cli.ExecutionExceptionHandler] (main) ERROR: Failed to start server in (development) mode 2022-08-24 18:40:53,271 ERROR [org.keycloak.quarkus.runtime.cli.ExecutionExceptionHandler] (main) Error details:: java.lang.NullPointerException at org.keycloak.quarkus.runtime.storage.database.jpa.AbstractJpaConnectionProviderFactory.createEntityManager(AbstractJpaConnectionProviderFactory.java:109) at org.keycloak.quarkus.runtime.storage.database.jpa.QuarkusJpaConnectionProviderFactory.create(QuarkusJpaConnectionProviderFactory.java:104) at org.keycloak.quarkus.runtime.storage.database.jpa.QuarkusJpaConnectionProviderFactory.create(QuarkusJpaConnectionProviderFactory.java:88) at org.keycloak.services.DefaultKeycloakSession.getProvider(DefaultKeycloakSession.java:316) at org.keycloak.models.jpa.JpaRealmProviderFactory.create(JpaRealmProviderFactory.java:64) at org.keycloak.models.jpa.JpaRealmProviderFactory.create(JpaRealmProviderFactory.java:40) at org.keycloak.services.DefaultKeycloakSession.getProvider(DefaultKeycloakSession.java:316) at org.keycloak.services.DefaultKeycloakSession.realmLocalStorage(DefaultKeycloakSession.java:228) at org.keycloak.models.cache.infinispan.RealmCacheSession.getRealmDelegate(RealmCacheSession.java:149) at org.keycloak.models.cache.infinispan.RealmCacheSession.getRealmsStream(RealmCacheSession.java:480) at de.captaingoldfish.scim.sdk.keycloak.provider.RealmRoleInitializer.setupRealmAccess(RealmRoleInitializer.java:102) at org.keycloak.models.utils.KeycloakModelUtils.runJobInTransaction(KeycloakModelUtils.java:242) at de.captaingoldfish.scim.sdk.keycloak.provider.RealmRoleInitializer.initializeRoles(RealmRoleInitializer.java:49) at de.captaingoldfish.scim.sdk.keycloak.provider.ScimEndpointProviderFactory.postInit(ScimEndpointProviderFactory.java:62) at org.keycloak.quarkus.runtime.integration.QuarkusKeycloakSessionFactory.init(QuarkusKeycloakSessionFactory.java:96) at org.keycloak.quarkus.runtime.integration.jaxrs.QuarkusKeycloakApplication.initializeKeycloakSessionFactory(QuarkusKeycloakApplication.java:68) at org.keycloak.quarkus.runtime.integration.jaxrs.QuarkusKeycloakApplication.startup(QuarkusKeycloakApplication.java:49) at org.keycloak.quarkus.runtime.integration.QuarkusLifecycleObserver.onStartupEvent(QuarkusLifecycleObserver.java:37) at org.keycloak.quarkus.runtime.integration.QuarkusLifecycleObserver_Observer_onStartupEvent_b0e82415b143738dc1f986a5fa4668e83d0a5dea.notify(Unknown Source) at io.quarkus.arc.impl.EventImpl$Notifier.notifyObservers(EventImpl.java:320) at io.quarkus.arc.impl.EventImpl$Notifier.notify(EventImpl.java:302) at io.quarkus.arc.impl.EventImpl.fire(EventImpl.java:73) at io.quarkus.arc.runtime.ArcRecorder.fireLifecycleEvent(ArcRecorder.java:128) at io.quarkus.arc.runtime.ArcRecorder.handleLifecycleEvents(ArcRecorder.java:97) at io.quarkus.deployment.steps.LifecycleEventsBuildStep$startupEvent1144526294.deploy_0(Unknown Source) at io.quarkus.deployment.steps.LifecycleEventsBuildStep$startupEvent1144526294.deploy(Unknown Source) at io.quarkus.runner.ApplicationImpl.doStart(Unknown Source) at io.quarkus.runtime.Application.start(Application.java:101) at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:103) at io.quarkus.runtime.Quarkus.run(Quarkus.java:67) at org.keycloak.quarkus.runtime.KeycloakMain.start(KeycloakMain.java:86) at org.keycloak.quarkus.runtime.cli.command.AbstractStartCommand.run(AbstractStartCommand.java:34) at picocli.CommandLine.executeUserObject(CommandLine.java:1939) at picocli.CommandLine.access$1300(CommandLine.java:145) at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2358) at picocli.CommandLine$RunLast.handle(CommandLine.java:2352) at picocli.CommandLine$RunLast.handle(CommandLine.java:2314) at picocli.CommandLine$AbstractParseResultHandler.execute(CommandLine.java:2179) at picocli.CommandLine$RunLast.execute(CommandLine.java:2316) at picocli.CommandLine.execute(CommandLine.java:2078) at org.keycloak.quarkus.runtime.cli.Picocli.parseAndRun(Picocli.java:88) at org.keycloak.quarkus.runtime.KeycloakMain.main(KeycloakMain.java:77) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at io.quarkus.bootstrap.runner.QuarkusEntryPoint.doRun(QuarkusEntryPoint.java:60) at io.quarkus.bootstrap.runner.QuarkusEntryPoint.main(QuarkusEntryPoint.java:31)

but

kc.bat --verbose start-dev --debug

works like a charm...

Does this fix your problem? If not I need more information in how to reproduce your problem since I am obviously not able to debug it since it works with remot-debugging enabled XD

— Reply to this email directly, view it on GitHub, or unsubscribe. You are receiving this because you authored the thread.Message ID: @.***>

mkg20001 commented 1 year ago

I had this error also and my solution was to simply restart keycloak over and over (while sleep 1s; do systemctl start keycloak; done) until it started working out of the blue.

It's either a race condition or some one-off migration with a race condition?

Captain-P-Goldfish commented 1 year ago

I tried to add a workaround that did not work either. But I tried it with keycloak 19 and the error does not seem to occur there. The current version kc-18-b1 is compatible with keycloak19

jaredtbates commented 1 year ago

This is an issue for me too, it seems Keycloak just restarts over and over until it eventually works. I'm using Keycloak in Docker with ISPN enabled, with these parameters to start: /opt/keycloak/bin/kc.sh --verbose start --optimized. When I add --debug to the end, it does the same thing.

Edit: switching to local caching without ISPN works

hrstn commented 1 year ago

With Keycloak 19.0.2 I can reproduce the same error when I start with the same parameters "kc.bat --verbose start-dev". 

2022-09-21 08:24:30,143 ERROR [org.keycloak.quarkus.runtime.cli.ExecutionExceptionHandler] (main) Error details:: java.lang.NullPointerException
        at org.keycloak.quarkus.runtime.storage.database.jpa.AbstractJpaConnectionProviderFactory.createEntityManager(AbstractJpaConnectionProviderFactory.java:107)
        at org.keycloak.quarkus.runtime.storage.legacy.database.LegacyJpaConnectionProviderFactory.create(LegacyJpaConnectionProviderFactory.java:81)
        at org.keycloak.quarkus.runtime.storage.legacy.database.LegacyJpaConnectionProviderFactory.create(LegacyJpaConnectionProviderFactory.java:65)
        at org.keycloak.services.DefaultKeycloakSession.getProvider(DefaultKeycloakSession.java:270)
        at org.keycloak.models.jpa.JpaRealmProviderFactory.create(JpaRealmProviderFactory.java:64)
        at org.keycloak.models.jpa.JpaRealmProviderFactory.create(JpaRealmProviderFactory.java:40)
        at org.keycloak.services.DefaultKeycloakSession.getProvider(DefaultKeycloakSession.java:270)
        at org.keycloak.models.cache.infinispan.RealmCacheSession.getRealmDelegate(RealmCacheSession.java:153)
        at org.keycloak.models.cache.infinispan.RealmCacheSession.getRealmsStream(RealmCacheSession.java:484)
        at de.captaingoldfish.scim.sdk.keycloak.provider.RealmRoleInitializer.setupRealmAccess(RealmRoleInitializer.java:102)
        at org.keycloak.models.utils.KeycloakModelUtils.runJobInTransaction(KeycloakModelUtils.java:250)
        at de.captaingoldfish.scim.sdk.keycloak.provider.RealmRoleInitializer.initializeRoles(RealmRoleInitializer.java:49)
        at de.captaingoldfish.scim.sdk.keycloak.provider.ScimEndpointProviderFactory.postInit(ScimEndpointProviderFactory.java:62)
        at org.keycloak.quarkus.runtime.integration.QuarkusKeycloakSessionFactory.init(QuarkusKeycloakSessionFactory.java:96)
        at org.keycloak.quarkus.runtime.integration.jaxrs.QuarkusKeycloakApplication.startup(QuarkusKeycloakApplication.java:42)
        at org.keycloak.quarkus.runtime.integration.QuarkusLifecycleObserver.onStartupEvent(QuarkusLifecycleObserver.java:37)
        at org.keycloak.quarkus.runtime.integration.QuarkusLifecycleObserver_Observer_onStartupEvent_b0e82415b143738dc1f986a5fa4668e83d0a5dea.notify(Unknown Source)
        at io.quarkus.arc.impl.EventImpl$Notifier.notifyObservers(EventImpl.java:320)
        at io.quarkus.arc.impl.EventImpl$Notifier.notify(EventImpl.java:302)
        at io.quarkus.arc.impl.EventImpl.fire(EventImpl.java:73)
        at io.quarkus.arc.runtime.ArcRecorder.fireLifecycleEvent(ArcRecorder.java:128)
        at io.quarkus.arc.runtime.ArcRecorder.handleLifecycleEvents(ArcRecorder.java:97)
        at io.quarkus.deployment.steps.LifecycleEventsBuildStep$startupEvent1144526294.deploy_0(Unknown Source)
        at io.quarkus.deployment.steps.LifecycleEventsBuildStep$startupEvent1144526294.deploy(Unknown Source)
        at io.quarkus.runner.ApplicationImpl.doStart(Unknown Source)
        at io.quarkus.runtime.Application.start(Application.java:101)
        at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:103)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:67)
        at org.keycloak.quarkus.runtime.KeycloakMain.start(KeycloakMain.java:103)
        at org.keycloak.quarkus.runtime.cli.command.AbstractStartCommand.run(AbstractStartCommand.java:37)
        at picocli.CommandLine.executeUserObject(CommandLine.java:1939)
        at picocli.CommandLine.access$1300(CommandLine.java:145)
        at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2358)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2352)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2314)
        at picocli.CommandLine$AbstractParseResultHandler.execute(CommandLine.java:2179)
        at picocli.CommandLine$RunLast.execute(CommandLine.java:2316)
        at picocli.CommandLine.execute(CommandLine.java:2078)
        at org.keycloak.quarkus.runtime.cli.Picocli.parseAndRun(Picocli.java:93)
        at org.keycloak.quarkus.runtime.KeycloakMain.main(KeycloakMain.java:89)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at io.quarkus.bootstrap.runner.QuarkusEntryPoint.doRun(QuarkusEntryPoint.java:60)
        at io.quarkus.bootstrap.runner.QuarkusEntryPoint.main(QuarkusEntryPoint.java:31)

NOTE: it seems to help to set "transaction-xa-enabled=false" (more start attempts are successful) but does not solve the problem completely.

On "transaction-xa-enabled=false" it crashes in the same class on line 109, but less often

        if (xaEnabled) {
            entityManager = PersistenceExceptionConverter.create(session, emf.createEntityManager(SynchronizationType.SYNCHRONIZED));
        } else {
            entityManager = PersistenceExceptionConverter.create(session, emf.createEntityManager());
        }
Captain-P-Goldfish commented 1 year ago

cannot confirm this... tested several times with keycloak 19.0.1 and keycloak 19.0.2.

using mysql:8 as database. Which one do you use?

jaredtbates commented 1 year ago

We use MySQL as well (specifically, AWS Aurora MySQL). Also using 19.0.1 right now. Seems like it might be a race condition of some kind but I'm not positive.

hrstn commented 1 year ago

We did test with postgresql, but i will test it with mysql on monday. but yes seems like a race condition.

Captain-P-Goldfish commented 1 year ago

I was able to provoke this problem. But it is as you say pretty unreliable. I tried to place a retry counter around the execution of the transaction but this does not solve the problem either. This needs to be reported in keycloak.

All I can do now is putting a try-catch block around it so that the startup will not fail. This will make problems for initial setups but not for already existing setups.

I opened a bug-report at keycloak: https://github.com/keycloak/keycloak/issues/14570

I will later add a new release that ignores the error and does not prevent the startup anymore

Captain-P-Goldfish commented 1 year ago

Alright new release is out. The error will be ignored from now on since it has no important impact. The error message does now also print a url to the wiki of this repository that explains what is not happening anymore and how to fix it if needed. I would guess that almost everyone can simply ignore this error.