#1566  Upgrade failed: OneDev 9.1.5 -> 9.1.9
Released
jbauer opened 7 months ago
INFO  - >>> INFO  - Building zip: /opt/onedev/site/db-backup/2023-09-18_12-12-31.zip
INFO  - >>> INFO  - Database is successfully backed up to /opt/onedev/site/db-backup/2023-09-18_12-12-31.zip
INFO  - >>> INFO  - Stopping application...
INFO  - Cleaning database with old program...
INFO  - >>> INFO  - Launching application from '/opt/onedev'...
INFO  - >>> INFO  - Cleaning temp directory...
INFO  - >>> INFO  - Starting application...
INFO  - >>> INFO  - Waiting for server to stop...
INFO  - >>> INFO  - Database is cleaned successfully
INFO  - >>> INFO  - Stopping application...
INFO  - Updating program files...
INFO  - Restoring database with new program...
INFO  - >>> INFO  - Launching application from '/opt/onedev'...
INFO  - >>> INFO  - Cleaning temp directory...
INFO  - >>> INFO  - Starting application...
INFO  - >>> INFO  - Restoring database from /opt/onedev/site/db-backup/2023-09-18_12-12-31.zip...
INFO  - >>> INFO  - Waiting for server to stop...
INFO  - >>> INFO  - Creating tables...
INFO  - >>> INFO  - Importing data into database...
INFO  - >>> INFO  - Importing from data file 'Roles.xml'...
INFO  - >>> ERROR - Error booting application
INFO  - >>> com.thoughtworks.xstream.security.ForbiddenClassException: io.onedev.server.model.Role
INFO  - >>> 	at com.thoughtworks.xstream.security.NoTypePermission.allows(NoTypePermission.java:26)
INFO  - >>> 	at com.thoughtworks.xstream.mapper.SecurityMapper.realClass(SecurityMapper.java:74)
INFO  - >>> 	at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:125)
INFO  - >>> 	at com.thoughtworks.xstream.mapper.CachingMapper.realClass(CachingMapper.java:47)
INFO  - >>> 	at com.thoughtworks.xstream.core.util.HierarchicalStreams.readClassType(HierarchicalStreams.java:29)
INFO  - >>> 	at io.onedev.server.data.migration.VersionedXmlDoc.toBean(VersionedXmlDoc.java:489)
INFO  - >>> 	at io.onedev.server.data.migration.VersionedXmlDoc.toBean(VersionedXmlDoc.java:474)
INFO  - >>> 	at io.onedev.server.data.DefaultDataManager.importData(DefaultDataManager.java:461)
INFO  - >>> 	at io.onedev.server.persistence.SessionInterceptor$1.call(SessionInterceptor.java:23)
INFO  - >>> 	at io.onedev.server.persistence.DefaultSessionManager.call(DefaultSessionManager.java:90)
INFO  - >>> 	at io.onedev.server.persistence.SessionInterceptor.invoke(SessionInterceptor.java:18)
INFO  - >>> 	at io.onedev.server.commandhandler.RestoreDatabase.doRestore(RestoreDatabase.java:129)
INFO  - >>> 	at io.onedev.server.commandhandler.RestoreDatabase.lambda$start$0(RestoreDatabase.java:79)
INFO  - >>> 	at io.onedev.server.commandhandler.CommandHandler.doMaintenance(CommandHandler.java:31)
INFO  - >>> 	at io.onedev.server.commandhandler.RestoreDatabase.start(RestoreDatabase.java:72)
INFO  - >>> 	at io.onedev.commons.loader.DefaultPluginManager.start(DefaultPluginManager.java:44)
INFO  - >>> 	at io.onedev.commons.loader.AppLoader.start(AppLoader.java:60)
INFO  - >>> 	at io.onedev.commons.bootstrap.Bootstrap.main(Bootstrap.java:198)
INFO  - >>> INFO  - Stopping application...
ERROR - Failed to upgrade /opt/onedev
INFO  - >>> INFO  - Launching application from '/opt/onedev'...
INFO  - >>> INFO  - Cleaning temp directory...
INFO  - >>> INFO  - Starting application...
INFO  - >>> INFO  - Waiting for server to stop...
INFO  - >>> ERROR - Error booting application
INFO  - >>> java.lang.RuntimeException: No data version found in database: this is normally caused by unsuccessful restore/upgrade, please clean the database and try again
INFO  - >>> 	at io.onedev.server.data.DefaultDataManager.readDbDataVersion(DefaultDataManager.java:266)
INFO  - >>> 	at io.onedev.server.data.DefaultDataManager.checkDataVersion(DefaultDataManager.java:192)
INFO  - >>> 	at io.onedev.server.commandhandler.CheckDataVersion.lambda$start$0(CheckDataVersion.java:51)
INFO  - >>> 	at io.onedev.server.persistence.PersistenceUtils.callWithTransaction(PersistenceUtils.java:47)
INFO  - >>> 	at io.onedev.server.commandhandler.CheckDataVersion.lambda$start$1(CheckDataVersion.java:51)
INFO  - >>> 	at io.onedev.server.commandhandler.CommandHandler.doMaintenance(CommandHandler.java:31)
INFO  - >>> 	at io.onedev.server.commandhandler.CheckDataVersion.start(CheckDataVersion.java:44)
INFO  - >>> 	at io.onedev.commons.loader.DefaultPluginManager.start(DefaultPluginManager.java:44)
INFO  - >>> 	at io.onedev.commons.loader.AppLoader.start(AppLoader.java:60)
INFO  - >>> 	at io.onedev.commons.bootstrap.Bootstrap.main(Bootstrap.java:198)
INFO  - >>> INFO  - Stopping application...
INFO  - Cleaning database with new program...
INFO  - >>> INFO  - Launching application from '/opt/onedev'...
INFO  - >>> INFO  - Cleaning temp directory...
INFO  - >>> INFO  - Starting application...
INFO  - >>> INFO  - Waiting for server to stop...
INFO  - >>> ERROR - Error booting application
INFO  - >>> java.lang.RuntimeException: No data version found in database: this is normally caused by unsuccessful restore/upgrade, please clean the database and try again
INFO  - >>> 	at io.onedev.server.data.DefaultDataManager.readDbDataVersion(DefaultDataManager.java:266)
INFO  - >>> 	at io.onedev.server.data.DefaultDataManager.checkDataVersion(DefaultDataManager.java:192)
INFO  - >>> 	at io.onedev.server.commandhandler.CleanDatabase.lambda$start$0(CleanDatabase.java:51)
INFO  - >>> 	at io.onedev.server.commandhandler.CommandHandler.doMaintenance(CommandHandler.java:31)
INFO  - >>> 	at io.onedev.server.commandhandler.CleanDatabase.start(CleanDatabase.java:42)
INFO  - >>> 	at io.onedev.commons.loader.DefaultPluginManager.start(DefaultPluginManager.java:44)
INFO  - >>> 	at io.onedev.commons.loader.AppLoader.start(AppLoader.java:60)
INFO  - >>> 	at io.onedev.commons.bootstrap.Bootstrap.main(Bootstrap.java:198)
INFO  - >>> INFO  - Stopping application...
ERROR - Error cleaning database
io.onedev.commons.utils.ExplicitException: Failed to run command: /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Xmx9998m --add-opens=java.base/sun.nio.ch=ALL-UNNAMED --add-opens=java.base/java.lang=ALL-UNNAMED --add-opens=java.base/java.lang.reflect=ALL-UNNAMED --add-opens=java.base/java.lang.invoke=ALL-UNNAMED --add-opens=java.base/java.util=ALL-UNNAMED --add-opens=java.base/java.text=ALL-UNNAMED --add-opens=java.desktop/java.awt.font=ALL-UNNAMED --add-modules=java.se --add-exports=java.base/jdk.internal.ref=ALL-UNNAMED --add-opens=java.management/sun.management=ALL-UNNAMED --add-opens=jdk.management/com.sun.management.internal=ALL-UNNAMED -classpath * io.onedev.commons.bootstrap.Bootstrap clean-db, return code: 1
	at io.onedev.commons.utils.command.ExecutionResult.buildException(ExecutionResult.java:54)
	at io.onedev.commons.utils.command.ExecutionResult.checkReturnCode(ExecutionResult.java:62)
	at io.onedev.server.commandhandler.Upgrade$3.call(Upgrade.java:427)
	at io.onedev.server.commandhandler.Upgrade.lambda$start$0(Upgrade.java:514)
	at io.onedev.server.persistence.PersistenceUtils.lambda$callWithLock$1(PersistenceUtils.java:116)
	at io.onedev.server.persistence.PersistenceUtils.callWithTransaction(PersistenceUtils.java:47)
	at io.onedev.server.persistence.PersistenceUtils.callWithLock(PersistenceUtils.java:106)
	at io.onedev.server.commandhandler.Upgrade.start(Upgrade.java:514)
	at io.onedev.commons.loader.DefaultPluginManager.start(DefaultPluginManager.java:44)
	at io.onedev.commons.loader.AppLoader.start(AppLoader.java:60)
	at io.onedev.commons.bootstrap.Bootstrap.main(Bootstrap.java:198)
	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.tanukisoftware.wrapper.WrapperSimpleApp.run(WrapperSimpleApp.java:349)
	at java.base/java.lang.Thread.run(Thread.java:829)
