Crowd 4.0.0 upgrade error - ERROR [engine.jdbc.spi.SqlExceptionHelper]

[David Low]

Currently on Crowd 3.4.5 Build 1070 with an Oracle 12c release 2 database

We are in the processes of upgrading our Crowd instances to Crowd 4.0.0.0 Build 1425

In two of our test instances, both initially experienced an error during the upgrade.

ERROR [engine.jdbc.spi.SqlExceptionHelper] Protocol violation: [ 16, 6, 7, 0, ]

Refer to the log below for full output.

After stopping and restarting crowd. The upgrade is successful on the second attempt. What could be causing this initial error?

2020-05-26 16:20:29,190 localhost-startStop-1 INFO [liquibase] ChangeSet liquibase/crowd_3_7_0/02_cwd_application_attribute_value_type_change.xml::KRAK-677::crowd ran successfully in 64ms
2020-05-26 16:20:29,199 localhost-startStop-1 INFO [liquibase] Data updated in cwd_cluster_message_id
2020-05-26 16:20:29,199 localhost-startStop-1 INFO [liquibase] ChangeSet liquibase/crowd_4_0_0/01_cwd_cluster_message_id.xml::KRAK-2897: Make cwd_cluster_message_id compatible with hibernate 5.4.0::crowd ran successfully in 4ms
2020-05-26 16:20:29,203 localhost-startStop-1 INFO [liquibase] Successfully released change log lock
2020-05-26 16:20:29,235 localhost-startStop-1 INFO [crowd.manager.upgrade.UpgradeManagerImpl] Trying to take lock for upgrade manager
2020-05-26 16:20:29,276 localhost-startStop-1 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 17401, SQLState: 99999
2020-05-26 16:20:29,276 localhost-startStop-1 ERROR [engine.jdbc.spi.SqlExceptionHelper] Protocol violation: [ 16, 6, 7, 0, ]
2020-05-26 16:20:29,278 localhost-startStop-1 WARN [v2.c3p0.impl.NewPooledConnection] [c3p0] A PooledConnection that has already signalled a Connection error is still in use!
2020-05-26 16:20:29,279 localhost-startStop-1 WARN [v2.c3p0.impl.NewPooledConnection] [c3p0] Another error has occurred [ java.sql.SQLException: Closed Statement ] which will not be reported to listeners!
java.sql.SQLException: Closed Statement
at oracle.jdbc.driver.OracleClosedStatement.getMaxRows(OracleClosedStatement.java:2234)
at oracle.jdbc.driver.OracleStatementWrapper.getMaxRows(OracleStatementWrapper.java:174)
at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.getMaxRows(NewProxyPreparedStatement.java:2045)
at org.hibernate.resource.jdbc.internal.ResourceRegistryStandardImpl.close(ResourceRegistryStandardImpl.java:168)
at org.hibernate.resource.jdbc.internal.ResourceRegistryStandardImpl.release(ResourceRegistryStandardImpl.java:96)
at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.getResultSet(AbstractLoadPlanBasedLoader.java:432)
at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeQueryStatement(AbstractLoadPlanBasedLoader.java:191)
at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:121)
at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:86)
at org.hibernate.loader.entity.plan.AbstractLoadPlanBasedEntityLoader.load(AbstractLoadPlanBasedEntityLoader.java:197)
at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:4342)
at org.hibernate.event.internal.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:482)
at org.hibernate.event.internal.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:452)
at org.hibernate.event.internal.DefaultLoadEventListener.load(DefaultLoadEventListener.java:203)
at org.hibernate.event.internal.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:262)
at org.hibernate.event.internal.DefaultLoadEventListener.doOnLoad(DefaultLoadEventListener.java:105)
at org.hibernate.event.internal.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:73)
at org.hibernate.internal.SessionImpl.fireLoad(SessionImpl.java:1260)
at org.hibernate.internal.SessionImpl.access$2000(SessionImpl.java:210)
at org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.doLoad(SessionImpl.java:2896)
at org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.lambda$load$1(SessionImpl.java:2877)
at org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.perform(SessionImpl.java:2833)
at org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.load(SessionImpl.java:2877)
at org.hibernate.internal.SessionImpl.get(SessionImpl.java:1096)
at com.atlassian.crowd.util.persistence.hibernate.HibernateDao.loadOptional(HibernateDao.java:95)
at com.atlassian.crowd.util.persistence.hibernate.HibernateDao.load(HibernateDao.java:73)
at com.atlassian.crowd.dao.property.PropertyDAOHibernate.find(PropertyDAOHibernate.java:17)
at com.atlassian.crowd.manager.property.PropertyManagerGeneric.getPropertyObject(PropertyManagerGeneric.java:450)
at com.atlassian.crowd.manager.property.PropertyManagerGeneric.getProperty(PropertyManagerGeneric.java:462)
at com.atlassian.crowd.manager.property.PropertyManagerGeneric.getPropertyInternal(PropertyManagerGeneric.java:485)
at com.atlassian.crowd.manager.property.PropertyManagerGeneric.getBuildNumber(PropertyManagerGeneric.java:332)
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 org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:295)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy62.getBuildNumber(Unknown Source)
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 org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at com.atlassian.spring.interceptors.SpringProfilingInterceptor.invoke(SpringProfilingInterceptor.java:16)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy63.getBuildNumber(Unknown Source)
at com.atlassian.crowd.manager.upgrade.UpgradeManagerImpl.getDataBuildNumber(UpgradeManagerImpl.java:68)
at com.atlassian.crowd.manager.upgrade.UpgradeManagerImpl.needUpgrade(UpgradeManagerImpl.java:103)
at com.atlassian.crowd.manager.upgrade.UpgradeManagerImpl.doUpgrade(UpgradeManagerImpl.java:118)
at com.atlassian.crowd.console.listener.StartupListener.migrateAndUpgradeCrowd(StartupListener.java:196)
at com.atlassian.crowd.console.listener.StartupListener.contextInitialized(StartupListener.java:60)
at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4770)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5236)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:754)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:730)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:744)
at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:624)
at org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1833)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
2020-05-26 16:20:29,283 localhost-startStop-1 WARN [v2.c3p0.impl.NewPooledConnection] [c3p0] A PooledConnection that has already signalled a Connection error is still in use!
2020-05-26 16:20:29,283 localhost-startStop-1 WARN [v2.c3p0.impl.NewPooledConnection] [c3p0] Another error has occurred [ java.sql.SQLRecoverableException: Closed Connection ] which will not be reported to listeners!
java.sql.SQLRecoverableException: Closed Connection
at oracle.jdbc.driver.PhysicalConnection.getAutoCommit(PhysicalConnection.java:1828)
at oracle.jdbc.driver.PhysicalConnection.rollback(PhysicalConnection.java:1953)
at com.mchange.v2.c3p0.impl.NewProxyConnection.rollback(NewProxyConnection.java:1033)
at org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor.rollback(AbstractLogicalConnectionImplementor.java:116)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.rollback(JdbcResourceLocalTransactionCoordinatorImpl.java:294)
at org.hibernate.engine.transaction.internal.TransactionImpl.rollback(TransactionImpl.java:145)
at org.springframework.orm.hibernate5.HibernateTransactionManager.doRollback(HibernateTransactionManager.java:654)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:838)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:812)
at org.springframework.transaction.interceptor.TransactionAspectSupport.completeTransactionAfterThrowing(TransactionAspectSupport.java:552)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:299)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy62.getBuildNumber(Unknown Source)
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 org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at com.atlassian.spring.interceptors.SpringProfilingInterceptor.invoke(SpringProfilingInterceptor.java:16)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy63.getBuildNumber(Unknown Source)
at com.atlassian.crowd.manager.upgrade.UpgradeManagerImpl.getDataBuildNumber(UpgradeManagerImpl.java:68)
at com.atlassian.crowd.manager.upgrade.UpgradeManagerImpl.needUpgrade(UpgradeManagerImpl.java:103)
at com.atlassian.crowd.manager.upgrade.UpgradeManagerImpl.doUpgrade(UpgradeManagerImpl.java:118)
at com.atlassian.crowd.console.listener.StartupListener.migrateAndUpgradeCrowd(StartupListener.java:196)
at com.atlassian.crowd.console.listener.StartupListener.contextInitialized(StartupListener.java:60)
at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4770)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5236)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:754)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:730)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:744)
at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:624)
at org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1833)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
2020-05-26 16:20:29,412 localhost-startStop-1 ERROR [crowd.console.listener.StartupListener] Errors experienced during the Crowd upgrade process: []
2020-05-26 16:20:29,412 localhost-startStop-1 INFO [com.atlassian.crowd.startup] System Information:
2020-05-26 16:20:29,412 localhost-startStop-1 INFO [com.atlassian.crowd.startup] Timezone: Australian Eastern Standard Time
2020-05-26 16:20:29,412 localhost-startStop-1 INFO [com.atlassian.crowd.startup] Java Version: 11.0.6
2020-05-26 16:20:29,412 localhost-startStop-1 INFO [com.atlassian.crowd.startup] Java Vendor: Oracle Corporation
2020-05-26 16:20:29,412 localhost-startStop-1 INFO [com.atlassian.crowd.startup] JVM Version: 11.0.6+10-LTS
2020-05-26 16:20:29,412 localhost-startStop-1 INFO [com.atlassian.crowd.startup] JVM Vendor: Oracle Corporation
2020-05-26 16:20:29,412 localhost-startStop-1 INFO [com.atlassian.crowd.startup] JVM Runtime: OpenJDK 64-Bit Server VM
2020-05-26 16:20:29,412 localhost-startStop-1 INFO [com.atlassian.crowd.startup] Username: crowd
2020-05-26 16:20:29,412 localhost-startStop-1 INFO [com.atlassian.crowd.startup] Operating System: Linux3.10.0-1127.el7.x86_64
2020-05-26 16:20:29,412 localhost-startStop-1 INFO [com.atlassian.crowd.startup] Architecture: amd64
2020-05-26 16:20:29,412 localhost-startStop-1 INFO [com.atlassian.crowd.startup] File Encoding: UTF-8
2020-05-26 16:20:29,412 localhost-startStop-1 INFO [com.atlassian.crowd.startup] JVM Statistics:
2020-05-26 16:20:29,412 localhost-startStop-1 INFO [com.atlassian.crowd.startup] Total Memory: 4096MB
2020-05-26 16:20:29,412 localhost-startStop-1 INFO [com.atlassian.crowd.startup] Used Memory: 444MB
2020-05-26 16:20:29,412 localhost-startStop-1 INFO [com.atlassian.crowd.startup] Free Memory: 3651MB
2020-05-26 16:20:29,413 localhost-startStop-1 INFO [com.atlassian.crowd.startup] Runtime Information:
2020-05-26 16:20:29,413 localhost-startStop-1 INFO [com.atlassian.crowd.startup] Version: 4.0.0
2020-05-26 16:20:29,413 localhost-startStop-1 INFO [com.atlassian.crowd.startup] Build Number: 1425
2020-05-26 16:20:29,413 localhost-startStop-1 INFO [com.atlassian.crowd.startup] Build Date: 2020-02-24
2020-05-26 16:20:29,413 localhost-startStop-1 INFO [crowd.console.listener.StartupListener] Upgrades not performed since the application has not been setup yet.
2020-05-26 16:20:29,413 localhost-startStop-1 ERROR [crowd.console.listener.StartupListener] Stopping Crowd startup due to earlier errors

[Muthukumar Muthiah]

I did see the same error when upgrading from 3.5.0 to 4.20