onedev/server

#1392 Upgrade 7.9.3->7.9.12 results in DocumentException: An invalid XML character (Unicode: 0xffff) was found in the element content of the document.

Released

wojtek opened 11 months ago

I tried to upgrade 7.9.3->7.9.12 (I'm aware that there are newer versions, but I intended to avoid jumping too much) and it result in following exception:

INFO - >>> INFO - Cleaning temp directory...
INFO - >>> INFO - Starting server...
INFO - >>> INFO - Database is cleaned successfully
INFO - >>> INFO - Stopping server...
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 server...
INFO - >>> INFO - Restoring database from /opt/onedev/site/db-backup/2023-05-24_21-28-29.zip...
INFO - >>> ERROR - Error booting application
INFO - >>> java.lang.RuntimeException: java.lang.reflect.InvocationTargetException
INFO - >>> at io.onedev.commons.bootstrap.Bootstrap.unchecked(Bootstrap.java:341)
INFO - >>> at io.onedev.commons.utils.ExceptionUtils.unchecked(ExceptionUtils.java:35)
INFO - >>> at io.onedev.server.migration.MigrationHelper.migrate(MigrationHelper.java:151)
INFO - >>> at io.onedev.server.persistence.DefaultDataManager.migrateData(DefaultDataManager.java:389)
INFO - >>> at io.onedev.server.commandhandler.RestoreDatabase.doRestore(RestoreDatabase.java:100)
INFO - >>> at io.onedev.server.commandhandler.RestoreDatabase.start(RestoreDatabase.java:79)
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:204)
INFO - >>> Caused by: java.lang.reflect.InvocationTargetException: null
INFO - >>> at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
INFO - >>> at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
INFO - >>> at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
INFO - >>> at java.base/java.lang.reflect.Method.invoke(Method.java:566)
INFO - >>> at io.onedev.server.migration.MigrationHelper.migrate(MigrationHelper.java:149)
INFO - >>> ... 6 common frames omitted
INFO - >>> Caused by: java.lang.RuntimeException: org.dom4j.DocumentException: Error on line 37770 of document : An invalid XML character (Unicode: 0xffff) was found in the element content of the document.
INFO - >>> at io.onedev.commons.bootstrap.Bootstrap.unchecked(Bootstrap.java:341)
INFO - >>> at io.onedev.commons.utils.ExceptionUtils.unchecked(ExceptionUtils.java:35)
INFO - >>> at io.onedev.server.migration.VersionedXmlDoc.fromXML(VersionedXmlDoc.java:417)
INFO - >>> at io.onedev.server.migration.VersionedXmlDoc.fromFile(VersionedXmlDoc.java:423)
INFO - >>> at io.onedev.server.migration.DataMigrator.migrate108(DataMigrator.java:4663)
INFO - >>> ... 11 common frames omitted
INFO - >>> Caused by: org.dom4j.DocumentException: Error on line 37770 of document : An invalid XML character (Unicode: 0xffff) was found in the element content of the document.
INFO - >>> at org.dom4j.io.SAXReader.read(SAXReader.java:511)
INFO - >>> at org.dom4j.io.SAXReader.read(SAXReader.java:408)
INFO - >>> at io.onedev.server.migration.VersionedXmlDoc.fromXML(VersionedXmlDoc.java:415)
INFO - >>> ... 13 common frames omitted
INFO - >>> Caused by: org.xml.sax.SAXParseException: An invalid XML character (Unicode: 0xffff) was found in the element content of the document.
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.util.ErrorHandlerWrapper.createSAXParseException(ErrorHandlerWrapper.java:204)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.util.ErrorHandlerWrapper.fatalError(ErrorHandlerWrapper.java:178)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.impl.XMLErrorReporter.reportError(XMLErrorReporter.java:400)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.impl.XMLErrorReporter.reportError(XMLErrorReporter.java:327)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.impl.XMLScanner.reportFatalError(XMLScanner.java:1465)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$FragmentContentDriver.next(XMLDocumentFragmentScannerImpl.java:2838)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(XMLDocumentScannerImpl.java:605)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.next(XMLNSDocumentScannerImpl.java:112)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:534)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:888)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:824)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:141)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1216)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:635)
INFO - >>> at org.dom4j.io.SAXReader.read(SAXReader.java:494)
INFO - >>> ... 15 common frames omitted
INFO - >>> INFO - Stopping server...
ERROR - Failed to upgrade /opt/onedev
INFO - >>> INFO - Launching application from '/opt/onedev'...
INFO - >>> INFO - Cleaning temp directory...
INFO - >>> INFO - Starting server...
INFO - >>> ERROR - Database is not populated yet
INFO - >>> INFO - Stopping server...
INFO - Restoring old program files...
INFO - Old program files restored
INFO - Restoring old database...
INFO - >>> INFO - Launching application from '/opt/onedev'...
INFO - >>> INFO - Cleaning temp directory...
INFO - >>> INFO - Starting server...
INFO - >>> INFO - Restoring database from /opt/onedev/site/db-backup/2023-05-24_21-28-29.zip...
INFO - >>> INFO - Creating tables...
INFO - >>> INFO - Importing data into database...
INFO - >>> INFO - Importing from data file 'Roles.xml'...
INFO - >>> INFO - Importing from data file 'LabelSpecs.xml'...
INFO - >>> INFO - Importing from data file 'ProjectUpdates.xml'...
INFO - >>> INFO - Importing from data file 'Projects.xml'...
INFO - >>> INFO - Importing from data file 'Users.xml'...
INFO - >>> INFO - Importing from data file 'Issues.xml.12'...
INFO - >>> INFO - Importing from data file 'Issues.xml.10'...
INFO - >>> INFO - Importing from data file 'Issues.xml'...
INFO - >>> INFO - Importing from data file 'Issues.xml.7'...
INFO - >>> INFO - Importing from data file 'Issues.xml.5'...
INFO - >>> INFO - Importing from data file 'Issues.xml.9'...
INFO - >>> INFO - Importing from data file 'Issues.xml.3'...
INFO - >>> INFO - Importing from data file 'Issues.xml.2'...
INFO - >>> INFO - Importing from data file 'Issues.xml.11'...
INFO - >>> INFO - Importing from data file 'Issues.xml.14'...
INFO - >>> INFO - Importing from data file 'Issues.xml.8'...
INFO - >>> INFO - Importing from data file 'Issues.xml.4'...
INFO - >>> INFO - Importing from data file 'Issues.xml.13'...
INFO - >>> INFO - Importing from data file 'Issues.xml.6'...
INFO - >>> ERROR - Error booting application
INFO - >>> java.lang.RuntimeException: org.dom4j.DocumentException: Error on line 37770 of document : An invalid XML character (Unicode: 0xffff) was found in the element content of the document.
INFO - >>> at io.onedev.commons.bootstrap.Bootstrap.unchecked(Bootstrap.java:341)
INFO - >>> at io.onedev.commons.utils.ExceptionUtils.unchecked(ExceptionUtils.java:35)
INFO - >>> at io.onedev.server.migration.VersionedXmlDoc.fromXML(VersionedXmlDoc.java:417)
INFO - >>> at io.onedev.server.migration.VersionedXmlDoc.fromFile(VersionedXmlDoc.java:423)
INFO - >>> at io.onedev.server.persistence.DefaultDataManager.importData(DefaultDataManager.java:541)
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:125)
INFO - >>> at io.onedev.server.commandhandler.RestoreDatabase.start(RestoreDatabase.java:79)
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:204)
INFO - >>> Caused by: org.dom4j.DocumentException: Error on line 37770 of document : An invalid XML character (Unicode: 0xffff) was found in the element content of the document.
INFO - >>> at org.dom4j.io.SAXReader.read(SAXReader.java:511)
INFO - >>> at org.dom4j.io.SAXReader.read(SAXReader.java:408)
INFO - >>> at io.onedev.server.migration.VersionedXmlDoc.fromXML(VersionedXmlDoc.java:415)
INFO - >>> ... 10 common frames omitted
INFO - >>> Caused by: org.xml.sax.SAXParseException: An invalid XML character (Unicode: 0xffff) was found in the element content of the document.
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.util.ErrorHandlerWrapper.createSAXParseException(ErrorHandlerWrapper.java:204)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.util.ErrorHandlerWrapper.fatalError(ErrorHandlerWrapper.java:178)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.impl.XMLErrorReporter.reportError(XMLErrorReporter.java:400)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.impl.XMLErrorReporter.reportError(XMLErrorReporter.java:327)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.impl.XMLScanner.reportFatalError(XMLScanner.java:1465)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$FragmentContentDriver.next(XMLDocumentFragmentScannerImpl.java:2838)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(XMLDocumentScannerImpl.java:605)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.next(XMLNSDocumentScannerImpl.java:112)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:534)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:888)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:824)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:141)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1216)
INFO - >>> at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:635)
INFO - >>> at org.dom4j.io.SAXReader.read(SAXReader.java:494)
INFO - >>> ... 12 common frames omitted
INFO - >>> INFO - Stopping server...