INFO  - Restoring old program files...
ERROR - Error restoring old program files
java.lang.RuntimeException: Failed to delete file /opt/onedev/conf/trust-certs
	at io.onedev.commons.utils.FileUtils.deleteFile(FileUtils.java:231)
	at io.onedev.commons.utils.FileUtils.deleteDir(FileUtils.java:197)
	at io.onedev.commons.utils.FileUtils.cleanDir(FileUtils.java:286)
	at io.onedev.server.commandhandler.Upgrade$3.call(Upgrade.java:442)
	at io.onedev.server.commandhandler.Upgrade.lambda$start$0(Upgrade.java:514)
	at io.onedev.server.persistence.PersistenceUtils.lambda$callWithLock$1(PersistenceUtils.java:116)
	at io.onedev.server.persistence.PersistenceUtils.callWithTransaction(PersistenceUtils.java:47)
	at io.onedev.server.persistence.PersistenceUtils.callWithLock(PersistenceUtils.java:106)
	at io.onedev.server.commandhandler.Upgrade.start(Upgrade.java:514)
	at io.onedev.commons.loader.DefaultPluginManager.start(DefaultPluginManager.java:44)
	at io.onedev.commons.loader.AppLoader.start(AppLoader.java:60)
	at io.onedev.commons.bootstrap.Bootstrap.main(Bootstrap.java:198)
	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.tanukisoftware.wrapper.WrapperSimpleApp.run(WrapperSimpleApp.java:349)
	at java.base/java.lang.Thread.run(Thread.java:829)
