Upgrade 9.1.1 -> 9.3.7 DB schema update issue

[kuliktomas]

Hi, I have upgraded from 9.1.1 to 9.3.7 and can see in the log a lot of ALTER denied messages

2026-02-26 10:16:51,076+0000 WARN  [org.hibernate.tool.schema.internal.ExceptionHandlerLoggedImpl] (ServerService Thread Pool -- 69) GenerationTarget encountered exception accepting command : Error executing DDL "alter table UserData modify column subjectEmail VARCHAR(256) BINARY" via JDBC [(conn=3355249) ALTER command denied to user 'appuser'@'pxc-db-haproxy-1.pxc-db-haproxy.percona.svc.c.cluster.local' for table 'UserData']: org.hibernate.tool.schema.spi.CommandAcceptanceException: Error executing DDL "alter table UserData modify column subjectEmail VARCHAR(256) BINARY" via JDBC [(conn=3355249) ALTER command denied to user 'appuser'@'pxc-db-haproxy-1.pxc-db-haproxy.percona.svc.c.cluster.local' for table 'UserData']
        at org.hibernate@6.6.3.Final//org.hibernate.tool.schema.internal.exec.GenerationTargetToDatabase.accept(GenerationTargetToDatabase.java:94)
        at org.hibernate@6.6.3.Final//org.hibernate.tool.schema.internal.AbstractSchemaMigrator.applySqlString(AbstractSchemaMigrator.java:576)
        at org.hibernate@6.6.3.Final//org.hibernate.tool.schema.internal.AbstractSchemaMigrator.applySqlStrings(AbstractSchemaMigrator.java:516)
        at org.hibernate@6.6.3.Final//org.hibernate.tool.schema.internal.AbstractSchemaMigrator.migrateTable(AbstractSchemaMigrator.java:334)
        at org.hibernate@6.6.3.Final//org.hibernate.tool.schema.internal.GroupedSchemaMigratorImpl.performTablesMigration(GroupedSchemaMigratorImpl.java:84)
        at org.hibernate@6.6.3.Final//org.hibernate.tool.schema.internal.AbstractSchemaMigrator.performMigration(AbstractSchemaMigrator.java:233)
        at org.hibernate@6.6.3.Final//org.hibernate.tool.schema.internal.AbstractSchemaMigrator.doMigration(AbstractSchemaMigrator.java:112)
        at org.hibernate@6.6.3.Final//org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.performDatabaseAction(SchemaManagementToolCoordinator.java:280)
        at org.hibernate@6.6.3.Final//org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.lambda$process$5(SchemaManagementToolCoordinator.java:144)
        at java.base/java.util.HashMap.forEach(Unknown Source)
        at org.hibernate@6.6.3.Final//org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.process(SchemaManagementToolCoordinator.java:141)
        at org.hibernate@6.6.3.Final//org.hibernate.boot.internal.SessionFactoryObserverForSchemaExport.sessionFactoryCreated(SessionFactoryObserverForSchemaExport.java:37)
        at org.hibernate@6.6.3.Final//org.hibernate.internal.SessionFactoryObserverChain.sessionFactoryCreated(SessionFactoryObserverChain.java:35)
        at org.hibernate@6.6.3.Final//org.hibernate.internal.SessionFactoryImpl.<init>(SessionFactoryImpl.java:324)
        at org.hibernate@6.6.3.Final//org.hibernate.boot.internal.SessionFactoryBuilderImpl.build(SessionFactoryBuilderImpl.java:463)
        at org.hibernate@6.6.3.Final//org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:1506)
        at org.hibernate.jipijapa-hibernate6@35.0.1.Final//org.jboss.as.jpa.hibernate.TwoPhaseBootstrapImpl.build(TwoPhaseBootstrapImpl.java:32)
        at org.jboss.as.jpa@35.0.1.Final//org.jboss.as.jpa.service.PersistenceUnitServiceImpl$1$1.run(PersistenceUnitServiceImpl.java:159)
        at org.jboss.as.jpa@35.0.1.Final//org.jboss.as.jpa.service.PersistenceUnitServiceImpl$1$1.run(PersistenceUnitServiceImpl.java:117)
        at java.base/java.security.AccessController.doPrivileged(Unknown Source)
        at org.wildfly.security.elytron-base@2.6.0.Final//org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:664)
        at org.jboss.as.jpa@35.0.1.Final//org.jboss.as.jpa.service.PersistenceUnitServiceImpl$1.run(PersistenceUnitServiceImpl.java:202)
        at org.jboss.threads@2.4.0.Final//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
        at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
        at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
        at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
        at java.base/java.lang.Thread.run(Unknown Source)
        at org.jboss.threads@2.4.0.Final//org.jboss.threads.JBossThread.run(JBossThread.java:513)

It seems it tries to run ALTER using the application user i.e. DATABASE_USER (does not have ALTER privileges) and not the DATABASE_USER_PRIVILEGED? Also after a while it just continues and reaches a working state where the application asks me for a post upgrade in the UI. I am not sure what state it is in actually :).