I get the backup file, extracted the files and checked Issues.xml.6 file, and the mentioned line has this (view in vim):

java.io.IOException: parsing HTTP/1.1 status line, receiving [^@^@^X^D^@^@^@^@^@^@^A^@^@^P^@^@^C^@^@^C￨^@^E^@^@@^@^@^F^@^@^_@^@^@u^G^@^@^@^@^@^?<00ffff><00ffff><00ffff>^@^@^@^AUnexpected HTTP/1.x request: POST /3/d
evice/35B5946ADE0725C022673325668C74D2289674FFB977A06226E536C8F9241553 ], parser state [STATUS_LINE]
        at java.net.http/jdk.internal.net.http.common.Utils.wrapWithExtraDetail(Unknown Source)
        at java.net.http/jdk.internal.net.http.Http1Response$HeadersReader.onReadError(Unknown Source)
        at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.checkForErrors(Unknown Source)
        at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.flush(Unknown Source)
        at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SynchronizedRestartableTask.run(Unknown Source)

I'm going to try to upgrade to the latest version, but considering there wasn't any similar issue it will probably still happen.

wojtek commented 11 months ago

less: Captura de pantalla 2023-05-25 a las 17.19.31.png

vim Captura de pantalla 2023-05-25 a las 17.19.58.png

