Jira Core 7.5.0 Upgrade PostgreSQL Issues

[tdarindc3]

After upgrading Jira Core from 7.3.6 to 7.5.0 the following errors started to be reported in the logs once Jira started up:

2017-09-19 14:38:18,854 JIRA-Bootstrap WARN [o.o.c.entity.jdbc.DatabaseUtil] Entity "OSHistoryStepPrev" has no table in the database
2017-09-19 14:38:18,854 JIRA-Bootstrap ERROR [o.o.c.entity.jdbc.DatabaseUtil] Could not create table "jira_core.OS_HISTORYSTEP_PREV"
2017-09-19 14:38:18,855 JIRA-Bootstrap ERROR [o.o.c.entity.jdbc.DatabaseUtil] SQL Exception while executing the following:
CREATE TABLE jira_core.OS_HISTORYSTEP_PREV (ID NUMERIC(18,0) NOT NULL, PREVIOUS_ID NUMERIC(18,0) NOT NULL, CONSTRAINT PK_OS_HISTORYSTEP_PREV PRIMARY KEY (ID, PREVIOUS_ID))
Error was: org.postgresql.util.PSQLException: ERROR: relation "os_historystep_prev" already exists
2017-09-19 14:38:18,855 JIRA-Bootstrap WARN [o.o.c.entity.jdbc.DatabaseUtil] Entity "OSMembership" has no table in the database
2017-09-19 14:38:18,855 JIRA-Bootstrap ERROR [o.o.c.entity.jdbc.DatabaseUtil] Could not create table "jira_core.membershipbase"
2017-09-19 14:38:18,856 JIRA-Bootstrap ERROR [o.o.c.entity.jdbc.DatabaseUtil] SQL Exception while executing the following:
CREATE TABLE jira_core.membershipbase (ID NUMERIC(18,0) NOT NULL, USER_NAME VARCHAR(255), GROUP_NAME VARCHAR(255), CONSTRAINT PK_membershipbase PRIMARY KEY (ID))
Error was: org.postgresql.util.PSQLException: ERROR: relation "membershipbase" already exists
2017-09-19 14:38:18,856 JIRA-Bootstrap WARN [o.o.c.entity.jdbc.DatabaseUtil] Entity "OSPropertyData" has no table in the database
2017-09-19 14:38:18,856 JIRA-Bootstrap ERROR [o.o.c.entity.jdbc.DatabaseUtil] Could not create table "jira_core.propertydata"
2017-09-19 14:38:18,857 JIRA-Bootstrap ERROR [o.o.c.entity.jdbc.DatabaseUtil] SQL Exception while executing the following:
CREATE TABLE jira_core.propertydata (ID NUMERIC(18,0) NOT NULL, propertyvalue OID, CONSTRAINT PK_propertydata PRIMARY KEY (ID))
Error was: org.postgresql.util.PSQLException: ERROR: relation "propertydata" already exists
2017-09-19 14:38:18,857 JIRA-Bootstrap WARN [o.o.c.entity.jdbc.DatabaseUtil] Entity "OSPropertyDate" has no table in the database
2017-09-19 14:38:18,857 JIRA-Bootstrap ERROR [o.o.c.entity.jdbc.DatabaseUtil] Could not create table "jira_core.propertydate"
2017-09-19 14:38:18,857 JIRA-Bootstrap ERROR [o.o.c.entity.jdbc.DatabaseUtil] SQL Exception while executing the following:
CREATE TABLE jira_core.propertydate (ID NUMERIC(18,0) NOT NULL, propertyvalue TIMESTAMPTZ, CONSTRAINT PK_propertydate PRIMARY KEY (ID))
Error was: org.postgresql.util.PSQLException: ERROR: relation "propertydate" already exists
2017-09-19 14:38:18,858 JIRA-Bootstrap WARN [o.o.c.entity.jdbc.DatabaseUtil] Entity "OSPropertyDecimal" has no table in the database
2017-09-19 14:38:18,858 JIRA-Bootstrap ERROR [o.o.c.entity.jdbc.DatabaseUtil] Could not create table "jira_core.propertydecimal"
2017-09-19 14:38:18,858 JIRA-Bootstrap ERROR [o.o.c.entity.jdbc.DatabaseUtil] SQL Exception while executing the following:
CREATE TABLE jira_core.propertydecimal (ID NUMERIC(18,0) NOT NULL, propertyvalue FLOAT8, CONSTRAINT PK_propertydecimal PRIMARY KEY (ID))
Error was: org.postgresql.util.PSQLException: ERROR: relation "propertydecimal" already exists

The Jira Core server still booted up fine but then started printing out messages every once in a while or when users interacted with the server along the lines of:

DEBUG   -   [c.a.activeobjects.osgi.ActiveObjectsServiceFactory] getService bundle [com.atlassian.whisper.atlassian-whisper-plugin]

WARN   -   [webresource] exception thrown in `addToUrl` during condition evaluation
com.atlassian.activeobjects.internal.ActiveObjectsInitException: bundle [com.atlassian.whisper.atlassian-whisper-plugin]
        at com.atlassian.activeobjects.osgi.TenantAwareActiveObjects$1$1$1.call(TenantAwareActiveObjects.java:95)
        at com.atlassian.activeobjects.osgi.TenantAwareActiveObjects$1$1$1.call(TenantAwareActiveObjects.java:86)
        at com.atlassian.sal.core.executor.ThreadLocalDelegateCallable.call(ThreadLocalDelegateCallable.java:38)
        at java.util.concurrent.FutureTask.run(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.RuntimeException: Could not get unique fields for table 'AO_21F425_MESSAGE_AO'
        at net.java.ao.schema.helper.DatabaseMetaDataReaderImpl.getUniqueFields(DatabaseMetaDataReaderImpl.java:189)
        at net.java.ao.schema.helper.DatabaseMetaDataReaderImpl.getFields(DatabaseMetaDataReaderImpl.java:83)
        at net.java.ao.schema.ddl.SchemaReader.readFields(SchemaReader.java:126)
        at net.java.ao.schema.ddl.SchemaReader.readTable(SchemaReader.java:110)
        at net.java.ao.schema.ddl.SchemaReader.access$000(SchemaReader.java:62)
        at net.java.ao.schema.ddl.SchemaReader$1.apply(SchemaReader.java:97)
        at com.google.common.collect.Iterators$8.transform(Iterators.java:799)
        at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:48)
        at com.google.common.collect.Iterators.addAll(Iterators.java:362)
        at com.google.common.collect.Lists.newArrayList(Lists.java:160)
        at com.google.common.collect.Lists.newArrayList(Lists.java:144)
        at net.java.ao.schema.ddl.SchemaReader.readSchema(SchemaReader.java:97)
        at net.java.ao.schema.ddl.SchemaReader.readSchema(SchemaReader.java:88)
        at net.java.ao.schema.ddl.SchemaReader.readSchema(SchemaReader.java:81)
        at net.java.ao.schema.SchemaGenerator.generateImpl(SchemaGenerator.java:107)
        at net.java.ao.schema.SchemaGenerator.migrate(SchemaGenerator.java:84)
        at net.java.ao.EntityManager.migrate(EntityManager.java:128)
        at com.atlassian.activeobjects.internal.EntityManagedActiveObjects.migrate(EntityManagedActiveObjects.java:51)
        at com.atlassian.activeobjects.internal.AbstractActiveObjectsFactory$1.doInTransaction(AbstractActiveObjectsFactory.java:77)
        at com.atlassian.activeobjects.internal.AbstractActiveObjectsFactory$1.doInTransaction(AbstractActiveObjectsFactory.java:72)
        at com.atlassian.sal.core.transaction.HostContextTransactionTemplate$1.doInTransaction(HostContextTransactionTemplate.java:21)
        at com.atlassian.jira.DefaultHostContextAccessor.doInTransaction(DefaultHostContextAccessor.java:34)
        ... 2 filtered

        at java.lang.reflect.Method.invoke(Unknown Source)
        at com.atlassian.plugin.util.ContextClassLoaderSettingInvocationHandler.invoke(ContextClassLoaderSettingInvocationHandler.java:26)
        at com.sun.proxy.$Proxy461.doInTransaction(Unknown Source)
        ... 2 filtered
        at java.lang.reflect.Method.invoke(Unknown Source)
        at com.atlassian.plugin.osgi.bridge.external.HostComponentFactoryBean$DynamicServiceInvocationHandler.invoke(HostComponentFactoryBean.java:136)
        at com.sun.proxy.$Proxy461.doInTransaction(Unknown Source)
        at com.atlassian.sal.core.transaction.HostContextTransactionTemplate.execute(HostContextTransactionTemplate.java:18)
        ... 3 filtered
        at java.lang.reflect.Method.invoke(Unknown Source)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:302)
        at org.eclipse.gemini.blueprint.service.importer.support.internal.aop.ServiceInvoker.doInvoke(ServiceInvoker.java:56)
        at org.eclipse.gemini.blueprint.service.importer.support.internal.aop.ServiceInvoker.invoke(ServiceInvoker.java:60)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
        at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:133)
        at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:121)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
        at org.eclipse.gemini.blueprint.service.util.internal.aop.ServiceTCCLInterceptor.invokeUnprivileged(ServiceTCCLInterceptor.java:70)
        at org.eclipse.gemini.blueprint.service.util.internal.aop.ServiceTCCLInterceptor.invoke(ServiceTCCLInterceptor.java:53)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
        at org.eclipse.gemini.blueprint.service.importer.support.LocalBundleContextAdvice.invoke(LocalBundleContextAdvice.java:57)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
        at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:133)
        at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:121)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:208)
        at com.sun.proxy.$Proxy936.execute(Unknown Source)
        at com.atlassian.activeobjects.internal.AbstractActiveObjectsFactory.create(AbstractActiveObjectsFactory.java:72)
        at com.atlassian.activeobjects.internal.DelegatingActiveObjectsFactory.create(DelegatingActiveObjectsFactory.java:32)
        at com.atlassian.activeobjects.osgi.TenantAwareActiveObjects$1$1$1.call(TenantAwareActiveObjects.java:91)
        ... 6 more
