Have a server fully working on version 18 using MSSQL database and trying to upgrade to 19.0.2 but it’s getting errors. This is my first upgrade, so tried following the directions, which seem simple enough, but on first start I get errors when its trying to update the database. I can see its connecting to the database and running commands, so unsure what is failing.
Not sure if there are any other steps I need to take. I tried without the --spi-connections-jpa-default-migration-strategy=update parameter and with --spi-connections-jpa-default-migration-strategy=manual parameter and anything I tried resulted in similar errors.
Also tried to reset things by running /opt/keycloak/bin/kc.sh build --db=mssql --transaction-xa-enabled=false and it didn’t seem to make any difference.
This is what I get:
# /opt/keycloak/bin/kc.sh start --spi-connections-jpa-default-migration-strategy=update
2022-09-22 18:47:24,163 INFO [org.keycloak.quarkus.runtime.hostname.DefaultHostnameProvider] (main) Hostname settings: Base URL: <unset>, Hostname: login.domain.net, Strict HTTPS: true, Path: <request>, Strict BackChannel: false, Admin URL: <unset>, Admin: <request>, Port: -1, Proxied: false
2022-09-22 18:47:25,824 INFO [org.keycloak.common.crypto.CryptoIntegration] (main) Detected crypto provider: org.keycloak.crypto.def.DefaultCryptoProvider
2022-09-22 18:47:28,514 WARN [org.infinispan.CONFIG] (keycloak-cache-init) ISPN000569: Unable to persist Infinispan internal caches as no global state enabled
2022-09-22 18:47:28,530 WARN [org.infinispan.PERSISTENCE] (keycloak-cache-init) ISPN000554: jboss-marshalling is deprecated and planned for removal
2022-09-22 18:47:28,591 INFO [org.infinispan.CONTAINER] (keycloak-cache-init) ISPN000556: Starting user marshaller 'org.infinispan.jboss.marshalling.core.JBossUserMarshaller'
2022-09-22 18:47:29,085 INFO [org.infinispan.CONTAINER] (keycloak-cache-init) ISPN000128: Infinispan version: Infinispan 'Triskaidekaphobia' 13.0.9.Final
2022-09-22 18:47:29,303 INFO [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000078: Starting JGroups channel `ISPN`
2022-09-22 18:47:29,304 INFO [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000088: Unable to use any JGroups configuration mechanisms provided in properties {}. Using default JGroups configuration!
2022-09-22 18:47:29,412 WARN [org.jgroups.protocols.UDP] (keycloak-cache-init) JGRP000015: the send buffer of socket MulticastSocket was set to 1.00MB, but the OS only allocated 212.99KB
2022-09-22 18:47:29,412 WARN [org.jgroups.protocols.UDP] (keycloak-cache-init) JGRP000015: the receive buffer of socket MulticastSocket was set to 20.00MB, but the OS only allocated 212.99KB
2022-09-22 18:47:29,413 WARN [org.jgroups.protocols.UDP] (keycloak-cache-init) JGRP000015: the send buffer of socket MulticastSocket was set to 1.00MB, but the OS only allocated 212.99KB
2022-09-22 18:47:29,413 WARN [org.jgroups.protocols.UDP] (keycloak-cache-init) JGRP000015: the receive buffer of socket MulticastSocket was set to 25.00MB, but the OS only allocated 212.99KB
2022-09-22 18:47:31,429 INFO [org.jgroups.protocols.pbcast.GMS] (keycloak-cache-init) qbkey01-61047: no members discovered after 2003 ms: creating cluster as coordinator
2022-09-22 18:47:31,440 INFO [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000094: Received new cluster view for channel ISPN: [qbkey01-61047|0] (1) [qbkey01-61047]
2022-09-22 18:47:31,447 INFO [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000079: Channel `ISPN` local address is `qbkey01-61047`, physical addresses are `[192.168.210.90:33645]`
2022-09-22 18:47:32,273 INFO [org.keycloak.connections.infinispan.DefaultInfinispanConnectionProviderFactory] (main) Node name: qbkey01-61047, Site name: null
2022-09-22 18:47:36,983 INFO [org.keycloak.quarkus.runtime.storage.legacy.liquibase.QuarkusJpaUpdaterProvider] (main) Updating database. Using changelog META-INF/jpa-changelog-master.xml
2022-09-22 18:47:38,182 WARN [com.arjuna.ats.jta] (main) ARJUNA016061: TransactionImple.enlistResource - XAResource.start returned: XAException.XAER_RMERR for < formatId=131077, gtrid_length=35, bqual_length=36, tx_uid=0:ffff7f000101:a423:632cadc9:0, node_name=quarkus, branch_uid=0:ffff7f000101:a423:632cadc9:3f, subordinatenodename=null, eis_name=0 >: javax.transaction.xa.XAException: com.microsoft.sqlserver.jdbc.SQLServerException: Failed to create the XA control connection. Error: "The connection is closed."
at com.microsoft.sqlserver.jdbc.SQLServerXAResource.DTC_XA_Interface(SQLServerXAResource.java:738)
at com.microsoft.sqlserver.jdbc.SQLServerXAResource.start(SQLServerXAResource.java:772)
at io.agroal.narayana.BaseXAResource.start(BaseXAResource.java:150)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:661)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:422)
at io.agroal.narayana.NarayanaTransactionIntegration.associate(NarayanaTransactionIntegration.java:93)
at io.agroal.pool.ConnectionPool.getConnection(ConnectionPool.java:245)
at io.agroal.pool.DataSource.getConnection(DataSource.java:86)
at io.quarkus.hibernate.orm.runtime.customized.QuarkusConnectionProvider.getConnection(QuarkusConnectionProvider.java:23)
at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:38)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:108)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:138)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:50)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:149)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:176)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:151)
at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:2122)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2059)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2037)
at org.hibernate.loader.Loader.doQuery(Loader.java:956)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:357)
at org.hibernate.loader.Loader.doList(Loader.java:2868)
at org.hibernate.loader.Loader.doList(Loader.java:2850)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2682)
at org.hibernate.loader.Loader.list(Loader.java:2677)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:540)
at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:400)
at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:219)
at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1454)
at org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1649)
at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1617)
at org.hibernate.query.Query.getResultList(Query.java:165)
at org.keycloak.models.jpa.MigrationModelAdapter.init(MigrationModelAdapter.java:59)
at org.keycloak.models.jpa.MigrationModelAdapter.<init>(MigrationModelAdapter.java:42)
at org.keycloak.models.jpa.JpaRealmProvider.getMigrationModel(JpaRealmProvider.java:93)
at org.keycloak.storage.datastore.LegacyMigrationManager.migrate(LegacyMigrationManager.java:119)
at org.keycloak.migration.MigrationModelManager.migrate(MigrationModelManager.java:33)
at org.keycloak.quarkus.runtime.storage.legacy.database.LegacyJpaConnectionProviderFactory.migrateModel(LegacyJpaConnectionProviderFactory.java:219)
at org.keycloak.quarkus.runtime.storage.legacy.database.LegacyJpaConnectionProviderFactory.initSchema(LegacyJpaConnectionProviderFactory.java:213)
at org.keycloak.models.utils.KeycloakModelUtils.runJobInTransaction(KeycloakModelUtils.java:250)
at org.keycloak.quarkus.runtime.storage.legacy.database.LegacyJpaConnectionProviderFactory.postInit(LegacyJpaConnectionProviderFactory.java:138)
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)
2022-09-22 18:47:38,194 WARN [com.arjuna.ats.jta] (main) ARJUNA016138: Failed to enlist XA resource io.agroal.narayana.BaseXAResource@3220833f: javax.transaction.SystemException: TransactionImple.enlistResource - XAResource.start ARJUNA016054: could not register transaction: < formatId=131077, gtrid_length=35, bqual_length=36, tx_uid=0:ffff7f000101:a423:632cadc9:0, node_name=quarkus, branch_uid=0:ffff7f000101:a423:632cadc9:3f, subordinatenodename=null, eis_name=0 >
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:714)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:422)
at io.agroal.narayana.NarayanaTransactionIntegration.associate(NarayanaTransactionIntegration.java:93)
at io.agroal.pool.ConnectionPool.getConnection(ConnectionPool.java:245)
at io.agroal.pool.DataSource.getConnection(DataSource.java:86)
....(stack cut off so post will fit)
2022-09-22 18:47:38,344 WARN [io.agroal.pool] (main) Datasource '<default>': Closing open connection after completion
2022-09-22 18:47:38,583 WARN [com.arjuna.ats.jta] (main) ARJUNA016061: TransactionImple.enlistResource - XAResource.start returned: XAException.XAER_RMERR for < formatId=131077, gtrid_length=35, bqual_length=36, tx_uid=0:ffff7f000101:a423:632cadc9:42, node_name=quarkus, branch_uid=0:ffff7f000101:a423:632cadc9:81, subordinatenodename=null, eis_name=0 >: javax.transaction.xa.XAException: com.microsoft.sqlserver.jdbc.SQLServerException: Failed to create the XA control connection. Error: "The connection is closed."
at com.microsoft.sqlserver.jdbc.SQLServerXAResource.DTC_XA_Interface(SQLServerXAResource.java:738)
at com.microsoft.sqlserver.jdbc.SQLServerXAResource.start(SQLServerXAResource.java:772)
at io.agroal.narayana.BaseXAResource.start(BaseXAResource.java:150)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:661)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:422)
at io.agroal.narayana.NarayanaTransactionIntegration.associate(NarayanaTransactionIntegration.java:93)
at io.agroal.pool.ConnectionPool.getConnection(ConnectionPool.java:245)
at io.agroal.pool.DataSource.getConnection(DataSource.java:86)
....(stack cut off so post will fit)
2022-09-22 18:47:38,584 WARN [com.arjuna.ats.jta] (main) ARJUNA016138: Failed to enlist XA resource io.agroal.narayana.BaseXAResource@6158113e: javax.transaction.SystemException: TransactionImple.enlistResource - XAResource.start ARJUNA016054: could not register transaction: < formatId=131077, gtrid_length=35, bqual_length=36, tx_uid=0:ffff7f000101:a423:632cadc9:42, node_name=quarkus, branch_uid=0:ffff7f000101:a423:632cadc9:81, subordinatenodename=null, eis_name=0 >
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:714)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:422)
at io.agroal.narayana.NarayanaTransactionIntegration.associate(NarayanaTransactionIntegration.java:93)
at io.agroal.pool.ConnectionPool.getConnection(ConnectionPool.java:245)
at io.agroal.pool.DataSource.getConnection(DataSource.java:86)
....(stack cut off so post will fit)
2022-09-22 18:47:39,285 WARN [io.agroal.pool] (main) Datasource '<default>': Closing open connection after completion
2022-09-22 18:47:39,577 WARN [com.arjuna.ats.jta] (main) ARJUNA016061: TransactionImple.enlistResource - XAResource.start returned: XAException.XAER_RMERR for < formatId=131077, gtrid_length=35, bqual_length=36, tx_uid=0:ffff7f000101:a423:632cadc9:8a, node_name=quarkus, branch_uid=0:ffff7f000101:a423:632cadc9:c9, subordinatenodename=null, eis_name=0 >: javax.transaction.xa.XAException: com.microsoft.sqlserver.jdbc.SQLServerException: Failed to create the XA control connection. Error: "The connection is closed."
at com.microsoft.sqlserver.jdbc.SQLServerXAResource.DTC_XA_Interface(SQLServerXAResource.java:738)
at com.microsoft.sqlserver.jdbc.SQLServerXAResource.start(SQLServerXAResource.java:772)
at io.agroal.narayana.BaseXAResource.start(BaseXAResource.java:150)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:661)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:422)
at io.agroal.narayana.NarayanaTransactionIntegration.associate(NarayanaTransactionIntegration.java:93)
at io.agroal.pool.ConnectionPool.getConnection(ConnectionPool.java:245)
at io.agroal.pool.DataSource.getConnection(DataSource.java:86)
....(stack cut off so post will fit)
2022-09-22 18:47:39,578 WARN [com.arjuna.ats.jta] (main) ARJUNA016138: Failed to enlist XA resource io.agroal.narayana.BaseXAResource@37922937: javax.transaction.SystemException: TransactionImple.enlistResource - XAResource.start ARJUNA016054: could not register transaction: < formatId=131077, gtrid_length=35, bqual_length=36, tx_uid=0:ffff7f000101:a423:632cadc9:8a, node_name=quarkus, branch_uid=0:ffff7f000101:a423:632cadc9:c9, subordinatenodename=null, eis_name=0 >
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:714)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:422)
at io.agroal.narayana.NarayanaTransactionIntegration.associate(NarayanaTransactionIntegration.java:93)
at io.agroal.pool.ConnectionPool.getConnection(ConnectionPool.java:245)
at io.agroal.pool.DataSource.getConnection(DataSource.java:86)
....(stack cut off so post will fit)
2022-09-22 18:47:39,595 WARN [io.agroal.pool] (main) Datasource '<default>': Closing open connection after completion
2022-09-22 18:47:40,268 INFO [io.quarkus] (main) Keycloak 19.0.2 on JVM (powered by Quarkus 2.7.6.Final) started in 17.973s. Listening on: https://0.0.0.0:443
2022-09-22 18:47:40,269 INFO [io.quarkus] (main) Profile prod activated.
2022-09-22 18:47:40,270 INFO [io.quarkus] (main) Installed features: [agroal, cdi, hibernate-orm, jdbc-h2, jdbc-mariadb, jdbc-mssql, jdbc-mysql, jdbc-oracle, jdbc-postgresql, keycloak, logging-gelf, narayana-jta, reactive-routes, resteasy, resteasy-jackson, smallrye-context-propagation, smallrye-health, smallrye-metrics, vault, vertx]
Any help would be appreciated. Thanks.