Should I assume that it eventually used the DATABASE_USER_PRIVILEGED even though I dont see it in the log (well there is technically this one line 2026-02-26 10:17:02,164+0000 INFO [org.ejbca.core.ejb.upgrade.UpgradeSessionBean] (ServerService Thread Pool -- 92) Database content version: 9.1.1, current application version: 9.3.7 -> Starting upgrade.). Or am I in some weird state?

Thank you!

[kuliktomas]

Must have been some config error, cannot replicate

[primetomas]

It's a hibernate setting that it will try to alter table. It will only use it as the user that you have in the datasource configuration though, nothing else, it's can't. It's generally safe to ignore these messages. Not sure why it doesn't repeat, maybe hibernate saves some state? We are evaluating hibernate config for future releases, it's changed a bit over the years.

[talcher]

Hello the EJBCA team,
whenever I use a fully privileged database user, I don't get those logs. On the contrary, everytime I restart the service with a unprivileged user, as defined by the official script, those lines pop up. It is somewhat annoying, given that around 220 logs are registered, plus their stacktrace, for each restart.

[primetomas]

Unfortunately a Hibernate change is behind this. We've been looking into changes to make it better, but haven't found an ideal way to work around the Hibernate change yet. They didn't provide a way to configure behavior better.
You can configure logging in WildFly/JBoss to get rid of these specific messages.

[primetomas]

In hibernate shipped since WildFly 32 hibernate applies hibernate.hbm2ddl.auto to column sizes. Unless you have altered column sizes yourself, you can just make sure that the column sizes match the defaults that EJBCA comes with. If you haven't manually altered column sizes the most probably cause is that the default size in EJBCA was increased, in which case increasing it on your database as well should make hibernate satisfied.

[talcher]

Thank you, Tomas, for your answer.

Actually, the situation is a bit trickier.
When I use the privileged user, I will only get a few logs, i.e. those related to the only one column whose size I have manually altered.
Then, I change the user to the unprivileged one. Whenever I restart the service, I will get the 220 logs plus stacktrace.
Why do I get those logs only for the unprivileged user?
And why so, even if I have used the privileged user before? I would have assumed that using the privileged user before would have changed the definition of the concerned columns; but no.

Regarding the reason why I get those logs for the not-manually alterered columns, I am surprised. Here is one of the logs I get with the unprivileged user:

WARN  [org.hibernate.tool.schema.internal.ExceptionHandlerLoggedImpl] (ServerService Thread Pool -- 50)
GenerationTarget encountered exception accepting command : Error executing DDL
"alter table if exists AccessRulesData modify column accessRule VARCHAR(250) BINARY not null" 
via JDBC [(conn=17082) ALTER command denied to user 'ejbca-unprivileged'@'server' for table `ejbca`.`AccessRulesData`]:
org.hibernate.tool.schema.spi.CommandAcceptanceException: Error executing DDL
"alter table if exists AccessRulesData modify column accessRule VARCHAR(250) BINARY not null"
via JDBC [(conn=17082) ALTER command denied to user 'ejbca-unprivileged'@'server' for table `ejbca`.`AccessRulesData`]

However, here is the AccessRulesData table :

SHOW CREATE TABLE AccessRulesData\g
=>
| AccessRulesData | CREATE TABLE `AccessRulesData` (
  `pK` int(11) NOT NULL,
  `accessRule` varchar(250) CHARACTER SET utf8mb3 COLLATE utf8mb3_bin NOT NULL,
  `isRecursive` tinyint(4) NOT NULL,
  `rowProtection` longtext DEFAULT NULL,
  `rowVersion` int(11) NOT NULL,
  `rule` int(11) NOT NULL,
  `AdminGroupData_accessRules` int(11) DEFAULT NULL,
  PRIMARY KEY (`pK`),
  KEY `FKdaev24clq6yofynpsh4kuojno` (`AdminGroupData_accessRules`),
  CONSTRAINT `FKdaev24clq6yofynpsh4kuojno` FOREIGN KEY (`AdminGroupData_accessRules`) REFERENCES `AdminGroupData` (`pK`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb3 COLLATE=utf8mb3_general_ci |

If I change the accessRule column to CHARACTER SET BINARY, to CHARACTER SET utf8mb4 COLLATE utf8mb4_bin or to the default value, I still get the very same log.

So, I do not understand why hibernate is dissatisfied.

Whatever the reasons why they appear, can I safely ignore those warnings or should I be cautious about losing some information?

Let me know if you need more input!

[primetomas]

You can safely ignore those warnings. Nothing can be lost by hibernate not being able to update the schema. The schema changes rarely. The only "real" warning should have been for the columns you manually modified. It's unclear why hibernate behaves this way now, hopefully it will be updated in hibernate to be nicer.

[talcher]

OK. Thank you, Tomas.