XWiki Error after (successful) upgrade from 10.11.8 to 13.10.5

Hey guys!

Last week we finally after long, long time did an upgrade of our wiki to the most recent 13.10.5 LTS release.

After thorough preparation in a test environment the upgrade itself went pretty smoothly overall. In the logs we just observed some Glossary Caching errors, which we payed little attention to. The wiki ran for more than one week without errors other than these caching messages. Now on the weekend we did a server reboot and horribly the wiki does not start anymore. The browser just shows this error:

HTTP Status 500 – Internal Server Error


Type Exception Report

Beschreibung The server encountered an unexpected condition that prevented it from fulfilling the request.

Exception

java.lang.NullPointerException
	com.xpn.xwiki.web.Utils.getContextComponentManager(Utils.java:682)
	com.xpn.xwiki.web.Utils.getComponent(Utils.java:739)
	com.xpn.xwiki.web.Utils.getComponent(Utils.java:768)
	com.xpn.xwiki.web.Utils.getComponent(Utils.java:721)
	org.xwiki.wysiwyg.filter.ConversionFilter.doFilter(ConversionFilter.java:55)
	org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	org.xwiki.container.servlet.filters.internal.SetHTTPHeaderFilter.doFilter(SetHTTPHeaderFilter.java:63)
	org.xwiki.container.servlet.filters.internal.SavedRequestRestorerFilter.doFilter(SavedRequestRestorerFilter.java:208)
	org.xwiki.container.servlet.filters.internal.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:111)
	org.xwiki.resource.servlet.RoutingFilter.doFilter(RoutingFilter.java:132)

Hinweis Der komplette Stacktrace der Ursache ist in den Server logs zu finden

Apache Tomcat/9.0.36

I guess the important part of the log is one of these stacktrace excerpts. Either:

[http-nio-8080-exec-5 - https://<OUR_WIKI_URL>/webjars/<SUBWIKI_NAME>/xwiki-platform-tree-webjar/13.10.5/tree.min.css?evaluate=true] ERROR>
org.xwiki.resource.ResourceReferenceHandlerException: Failed to evaluate the Velocity code from WebJar resource [xwiki-platform-tree-webjar/13.10.5/tree.min.css]
         at org.xwiki.webjars.internal.filter.VelocityWebJarsResourceFilter.filter(VelocityWebJarsResourceFilter.java:66)
         [...]
         at java.lang.Thread.run(Thread.java:825)
 Caused by: java.lang.NullPointerException: null
         at com.xpn.xwiki.web.Utils.getContextComponentManager(Utils.java:682)
         at com.xpn.xwiki.web.Utils.getComponent(Utils.java:739)
         at com.xpn.xwiki.web.Utils.getComponent(Utils.java:768)
         at com.xpn.xwiki.web.Utils.getComponent(Utils.java:721)
         at com.xpn.xwiki.internal.script.DeprecatedScriptContextInitializer.initialize(DeprecatedScriptContextInitializer.java:53)
         at org.xwiki.script.internal.DefaultScriptContextManager.getScriptContext(DefaultScriptContextManager.java:65)
         at com.xpn.xwiki.render.DefaultVelocityManager.getVelocityContext(DefaultVelocityManager.java:197)
         at org.xwiki.webjars.internal.filter.VelocityWebJarsResourceFilter.filter(VelocityWebJarsResourceFilter.java:61)
         ... 38 common frames omitted

or maybe this one:

[main] ERROR .o.i.DefaultObservationManager - Failed to lookup the Event Listener [MentionsUpdatedEventListener] corresponding to the Component registration event for [org.xwiki.mentions.internal.listeners.MentionsUpdatedEventListener]. Ignoring the event
Apr 25 10:49:38 server[2725]: org.xwiki.component.manager.ComponentLookupException: Failed to lookup component [org.xwiki.mentions.internal.listeners.MentionsUpdatedEventListener] identified by type [interface org.xwiki.observation.EventListener] and hint [MentionsUpdatedEventListener]
[...]
Caused by: org.xwiki.component.manager.ComponentLookupException: Failed to lookup component [org.xwiki.mentions.internal.DefaultMentionsEventExecutor] identified by type [interface org.xwiki.mentions.internal.MentionsEventExecutor] and hint [default]
[...]
Caused by: org.xwiki.component.phase.InitializationException: Failed to initialize the queue
[...]
Caused by: org.h2.mvstore.MVStoreException: The write format 1 is smaller than the supported format 2 [2.1.212/5]

A quick grep of all Errors in the tomcat logs after the last restart of XWiki showed the following:

# journalctl -u tomcat | grep Error
WARNING [main] org.apache.tomcat.util.IntrospectionUtils.setProperty Error setting property [URIEncoding] to [UTF-8] on class [class org.apache.catalina.connector.Connector]
Caused by: java.lang.NoSuchMethodError: java/nio/ByteBuffer.clear()Ljava/nio/ByteBuffer; (loaded from /usr/lib64/jvm/java-1.8.0-ibm-1.8.0/jre/lib/rt.jar by <Bootstrap Loader>) called from class org.apache.tomcat.util.buf.CharsetUtil (loaded from file:/usr/share/java/tomcat/tomcat-util.jar by java.net.URLClassLoader@5c4a16bb).
java.lang.UnsupportedClassVersionError: JVMCFRE003 bad major version; class=com/vladsch/flexmark/util/data/DataHolder, offset=6

Might that be related to General error: "The write format 1 is smaller than the supported format 2 [2.0.202/5]" [50000-202] HY000/50000 · Issue #3214 · h2database/h2database · GitHub?

Can someone please help us to pinpoint the cause? Help is very much appreciated! If you need more information, please let me know. We are pretty desperate by now.

Best,
Björn

After some research yesterday I added some details to the post. I guess it is no good sign, that there is no hint yet from one of the XWiki guys. Does that mean, the problem needs some digging?

By now we observed, that the wiki actually runs a couple of hours after resetting to a previous snapshot of the database’s and the application’s machine to a state within this one week after the upgrade before the first crash. We are just trying to find out, what happens, when it crashes again.

Hi, what would help would be the start of the tomcat log file after the restart so that we can see what’s the first errors. Subsequent errors are probably more a consequence than the cause.

Also could you verify that you have set a permanent directory and that it’s not pointing to the temporary directory (in which case it could have been wiped out by your OS or someone)?

Thx

Regarding this error, is it possible that you’ve got flexmark-java installed in version 0.64.0 which requires Java 11?

Regarding the org.h2.mvstore.MVStoreException, see here.

I’m wondering if it is possible that XWiki is too eagerly updating dependencies of extensions, thus getting more recent versions than actually supported? In both cases, these dependencies shouldn’t have been in that version.

Thanks for your hints and suggestions! I will dig into all your hints and report on any findings:

  • closely watch tomcat log file after the restart
  • verify that we have set a permanent directory (Almost surely, but I will check as soon, as a tomcat restart does no harm, because that is definitely triggering downtime since XWiki does not come up anymore.)
  • check flexmark-java version (@MichaelHamann which version should it be?)
  • check the linked issue regarding the MV2 error

Thank you so much for sharing your ideas! These are highly valuable for us.

It should be version 0.62.2 as it is referenced in the markdown extension.

So here now is the full tomcat logs after a restart until nothing happens anymore without XWiki being accessible (of course strippend by some intermediate stacktrace lines): Errornous XWiki tomcat logs - Paste-bin for Sharing Code and Text

The wiki runs with the permanent directory /var/lib/xwiki/data as mentioned in the docs to be reasonable.

I will now check the other two hints and would be very grateful if you could take a closer look at the logs and hopefully provide another clue on the root cause.

Thanks for your effort and the thoughts you put into this!

Indeed we have 0.64.0 installed. Unfortunatelay I cannot downgrade due to the following error:
Screenshot_20220426_205416

Oh no… something seems to be really messed up here. Do you have any suggestions on how to enforce a downgrade?

I guess that is very much indicating one possible root cause. When checking for Extension Upgrades I noticed errors of the form:

org.xwiki.extension.ResolveException: Failed to find version for extension id [org.xwiki.contrib.replication:replication-ui]
                       [...]
server[28809]: Caused by: java.io.IOException: Failed to request [https://store.xwiki.com/xwiki/rest/repository/extensions/org.xwiki.contrib.replication%3Areplication-ui/versions?requireTotalHits=true&start=0&number=-1]
                       [...]
server[28809]: Caused by: javax.net.ssl.SSLHandshakeException: Remote host terminated the handshake

This I try to solve with our firewall guys before anything else needs attention as far as I can see.

Thanks for your support so far!

The firewall guys have done their job. Now I try to manually install the 0.62.2 version of the flexmark-java extensions (utilities, core, …) but I always receive messages like

The extension with feature [com.vladsch.flexmark:flexmark/0.62.2] is not compatible with existing backward dependency constraint [0.64.0]

Can you tell me, if it is possible to automatically again resolve the dependencies correctly and exchange all non matching versions?

Right now I am successfully uninstalling the flexmark-java stack manually in the right order and just arrived at the core.

Unfortunately I can’t get it done until the wiki crashes over and over again.

The last log entry then is:

systemd[1]: tomcat.service: Main process exited, code=killed, status=9/KILL
systemd[1]: tomcat.service: Failed with result 'signal'.

I seem to have managed to reach a somewhat stable situation. I am just cleaning up our Extensions and watch the log closely.

Until now I focused on uninstalling all markdown syntaxes for now and their dependencies, that were not needed by other extensions:

  • pegdown
  • parboild java (and core)
  • the whole flexmark-java stack

I afterwards even managed to restart tomcat once with the wiki successfully firing up afterwards. That’s a huge success. I keep you updated.

Regarding the MV2 issue, I temporarily got rid of the Mentions Application and the MV2 extension. Now finally everythingseems to run smoothly again. Difficult to pinpoint the exact causes of the trouble, but I will try later today to summarize our steps and findings based on the suggestions.

EDIT: The assumption about the root cause in this post might be wrong as MichaelHamann and Vincent Massol expressed their doubt about it. In their responses below.


The reason for the crashes was apparently properly identified in the answer marked as solution. XWiki installed some extensions that were actually not compatible with our installed application version and other extensions. The root cause of this behaviour was, that our firewall blocked requests to the URL store.xwiki.com . Although XWiki reported connection errors during extension upgrader runs, the process finished with a success message and the hint: “All extensions are up to date.”

Our instance ran for months, maybe years before the upgrade and one and a half weeks despite these error messages. That is why everybody got used to the message and did not pay much attention to it. We learned our lesson (once again) about this short coming, but still I am wondering, if XWiki should warn a little more obvious about potentially dangerous events during the upgrade process like: “Connection errors occured during the version checks. You might have ended up with incompatible extensions that could seriously degrade XWiki performance or cause XWiki to crash without the ability to recover.”

@vmassol @MichaelHamann Do you think it is worth filing an issue on jira.xwiki.org, concerning this aspect?

Hi you mention store.xwiki.com but I haven’t seen any mention of extensions coming from that store in the messages above. Are you sure that this is the problem? Are you using paying extensions from store.xwiki.com?

I’m not convinced that the firewall issue is the root cause for installing wrong extension versions as the involved extensions don’t use any information from store.xwiki.com. I think there could be another reason and it would indeed be very interesting to find out why this is happening not only to you but apparently also to other users as shown in the thread about the MV2 error.

I’ve already tried reproducing this issue by installation Markdown on 13.10.5 or upgrading 13.10.4 to 13.10.5 after installing Markdown, but I couldn’t reproduce that the dependencies were upgraded beyond the supported version. However, I’m not sure we actually have code that prevents such an upgrade as extensions typically also depend on certain versions of the XWiki core extensions but are still used on more recent versions of these extensions. Maybe somebody more familiar with the extension version management has a better idea why this could happen?

Uh, that’s interesting. Actually we had Markdown installed in 10.11.8 and upgraded right away to 13.10.5.

As far as I know, we do not use any paid extensions. Is any part of the scripting API useful for finding installed extensions by their source? Otherwise I would have to click through over 200 extensions in the worst case.
Also, does the source necessarily show in the details in the GUI or is there a better way to find the reason for something trying to request store.xwiki.com?

AFAIK, you can find licensed (paid) extensions on AdministrationExtensionsLicenses (the License menu does not exist if you never installed a licensed extension).

If a paid extension was installed in a subwiki only, would that show in the main wiki or only in the subwiki?