Upgrading WSO2 IS 5.9 to WSO2 IS 5.10 failed due to “Unknown column 'UM_USER_ID' in 'field list'”

1
votes

I was trying to upgrade my existing WSO2 IS 5.9 instance to WSO2 IS 5.10. However, the migration failed with the JDBC error "Unknown column 'UM_USER_ID' in 'field list" even though I had followed the migration guide at https://is.docs.wso2.com/en/latest/setup/migration-guide exactly.

From the look of it, it seems like WSO2 IS crashed before it could run the actual migration tasks to upgrade the database which end up the column 'UM_USER_ID' was not there.

I wonder if any one has any clue?

Below is the detail of my environment & the actual error:

  • Server: Ubuntu Bionic 18.04.3
  • OpenJDK 1.8.0.242
  • MySQL 5.7.29. I have removed the NO_ZERO_DATE from the sql mode.
  • mysql-connector-java-5.1.47-bin.jar
  • wso2is migration resources version 1.0.82. I did look into the db scripts in this migration resources version and make some changes to fix some issues.

Below is the actual exceptions in the log file:

TID: [-1234] [] [2020-04-03 17:11:25,228] []  INFO {org.wso2.carbon.core.internal.CarbonCoreActivator} - Starting WSO2 Carbon...
TID: [-1] [] [2020-04-03 17:11:24,348] []  INFO {org.ops4j.pax.logging.spi.support.EventAdminConfigurationNotifier} - Sending Event Admin nofification (configuration successful) to org/ops4j/pax/logging/Configuration
TID: [-1234] [] [2020-04-03 17:11:25,267] []  INFO {org.wso2.carbon.core.internal.CarbonCoreActivator} - Operating System : Linux 4.15.0-76-generic, amd64
TID: [-1234] [] [2020-04-03 17:11:25,268] []  INFO {org.wso2.carbon.core.internal.CarbonCoreActivator} - Java Home        : /usr/lib/jvm/java-8-openjdk-amd64/jre
TID: [-1234] [] [2020-04-03 17:11:25,271] []  INFO {org.wso2.carbon.core.internal.CarbonCoreActivator} - Java Version     : 1.8.0_242
TID: [-1234] [] [2020-04-03 17:11:25,273] []  INFO {org.wso2.carbon.core.internal.CarbonCoreActivator} - Java VM          : OpenJDK 64-Bit Server VM 25.242-b08,Private Build
TID: [-1234] [] [2020-04-03 17:11:25,275] []  INFO {org.wso2.carbon.core.internal.CarbonCoreActivator} - Carbon Home      : /opt/wso2is
TID: [-1234] [] [2020-04-03 17:11:25,288] []  INFO {org.wso2.carbon.core.internal.CarbonCoreActivator} - Java Temp Dir    : /opt/wso2is/tmp
TID: [-1234] [] [2020-04-03 17:11:25,288] []  INFO {org.wso2.carbon.core.internal.CarbonCoreActivator} - User             : root, en-US, Etc/UTC
TID: [-1] [] [2020-04-03 17:11:25,769] []  INFO {org.wso2.carbon.crypto.provider.internal.DefaultCryptoProviderComponent} - 'CryptoService.Secret' property has not been set. 'org.wso2.carbon.crypto.provider.SymmetricKeyInternalCryptoProvider' won't be registered as an internal crypto provider. Please set the secret if the provider needs to be registered.
TID: [-1] [] [2020-04-03 17:11:26,187] []  INFO {org.wso2.carbon.event.output.adapter.kafka.internal.ds.KafkaEventAdapterServiceDS} - Successfully deployed the Kafka output event adaptor service
TID: [-1] [] [2020-04-03 17:11:27,225] []  INFO {org.wso2.carbon.identity.oauth.uma.grant.internal.UMA2GrantServiceComponent} - Policy evaluator registered successfully: DefaultPolicyEvaluator
TID: [-1] [] [2020-04-03 17:11:27,225] []  INFO {org.wso2.carbon.identity.oauth.uma.grant.internal.UMA2GrantServiceComponent} - UMA Grant component activated successfully.
TID: [-1234] [] [2020-04-03 17:11:27,844] []  INFO {org.wso2.carbon.ldap.server.DirectoryActivator} - Embedded LDAP is disabled.
TID: [-1] [] [2020-04-03 17:11:27,887] []  INFO {org.wso2.carbon.mex.internal.Office365SupportMexComponent} - Office365Support MexServiceComponent bundle activated successfully..
TID: [-1] [] [2020-04-03 17:11:27,903] []  INFO {org.wso2.carbon.mex2.internal.DynamicCRMCustomMexComponent} - DynamicCRMSupport MexServiceComponent bundle activated successfully.
TID: [-1234] [] [2020-04-03 17:11:31,884] [] ERROR {org.wso2.carbon.user.core.common.DefaultRealm} - nullType class java.lang.reflect.InvocationTargetException org.wso2.carbon.user.core.UserStoreException: nullType class java.lang.reflect.InvocationTargetException
    at org.wso2.carbon.user.core.common.DefaultRealm.createObjectWithOptions(DefaultRealm.java:397)
    at org.wso2.carbon.user.core.common.DefaultRealm.initializeObjects(DefaultRealm.java:224)
    at org.wso2.carbon.user.core.common.DefaultRealm.init(DefaultRealm.java:129)
    at org.wso2.carbon.user.core.common.DefaultRealmService.initializeRealm(DefaultRealmService.java:276)
    at org.wso2.carbon.user.core.common.DefaultRealmService.(DefaultRealmService.java:102)
    at org.wso2.carbon.user.core.common.DefaultRealmService.(DefaultRealmService.java:115)
    at org.wso2.carbon.user.core.internal.Activator.startDeploy(Activator.java:72)
    at org.wso2.carbon.user.core.internal.BundleCheckActivator.start(BundleCheckActivator.java:61)
    at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:842)
    at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:1)
    at java.security.AccessController.doPrivileged(Native Method)
    at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:834)
    at org.eclipse.osgi.internal.framework.BundleContextImpl.start(BundleContextImpl.java:791)
    at org.eclipse.osgi.internal.framework.EquinoxBundle.startWorker0(EquinoxBundle.java:1013)
    at org.eclipse.osgi.internal.framework.EquinoxBundle$EquinoxModule.startWorker(EquinoxBundle.java:365)
    at org.eclipse.osgi.container.Module.doStart(Module.java:598)
    at org.eclipse.osgi.container.Module.start(Module.java:462)
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$1.run(ModuleContainer.java:1820)
    at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$2$1.execute(EquinoxContainerAdaptor.java:150)
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1813)
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1770)
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1735)
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1661)
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1)
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234)
    at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345)
