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. (OD-1392)
wojtek opened 3 years 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 3 years 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 3 years ago

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

  • wojtek commented 3 years 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 3 years ago

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

  • Robin Shen commented 3 years 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 3 years ago
    Previous Value Current Value
    false
    true
  • Robin Shen commented 3 years ago

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

  • Robin Shen commented 3 years 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 3 years 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' 3 years ago
    Previous Value Current Value
    Open
    Closed
  • OneDev commented 3 years ago

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

  • Robin Shen changed confidential 3 years ago
    Previous Value Current Value
    true
    false
  • OneDev changed state to 'Released' 3 years ago
    Previous Value Current Value
    Closed
    Released
  • OneDev commented 3 years ago

    State changed as build #3659 is successful

  • Robin Shen commented 3 years ago

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

  • Robin Shen commented 3 years ago

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

    Features currently included in EE version:

    1. Custom dashboard
    2. Separate storage for LFS and artifacts
    3. Open web terminal to analyze build failure
    4. Clustering and replication to distribute OneDev projects to different servers for performance and reliability purpose
    5. Cross project code search
  • wojtek commented 3 years 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 3 years 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)
    
issue 1/1
Type
Bug
Priority
Normal
Assignee
Affected Versions
7.9.12
Issue Votes (0)
Watchers (4)
Reference
OD-1392
Please wait...
Connection lost or session expired, reload to recover
Page is in error, reload to recover