wojtek commented 11 months ago

1dev 7.9.3: Captura de pantalla 2023-05-25 a las 17.58.08.png

wojtek commented 11 months ago

Upgrading to latest 8.2.6 yields the same problem.

I'm not sure that info at the end:

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-05-25_23-54-35.zip

Would change anything.

wojtek commented 11 months ago

Btw. what is the recommended option for HA to avoid crash / system downtime?

Robin Shen commented 11 months ago

Seems that some characters in your database are treated as invalid chars in XML. Can you please attach Issues.xml.6 here? I will check what might be wrong, and fix it so that you can continue to restore.

Robin Shen changed confidential 11 months ago

Previous Value	Current Value
false	true

Robin Shen commented 11 months ago

I have changed the issue as confidential so that no one else can see the file.

Robin Shen commented 11 months ago

Btw. what is the recommended option for HA to avoid crash / system downtime?

This feature is already in EE version, which will be released in the end of this year.

wojtek commented 11 months ago

As said earlier it's unicode symbol U+FFFF which is invalid. Oddly enough 1dev doesn't accept it in the comment (it got into 1dev via import).

Here's the short/cut file with single line as it doesn't make sense to upload complete file...

Could you give more information about the EE version? Any link to ticket?

OneDev changed state to 'Closed' 11 months ago

Previous Value	Current Value
Open	Closed

OneDev commented 11 months ago

State changed as code fixing the issue is committed (8c830375)

Robin Shen changed confidential 11 months ago

Previous Value	Current Value
true	false

OneDev changed state to 'Released' 11 months ago

Previous Value	Current Value
Closed	Released

OneDev commented 11 months ago

State changed as build #3659 is successful

Robin Shen commented 11 months ago

You may restore the backup with 8.2.7 to get around the issue.

Robin Shen commented 11 months ago

