bug on install/upgrade

[duncdrum]

2017-09-29 09:17:04,195 [qtp53503860-39] INFO  (Deploy.java [load]:274) - Retrieving package from http://demo.exist-db.org/exist/apps/public-repo/modules/find.xql?name=http%3A%2F%2Fexist-db.org%2Fapps%2Fdoc&processor=3.5.0&version=0.4.9 
2017-09-29 09:17:13,305 [qtp53503860-39] WARN  (CommentImpl.java [serialize]:76) - org.exist.xquery.XPathException: err:XPST0003 Ampersands (&) must be escaped (following character was not a name start character). 
2017-09-29 09:17:14,165 [qtp53503860-39] ERROR (Deploy.java [installAndDeploy]:194) - Deployment incomplete, 1 issues found: indexing.xml: The XML parser reported a problem: fatal error at (247,11) : The element type "note" must be terminated by the matching end-tag "</note>". 
org.expath.pkg.repo.PackageException: Deployment incomplete, 1 issues found: indexing.xml: The XML parser reported a problem: fatal error at (247,11) : The element type "note" must be terminated by the matching end-tag "</note>".
	at org.exist.repo.Deployment.deploy(Deployment.java:462) ~[exist.jar:3.5.0]
	at org.exist.repo.Deployment.installAndDeploy(Deployment.java:281) ~[exist.jar:3.5.0]
	at org.exist.repo.Deployment.installAndDeploy(Deployment.java:163) ~[exist.jar:3.5.0]
	at org.exist.xquery.modules.expathrepo.Deploy.installAndDeploy(Deploy.java:188) [exist-modules.jar:3.5.0]
	at org.exist.xquery.modules.expathrepo.Deploy.eval(Deploy.java:163) [exist-modules.jar:3.5.0]
	at org.exist.xquery.BasicFunction.eval(BasicFunction.java:74) [exist.jar:3.5.0]
	at org.exist.xquery.InternalFunctionCall.eval(InternalFunctionCall.java:41) [exist.jar:3.5.0]
	at org.exist.xquery.DebuggableExpression.eval(DebuggableExpression.java:58) [exist.jar:3.5.0]
	at org.exist.xquery.LetExpr.eval(LetExpr.java:111) [exist.jar:3.5.0]
	at org.exist.xquery.LetExpr.eval(LetExpr.java:111) [exist.jar:3.5.0]
	at org.exist.xquery.UserDefinedFunction.eval(UserDefinedFunction.java:160) [exist.jar:3.5.0]
	at org.exist.xquery.FunctionCall.evalFunction(FunctionCall.java:302) [exist.jar:3.5.0]
	at org.exist.xquery.FunctionCall.eval(FunctionCall.java:223) [exist.jar:3.5.0]
	at org.exist.xquery.AbstractExpression.eval(AbstractExpression.java:71) [exist.jar:3.5.0]
	at org.exist.xquery.value.FunctionReference.eval(FunctionReference.java:82) [exist.jar:3.5.0]
	at org.exist.xquery.DynamicFunctionCall.eval(DynamicFunctionCall.java:76) [exist.jar:3.5.0]
	at org.exist.xquery.DebuggableExpression.eval(DebuggableExpression.java:58) [exist.jar:3.5.0]
	at org.exist.xquery.ConditionalExpression.eval(ConditionalExpression.java:102) [exist.jar:3.5.0]
	at org.exist.xquery.AbstractExpression.eval(AbstractExpression.java:71) [exist.jar:3.5.0]
	at org.exist.xquery.PathExpr.eval(PathExpr.java:276) [exist.jar:3.5.0]
	at org.exist.xquery.TryCatchExpression.eval(TryCatchExpression.java:142) [exist.jar:3.5.0]
	at org.exist.xquery.DebuggableExpression.eval(DebuggableExpression.java:58) [exist.jar:3.5.0]
	at org.exist.xquery.LetExpr.eval(LetExpr.java:111) [exist.jar:3.5.0]
	at org.exist.xquery.AbstractExpression.eval(AbstractExpression.java:71) [exist.jar:3.5.0]
	at org.exist.xquery.PathExpr.eval(PathExpr.java:276) [exist.jar:3.5.0]
	at org.exist.xquery.AbstractExpression.eval(AbstractExpression.java:71) [exist.jar:3.5.0]
	at org.exist.xquery.SwitchExpression.eval(SwitchExpression.java:110) [exist.jar:3.5.0]
	at org.exist.xquery.DebuggableExpression.eval(DebuggableExpression.java:58) [exist.jar:3.5.0]
	at org.exist.xquery.ConditionalExpression.eval(ConditionalExpression.java:102) [exist.jar:3.5.0]
	at org.exist.xquery.UserDefinedFunction.eval(UserDefinedFunction.java:160) [exist.jar:3.5.0]
	at org.exist.xquery.FunctionCall.evalFunction(FunctionCall.java:302) [exist.jar:3.5.0]
	at org.exist.xquery.FunctionCall.eval(FunctionCall.java:223) [exist.jar:3.5.0]
	at org.exist.xquery.AbstractExpression.eval(AbstractExpression.java:71) [exist.jar:3.5.0]
	at org.exist.xquery.value.FunctionReference.eval(FunctionReference.java:82) [exist.jar:3.5.0]
	at org.exist.xquery.DynamicFunctionCall.eval(DynamicFunctionCall.java:76) [exist.jar:3.5.0]
	at org.exist.xquery.ConditionalExpression.eval(ConditionalExpression.java:100) [exist.jar:3.5.0]
	at org.exist.xquery.UserDefinedFunction.eval(UserDefinedFunction.java:160) [exist.jar:3.5.0]
	at org.exist.xquery.FunctionCall.evalFunction(FunctionCall.java:302) [exist.jar:3.5.0]
	at org.exist.xquery.FunctionCall.eval(FunctionCall.java:223) [exist.jar:3.5.0]
	at org.exist.xquery.DebuggableExpression.eval(DebuggableExpression.java:58) [exist.jar:3.5.0]
	at org.exist.xquery.LetExpr.eval(LetExpr.java:111) [exist.jar:3.5.0]
	at org.exist.xquery.LetExpr.eval(LetExpr.java:111) [exist.jar:3.5.0]
	at org.exist.xquery.LetExpr.eval(LetExpr.java:111) [exist.jar:3.5.0]
	at org.exist.xquery.LetExpr.eval(LetExpr.java:111) [exist.jar:3.5.0]
	at org.exist.xquery.LetExpr.eval(LetExpr.java:111) [exist.jar:3.5.0]
	at org.exist.xquery.AbstractExpression.eval(AbstractExpression.java:71) [exist.jar:3.5.0]
	at org.exist.xquery.PathExpr.eval(PathExpr.java:276) [exist.jar:3.5.0]
	at org.exist.xquery.AbstractExpression.eval(AbstractExpression.java:71) [exist.jar:3.5.0]
	at org.exist.xquery.XQuery.execute(XQuery.java:253) [exist.jar:3.5.0]
	at org.exist.xquery.XQuery.execute(XQuery.java:185) [exist.jar:3.5.0]
	at org.exist.http.RESTServer.executeXQuery(RESTServer.java:1538) [exist-optional.jar:3.5.0]
	at org.exist.http.RESTServer.doPost(RESTServer.java:679) [exist-optional.jar:3.5.0]
	at org.exist.http.servlets.EXistServlet.doPost(EXistServlet.java:451) [exist-optional.jar:3.5.0]
	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:841) [jetty-servlet-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535) [jetty-servlet-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:566) [jetty-security-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:190) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) [jetty-servlet-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:163) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:73) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.exist.http.urlrewrite.Forward.doRewrite(Forward.java:50) [exist-optional.jar:3.5.0]
	at org.exist.http.urlrewrite.XQueryURLRewrite.doRewrite(XQueryURLRewrite.java:548) [exist-optional.jar:3.5.0]
	at org.exist.http.urlrewrite.XQueryURLRewrite.service(XQueryURLRewrite.java:352) [exist-optional.jar:3.5.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:841) [jetty-servlet-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1650) [jetty-servlet-9.4.6.v20170531.jar:9.4.6.v20170531]
	at de.betterform.agent.web.filter.XFormsFilter.doFilter(XFormsFilter.java:171) [betterform-exist-5.1-SNAPSHOT-20160615.jar:?]
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1629) [jetty-servlet-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533) [jetty-servlet-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:524) [jetty-security-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:190) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) [jetty-servlet-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:219) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:126) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:454) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.Server.handle(Server.java:564) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:317) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) [jetty-server-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279) [jetty-io-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110) [jetty-io-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124) [jetty-io-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.util.thread.Invocable.invokePreferred(Invocable.java:128) [jetty-util-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.util.thread.Invocable$InvocableExecutor.invoke(Invocable.java:222) [jetty-util-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:294) [jetty-util-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:199) [jetty-util-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:673) [jetty-util-9.4.6.v20170531.jar:9.4.6.v20170531]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:591) [jetty-util-9.4.6.v20170531.jar:9.4.6.v20170531]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_144]