WARN  - Please restore manually from "/opt/onedev/site/program-backup/2023-09-18_12-12-31"
ERROR - !! Failed to upgrade /opt/onedev
OneDev is unable to restore old database, please do it manually by first resetting it (delete and create), and then running below command:
/opt/onedev/bin/restore-db.sh /opt/onedev/site/db-backup/2023-09-18_12-12-31.zip
INFO  - Stopping application...
<-- Wrapper Stopped
OneDev changed state to 'Closed' 7 months ago
Previous Value Current Value
Open
Closed
OneDev commented 7 months ago

State changed as code fixing the issue is committed (9135668a)

Referenced from commit 7 months ago
jbauer commented 7 months ago

I guess I have to copy back the contents of /opt/onedev/sites/program-backup/<date> to /opt/onedev/ and then figure out a way how to call /opt/onedev/bin/restore-db.sh /opt/onedev/site/db-backup/2023-09-18_12-12-31.zip from a docker container with mounted onedev?

jbauer commented 7 months ago

Also note Failed to delete file /opt/onedev/conf/trust-certs which contains a ca.crt file for OneDev. Maybe that is a second issue

Robin Shen commented 7 months ago

Yes, please restore the program backup manually. Then you can start OneDev container (database may be empty now). Then exec into the container, and run "bin/restore-db.sh" to restore database.

jbauer commented 7 months ago

But I would use the 9.1.5 container for it, right?

Robin Shen commented 7 months ago

Yes, that is right.

OneDev changed state to 'Released' 7 months ago
Previous Value Current Value
Closed
Released
OneDev commented 7 months ago

State changed as build #4106 is successful

Robin Shen commented 7 months ago

Also note Failed to delete file /opt/onedev/conf/trust-certs which contains a ca.crt file for OneDev. Maybe that is a second issue

Is /opt/onedev/conf/trust-certs a separate mount path?

jbauer commented 7 months ago

Also note Failed to delete file /opt/onedev/conf/trust-certs which contains a ca.crt file for OneDev. Maybe that is a second issue

Is /opt/onedev/conf/trust-certs a separate mount path?

Yes it is. Reason is that others (e.g. OneDev agent, other services) also need the ca.crt. So I have a docker volume mounted with just the ca.crt.

      - type: volume
        source: ca-cert
        target: /opt/onedev/conf/trust-certs
        
      - type: volume
        source: ca-cert
        target: /agent/conf/trust-certs
jbauer commented 7 months ago

@robin Executing the restore command in console of 9.1.5 container results in

INFO  - Validating data file 'LinkSpecs.xml'...
ERROR - Error booting application
java.lang.RuntimeException: Error validating entity (entity class: class io.onedev.server.model.LinkSpec, entity id: 3, entity property: issueQuery, error message: Malformed query)
        at io.onedev.server.data.DefaultDataManager.reportError(DefaultDataManager.java:511)
        at io.onedev.server.data.DefaultDataManager.validateData(DefaultDataManager.java:498)
        at io.onedev.server.commandhandler.RestoreDatabase.doRestore(RestoreDatabase.java:108)
        at io.onedev.server.commandhandler.RestoreDatabase.lambda$start$0(RestoreDatabase.java:79)
        at io.onedev.server.commandhandler.CommandHandler.doMaintenance(CommandHandler.java:31)
        at io.onedev.server.commandhandler.RestoreDatabase.start(RestoreDatabase.java:72)
        at io.onedev.commons.loader.DefaultPluginManager.start(DefaultPluginManager.java:44)
        at io.onedev.commons.loader.AppLoader.start(AppLoader.java:60)
        at io.onedev.commons.bootstrap.Bootstrap.main(Bootstrap.java:198)
        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.tanukisoftware.wrapper.WrapperSimpleApp.run(WrapperSimpleApp.java:349)
        at java.base/java.lang.Thread.run(Thread.java:829)
INFO  - Stopping application...

Any idea? Does it validate against the database tables? I have not deleted the db as I thought it is empty anyways.

jbauer commented 7 months ago

The relevant XML of LinkSpecs.xml is

  <io.onedev.server.model.LinkSpec revision="0.0">
    <id>3</id>
    <name>Task</name>
    <multiple>true</multiple>
    <issueQuery>"Typ" is "Aufgabe"</issueQuery>
    <opposite>
      <name>Parent</name>
      <multiple>false</multiple>
    </opposite>
    <order>3</order>
  </io.onedev.server.model.LinkSpec>
Robin Shen commented 7 months ago

"Typ" is "Aufgabe" is invalid. Should be "Type" is "Aufgabe" instead. Please fix this manually and repack the zip file to restore

jbauer commented 7 months ago

"Typ" is "Aufgabe" is invalid. Should be "Type" is "Aufgabe" instead. Please fix this manually and repack the zip file to restore

In my installation I have renamed Type to german Typ. I do not have any issue field named Type, so Typ is generally correct.

Robin Shen commented 7 months ago

That is odd. Nevertheless, you may run restore-db.sh /path/to/backup.zip false to bypass validation. After restore, you may check that query further.

jbauer commented 7 months ago

As an example taken from IssueFields.xml

<io.onedev.server.model.IssueField revision="0.0">
    <id>744</id>
    <issue>74</issue>
    <name>Typ</name>
    <value>Verbesserung</value>
    <type>Enumeration</type>
    <ordinal>2</ordinal>
  </io.onedev.server.model.IssueField>

That is basically translated from English Type -> Improvement to German Typ -> Verbesserung.

jbauer commented 7 months ago