Caused by: org.postgresql.util.PSQLException: ERROR: column i.indproc does not exist
  Hint: Perhaps you meant to reference the column "i.indpred".
  Position: 610
        at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2455)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2155)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:288)
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:356)
        at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:303)
        at org.postgresql.jdbc.PgStatement.executeCachedSql(PgStatement.java:289)
        at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:266)
        at org.postgresql.jdbc.PgStatement.executeQuery(PgStatement.java:233)
        at org.postgresql.jdbc.PgDatabaseMetaData.getIndexInfo(PgDatabaseMetaData.java:2967)
        at org.apache.commons.dbcp2.DelegatingDatabaseMetaData.getIndexInfo(DelegatingDatabaseMetaData.java:327)

        at org.apache.commons.dbcp2.DelegatingDatabaseMetaData.getIndexInfo(DelegatingDatabaseMetaData.java:327)
        at net.java.ao.DatabaseProvider.getIndexes(DatabaseProvider.java:506)
        at net.java.ao.schema.helper.DatabaseMetaDataReaderImpl.getUniqueFields(DatabaseMetaDataReaderImpl.java:178)
        ... 63 more

This was not just in reference to the AO_21F425_MESSAGE_AO but other plugin tables as well at times.  The postgresql database is version 9.5.9.14 and the driver version used in 7.5.0 is 9.4.1212.

In the database logs, the following was logged during these exceptions:

2017-09-19 11:59:27.852 EDT :LOG:  00000: execute S_2: INSERT INTO jira_core.rundetails (ID, JOB_ID, START_TIME, RUN_DURATION, RUN_OUTCOME, INFO_MESSAGE) VALUES ($1, $2, $3, $4, $5, $6)
2017-09-19 11:59:27.852 EDT :DETAIL:  parameters: $1 = '420229', $2 = 'JiraPluginScheduler:com.atlassian.troubleshooting.healthcheck.scheduler.HealthCheckSchedulerImpl:job', $3 = '2017-09-19 11:59:48.58-04', $4 = '16472', $5 = 'F', $6 = 'ActiveObjectsInitException: bundle [com.atlassian.troubleshooting.plugin-jira]
        RuntimeException: Could not get unique fields for table ''AO_2F1435_HEALTH_CHECK_STATUS''
        PSQLException: ERROR: column i.indproc does not exist
          Hint: Perhaps you meant to refer'

I decided to replace the jdbc driver for postgresql with the previous jdbc driver from 7.3.6.  This replaced the 7.5.0 postgresql-9.4.1212.jar with the old 7.3.6 postgresql-9.1-903.jdbc4-atlassian-hosted.jar file in the jira lib directory.

After this was done, the server started up and ran without continuously outputting all of the errors above.  It appears that something is incorrect with the postgresql jdbc driver (the 9.4.1212) that is provided with the 7.5.0 installation.

[somethingblue]

Hi Thomas,

I tried to replicate the steps you took but was unable to do so.  Here's what I did:

1. I installed Postgres 9.5.9-1 in Ubuntu
2. I installed JIRA 7.3.6 and verified it is using the postgresql-9.1-903.jdbc4-atlassian-hosted.jar
3. I created data in my instance
4. I upgraded JIRA to 7.5.0 and verified it is using the postgresql-9.4.1212.jar

After the upgrade JIRA restarted and did not present any issues such as the ones you saw on startup.  I did check to see if there were any outstanding bugs or reports of this behavior from other customers and I was unable to find any reports of this so I'm hesitant at this point to say the issue is with the driver in particular.

What I'm seeing are errors that a table can't be created but then you'll see that is says the table already exists:

2017-09-19 14:38:18,858 JIRA-Bootstrap WARN [o.o.c.entity.jdbc.DatabaseUtil] Entity "OSPropertyDecimal" has no table in the database
2017-09-19 14:38:18,858 JIRA-Bootstrap ERROR [o.o.c.entity.jdbc.DatabaseUtil] Could not create table "jira_core.propertydecimal"

CREATE TABLE jira_core.propertydecimal (ID NUMERIC(18,0) NOT NULL, propertyvalue FLOAT8, CONSTRAINT PK_propertydecimal PRIMARY KEY (ID))
Error was: org.postgresql.util.PSQLException: ERROR: relation "propertydecimal" already exists

At this point you could be running into an issue where the JIRA user may not be able to connect to that table, etc.

I would be interested in knowing what happens with a new database:

1. Backup your existing database
2. Create a new database for JIRA with a different name using the steps in Connecting JIRA applications to PostgreSQL
3. Use the dbconfig.xml to change the location or use the JIRA Configuration Utility to change the database you're using
4. Restart JIRA.

See if you run into the same issues when you do that and we'll go from there.

Cheers,

Branden

[tdarindc3]

I originally thought the database I was connecting to was PostgreSQL.  It is EnterpriseDB.  Enterprise DB seems to use a 4 part versioning scheme.  In this case 9.5.9.14.  I looked at the code of the 9.4.1212 driver and this seems to only account for parsing 3 part version numbers.  This causes an error when it tries to find the database version in the driver and makes it default to a legacy query which causes the "i.indproc" message.  (In the org.postgresql.core.ServerVersion class.)

I looked at the code of the latest driver 42.1.4.  The 42.1.4 jdbc driver was updated to account for versioning of 4 or more parts by just using the preceding version parts and ignoring the rest.  I updated the jdbc jar in the Jira deployment to the 42.1.4 jdbc jar and restarted the Jira server and everything is working correctly.

The previous postgresql jdbc jar in the 7.3.6 (postgresql-9.1-903.jdbc4-atlassian-hosted.jar) must have handled this differently in order for it to have worked.