Caused by: java.lang.reflect.InvocationTargetException
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    at org.wso2.carbon.user.core.common.DefaultRealm.createObjectWithOptions(DefaultRealm.java:351)
    ... 25 more
Caused by: org.wso2.carbon.user.core.UserStoreException: Database error occurred while retrieving userID for a UserName : admin
    at org.wso2.carbon.user.core.jdbc.UniqueIDJDBCUserStoreManager.doGetUserIDFromUserNameWithID(UniqueIDJDBCUserStoreManager.java:1284)
    at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getUserIDFromUserName(AbstractUserStoreManager.java:11773)
    at org.wso2.carbon.user.core.common.AbstractUserStoreManager.addInitialAdminData(AbstractUserStoreManager.java:8401)
    at org.wso2.carbon.user.core.jdbc.JDBCUserStoreManager.(JDBCUserStoreManager.java:319)
    at org.wso2.carbon.user.core.jdbc.JDBCUserStoreManager.(JDBCUserStoreManager.java:258)
    at org.wso2.carbon.user.core.jdbc.UniqueIDJDBCUserStoreManager.(UniqueIDJDBCUserStoreManager.java:125)
    ... 30 more
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Unknown column 'UM_USER_ID' in 'field list'
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
    at com.mysql.jdbc.Util.getInstance(Util.java:408)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:944)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3978)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3914)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2530)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2683)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2495)
    at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1903)
    at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2011)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.apache.tomcat.jdbc.pool.StatementFacade$StatementProxy.invoke(StatementFacade.java:114)
    at com.sun.proxy.$Proxy51.executeQuery(Unknown Source)
    at org.wso2.carbon.user.core.jdbc.UniqueIDJDBCUserStoreManager.doGetUserIDFromUserNameWithID(UniqueIDJDBCUserStoreManager.java:1275)
    ... 35 more

