Trouble restarting XWiki (tomcat) reliably

Help / Discuss
1

Hi,

I have a weird issue where I cannot reliably restart things. Running tomcat9 von Debian XWiki. I’m sure how to debug this further, but the thing I noticed was that if ti gets stuck during tomcat startup, it stalls in one particular place:

Nov 17 16:35:04 xwiki systemd[1]: Starting Apache Tomcat 9 Web Application Server...
Nov 17 16:35:04 xwiki systemd[1]: Started Apache Tomcat 9 Web Application Server.
Nov 17 16:35:04 xwiki tomcat9[3212]: NOTE: Picked up JDK_JAVA_OPTIONS:  --add-opens=java.base/java.lang=ALL-UNNAMED --add-opens=java.base/java.io=ALL-UNNAMED --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
Nov 17 16:35:05 xwiki tomcat9[3212]: Server version name:   Apache Tomcat/9.0.31 (Debian)
Nov 17 16:35:05 xwiki tomcat9[3212]: Server built:          Oct 25 2022 15:43:18 UTC
Nov 17 16:35:05 xwiki tomcat9[3212]: Server version number: 9.0.31.0
Nov 17 16:35:05 xwiki tomcat9[3212]: OS Name:               Linux
Nov 17 16:35:05 xwiki tomcat9[3212]: OS Version:            4.19.0-22-amd64
Nov 17 16:35:05 xwiki tomcat9[3212]: Architecture:          amd64
Nov 17 16:35:05 xwiki tomcat9[3212]: Java Home:             /usr/lib/jvm/java-11-openjdk-amd64
Nov 17 16:35:05 xwiki tomcat9[3212]: JVM Version:           11.0.16+8-post-Debian-1deb10u1
Nov 17 16:35:05 xwiki tomcat9[3212]: JVM Vendor:            Debian
Nov 17 16:35:05 xwiki tomcat9[3212]: CATALINA_BASE:         /var/lib/tomcat9
Nov 17 16:35:05 xwiki tomcat9[3212]: CATALINA_HOME:         /usr/share/tomcat9
Nov 17 16:35:05 xwiki tomcat9[3212]: Command line argument: --add-opens=java.base/java.lang=ALL-UNNAMED
Nov 17 16:35:05 xwiki tomcat9[3212]: Command line argument: --add-opens=java.base/java.io=ALL-UNNAMED
Nov 17 16:35:05 xwiki tomcat9[3212]: Command line argument: --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
Nov 17 16:35:05 xwiki tomcat9[3212]: Command line argument: -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.properties
Nov 17 16:35:05 xwiki tomcat9[3212]: Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
Nov 17 16:35:05 xwiki tomcat9[3212]: Command line argument: -Djava.awt.headless=true
Nov 17 16:35:05 xwiki tomcat9[3212]: Command line argument: -Xmx1024m
Nov 17 16:35:05 xwiki tomcat9[3212]: Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
Nov 17 16:35:05 xwiki tomcat9[3212]: Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
Nov 17 16:35:05 xwiki tomcat9[3212]: Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
Nov 17 16:35:05 xwiki tomcat9[3212]: Command line argument: -Dignore.endorsed.dirs=
Nov 17 16:35:05 xwiki tomcat9[3212]: Command line argument: -Dcatalina.base=/var/lib/tomcat9
Nov 17 16:35:05 xwiki tomcat9[3212]: Command line argument: -Dcatalina.home=/usr/share/tomcat9
Nov 17 16:35:05 xwiki tomcat9[3212]: Command line argument: -Djava.io.tmpdir=/tmp
Nov 17 16:35:05 xwiki tomcat9[3212]: An older version [1.2.21] of the APR based Apache Tomcat Native library is installed, while Tomcat recommends a minimum version of [1.2.23]
Nov 17 16:35:05 xwiki tomcat9[3212]: Loaded APR based Apache Tomcat Native library [1.2.21] using APR version [1.6.5].
Nov 17 16:35:05 xwiki tomcat9[3212]: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
Nov 17 16:35:05 xwiki tomcat9[3212]: APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
Nov 17 16:35:05 xwiki tomcat9[3212]: OpenSSL successfully initialized [OpenSSL 1.1.1n  15 Mar 2022]
Nov 17 16:35:05 xwiki tomcat9[3212]: Initializing ProtocolHandler ["http-nio-8080"]
Nov 17 16:35:06 xwiki tomcat9[3212]: Server initialization in [1,089] milliseconds
Nov 17 16:35:06 xwiki tomcat9[3212]: Starting service [Catalina]
Nov 17 16:35:06 xwiki tomcat9[3212]: Starting Servlet engine: [Apache Tomcat/9.0.31 (Debian)]
Nov 17 16:35:06 xwiki tomcat9[3212]: Deploying deployment descriptor [/etc/tomcat9/Catalina/localhost/ROOT.xml]
Nov 17 16:35:06 xwiki tomcat9[3212]: Deployment of deployment descriptor [/etc/tomcat9/Catalina/localhost/ROOT.xml] with an external docBase means the directory [/var/lib/tomcat9/webapps/ROOT] in the appBase will be ignored
Nov 17 16:35:13 xwiki tomcat9[3212]: 2022-11-17 16:35:13,836 [main] INFO  iPropertiesConfigurationSource - Loading [xwiki.properties] from default location [/etc/xwiki/xwiki.properties]
Nov 17 16:35:14 xwiki tomcat9[3212]: 2022-11-17 16:35:14,166 [main] INFO  o.x.e.i.ServletEnvironment     - Using permanent directory [/var/lib/xwiki/data]
Nov 17 16:35:28 xwiki tomcat9[3212]: 2022-11-17 16:35:28,580 [main] INFO  o.x.s.s.i.EmbeddedSolr         - Updating Solr home directory at [/var/lib/xwiki/data/store/solr]
Nov 17 16:35:28 xwiki tomcat9[3212]: 2022-11-17 16:35:28,592 [main] INFO  o.x.s.s.i.EmbeddedSolr         - Starting embedded Solr server...
Nov 17 16:35:28 xwiki tomcat9[3212]: 2022-11-17 16:35:28,592 [main] INFO  o.x.s.s.i.EmbeddedSolr         - Using Solr home directory: [/var/lib/xwiki/data/store/solr]
Nov 17 16:35:30 xwiki tomcat9[3212]: 2022-11-17 16:35:30,439 [main] WARN  o.e.j.u.s.S.config             - Trusting all certificates configured for Client@46d393cd[provider=null,keyStore=null,trustStore=null]
Nov 17 16:35:30 xwiki tomcat9[3212]: 2022-11-17 16:35:30,439 [main] WARN  o.e.j.u.s.S.config             - No Client EndPointIdentificationAlgorithm configured for Client@46d393cd[provider=null,keyStore=null,trustStore=null]
Nov 17 16:35:30 xwiki tomcat9[3212]: 2022-11-17 16:35:30,741 [main] WARN  o.e.j.u.s.S.config             - Trusting all certificates configured for Client@7ea2ce9d[provider=null,keyStore=null,trustStore=null]
Nov 17 16:35:30 xwiki tomcat9[3212]: 2022-11-17 16:35:30,741 [main] WARN  o.e.j.u.s.S.config             - No Client EndPointIdentificationAlgorithm configured for Client@7ea2ce9d[provider=null,keyStore=null,trustStore=null]
Nov 17 16:35:30 xwiki tomcat9[3212]: 2022-11-17 16:35:30,897 [main] WARN  o.a.s.c.CoreContainer          - Not all security plugins configured!  authentication=disabled authorization=disabled.  Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external.  See https://s.apache.org/solrsecurity for more info

