[Exist-open] Exist 4.7.1 corrupts its database

SourceForge Headquarters 1320 Columbia Street Suite 310 San Diego, CA 92101 +1 (858) 422-6466

We have eXists 4.7.1 running in master-slave mode in windows environment. For a reason unknown to us it sometimes corrupts itself, and goes into inconsistent state. Inconsistent is replicated to slave as well. To us our only mitigation is to completely recover from backups whole database. This happens from time to time.

Steps done before crash:

  1.  User checks the record for modifications
  2.  User modifies the record
  3.  User saves the record.
  4.  In DB we can see that saving is started. There is lot of warnings for 'document not locked for write !' in DB, assumption is that this refers the copied reford files.
  5.  However, the saved record and it's elements are replicated to slave. Interestingly, the owner in slave files seems to be SYSTEM instead of admin
  6.  Something goes wrong in master - after that the RCP calls start to throw indefinete loop errors (see copy-paste at the end)
  7.  This indefinete looping seems to cause db to go inconsistent state.

Is there any hint's what is going on and how to prevent this from happening?

eXists log where errors start to happen:
2022-02-01 14:42:53,800 [qtp807053698-292480] INFO  (ReplicationTrigger.java [afterCreateCollection]:228) - Create collection '/db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761'
2022-02-01 14:42:53,821 [qtp807053698-292480] INFO  (ReplicationTrigger.java [afterCreateCollection]:228) - Create collection '/db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761/TOSELEMENTS'
2022-02-01 14:42:53,913 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:54,017 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:54,020 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:54,036 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:54,040 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:54,044 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:54,122 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:54,132 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:54,134 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:54,143 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:54,147 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:54,149 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:54,848 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:54,977 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:54,999 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,002 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,018 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,028 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,036 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,118 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,131 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,151 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,165 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,333 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,384 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,395 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,402 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,520 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,732 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,761 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:55,765 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:56,444 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:56,449 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:56,484 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:56,490 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:56,493 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:56,500 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:56,535 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:56,539 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:56,704 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:56,711 [qtp807053698-292480] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:56,712 [qtp807053698-292480] INFO  (ReplicationTrigger.java [afterCopyCollection]:291) - Copy collection from '/db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1639466517762/TOSELEMENTS' to '/db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761/TOSELEMENTS'
2022-02-01 14:42:56,751 [qtp807053698-292426] WARN  (DocumentImpl.java [write]:466) - document not locked for write !
2022-02-01 14:42:56,751 [qtp807053698-292426] INFO  (ReplicationTrigger.java [afterCopyDocument]:148) - Copy document from '/db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1639466517762/tos.xml' to '/db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761/tos.xml'
2022-02-01 14:42:56,809 [qtp807053698-292531] ERROR (NativeBroker.java [openCollection]:914) - The collection received from the cache is not the requested: /db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761/TOSELEMENTS; received: /db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761
2022-02-01 14:42:56,812 [qtp807053698-292426] ERROR (NativeBroker.java [openCollection]:914) - The collection received from the cache is not the requested: /db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761/TOSELEMENTS; received: /db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761
2022-02-01 14:42:56,812 [qtp807053698-292426] WARN  (TransactionManager.java [close]:389) - Transaction was not committed or aborted, auto aborting!
2022-02-01 14:42:56,820 [qtp807053698-292531] ERROR (NativeBroker.java [openCollection]:914) - The collection received from the cache is not the requested: /db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761/TOSELEMENTS; received: /db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761
2022-02-01 14:42:56,821 [qtp807053698-292531] ERROR (NativeBroker.java [openCollection]:914) - The collection received from the cache is not the requested: /db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761/TOSELEMENTS; received: /db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761
2022-02-01 14:42:56,821 [qtp807053698-292531] ERROR (NativeBroker.java [openCollection]:914) - The collection received from the cache is not the requested: /db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761/TOSELEMENTS; received: /db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761
2022-02-01 14:42:56,822 [qtp807053698-292531] ERROR (NativeBroker.java [openCollection]:914) - The collection received from the cache is not the requested: /db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761/TOSELEMENTS; received: /db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761
2022-02-01 14:42:56,822 [qtp807053698-292531] ERROR (NativeBroker.java [openCollection]:914) - The collection received from the cache is not the requested: /db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761/TOSELEMENTS; received: /db/TOSAPP/TOS3/1.2.246.10.22886666/CODE/INTERNAL/PUBLISHED/1643719373761

