exist
exist copied to clipboard
[BUG] Attempt to copy temporary document throws NPE, possibly corrupts structural index
We have been dealing with the following intermittent NPE being thrown after updating nodes in a document repeatedly:
ERROR (XQueryURLRewrite.java [service]:365) - Error while processing /exist/rest/db/etc/Locks.xml: An unknown error occurred: null
javax.servlet.ServletException: An unknown error occurred: null
at org.exist.http.servlets.EXistServlet.doPost(EXistServlet.java:572) ~[exist.uber.jar:6.2.0]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707) ~[exist.uber.jar:6.2.0]
at org.exist.http.servlets.EXistServlet.service(EXistServlet.java:588) ~[exist.uber.jar:6.2.0]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1459) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1656) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:552) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:618) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:167) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:81) ~[exist.uber.jar:6.2.0]
at org.exist.http.urlrewrite.Forward.doRewrite(Forward.java:50) ~[exist.uber.jar:6.2.0]
at org.exist.http.urlrewrite.XQueryURLRewrite.service(XQueryURLRewrite.java:203) ~[exist.uber.jar:6.2.0]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1450) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1656) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:292) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:552) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:571) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:234) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:722) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) ~[exist.uber.jar:6.2.0]
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) ~[exist.uber.jar:6.2.0]
at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_332]
Caused by: java.lang.NullPointerException
at org.exist.dom.persistent.DocumentImpl.<init>(DocumentImpl.java:205) ~[exist.uber.jar:6.2.0]
at org.exist.storage.NativeBroker.defragXMLResource(NativeBroker.java:3036) ~[exist.uber.jar:6.2.0]
at org.exist.xquery.update.Modification.checkFragmentation(Modification.java:284) ~[exist.uber.jar:6.2.0]
at org.exist.xquery.update.Modification.checkFragmentation(Modification.java:260) ~[exist.uber.jar:6.2.0]
at org.exist.xquery.XQueryContext.reset(XQueryContext.java:1452) ~[exist.uber.jar:6.2.0]
at org.exist.xquery.XQueryContext.reset(XQueryContext.java:1428) ~[exist.uber.jar:6.2.0]
at org.exist.xquery.XQuery.execute(XQuery.java:469) ~[exist.uber.jar:6.2.0]
at org.exist.xquery.XQuery.execute(XQuery.java:348) ~[exist.uber.jar:6.2.0]
at org.exist.xquery.XQuery.execute(XQuery.java:335) ~[exist.uber.jar:6.2.0]
at org.exist.http.RESTServer.search(RESTServer.java:1371) ~[exist.uber.jar:6.2.0]
at org.exist.http.RESTServer.doPost(RESTServer.java:860) ~[exist.uber.jar:6.2.0]
at org.exist.http.servlets.EXistServlet.doPost(EXistServlet.java:538) ~[exist.uber.jar:6.2.0]
... 65 more
From there, any queries into the document return no results until we reindex the document.
Looking at NativeBroker.java:3036, it appears null
is being passed as pool
into the DocumentImpl
constructor, which then calls pool.getSecurityManager()
, guaranteeing an NPE.
We are uncertain about the context that leads up to this execution path (given the difficulty in reliably reproducing the error), as well as the implications of simply wrapping in a ternary that checks for nulls, although we are currently testing a recompiled JAR with DocumentImpl.java:205 like so:
pool != null ? PermissionFactory.getDefaultResourcePermission(pool.getSecurityManager()) : collection.getPermissions(), 0, null,
This is using the existdb:6.2.0 Docker container.