@robin Do I still need to do anything? I have restored the backup without validation and now OneDev does not start and continuously logs io.onedev.server.OneDev - Maintenance in progress, waiting... every 5 seconds

Robin Shen commented 7 months ago

Seems like there is another bug here. Please remove file /opt/onedev/maintenance and then restart the container to see if it works.

jbauer commented 7 months ago

@robin Yes that file exists. After deleting it OneDev has started.

I also checked the issue links in OneDev UI and it seems totally correct. OneDev even suggests "Typ" is "Aufgabe" via auto completion. There also some issues in the DB which use this issue link. So I guess there is some issue in the validation code.

Robin Shen commented 7 months ago

I tested locally and it works. Maybe there is some different charset? If you reproduce the issue with a sample backup, it will help me to address the issue.

Robin Shen commented 7 months ago

There are multiple issues here when OneDev fails to ugprade. I will investigate them hoping to make the upgrade experience smoother, even for a failed upgrade.

bufferUnderrun commented 7 months ago

Successfully upgrade from v9.1.2 to v9.1.10 but there a step which is slower than before.

Robin Shen commented 7 months ago

Successfully upgrade from v9.1.2 to v9.1.10 but there a step which is slower than before.

No changes affecting performance as far as I know.

jbauer commented 7 months ago

I tested locally and it works. Maybe there is some different charset? If you reproduce the issue with a sample backup, it will help me to address the issue.

@robin I have a git clone of onedev/server. I updated it to 9.1.5 and now I am wondering how I could execute restore-db.sh against it locally in IDE so I can debug it? Seems like the script does not exist in git? Do I need to generate it somehow?

Robin Shen commented 7 months ago

You may create a Run Configuration in IntelliJ the same as running OneDev server, but with command param restore-db /path/to/backup.zip

jbauer commented 7 months ago

@robin Grrr just typed an answer and OneDev had reloaded because you updated it to 9.1.12 :)

So the issue with restore-db command/shell script is that the DB was empty. If the restore command validates a backup XML file that contains an issue query the code ends up in IssueQuery.checkField(fieldName, operator, options) and tries to load global issue properties from the DB. Because DB is empty getGlobalIssueSetting() returns null and an NPE is thrown. That NPE is catched in IssueQueryValidator.isValid(value, constraintContext) however the stack trace is never logged. Instead the NPE message is checked and because there isn't any message it is replaced with Malformed query and then converted to a misleading constraint violation.

To me it looks like you can not restore a DB backup if that backup contains any XML file with some issue query. It does not need to be a LinkSpec (which is my case). I think if you want to validate the backup you need to insert some data while validating. So maybe you need a dependency tree of your entities to validate them in correct order and insert validated data right away. Otherwise validating on empty DB doesn't really work. Or you skip validating issue queries containing custom field names. But then validation is only half-baked.

There might be other validators that require settings from the DB.

jbauer commented 7 months ago

@robin Oh and while testing around I noticed that the <package>.Bootstrap clean-db command does not delete all tables. After executing there were still o_clusterserver and o_databaselock tables in the database.

Robin Shen commented 7 months ago

To me it looks like you can not restore a DB backup if that backup contains any XML file with some issue query. It does not need to be a LinkSpec (which is my case). I think if you want to validate the backup you need to insert some data while validating. So maybe you need a dependency tree of your entities to validate them in correct order and insert validated data right away. Otherwise validating on empty DB doesn't really work. Or you skip validating issue queries containing custom field names. But then validation is only half-baked.

Thanks for the investigation.

Oh and while testing around I noticed that the .Bootstrap clean-db command does not delete all tables. After executing there were still o_clusterserver and o_databaselock tables in the database.

These two are special tables and will never change. It wont't be cleaned also

Robin Shen commented 7 months ago

Data validation will be turned off completely for data restore. It does not provide much value as data file itself is exported from OneDev. And it causes much trouble instead.

issue 1 of 1
Type
Bug
Priority
Critical
Assignee
Affected Versions
9.1.5, 9.1.9
Labels
No labels
Issue Votes (0)
Watchers (4)
Reference
onedev/server#1566
Please wait...
Page is in error, reload to recover