The stack trace:
2022-02-01 14:42:53,484 [qtp807053698-292426] INFO  (RpcConnection.java [doQuery]:257) - query took 0ms.
2022-02-01 14:42:53,534 [qtp807053698-292211] INFO  (RpcConnection.java [doQuery]:257) - query took 0ms.
2022-02-01 14:42:53,566 [qtp807053698-292508] INFO  (RpcConnection.java [doQuery]:257) - query took 0ms.
2022-02-01 14:42:53,583 [qtp807053698-292480] INFO  (RpcConnection.java [doQuery]:257) - query took 0ms.
2022-02-01 14:42:53,756 [qtp807053698-292531] INFO  (RpcConnection.java [doQuery]:257) - query took 0ms.
2022-02-01 14:42:53,811 [qtp807053698-292480] INFO  (RpcConnection.java [doQuery]:257) - query took 12ms.
2022-02-01 14:42:56,714 [qtp807053698-292480] INFO  (RpcConnection.java [doQuery]:257) - query took 2894ms.
2022-02-01 14:42:56,755 [qtp807053698-292426] INFO  (RpcConnection.java [doQuery]:257) - query took 11ms.
2022-02-01 14:42:58,022 [qtp807053698-292531] ERROR (XmlRpcErrorLogger.java [log]:36) - Failed to invoke method queryPT in class org.exist.xmlrpc.RpcConnection: null
org.apache.xmlrpc.common.XmlRpcInvocationException: Failed to invoke method queryPT in class org.exist.xmlrpc.RpcConnection: null
                             at org.apache.xmlrpc.server.ReflectiveXmlRpcHandler.invoke(ReflectiveXmlRpcHandler.java:129) ~[xmlrpc-server-3.1.3.jar:3.1.3]
                             at org.apache.xmlrpc.server.ReflectiveXmlRpcHandler.execute(ReflectiveXmlRpcHandler.java:106) ~[xmlrpc-server-3.1.3.jar:3.1.3]
                             at org.apache.xmlrpc.server.XmlRpcServerWorker.execute(XmlRpcServerWorker.java:46) ~[xmlrpc-server-3.1.3.jar:3.1.3]
                             at org.apache.xmlrpc.server.XmlRpcServer.execute(XmlRpcServer.java:86) ~[xmlrpc-server-3.1.3.jar:3.1.3]
                             at org.apache.xmlrpc.server.XmlRpcStreamServer.execute(XmlRpcStreamServer.java:200) [xmlrpc-server-3.1.3.jar:3.1.3]
                             at org.apache.xmlrpc.webserver.XmlRpcServletServer.execute(XmlRpcServletServer.java:112) [xmlrpc-server-3.1.3.jar:3.1.3]
                             at org.apache.xmlrpc.webserver.XmlRpcServlet.doPost(XmlRpcServlet.java:196) [xmlrpc-server-3.1.3.jar:3.1.3]
                             at org.exist.xmlrpc.RpcServlet.doPost(RpcServlet.java:99) [exist.jar:4.7.1]
                             at javax.servlet.http.HttpServlet.service(HttpServlet.java:707) [servlet-api-3.1.jar:3.1.0]
                             at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [servlet-api-3.1.jar:3.1.0]
                             at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:867) [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:542) [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:566) [jetty-security-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480) [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:168) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:78) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.exist.http.urlrewrite.Forward.doRewrite(Forward.java:51) [exist-optional.jar:4.7.1]
                             at org.exist.http.urlrewrite.XQueryURLRewrite.service(XQueryURLRewrite.java:206) [exist-optional.jar:4.7.1]
                             at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [servlet-api-3.1.jar:3.1.0]
                             at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:859) [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:542) [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:524) [jetty-security-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480) [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:126) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:703) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.Server.handle(Server.java:502) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305) [jetty-io-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [jetty-io-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) [jetty-io-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333) [jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310) [jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168) [jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126) [jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366) [jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765) [jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683) [jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
                             at java.lang.Thread.run(Thread.java:748) [?:1.8.0_201]
Caused by: java.lang.StackOverflowError
                             at java.lang.ThreadLocal$ThreadLocalMap.getEntry(ThreadLocal.java:419) ~[?:1.8.0_201]
                             at java.lang.ThreadLocal$ThreadLocalMap.access$000(ThreadLocal.java:298) ~[?:1.8.0_201]
                             at java.lang.ThreadLocal.get(ThreadLocal.java:163) ~[?:1.8.0_201]
                             at org.apache.logging.log4j.core.config.AppenderControl.isRecursiveCall(AppenderControl.java:104) ~[log4j-core-2.11.0.jar:2.11.0]
                             at org.apache.logging.log4j.core.config.AppenderControl.shouldSkip(AppenderControl.java:88) ~[log4j-core-2.11.0.jar:2.11.0]
                             at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:81) ~[log4j-core-2.11.0.jar:2.11.0]
                             at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:448) ~[log4j-core-2.11.0.jar:2.11.0]
                             at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:433) ~[log4j-core-2.11.0.jar:2.11.0]
                             at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:417) ~[log4j-core-2.11.0.jar:2.11.0]
                             at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:403) ~[log4j-core-2.11.0.jar:2.11.0]
                             at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63) ~[log4j-core-2.11.0.jar:2.11.0]
                             at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:146) ~[log4j-core-2.11.0.jar:2.11.0]
                             at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2170) ~[log4j-api-2.11.0.jar:2.11.0]
                             at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2125) ~[log4j-api-2.11.0.jar:2.11.0]
                             at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2108) ~[log4j-api-2.11.0.jar:2.11.0]
                             at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2002) ~[log4j-api-2.11.0.jar:2.11.0]
                             at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1974) ~[log4j-api-2.11.0.jar:2.11.0]
                             at org.apache.logging.log4j.spi.AbstractLogger.error(AbstractLogger.java:731) ~[log4j-api-2.11.0.jar:2.11.0]
                             at org.exist.storage.NativeBroker.openCollection(NativeBroker.java:914) ~[exist.jar:4.7.1]
                             at org.exist.storage.NativeBroker.openCollection(NativeBroker.java:771) ~[exist.jar:4.7.1]
                             at org.exist.storage.NativeBroker.removeCollection(NativeBroker.java:1392) ~[exist.jar:4.7.1]
                             at org.exist.storage.NativeBroker.removeCollection(NativeBroker.java:1394) ~[exist.jar:4.7.1]   .... //This line repeats recursively to the end

[Exist-open] Exist 4.7.1 corrupts its database

eXist-db is a feature rich Open Source native XML database

[Exist-open] Exist 4.7.1 corrupts its database