Could you give more information about the EE version? Any link to ticket?

Features currently included in EE version:

Custom dashboard
Separate storage for LFS and artifacts
Open web terminal to analyze build failure
Clustering and replication to distribute OneDev projects to different servers for performance and reliability purpose
Cross project code search

wojtek commented 11 months ago

You may restore the backup with 8.2.7 to get around the issue.

Thank you. I took a look at the commit and it seems to fix the issue, though to avoid data-loss - could we maybe replace invalid string with string representation akin vim's: <00ffff>? Or like in the exception message: (Unicode: 0xffff)

Context - it was a bug report, so we fixed it but we knew what the character was.

Could you give more information about the EE version? Any link to ticket?

Features currently included in EE version:

Thanks. I assume those EE would stand for Enterprise Edition?

wojtek commented 11 months ago

I tried 8.2.7 version:

$ kubectl describe deployments.apps/onedev
Name:               onedev
Namespace:          onedev-prod
CreationTimestamp:  Mon, 07 Feb 2022 14:47:45 -0300
…
  Containers:
   onedev:
    Image:       1dev/server:8.2.7

But it failed with the same exception:

INFO  - >>> INFO  - Restoring database from /opt/onedev/site/db-backup/2023-05-26_16-20-59.zip...
INFO  - >>> INFO  - Creating tables...
INFO  - >>> INFO  - Importing data into database...
INFO  - >>> INFO  - Importing from data file 'Roles.xml'...
INFO  - >>> INFO  - Importing from data file 'LabelSpecs.xml'...
INFO  - >>> INFO  - Importing from data file 'ProjectUpdates.xml'...
INFO  - >>> INFO  - Importing from data file 'Projects.xml'...
INFO  - >>> INFO  - Importing from data file 'Users.xml'...
INFO  - >>> INFO  - Importing from data file 'Issues.xml.12'...
INFO  - >>> INFO  - Importing from data file 'Issues.xml.10'...
INFO  - >>> INFO  - Importing from data file 'Issues.xml'...
INFO  - >>> INFO  - Importing from data file 'Issues.xml.7'...
INFO  - >>> INFO  - Importing from data file 'Issues.xml.5'...
INFO  - >>> INFO  - Importing from data file 'Issues.xml.9'...
INFO  - >>> INFO  - Importing from data file 'Issues.xml.3'...
INFO  - >>> INFO  - Importing from data file 'Issues.xml.2'...
INFO  - >>> INFO  - Importing from data file 'Issues.xml.11'...
INFO  - >>> INFO  - Importing from data file 'Issues.xml.14'...
INFO  - >>> INFO  - Importing from data file 'Issues.xml.8'...
INFO  - >>> INFO  - Importing from data file 'Issues.xml.4'...
INFO  - >>> INFO  - Importing from data file 'Issues.xml.13'...
INFO  - >>> INFO  - Importing from data file 'Issues.xml.6'...
INFO  - >>> ERROR - Error booting application
INFO  - >>> java.lang.RuntimeException: org.dom4j.DocumentException: Error on line 37770 of document  : An invalid XML character (Unicode: 0xffff) was found in the element content of the document.
INFO  - >>> 	at io.onedev.commons.bootstrap.Bootstrap.unchecked(Bootstrap.java:341)
INFO  - >>> 	at io.onedev.commons.utils.ExceptionUtils.unchecked(ExceptionUtils.java:35)
INFO  - >>> 	at io.onedev.server.migration.VersionedXmlDoc.fromXML(VersionedXmlDoc.java:417)
INFO  - >>> 	at io.onedev.server.migration.VersionedXmlDoc.fromFile(VersionedXmlDoc.java:423)
INFO  - >>> 	at io.onedev.server.persistence.DefaultDataManager.importData(DefaultDataManager.java:541)
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:125)
INFO  - >>> 	at io.onedev.server.commandhandler.RestoreDatabase.start(RestoreDatabase.java:79)
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:204)

Type	Bug
Priority	Normal
Assignee	Robin Shen
Affected Versions	7.9.12

Issue Votes (0)

Watchers (4)

Reference

onedev/server#1392