Right there ↑↑↑ it gets stuck. If it makes it past there, all is fine. What follows in that case looks like…

Nov 17 16:35:35 xwiki tomcat9[3212]: 2022-11-17 16:35:35,095 [recoveryExecutor-25-thread-1-processing-x:search] WARN  o.a.s.u.UpdateLog              - Starting log replay tlog{file=/var/lib/xwiki/data/store/solr/search/../../../cache/solr/search/tlog/tlog.0000000000000002473 refcount=2}  active=false starting pos=0 inSortedOrder=false
Nov 17 16:35:35 xwiki tomcat9[3212]: 2022-11-17 16:35:35,174 [main] INFO  o.x.s.s.i.EmbeddedSolr         - Started embedded Solr server.
Nov 17 16:35:36 xwiki tomcat9[3212]: 2022-11-17 16:35:36,395 [recoveryExecutor-25-thread-1-processing-x:search] WARN  o.a.s.u.UpdateLog              - Log replay finished. recoveryInfo=RecoveryInfo{adds=6 deletes=0 deleteByQuery=0 errors=0 positionOfStart=0}
Nov 17 16:35:37 xwiki tomcat9[3212]: WARNING: An illegal reflective access operation has occurred
Nov 17 16:35:37 xwiki tomcat9[3212]: WARNING: Illegal reflective access by com.thoughtworks.xstream.converters.reflection.FieldDictionary (file:/usr/lib/xwiki/WEB-INF/lib/xstream-1.4.17.jar) to field java.util.Collections$UnmodifiableMap.serialVersionUID
Nov 17 16:35:37 xwiki tomcat9[3212]: WARNING: Please consider reporting this to the maintainers of com.thoughtworks.xstream.converters.reflection.FieldDictionary
Nov 17 16:35:37 xwiki tomcat9[3212]: WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
Nov 17 16:35:37 xwiki tomcat9[3212]: WARNING: All illegal access operations will be denied in a future release
Nov 17 16:35:38 xwiki tomcat9[3212]: 2022-11-17 16:35:38,368 [main] INFO  o.x.s.f.i.FilesystemStoreTools - Using filesystem store directory [/var/lib/xwiki/data/store/file]
Nov 17 16:35:38 xwiki tomcat9[3212]: 2022-11-17 16:35:38,414 [main] WARN  x.w.i.XWikiEndpointInitializer - The servlet container doesn't support the Java API for WebSocket (JSR 356).
Nov 17 16:35:38 xwiki tomcat9[3212]: Deployment of deployment descriptor [/etc/tomcat9/Catalina/localhost/ROOT.xml] has finished in [32,479] ms
Nov 17 16:35:38 xwiki tomcat9[3212]: Starting ProtocolHandler ["http-nio-8080"]
Nov 17 16:35:38 xwiki tomcat9[3212]: Server startup in [32,596] milliseconds

Does anyone have any idea or pointer as to what could be causing this? It’s not deterministic, I can’t seem to nail it down to something. Sometimes it works, sometimes it doesn’t. I don’t change anything in the meantime…

How to debug further? Thanks so much!

2

What’s your version of XWiki ? It looks a lot like Loading.... See Loading... for a workaround.

3

Dear Thomas,

many thanks, spot on, that appeared to be the issue!

I employed the suggested workaround (editing the core.properties files…) and now XWiki reliably starts again. This is for the latest XWiki Debian 14.9, installed with apt.

What are the “downsides” of disabling load on startup for these cores in layman’s terms?

Happy to assist in debugging this further. Cheers!

4

The only difference is that it’s going to be initialized the first time it’s used instead of all at the same time. So I guess the only downside is that it makes the first request that needs a specific core slightly slower.