Local single XWiki became excrutiatingly slow after update

Help / Discuss
1

Hello,

Upgraded to xwiki 16.4.0 using the upgrade wiki page (apt-get update & upgrade) then had issues with Java which required to purge openjdk-11 (apt-get purge openjdk-11*) in favor of openjdk-17 which apparently got automatically installed during the above mentioned system upgrade.

Point of remark: There’s something definitely not working with the upgrade procedure as I’m not the only one who encountered the issue with tomcat still using Java 11 even after 17 is installed…

Anyways I managed to get past this problem and could start Tomcat and got to the Xwiki wizard page which I ran (as admin) to finish upgrading the flavor and everything else. No errors anywhere during the process (other than a few warnings of deprecate content, etc).

Tomcat starts without issues, site loads properly (although slower than before).

Issue now is that the site is extremely slow. For example from the moment I click “Log in” to the moment the credentials window appear, it takes a good 10-15 sec. Logging out usually takes 40-50 sec…

Navigation within the wiki is also much slower than before.

Please note: nothing has changed on the way the database is stored and accessed, and storage / hardware is identical to previously.

Machine specs:
VM running on Proxmox VE
Ubuntu 20.04.6 LTS (GNU/Linux 5.4.0-186-generic x86_64)

System information:
System load: 0.02
Processes: 156
Usage of /: 49.7% of 18.53GB
Memory usage: 44%
Swap usage: 0%

Java Version
openjdk 17.0.11 2024-04-16
OpenJDK Runtime Environment (build 17.0.11+9-Ubuntu-120.04.2)
OpenJDK 64-Bit Server VM (build 17.0.11+9-Ubuntu-120.04.2, mixed mode, sharing)

Installed packages:
xwiki-common/stable,now 16.4.0 all [installed,automatic]
xwiki-mariadb-common/stable,now 16.4.0 all [installed,automatic]
xwiki-tomcat9-common/stable,now 16.4.0 all [installed]
xwiki-tomcat9-mariadb/stable,now 16.4.0 all [installed]

Storage:
Permanent dir is a NFS mount point on a local Freenas server.

Database:
MadiaDB running on another VM on the same PVE host.

Catalina.log (cold start, login, some navigation, logout)

24-Jun-2024 21:33:26.991 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name:   Apache Tomcat/9.0.31 (Ubuntu)
24-Jun-2024 21:33:26.992 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Nov 18 2022 19:07:15 UTC
24-Jun-2024 21:33:26.992 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 9.0.31.0
24-Jun-2024 21:33:26.992 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
24-Jun-2024 21:33:26.993 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            5.4.0-186-generic
24-Jun-2024 21:33:26.994 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
24-Jun-2024 21:33:26.994 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /usr/lib/jvm/java-17-openjdk-amd64
24-Jun-2024 21:33:26.994 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           17.0.11+9-Ubuntu-120.04.2
24-Jun-2024 21:33:26.995 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Ubuntu
24-Jun-2024 21:33:26.995 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /var/lib/tomcat9
24-Jun-2024 21:33:26.995 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /usr/share/tomcat9
24-Jun-2024 21:33:27.017 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.lang=ALL-UNNAMED
24-Jun-2024 21:33:27.018 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.io=ALL-UNNAMED
24-Jun-2024 21:33:27.018 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
24-Jun-2024 21:33:27.018 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.properties
24-Jun-2024 21:33:27.019 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
24-Jun-2024 21:33:27.019 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.awt.headless=true
24-Jun-2024 21:33:27.021 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xmx4096m
24-Jun-2024 21:33:27.021 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.security.egd=file:/dev/./urandom
24-Jun-2024 21:33:27.021 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
24-Jun-2024 21:33:27.021 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
24-Jun-2024 21:33:27.021 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
24-Jun-2024 21:33:27.022 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
24-Jun-2024 21:33:27.022 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/var/lib/tomcat9
24-Jun-2024 21:33:27.022 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/share/tomcat9
24-Jun-2024 21:33:27.022 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/tmp
24-Jun-2024 21:33:27.023 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded APR based Apache Tomcat Native library [1.2.23] using APR version [1.6.5].
24-Jun-2024 21:33:27.023 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
24-Jun-2024 21:33:27.023 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
24-Jun-2024 21:33:27.029 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 1.1.1f  31 Mar 2020]
24-Jun-2024 21:33:27.510 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
24-Jun-2024 21:33:27.571 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [947] milliseconds
24-Jun-2024 21:33:27.730 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
24-Jun-2024 21:33:27.732 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/9.0.31 (Ubuntu)]
24-Jun-2024 21:33:27.747 INFO [main] org.apache.catalina.startup.HostConfig.deployDescriptor Deploying deployment descriptor [/etc/tomcat9/Catalina/localhost/xwiki.xml]
24-Jun-2024 21:33:27.773 WARNING [main] org.apache.catalina.startup.HostConfig.deployDescriptor The path attribute with value [/xwiki] in deployment descriptor [/etc/tomcat9/Catalina/localhost/xwiki.xml] has been ignored
24-Jun-2024 21:34:02.361 INFO [main] org.apache.catalina.startup.HostConfig.deployDescriptor Deployment of deployment descriptor [/etc/tomcat9/Catalina/localhost/xwiki.xml] has finished in [34,605] ms
24-Jun-2024 21:34:02.363 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/var/lib/tomcat9/webapps/ROOT]
24-Jun-2024 21:34:04.022 INFO [main] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
24-Jun-2024 21:34:04.027 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/var/lib/tomcat9/webapps/ROOT] has finished in [1,664] ms
24-Jun-2024 21:34:04.032 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
24-Jun-2024 21:34:04.044 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in [36,472] milliseconds
1 Like
2

Could it just be that your wiki is still performing a migration or indexing the content? If that’s the case then it should be back to normal speed once it’s done.

3

Hello Vincent,

24hrs later, its still slow. I would imagine if indexing was running it would be done by now as this wiki has less than 50 pages overall (rather small).

Something doesnt feel right. I just tried logging in and navigating a bit then logging out, I had to press the “Log out” link twice to get the page to refresh and show me as logged out…

Its either extremely slow or there’s something wrong with the refresh rate?

4

ok then it’s probably something else.

Ideas:

5

Tried the debug feature and it seems most of the delays are happening around template rendering…

572ms is half of a second… my wiki feels much much slower than that.

In the meantime I will try to install glowroot.

debug
debug1695×961 213 KB

6

OK its more than a performance issue. Xwiki is broken now.

I can browse the wiki fine (albeit very slowly as indicated before) but anything else is broken. Logging in/out is painfully slow or not working and when trying to edit an existing page I get a blank window with a rotating cursor which never ends.

Catalina.out does show tons of similar messages such as:

[2024-07-01 11:28:32] [info] 2024-07-01 11:28:32,214 [http-nio-8080-exec-7 - http://wiki.tuxdomain/xwiki/webjars/wiki%3Axwiki/webjar-blueimp-gallery/css/blueimp-gallery.min.css] ERROR o.a.v.rendering                - Left side ($unlicensedSheets.size()) of comparison operation has null value at xwiki:Licenses.Code.MissingLicensesUIX[line 13, column 61]
[2024-07-01 11:28:32] [info] 2024-07-01 11:28:32,956 [http-nio-8080-exec-6 - http://wiki.tuxdomain/xwiki/webjars/wiki%3Axwiki/xwiki-platform-image-lightbox-webjar/lightbox.min.js?r=1] ERROR o.a.v.rendering                - Left side ($unlicensedSheets.size()) of comparison operation has null value at xwiki:Licenses.Code.MissingLicensesUIX[line 13, column 61]
[2024-07-01 11:28:33] [info] 2024-07-01 11:28:33,399 [http-nio-8080-exec-10 - http://wiki.tuxdomain/xwiki/webjars/wiki%3Axwiki/xwiki-platform-ckeditor-webjar/ckeditor.js] ERROR o.a.v.rendering                - Left side ($unlicensedSheets.size()) of comparison operation has null value at xwiki:Licenses.Code.MissingLicensesUIX[line 13, column 61]
[2024-07-01 11:28:41] [info] 2024-07-01 11:28:41,354 [http-nio-8080-exec-5 - http://wiki.tuxdomain/xwiki/webjars/wiki%3Axwiki/xwiki-platform-ckeditor-plugins/webjar.bundle.min.css?evaluate=true] ERROR o.a.v.rendering                - Left side ($unlicensedSheets.size()) of comparison operation has null value at xwiki:Licenses.Code.MissingLicensesUIX[line 13, column 61]
[2024-07-01 11:28:41] [info] 2024-07-01 11:28:41,417 [http-nio-8080-exec-10 - http://wiki.tuxdomain/xwiki/webjars/wiki%3Axwiki/webjar-blueimp-gallery/css/blueimp-gallery.min.css] ERROR o.a.v.rendering                - Left side ($unlicensedSheets.size()) of comparison operation has null value at xwiki:Licenses.Code.MissingLicensesUIX[line 13, column 61]
[2024-07-01 11:28:41] [info] 2024-07-01 11:28:41,487 [http-nio-8080-exec-9 - http://wiki.tuxdomain/xwiki/webjars/wiki%3Axwiki/xwiki-platform-image-lightbox-webjar/less/lightbox.less?evaluate=true] ERROR o.a.v.rendering                - Left side ($unlicensedSheets.size()) of comparison operation has null value at xwiki:Licenses.Code.MissingLicensesUIX[line 13, column 61]
[2024-07-01 11:28:42] [info] 2024-07-01 11:28:42,836 [http-nio-8080-exec-7 - http://wiki.tuxdomain/xwiki/webjars/wiki%3Axwiki/xwiki-platform-ckeditor-webjar/ckeditor.js] ERROR o.a.v.rendering                - Left side ($unlicensedSheets.size()) of comparison operation has null value at xwiki:Licenses.Code.MissingLicensesUIX[line 13, column 61]
[2024-07-01 11:28:42] [info] 2024-07-01 11:28:42,892 [http-nio-8080-exec-10 - http://wiki.tuxdomain/xwiki/webjars/wiki%3Axwiki/xwiki-platform-image-lightbox-webjar/lightbox.min.js?r=1] ERROR o.a.v.rendering                - Left side ($unlicensedSheets.size()) of comparison operation has null value at xwiki:Licenses.Code.MissingLicensesUIX[line 13, column 61]
[2024-07-01 11:30:04] [info] 2024-07-01 11:30:04,156 [http-nio-8080-exec-9 - http://wiki.tuxdomain/xwiki/webjars/wiki%3Axwiki/xwiki-platform-ckeditor-plugins/webjar.bundle.min.css?evaluate=true] ERROR o.a.v.rendering                - Left side ($unlicensedSheets.size()) of comparison operation has null value at xwiki:Licenses.Code.MissingLicensesUIX[line 13, column 61]
[2024-07-01 11:30:04] [info] 2024-07-01 11:30:04,368 [http-nio-8080-exec-6 - http://wiki.tuxdomain/xwiki/webjars/wiki%3Axwiki/xwiki-platform-image-lightbox-webjar/less/lightbox.less?evaluate=true] ERROR o.a.v.rendering                - Left side ($unlicensedSheets.size()) of comparison operation has null value at xwiki:Licenses.Code.MissingLicensesUIX[line 13, column 61]
[2024-07-01 11:30:04] [info] 2024-07-01 11:30:04,407 [http-nio-8080-exec-2 - http://wiki.tuxdomain/xwiki/webjars/wiki%3Axwiki/webjar-blueimp-gallery/css/blueimp-gallery.min.css] ERROR o.a.v.rendering                - Left side ($unlicensedSheets.size()) of comparison operation has null value at xwiki:Licenses.Code.MissingLicensesUIX[line 13, column 61]
[2024-07-01 11:30:05] [info] 2024-07-01 11:30:05,815 [http-nio-8080-exec-5 - http://wiki.tuxdomain/xwiki/webjars/wiki%3Axwiki/xwiki-platform-image-lightbox-webjar/lightbox.min.js?r=1] ERROR o.a.v.rendering                - Left side ($unlicensedSheets.size()) of comparison operation has null value at xwiki:Licenses.Code.MissingLicensesUIX[line 13, column 61]
[2024-07-01 11:30:05] [info] 2024-07-01 11:30:05,946 [http-nio-8080-exec-7 - http://wiki.tuxdomain/xwiki/webjars/wiki%3Axwiki/xwiki-platform-ckeditor-webjar/ckeditor.js] ERROR o.a.v.rendering                - Left side ($unlicensedSheets.size()) of comparison operation has null value at xwiki:Licenses.Code.MissingLicensesUIX[line 13, column 61]
7

I can suggest an idea : would you check the path of java in the tomcat9 file under /etc/default?
I had noticed it was not right when I started testing, and changed it for the right path to the java directory. The original path was JAVA_HOME=/usr/lib/jvm/java-8-openjdk wheras the installed version was java-11-openjdk at that time.

1 Like
8

Hi!

These info messages are coming from an application that handles pro application licenses GitHub - xwikisas/application-licensing: Manage and enforce application licenses for pro extensions. I don’t think it should affect your instance slowness, but it’s not nice either to have so many info messages displayed.

I’ll try to reproduce and open a ticket. I’ll get back to you about it

1 Like