TID: [-1234] [] [2020-04-03 17:11:31,976] [] ERROR {org.wso2.carbon.user.core.internal.Activator} - Cannot start User Manager Core bundle org.wso2.carbon.user.core.UserStoreException: Cannot initialize the realm.
    at org.wso2.carbon.user.core.common.DefaultRealmService.initializeRealm(DefaultRealmService.java:286)
    at org.wso2.carbon.user.core.common.DefaultRealmService.(DefaultRealmService.java:102)
    at org.wso2.carbon.user.core.common.DefaultRealmService.(DefaultRealmService.java:115)
    at org.wso2.carbon.user.core.internal.Activator.startDeploy(Activator.java:72)
    at org.wso2.carbon.user.core.internal.BundleCheckActivator.start(BundleCheckActivator.java:61)
    at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:842)
    at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:1)
    at java.security.AccessController.doPrivileged(Native Method)
    at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:834)
    at org.eclipse.osgi.internal.framework.BundleContextImpl.start(BundleContextImpl.java:791)
    at org.eclipse.osgi.internal.framework.EquinoxBundle.startWorker0(EquinoxBundle.java:1013)
    at org.eclipse.osgi.internal.framework.EquinoxBundle$EquinoxModule.startWorker(EquinoxBundle.java:365)
    at org.eclipse.osgi.container.Module.doStart(Module.java:598)
    at org.eclipse.osgi.container.Module.start(Module.java:462)
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$1.run(ModuleContainer.java:1820)
    at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$2$1.execute(EquinoxContainerAdaptor.java:150)
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1813)
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1770)
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1735)
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1661)
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1)
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234)
    at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345)
Caused by: org.wso2.carbon.user.core.UserStoreException: nullType class java.lang.reflect.InvocationTargetException
    at org.wso2.carbon.user.core.common.DefaultRealm.initializeObjects(DefaultRealm.java:318)
    at org.wso2.carbon.user.core.common.DefaultRealm.init(DefaultRealm.java:129)
    at org.wso2.carbon.user.core.common.DefaultRealmService.initializeRealm(DefaultRealmService.java:276)
    ... 22 more
Caused by: org.wso2.carbon.user.core.UserStoreException: nullType class java.lang.reflect.InvocationTargetException
    at org.wso2.carbon.user.core.common.DefaultRealm.createObjectWithOptions(DefaultRealm.java:397)
    at org.wso2.carbon.user.core.common.DefaultRealm.initializeObjects(DefaultRealm.java:224)
    ... 24 more
Caused by: java.lang.reflect.InvocationTargetException
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    at org.wso2.carbon.user.core.common.DefaultRealm.createObjectWithOptions(DefaultRealm.java:351)
    ... 25 more