[duncdrum]

when I check indexing.xml it reports as valid docbook 5.1 ???

[duncdrum]

I can't find any fault with indexing.xml but when upgrading on two separate systems it failed to be deployed with the other docs, raising an error.
This 682e0f3 gets rid of the installation error regarding <note>

The warning about & comes from another place.

[adamretter]

@duncdrum Yes, I am also able to reproduce this. The warning about the & can be safely ignored. I am just trying to get to the bottom of the error in indexing.xml now...

[adamretter]

@duncdrum Okay I found the issue. Somehow it is in the deployed package i.e. documentation version 0.4.9, but is not in the code on GitHub.

If you download the package file directly: http://demo.exist-db.org/exist/apps/public-repo/public/doc-0.4.9.xar and unpack it and examine the file data/indexing.xml you will find that it is not well-formed XML as there is a <note> on line 131 with no corresponding close tag. e.g.:

$ wget http://demo.exist-db.org/exist/apps/public-repo/public/doc-0.4.9.xar && unzip -p doc-0.4.9.xar data/indexing.xml | xmllint --stream -

@ljo Any idea how this came about?

I will first replace the package with a correct one, and then try and update the build system so that this can't happen in future...

[adamretter]

@duncdrum I just released version 0.5.0 of the documentation app, I think that should fix the issue. Thanks for reporting and helping us investigate

[duncdrum]

@adamretter thanks for looking into this. I didn't see how the repo.xml stuff would have killed indexing.xml. Hence no PR but just some blind poking in between other work.