I am trying to migrate a Stash instance from the internal database (HSQLDB) to PostgreSQL 9.3.5.
The migration is failing with the following error in browser:
Stash could not be migrated to the new database. Some data may have already been written to the new database leaving it in an inconsistent state. You will need to empty or recreate the new database before trying again.
com.atlassian.stash.internal.maintenance.migration.DatabaseMigrationTask.run(DatabaseMigrationTask.java:51)
com.atlassian.stash.internal.maintenance.DefaultMaintenanceTaskMonitor.run(DefaultMaintenanceTaskMonitor.java:183)
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
...
Failed to execute change: Insert Row; nested exception is org.postgresql.util.PSQLException: ERROR: invalid byte sequence for encoding "UTF8": 0x00
com.atlassian.stash.internal.backup.liquibase.DefaultLiquibaseDao.insert(DefaultLiquibaseDao.java:274)
com.atlassian.stash.internal.backup.liquibase.DatabaseUpdater.endElement(DatabaseUpdater.java:81)
org.apache.xerces.parsers.AbstractSAXParser.endElement(Unknown Source)
...
ERROR: invalid byte sequence for encoding "UTF8": 0x00
org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2102)
org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1835)
org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:257)
...
We are usign an empty PostgreSQL database as required by the Stash migration documentation. https://confluence.atlassian.com/display/STASH/Connecting+Stash+to+PostgreSQL
The schema is populated durring the migration with 71 tables some of them containing data.
In the atlassian-stash.log file the part where the migration is failing is:
2014-11-28 21:52:27,137 INFO [threadpool:thread-2] mvutcovici @16LK6DXx1311x84x0 16mw1ju 10.128.221.98 "POST /admin/db/edit HTTP/1.1" c.a.s.i.b.l.DefaultLiquibaseMigrationDao Found 61 non-empty change sets to apply to the target database
2014-11-28 21:52:27,137 INFO [threadpool:thread-2] mvutcovici @16LK6DXx1311x84x0 16mw1ju 10.128.221.98 "POST /admin/db/edit HTTP/1.1" c.a.s.i.b.l.DefaultLiquibaseMigrationDao Connecting to target database
.............
2014-11-28 21:52:28,936 DEBUG [threadpool:thread-2] mvutcovici @16LK6DXx1311x84x0 16mw1ju 10.128.221.98 "POST /admin/db/edit HTTP/1.1" c.a.s.i.b.liquibase.DatabaseUpdater Executing changeset 32 of 61, containing 293 changes with id plugin_setting-41
2014-11-28 21:52:28,950 DEBUG [threadpool:thread-2] mvutcovici @16LK6DXx1311x84x0 16mw1ju 10.128.221.98 "POST /admin/db/edit HTTP/1.1" c.a.s.i.b.l.DefaultLiquibaseDao Unlocking Liquibase
2014-11-28 21:52:29,059 ERROR [threadpool:thread-2] mvutcovici @16LK6DXx1311x84x0 16mw1ju 10.128.221.98 "POST /admin/db/edit HTTP/1.1" c.a.s.i.b.l.DefaultLiquibaseDao Failed to release Liquibase lock
liquibase.exception.LockException: liquibase.exception.UnexpectedLiquibaseException: org.postgresql.util.PSQLException: ERROR: current transaction is aborted, commands ignored until end of transaction block
at liquibase.lockservice.LockService.releaseLock(LockService.java:152) ~[LockService.class:na]
at com.atlassian.stash.internal.backup.liquibase.DefaultLiquibaseDao$2.apply(DefaultLiquibaseDao.java:83) [DefaultLiquibaseDao$2.class:na]
at com.atlassian.stash.internal.backup.liquibase.DefaultLiquibaseDao$2.apply(DefaultLiquibaseDao.java:79) [DefaultLiquibaseDao$2.class:na]
at com.atlassian.fugue.Option$Some.foreach(Option.java:441) [Option$Some.class:na]
at com.atlassian.stash.internal.backup.liquibase.DefaultLiquibaseDao.unlock(DefaultLiquibaseDao.java:471) [DefaultLiquibaseDao.class:na]
at com.atlassian.stash.internal.backup.liquibase.DefaultLiquibaseDao.withLock(DefaultLiquibaseDao.java:303) [DefaultLiquibaseDao.class:na]
at com.atlassian.stash.internal.backup.liquibase.DefaultLiquibaseMigrationDao.restore(DefaultLiquibaseMigrationDao.java:168) [DefaultLiquibaseMigrationDao.class:na]
at com.atlassian.stash.internal.maintenance.restore.DatabaseRestoreStep.run(DatabaseRestoreStep.java:104) [DatabaseRestoreStep.class:na]
at com.atlassian.stash.internal.maintenance.CompositeMaintenanceTask$Step.run(CompositeMaintenanceTask.java:130) [CompositeMaintenanceTask$Step.class:na]
at com.atlassian.stash.internal.maintenance.CompositeMaintenanceTask.run(CompositeMaintenanceTask.java:69) [CompositeMaintenanceTask.class:na]
at com.atlassian.stash.internal.maintenance.restore.RestorePhase.run(RestorePhase.java:26) [RestorePhase.class:na]
at com.atlassian.stash.internal.maintenance.CompositeMaintenanceTask$Step.run(CompositeMaintenanceTask.java:130) [CompositeMaintenanceTask$Step.class:na]
at com.atlassian.stash.internal.maintenance.CompositeMaintenanceTask.run(CompositeMaintenanceTask.java:69) [CompositeMaintenanceTask.class:na]
at com.atlassian.stash.internal.maintenance.CompositeMaintenanceTask$Step.run(CompositeMaintenanceTask.java:130) [CompositeMaintenanceTask$Step.class:na]
at com.atlassian.stash.internal.maintenance.CompositeMaintenanceTask.run(CompositeMaintenanceTask.java:69) [CompositeMaintenanceTask.class:na]
at com.atlassian.stash.internal.maintenance.MaintenanceModePhase.run(MaintenanceModePhase.java:27) [MaintenanceModePhase.class:na]
at com.atlassian.stash.internal.maintenance.migration.BaseMigrationTask.run(BaseMigrationTask.java:60) [BaseMigrationTask.class:na]
at com.atlassian.stash.internal.maintenance.migration.DatabaseMigrationTask.run(DatabaseMigrationTask.java:46) [DatabaseMigrationTask.class:na]
at com.atlassian.stash.internal.maintenance.DefaultMaintenanceTaskMonitor.run(DefaultMaintenanceTaskMonitor.java:183) [DefaultMaintenanceTaskMonitor.class:na]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [na:1.7.0_72]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) [na:1.7.0_72]
at com.atlassian.stash.internal.concurrent.StateTransferringExecutor$StateTransferringRunnable.run(StateTransferringExecutor.java:69) [StateTransferringExecutor$StateTransferringRunnable.class:na]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [na:1.7.0_72]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) [na:1.7.0_72]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178) [na:1.7.0_72]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292) [na:1.7.0_72]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_72]
at java.lang.Thread.run(Thread.java:745) [na:1.7.0_72]
... 1 frame trimmed
Caused by: liquibase.exception.UnexpectedLiquibaseException: org.postgresql.util.PSQLException: ERROR: current transaction is aborted, commands ignored until end of transaction block
at liquibase.snapshot.jvm.JdbcDatabaseSnapshotGenerator.hasTable(JdbcDatabaseSnapshotGenerator.java:63) ~[JdbcDatabaseSnapshotGenerator.class:na]
at liquibase.snapshot.jvm.JdbcDatabaseSnapshotGenerator.hasDatabaseChangeLogLockTable(JdbcDatabaseSnapshotGenerator.java:49) ~[JdbcDatabaseSnapshotGenerator.class:na]
at liquibase.database.AbstractDatabase.hasDatabaseChangeLogLockTable(AbstractDatabase.java:549) ~[AbstractDatabase.class:na]
at liquibase.lockservice.LockService.releaseLock(LockService.java:135) ~[LockService.class:na]
... 28 common frames omitted
Caused by: org.postgresql.util.PSQLException: ERROR: current transaction is aborted, commands ignored until end of transaction block
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2102) ~[postgresql-9.1-901.jdbc4.jar:na]
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1835) ~[postgresql-9.1-901.jdbc4.jar:na]
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:257) ~[postgresql-9.1-901.jdbc4.jar:na]
at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:500) ~[postgresql-9.1-901.jdbc4.jar:na]
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:374) ~[postgresql-9.1-901.jdbc4.jar:na]
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:254) ~[postgresql-9.1-901.jdbc4.jar:na]
at org.postgresql.jdbc2.AbstractJdbc2DatabaseMetaData.getTables(AbstractJdbc2DatabaseMetaData.java:2069) ~[postgresql-9.1-901.jdbc4.jar:na]
at liquibase.snapshot.jvm.JdbcDatabaseSnapshotGenerator.hasTable(JdbcDatabaseSnapshotGenerator.java:54) ~[JdbcDatabaseSnapshotGenerator.class:na]
... 31 common frames omitted
2014-11-28 21:52:29,110 DEBUG [threadpool:thread-2] mvutcovici @16LK6DXx1311x84x0 16mw1ju 10.128.221.98 "POST /admin/db/edit HTTP/1.1" c.a.s.i.b.l.DefaultLiquibaseDao Liquibase unlocked
2014-11-28 21:52:29,110 DEBUG [threadpool:thread-2] mvutcovici @16LK6DXx1311x84x0 16mw1ju 10.128.221.98 "POST /admin/db/edit HTTP/1.1" c.a.s.i.b.l.DefaultLiquibaseMigrationDao Deleting temporary file
2014-11-28 21:52:29,129 DEBUG [threadpool:thread-2] mvutcovici @16LK6DXx1311x84x0 16mw1ju 10.128.221.98 "POST /admin/db/edit HTTP/1.1" c.a.s.i.b.l.DefaultLiquibaseDao Unlocking Liquibase
..........
2014-11-28 21:52:29,155 DEBUG [threadpool:thread-2] mvutcovici @16LK6DXx1311x84x0 16mw1ju 10.128.221.98 "POST /admin/db/edit HTTP/1.1" c.a.s.i.m.restore.RestorePhase Successfully deleted unpacked files from /opt/stash-home/tmp/backup-mvutcovici-20141128-215202-764Z.zip-unpack84449949564272605.backup
2014-11-28 21:52:29,164 ERROR [threadpool:thread-2] mvutcovici @16LK6DXx1311x84x0 16mw1ju 10.128.221.98 "POST /admin/db/edit HTTP/1.1" c.a.s.i.m.m.BaseMigrationTask Reverting database configuration after a failed migration attempt
com.atlassian.stash.internal.backup.liquibase.LiquibaseChangeExecutionException: Failed to execute change: Insert Row; nested exception is org.postgresql.util.PSQLException: ERROR: invalid byte sequence for encoding "UTF8": 0x00
There are some temporary zip files generated in the stash.home/export/ and in the last one, in the stash-data.xml file there, the 32 changeset has the id "sta_project_permission-32".
I've activated debug loggin in postgresql. Here is the relevant log from the database server:
< 2014-12-01 14:21:17.997 GMT >LOG: 00000: execute S_29: insert into plugin_setting (namespace, key_name, key_value, id) values ($1, $2, $3, $4)
< 2014-12-01 14:21:17.997 GMT >DETAIL: parameters: $1 = 'stash.global.settings', $2 = 'applinks.local.RDV.stash_project.linked.entities', $3 = '#java.util.List
', $4 = '17'
< 2014-12-01 14:21:17.997 GMT >LOCATION: exec_execute_message, postgres.c:1906
< 2014-12-01 14:21:17.997 GMT >LOG: 00000: execute S_29: insert into plugin_setting (namespace, key_name, key_value, id) values ($1, $2, $3, $4)
< 2014-12-01 14:21:17.997 GMT >DETAIL: parameters: $1 = 'stash.global.settings', $2 = 'applinks.local.RDVSER.stash_project.linked.entities', $3 = '#java.util.List
', $4 = '18'
< 2014-12-01 14:21:17.997 GMT >LOCATION: exec_execute_message, postgres.c:1906
< 2014-12-01 14:21:17.998 GMT >ERROR: 22021: invalid byte sequence for encoding "UTF8": 0x00
< 2014-12-01 14:21:17.998 GMT >LOCATION: report_invalid_encoding, wchar.c:2020
< 2014-12-01 14:21:17.998 GMT >STATEMENT: insert into plugin_setting (namespace, key_name, key_value, id) values ($1, $2, $3, $4)
< 2014-12-01 14:21:18.003 GMT >ERROR: 25P02: current transaction is aborted, commands ignored until end of transaction block
< 2014-12-01 14:21:18.004 GMT >LOCATION: exec_parse_message, postgres.c:1259
< 2014-12-01 14:21:18.004 GMT >STATEMENT: SELECT NULL AS TABLE_CAT, n.nspname AS TABLE_SCHEM, c.relname AS TABLE_NAME, CASE n.nspname ~ '^pg_' OR n.nspname = 'information_schema' WHEN true THEN CASE WHEN n.nspname = 'pg_catalog' OR n.nspname = 'information_schema' THEN CASE c.relkind WHEN 'r' THEN 'SYSTEM TABLE' WHEN 'v' THEN 'SYSTEM VIEW' WHEN 'i' THEN 'SYSTEM INDEX' ELSE NULL END WHEN n.nspname = 'pg_toast' THEN CASE c.relkind WHEN 'r' THEN 'SYSTEM TOAST TABLE' WHEN 'i' THEN 'SYSTEM TOAST INDEX' ELSE NULL END ELSE CASE c.relkind WHEN 'r' THEN 'TEMPORARY TABLE' WHEN 'i' THEN 'TEMPORARY INDEX' WHEN 'S' THEN 'TEMPORARY SEQUENCE' WHEN 'v' THEN 'TEMPORARY VIEW' ELSE NULL END END WHEN false THEN CASE c.relkind WHEN 'r' THEN 'TABLE' WHEN 'i' THEN 'INDEX' WHEN 'S' THEN 'SEQUENCE' WHEN 'v' THEN 'VIEW' WHEN 'c' THEN 'TYPE' ELSE NULL END ELSE NULL END AS TABLE_TYPE, d.description AS REMARKS FROM pg_catalog.pg_namespace n, pg_catalog.pg_class c LEFT JOIN pg_catalog.pg_description d ON (c.oid = d.objoid AND d.objsubid = 0) LEFT JOIN pg_catalog.pg_class dc ON (d.classoid=dc.oid AND dc.relname='pg_class') LEFT JOIN pg_catalog.pg_namespace dn ON (dn.oid=dc.relnamespace AND dn.nspname='pg_catalog') WHERE c.relnamespace = n.oid AND n.nspname LIKE 'public' AND c.relname LIKE 'databasechangeloglock' AND (false OR ( c.relkind = 'r' AND n.nspname !~ '^pg_' AND n.nspname <> 'information_schema' ) ) ORDER BY TABLE_TYPE,TABLE_SCHEM,TABLE_NAME
< 2014-12-01 14:21:18.013 GMT >LOG: 00000: execute S_30: ROLLBACKThe XML entries from stash-data.xml file related to the PostgreSQL messages above:
<changeSet id="plugin_setting-41" author="mvutcovici">
......
<insert tableName="plugin_setting">
<column name="namespace" colType="character"><![CDATA[stash.global.settings]]></column>
<column name="key_name" colType="character"><![CDATA[applinks.local.RDV.stash_project.linked.entities]]></column>
<column name="key_value" colType="character"><![CDATA[#java.util.List\u000A]]></column>
<column name="id" colType="numeric"><![CDATA[17]]></column>
</insert>
<insert tableName="plugin_setting">
<column name="namespace" colType="character"><![CDATA[stash.global.settings]]></column>
<column name="key_name" colType="character"><![CDATA[applinks.local.RDVSER.stash_project.linked.entities]]></column>
<column name="key_value" colType="character"><![CDATA[#java.util.List\u000A]]></column>
<column name="id" colType="numeric"><![CDATA[18]]></column>
</insert>
<insert tableName="plugin_setting">
<column name="namespace" colType="character"><![CDATA[stash.global.settings]]></column>
<column name="key_name" colType="character"><![CDATA[audit.cleanup.last.run]]></column>
<column name="key_value" colType="character"><![CDATA[\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000]]></column>
<column name="id" colType="numeric"><![CDATA[19]]></column>
</insert>
.....
The error 'ERROR: 22021: invalid byte sequence for encoding "UTF8": 0x00' is related to: http://stackoverflow.com/a/1348551/290087
How can we populate the "audit.cleanup.last.run" field?
OS: CentOS 6.5 64bit
Java: Oracle Server JRE 7u72 64bit
DB Source: internal HSQLDB 2.2.4 (that is part of Stash installation)
DB Destination: postgresql93-server-9.3.5-1PGDG.rhel6.x86_64
Stash: v3.3.0 Installed using the install4j installer from atlassian-stash-3.3.0-x64.bin package.
Any help will be appreciated.