Caused by: org.wso2.carbon.user.core.UserStoreException: Database error occurred while retrieving userID for a UserName : admin
    at org.wso2.carbon.user.core.jdbc.UniqueIDJDBCUserStoreManager.doGetUserIDFromUserNameWithID(UniqueIDJDBCUserStoreManager.java:1284)
    at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getUserIDFromUserName(AbstractUserStoreManager.java:11773)
    at org.wso2.carbon.user.core.common.AbstractUserStoreManager.addInitialAdminData(AbstractUserStoreManager.java:8401)
    at org.wso2.carbon.user.core.jdbc.JDBCUserStoreManager.(JDBCUserStoreManager.java:319)
    at org.wso2.carbon.user.core.jdbc.JDBCUserStoreManager.(JDBCUserStoreManager.java:258)
    at org.wso2.carbon.user.core.jdbc.UniqueIDJDBCUserStoreManager.(UniqueIDJDBCUserStoreManager.java:125)
    ... 30 more
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Unknown column 'UM_USER_ID' in 'field list'
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
    at com.mysql.jdbc.Util.getInstance(Util.java:408)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:944)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3978)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3914)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2530)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2683)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2495)
    at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1903)
    at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2011)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.apache.tomcat.jdbc.pool.StatementFacade$StatementProxy.invoke(StatementFacade.java:114)
    at com.sun.proxy.$Proxy51.executeQuery(Unknown Source)
    at org.wso2.carbon.user.core.jdbc.UniqueIDJDBCUserStoreManager.doGetUserIDFromUserNameWithID(UniqueIDJDBCUserStoreManager.java:1275)
    ... 35 more

TID: [-1] [] [2020-04-03 17:11:32,384] []  INFO {org.apache.jasper.servlet.TldScanner} - At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
TID: [-1] [] [2020-04-03 17:11:32,766] []  INFO {org.wso2.carbon.identity.authenticator.x509Certificate.internal.X509CertificateServiceComponent} - X509 Certificate Servlet activated successfully..
2
wso2wso2is
During the migration, in the last migration step (From 5.9 to 5.10) migration client is altering the UM_USER table to add the new column. Could you please check for below 1. Did you pass the JVM migration arguments on the server startup? sh wso2server.sh -Dmigrate -Dcomponent=identity 2. Did you copy the org.wso2.carbon.is.migration-1.0.82.jar to the /dropins directory? – Nipun Thathsara
@NipunThathsara 1) Yes. 2) Yes. When execute the command 'sh wso2server.sh -Dmigrate -Dcomponent=identity', it then run into the exception I provided above and stuck there. – Andy Bui
It seems there is an issue when you are using the "UniqueIDJDBCUserStoreManager" for the primary userstore before the migration. Because it tried to initialize the userstore before running the migration. Hence try to run the migration with old "JDBCUserStoreManager" [user_store] type = "database" – Sajith

2 Answers

3
votes

The reason for this is you have configured UniqueIDJDBCUserStoreManager for the primary userstore before the migration. Hence, it fails during server initialization and before the migration starts.

[user_store]
type = "database_unique_id"

Therefore, the solution is to use JDBCUserStoreManager during the migration.

[user_store]
type = "database"

Later, you can switch to UniqueIDJDBCUserStoreManager becaue we do nessary schema updates during the migration process.

PS: If you had not enabled SCIM in the previous version, it could fail to update user IDs [1]. So, we have to start the migration by disabling SCIM for the primary userstore specifically since 5.10.0 sets SCIM enabled by default while 5.9.0 had SCIM disabled by default for JDBCUserStoreManager

[user_store]
type = "database"
scim_enabled=false

[1] https://github.com/wso2/product-is/issues/8034

0
votes

The mysql script being executed for the addition of the UM_USER_ID column was wrong[1]. The UM_USER_ID column has been added with DEFAULT 'NONE'

ALTER TABLE `UM_USER` ADD COLUMN `UM_USER_ID` CHAR(36) NOT NULL DEFAULT 'NONE', ADD UNIQUE(UM_USER_ID, UM_TENANT_ID);
UPDATE UM_USER SET UM_USER_ID = UUID();

A UNIQUE constraint cannot be added there, migrations with only one user(admin user) will succeed. It has been fixed with commit[1]

[1]https://github.com/wso2-extensions/identity-migration-resources/commit/888a332c498d40f0e2a049cd17fbcd35caafde99