Uploaded image for project: 'XWiki Platform'
  1. XWiki Platform
  2. XWIKI-16854

Random ArrayIndexOutOfBoundsException when displaying a running job log

    XMLWordPrintable

Details

    • Bug
    • Resolution: Unresolved
    • Major
    • None
    • 11.9
    • Logging, Root Webapp
    • None
    • Windows 10 Pro 64 bit, Firefox 70, using a local instance of XWiki 11.9 on Oracle 12c
    • Unknown

    Description

      STEPS TO REPRODUCE

      1. Create an older instance of XWiki (8.4.6, with filesystem attachment storage) configured with Oracle (12c)
      2. Create a subwiki
      3. Close the instance
      4. Go to a newer instance (11.9) and copy/cut the
        [...]webapps\xwiki

        folder and replace it (first delete the old one) in the same location on the older version

      1. Start XWiki and follow the Distribution Wizard through the upgrade process for the Main Wiki as well as for subwiki

      EXPECTED RESULTS

      The upgrade process for Main Wiki as well as for the subwiki is completed successfully without errors.

      ACTUAL RESULTS

      Sometimes, towards the end of the upgrade (Step 1) on the subwiki, the following error is displayed on DW:

      Error number 4001 in 4: Error while evaluating velocity template distribution.vm

      Here is the stacktrace from console:

      2019-11-11 14:50:17,147 [http://localhost:8465/xwiki/wiki/subwikiglobal/distribution/XWiki/Distribution] ERROR o.x.v.i.DefaultVelocityEngine  - Exception in macro #printLogMessage called at 293:/templates/distribution.vm[line 21, column 9] 
      2019-11-11 14:50:17,148 [http://localhost:8465/xwiki/wiki/subwikiglobal/distribution/XWiki/Distribution] ERROR o.x.v.i.DefaultVelocityEngine  - Exception in macro #displayJobProgressBar called at 293:/templates/distribution.vm[line 289, column 5] 
      2019-11-11 14:50:17,150 [http://localhost:8465/xwiki/wiki/subwikiglobal/distribution/XWiki/Distribution] ERROR o.x.v.i.DefaultVelocityEngine  - Exception in macro #displayProgressBar called at 293:/templates/distribution.vm[line 974, column 7] 
      2019-11-11 14:50:17,154 [http://localhost:8465/xwiki/wiki/subwikiglobal/distribution/XWiki/Distribution] ERROR o.x.v.i.DefaultVelocityEngine  - Exception in macro #displayExtension called at 293:/templates/distribution.vm[line 1035, column 7] 
      2019-11-11 14:50:17,155 [http://localhost:8465/xwiki/wiki/subwikiglobal/distribution/XWiki/Distribution] ERROR o.x.v.i.DefaultVelocityEngine  - Exception in macro #handleExtensionAction called at 293:/templates/distribution.vm[line 994, column 5] 
      2019-11-11 14:50:17,156 [http://localhost:8465/xwiki/wiki/subwikiglobal/distribution/XWiki/Distribution] ERROR o.x.v.i.DefaultVelocityEngine  - Exception in macro #handleExtensionRequest called at 293:/templates/distribution.vm[line 180, column 7] 
      2019-11-11 14:50:17,164 [http://localhost:8465/xwiki/wiki/subwikiglobal/distribution/XWiki/Distribution] ERROR c.x.x.XWiki                    - Error while evaluating velocity template [distribution.vm] 
      org.xwiki.rendering.RenderingException: Failed to execute renderer
      	at org.xwiki.rendering.async.internal.DefaultAsyncRendererExecutor.syncRender(DefaultAsyncRendererExecutor.java:267)
      	at org.xwiki.rendering.async.internal.DefaultAsyncRendererExecutor.render(DefaultAsyncRendererExecutor.java:247)
      	at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRendererExecutor.render(DefaultBlockAsyncRendererExecutor.java:154)
      	at com.xpn.xwiki.internal.template.InternalTemplateManager.render(InternalTemplateManager.java:772)
      	at com.xpn.xwiki.internal.template.InternalTemplateManager.renderFromSkin(InternalTemplateManager.java:745)
      	at com.xpn.xwiki.internal.template.InternalTemplateManager.renderFromSkin(InternalTemplateManager.java:725)
      	at com.xpn.xwiki.internal.template.InternalTemplateManager.render(InternalTemplateManager.java:711)
      	at com.xpn.xwiki.internal.template.DefaultTemplateManager.render(DefaultTemplateManager.java:78)
      	at com.xpn.xwiki.XWiki.evaluateTemplate(XWiki.java:2480)
      	at com.xpn.xwiki.web.Utils.parseTemplate(Utils.java:179)
      	at com.xpn.xwiki.web.XWikiAction.execute(XWikiAction.java:516)
      	at com.xpn.xwiki.web.XWikiAction.execute(XWikiAction.java:218)
      	at org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java:425)
      	at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:228)
      	at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1913)
      	at org.apache.struts.action.ActionServlet.doPost(ActionServlet.java:462)
      	at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
      	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
      	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:808)
      	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1669)
      	at com.xpn.xwiki.web.ActionFilter.doFilter(ActionFilter.java:112)
      	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
      	at org.xwiki.wysiwyg.filter.ConversionFilter.doFilter(ConversionFilter.java:109)
      	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
      	at org.xwiki.container.servlet.filters.internal.SetHTTPHeaderFilter.doFilter(SetHTTPHeaderFilter.java:63)
      	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
      	at org.xwiki.container.servlet.filters.internal.SavedRequestRestorerFilter.doFilter(SavedRequestRestorerFilter.java:208)
      	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
      	at org.xwiki.container.servlet.filters.internal.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:111)
      	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
      	at org.xwiki.resource.servlet.RoutingFilter.doFilter(RoutingFilter.java:132)
      	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
      	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585)
      	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
      	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)
      	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)
      	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)
      	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)
      	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
      	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)
      	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
      	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:215)
      	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:110)
      	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
      	at org.eclipse.jetty.server.Server.handle(Server.java:499)
      	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310)
      	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)
      	at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)
      	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
      	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
      	at java.lang.Thread.run(Unknown Source)
      Caused by: org.xwiki.rendering.RenderingException: Failed to evaluate template
      	at com.xpn.xwiki.internal.template.TemplateAsyncRenderer.evaluateContent(TemplateAsyncRenderer.java:220)
      	at com.xpn.xwiki.internal.template.TemplateAsyncRenderer.renderVelocity(TemplateAsyncRenderer.java:181)
      	at com.xpn.xwiki.internal.template.TemplateAsyncRenderer.render(TemplateAsyncRenderer.java:137)
      	at com.xpn.xwiki.internal.template.TemplateAsyncRenderer.render(TemplateAsyncRenderer.java:53)
      	at org.xwiki.rendering.async.internal.DefaultAsyncRendererExecutor.lambda$syncRender$0(DefaultAsyncRendererExecutor.java:264)
      	at com.xpn.xwiki.internal.security.authorization.DefaultAuthorExecutor.call(DefaultAuthorExecutor.java:98)
      	at org.xwiki.rendering.async.internal.DefaultAsyncRendererExecutor.syncRender(DefaultAsyncRendererExecutor.java:264)
      	... 50 common frames omitted
      Caused by: org.xwiki.velocity.XWikiVelocityException: Failed to evaluate content with id [/templates/distribution.vm]
      	at org.xwiki.velocity.internal.DefaultVelocityEngine.evaluate(DefaultVelocityEngine.java:227)
      	at com.xpn.xwiki.render.DefaultVelocityManager.evaluate(DefaultVelocityManager.java:358)
      	at com.xpn.xwiki.internal.template.VelocityTemplateEvaluator.evaluateContent(VelocityTemplateEvaluator.java:95)
      	at com.xpn.xwiki.internal.template.TemplateAsyncRenderer.evaluateContent(TemplateAsyncRenderer.java:218)
      	... 56 common frames omitted
      Caused by: org.apache.velocity.exception.MethodInvocationException: Invocation of method 'get' in  class [Ljava.lang.Object; threw exception java.lang.ArrayIndexOutOfBoundsException at 293:/templates/distribution.vm[line 60, column 44]
      	at org.apache.velocity.runtime.parser.node.ASTMethod.handleInvocationException(ASTMethod.java:243)
      	at org.apache.velocity.runtime.parser.node.ASTMethod.execute(ASTMethod.java:187)
      	at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:280)
      	at org.apache.velocity.runtime.parser.node.ASTReference.value(ASTReference.java:567)
      	at org.apache.velocity.runtime.parser.node.ASTExpression.value(ASTExpression.java:71)
      	at org.apache.velocity.runtime.parser.node.ASTSetDirective.render(ASTSetDirective.java:142)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:87)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:420)
      	at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:216)
      	at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:311)
      	at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:230)
      	at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:87)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:216)
      	at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:311)
      	at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:230)
      	at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:87)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:216)
      	at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:311)
      	at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:230)
      	at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:216)
      	at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:311)
      	at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:230)
      	at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:87)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:342)
      	at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:106)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:216)
      	at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:311)
      	at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:230)
      	at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:342)
      	at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:106)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:216)
      	at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:311)
      	at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:230)
      	at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:87)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.parser.node.ASTElseIfStatement.render(ASTElseIfStatement.java:92)
      	at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:106)
      	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
      	at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:342)
      	at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:106)
      	at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:342)
      	at org.xwiki.velocity.internal.DefaultVelocityEngine.evaluateInternal(DefaultVelocityEngine.java:259)
      	at org.xwiki.velocity.internal.DefaultVelocityEngine.evaluate(DefaultVelocityEngine.java:222)
      	... 59 common frames omitted
      Caused by: java.lang.ArrayIndexOutOfBoundsException: null
      	at java.lang.reflect.Array.get(Native Method)
      	at org.apache.velocity.util.ArrayListWrapper.get(ArrayListWrapper.java:43)
      	at sun.reflect.GeneratedMethodAccessor563.invoke(Unknown Source)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
      	at java.lang.reflect.Method.invoke(Unknown Source)
      	at org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.doInvoke(UberspectImpl.java:395)
      	at org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.invoke(UberspectImpl.java:384)
      	at org.apache.velocity.runtime.parser.node.ASTMethod.execute(ASTMethod.java:173)
      	... 121 common frames omitted

      I've reproduced the issue sometimes (though rare) also on DW for Main Wiki when upgrading from XWiki 8.4.6 to 11.9. If clicked 'Later', the DW follows its normal flow.

      Please find attached the screenshot and the full log.

      It is to be mentioned that the error does not reproduce all the times and it did not reproduce when upgraded from XWiki 10.11.9 to 11.9 or from 8.4.6 to 11.8.1.

      Attachments

        1. 2019_11_11_Oracle_subwiki.log
          346 kB
          Ilie Andriuta
        2. Error_8_4_6_to_11_9_Oracle.jpg
          133 kB
          Ilie Andriuta

        Issue Links

          Activity

            People

              Unassigned Unassigned
              iandriuta Ilie Andriuta
              Votes:
              1 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

                Created:
                Updated: