Java memory leak hell, I want to die

#1

So, I had a great system running Lucee on Java 11 (10.0.2) and Tomcat 9.0.16

And then on Monday, I ran an update of my system, Ubuntu 18.04.01 LTS, minor updates. Or so I thought.

Apparently, it updated Java to 11.0.3+7-Ubuntu-1ubuntu218.04.1

And then, all my Lucee sites came tumbling down.

WTF?

I have spent the last two days trying to solve this and I am at a loss.

I updated Tomcat to 9.0.20 (from 9.0.16) and that did nothing.

I have tried to find a solution on my test server at Digital Ocean as well, to no avail. Two different systems and locations, same OS version (Same kernel), same Java version, same Tomcat, etc. Same problem.

Here is the relevant server.xml section and log to explain what is happening

<!-- 
		=========
		start default host
		========= 
		-->
		<Host name="tomcat.bluebongos.com"  appBase="webapps" unpackWARs="true" autoDeploy="true">

			<Valve className="org.apache.catalina.valves.AccessLogValve" directory="logs/0-lucee" prefix="tomcat.bluebongos.com" maxDays="10" suffix=".log" pattern="%h %l %u %t &quot;%r&quot; %s %b" />

		</Host>
		<!-- 
		=========
		end default host
		========= 
		-->
		
		
		
		<!-- 
		=========
		start next host
		========= 
		-->
		<Host name="pia.bluebongos.com" appBase="webapps" unpackWARs="true" autoDeploy="true">
			<Context path="" docBase="/dataweb/websites/partnersinachievement/pia.bluebongos.com/web/" />
			<Valve className="org.apache.catalina.valves.AccessLogValve" directory="logs/0-lucee" prefix="pia.bluebongos.com" maxDays="10" suffix=".log" pattern="%h %l %u %t &quot;%r&quot; %s %b" />
		</Host>

When I start up Tomcat, it seems OK. The context starts up and runs, although with an error:

15-May-2019 21:28:30.759 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name:   Apache Tomcat/9.0.20
15-May-2019 21:28:30.763 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          May 3 2019 22:26:00 UTC
15-May-2019 21:28:30.764 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 9.0.20.0
15-May-2019 21:28:30.764 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
15-May-2019 21:28:30.765 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            4.15.0-50-generic
15-May-2019 21:28:30.765 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
15-May-2019 21:28:30.765 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /usr/lib/jvm/java-11-openjdk-amd64
15-May-2019 21:28:30.765 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           11.0.3+7-Ubuntu-1ubuntu218.04.1
15-May-2019 21:28:30.765 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Oracle Corporation
15-May-2019 21:28:30.765 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /opt/tomcat
15-May-2019 21:28:30.766 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /opt/tomcat
15-May-2019 21:28:30.783 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.lang=ALL-UNNAMED
15-May-2019 21:28:30.784 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.io=ALL-UNNAMED
15-May-2019 21:28:30.784 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
15-May-2019 21:28:30.785 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/opt/tomcat/conf/logging.properties
15-May-2019 21:28:30.785 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
15-May-2019 21:28:30.785 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xms16384m
15-May-2019 21:28:30.785 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xmx16384m
15-May-2019 21:28:30.785 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xmn2048m
15-May-2019 21:28:30.786 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xss1024k
15-May-2019 21:28:30.786 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:+ExplicitGCInvokesConcurrent
15-May-2019 21:28:30.786 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:+UseParallelGC
15-May-2019 21:28:30.786 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:+CMSClassUnloadingEnabled
15-May-2019 21:28:30.786 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.awt.headless=true
15-May-2019 21:28:30.786 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Duser.timezone=America/New_York
15-May-2019 21:28:30.787 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.security.egd=file:/dev/./urandom
15-May-2019 21:28:30.787 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
15-May-2019 21:28:30.787 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
15-May-2019 21:28:30.787 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
15-May-2019 21:28:30.787 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xms512M
15-May-2019 21:28:30.787 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xmx1024M
15-May-2019 21:28:30.788 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:+UseParallelGC
15-May-2019 21:28:30.788 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
15-May-2019 21:28:30.788 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/opt/tomcat
15-May-2019 21:28:30.788 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/opt/tomcat
15-May-2019 21:28:30.788 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/opt/tomcat/temp
15-May-2019 21:28:30.788 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded APR based Apache Tomcat Native library [1.2.21] using APR version [1.6.3].
15-May-2019 21:28:30.788 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
15-May-2019 21:28:30.789 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
15-May-2019 21:28:30.793 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 1.1.1b  26 Feb 2019]
15-May-2019 21:28:31.134 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
15-May-2019 21:28:31.167 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["https-openssl-nio-8443"]
15-May-2019 21:28:31.278 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-8009"]
15-May-2019 21:28:31.281 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [795] milliseconds
15-May-2019 21:28:31.348 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
15-May-2019 21:28:31.348 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/9.0.20]
15-May-2019 21:28:31.719 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.
15-May-2019 21:28:35.515 INFO [main] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/opt/tomcat/webapps/ROOT.war]
15-May-2019 21:28:35.568 SEVERE [main] org.apache.catalina.startup.HostConfig.deployWAR Error deploying web application archive [/opt/tomcat/webapps/ROOT.war]
	java.lang.IllegalStateException: Error starting child
		at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:716)
		at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:690)
		at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:705)
		at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:978)
		at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1849)
		at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
		at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
		at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
		at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:118)
		at org.apache.catalina.startup.HostConfig.deployWARs(HostConfig.java:773)
		at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:427)
		at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1576)
		at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:309)
		at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123)
		at org.apache.catalina.util.LifecycleBase.setStateInternal(LifecycleBase.java:423)
		at org.apache.catalina.util.LifecycleBase.setState(LifecycleBase.java:366)
		at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:929)
		at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:841)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
		at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1377)
		at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1367)
		at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
		at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
		at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:140)
		at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:902)
		at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:262)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
		at org.apache.catalina.core.StandardService.startInternal(StandardService.java:421)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
		at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:932)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
		at org.apache.catalina.startup.Catalina.start(Catalina.java:633)
		at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
		at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
		at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
		at java.base/java.lang.reflect.Method.invoke(Method.java:566)
		at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:344)
		at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:475)
	Caused by: org.apache.catalina.LifecycleException: Failed to start component [StandardEngine[Catalina].StandardHost[tomcat.bluebongos.com].StandardContext[]]
		at org.apache.catalina.util.LifecycleBase.handleSubClassException(LifecycleBase.java:440)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:198)
		at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:713)
		... 37 more
	Caused by: java.lang.IllegalStateException: Unknown protocol: jrt
		at org.apache.felix.framework.URLHandlersStreamHandlerProxy.hashCode(URLHandlersStreamHandlerProxy.java:224)
		at java.base/java.net.URL.hashCode(URL.java:957)
		at java.base/java.util.HashMap.hash(HashMap.java:339)
		at java.base/java.util.HashMap.containsKey(HashMap.java:591)
		at java.base/java.util.HashSet.contains(HashSet.java:204)
		at org.apache.tomcat.util.scan.StandardJarScanner.processURLs(StandardJarScanner.java:288)
		at org.apache.tomcat.util.scan.StandardJarScanner.doScanClassPath(StandardJarScanner.java:278)
		at org.apache.tomcat.util.scan.StandardJarScanner.scan(StandardJarScanner.java:229)
		at org.apache.catalina.startup.ContextConfig.processJarsForWebFragments(ContextConfig.java:1963)
		at org.apache.catalina.startup.ContextConfig.webConfig(ContextConfig.java:1129)
		at org.apache.catalina.startup.ContextConfig.configureStart(ContextConfig.java:775)
		at org.apache.catalina.startup.ContextConfig.lifecycleEvent(ContextConfig.java:301)
		at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123)
		at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5048)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
		... 38 more
15-May-2019 21:28:35.571 INFO [main] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/opt/tomcat/webapps/ROOT.war] has finished in [56] ms
15-May-2019 21:28:35.579 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
15-May-2019 21:28:35.595 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["https-openssl-nio-8443"]
15-May-2019 21:28:35.605 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
15-May-2019 21:28:35.611 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in [4,329] milliseconds


Now.

Add a second host. Just as I have done before this upgrade. Nothing changed. Same server.xml file, no changes to web files.

Multi homing was working perfectly, things were groovy, until this minor upgrade and Java change.

Now, here is what happens when I try to run a second site:

<!-- 
		=========
		start default host
		========= 
		-->
		<Host name="tomcat.bluebongos.com"  appBase="webapps" unpackWARs="true" autoDeploy="true">

			<Valve className="org.apache.catalina.valves.AccessLogValve" directory="logs/0-lucee" prefix="tomcat.bluebongos.com" maxDays="10" suffix=".log" pattern="%h %l %u %t &quot;%r&quot; %s %b" />

		</Host>
		<!-- 
		=========
		end default host
		========= 
		-->
		
		
		
		<!-- 
		=========
		start next host
		========= 
		-->
		<Host name="pia.bluebongos.com" appBase="webapps" unpackWARs="true" autoDeploy="true">
			<Context path="" docBase="/dataweb/websites/partnersinachievement/pia.bluebongos.com/web/" />
			<Valve className="org.apache.catalina.valves.AccessLogValve" directory="logs/0-lucee" prefix="pia.bluebongos.com" maxDays="10" suffix=".log" pattern="%h %l %u %t &quot;%r&quot; %s %b" />
		</Host>
		
		
		<!-- 
		=========
		start next host
		========= 
		-->
		<Host name="tasks.bluebongos.com" appBase="webapps" unpackWARs="true" autoDeploy="true">
			<Context path="" docBase="/dataweb/websites/bluebongos/tasks.bluebongos.com/web/" />
				<Valve className="org.apache.catalina.valves.AccessLogValve" directory="logs/0-lucee" prefix="tasks.bluebongos.com" maxDays="10" suffix=".log" pattern="%h %l %u %t &quot;%r&quot; %s %b" />
		</Host>

And the log file

15-May-2019 21:18:43.521 INFO [main] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/opt/tomcat/webapps/ROOT.war]
15-May-2019 21:18:43.556 SEVERE [main] org.apache.catalina.startup.HostConfig.deployWAR Error deploying web application archive [/opt/tomcat/webapps/ROOT.war]
	java.lang.IllegalStateException: Error starting child
		at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:716)
		at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:690)
		at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:705)
		at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:978)
		at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1849)
		at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
		at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
		at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
		at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:118)
		at org.apache.catalina.startup.HostConfig.deployWARs(HostConfig.java:773)
		at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:427)
		at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1576)
		at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:309)
		at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123)
		at org.apache.catalina.util.LifecycleBase.setStateInternal(LifecycleBase.java:423)
		at org.apache.catalina.util.LifecycleBase.setState(LifecycleBase.java:366)
		at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:929)
		at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:841)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
		at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1377)
		at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1367)
		at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
		at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
		at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:140)
		at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:902)
		at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:262)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
		at org.apache.catalina.core.StandardService.startInternal(StandardService.java:421)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
		at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:932)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
		at org.apache.catalina.startup.Catalina.start(Catalina.java:633)
		at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
		at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
		at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
		at java.base/java.lang.reflect.Method.invoke(Method.java:566)
		at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:344)
		at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:475)
	Caused by: org.apache.catalina.LifecycleException: Failed to start component [StandardEngine[Catalina].StandardHost[tomcat.bluebongos.com].StandardContext[]]
		at org.apache.catalina.util.LifecycleBase.handleSubClassException(LifecycleBase.java:440)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:198)
		at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:713)
		... 37 more
	Caused by: java.lang.IllegalStateException: Unknown protocol: jrt
		at org.apache.felix.framework.URLHandlersStreamHandlerProxy.hashCode(URLHandlersStreamHandlerProxy.java:224)
		at java.base/java.net.URL.hashCode(URL.java:957)
		at java.base/java.util.HashMap.hash(HashMap.java:339)
		at java.base/java.util.HashMap.containsKey(HashMap.java:591)
		at java.base/java.util.HashSet.contains(HashSet.java:204)
		at org.apache.tomcat.util.scan.StandardJarScanner.processURLs(StandardJarScanner.java:288)
		at org.apache.tomcat.util.scan.StandardJarScanner.doScanClassPath(StandardJarScanner.java:278)
		at org.apache.tomcat.util.scan.StandardJarScanner.scan(StandardJarScanner.java:229)
		at org.apache.catalina.startup.ContextConfig.processJarsForWebFragments(ContextConfig.java:1963)
		at org.apache.catalina.startup.ContextConfig.webConfig(ContextConfig.java:1129)
		at org.apache.catalina.startup.ContextConfig.configureStart(ContextConfig.java:775)
		at org.apache.catalina.startup.ContextConfig.lifecycleEvent(ContextConfig.java:301)
		at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123)
		at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5048)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
		... 38 more
15-May-2019 21:18:43.558 INFO [main] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/opt/tomcat/webapps/ROOT.war] has finished in [37] ms
15-May-2019 21:18:43.558 SEVERE [main] org.apache.catalina.core.ContainerBase.startInternal A child container failed during start
	java.util.concurrent.ExecutionException: org.apache.catalina.LifecycleException: A child container failed during start
		at java.base/java.util.concurrent.FutureTask.report(FutureTask.java:122)
		at java.base/java.util.concurrent.FutureTask.get(FutureTask.java:191)
		at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:909)
		at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:262)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
		at org.apache.catalina.core.StandardService.startInternal(StandardService.java:421)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
		at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:932)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
		at org.apache.catalina.startup.Catalina.start(Catalina.java:633)
		at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
		at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
		at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
		at java.base/java.lang.reflect.Method.invoke(Method.java:566)
		at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:344)
		at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:475)
	Caused by: org.apache.catalina.LifecycleException: A child container failed during start
		at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:921)
		at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:841)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
		at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1377)
		at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1367)
		at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
		at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
		at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:140)
		at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:902)
		... 13 more
	Caused by: java.util.concurrent.ExecutionException: org.apache.catalina.LifecycleException: Failed to start component [StandardEngine[Catalina].StandardHost[tasks.bluebongos.com].StandardContext[]]
		at java.base/java.util.concurrent.FutureTask.report(FutureTask.java:122)
		at java.base/java.util.concurrent.FutureTask.get(FutureTask.java:191)
		at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:909)
		... 21 more
	Caused by: org.apache.catalina.LifecycleException: Failed to start component [StandardEngine[Catalina].StandardHost[tasks.bluebongos.com].StandardContext[]]
		at org.apache.catalina.util.LifecycleBase.handleSubClassException(LifecycleBase.java:440)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:198)
		at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1377)
		at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1367)
		at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
		at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
		at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:140)
		at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:902)
		... 21 more
	Caused by: java.lang.IllegalStateException: Unknown protocol: jrt
		at org.apache.felix.framework.URLHandlersStreamHandlerProxy.hashCode(URLHandlersStreamHandlerProxy.java:224)
		at java.base/java.net.URL.hashCode(URL.java:957)
		at java.base/java.util.HashMap.hash(HashMap.java:339)
		at java.base/java.util.HashMap.containsKey(HashMap.java:591)
		at java.base/java.util.HashSet.contains(HashSet.java:204)
		at org.apache.tomcat.util.scan.StandardJarScanner.processURLs(StandardJarScanner.java:288)
		at org.apache.tomcat.util.scan.StandardJarScanner.doScanClassPath(StandardJarScanner.java:278)
		at org.apache.tomcat.util.scan.StandardJarScanner.scan(StandardJarScanner.java:229)
		at org.apache.catalina.startup.ContextConfig.processJarsForWebFragments(ContextConfig.java:1963)
		at org.apache.catalina.startup.ContextConfig.webConfig(ContextConfig.java:1129)
		at org.apache.catalina.startup.ContextConfig.configureStart(ContextConfig.java:775)
		at org.apache.catalina.startup.ContextConfig.lifecycleEvent(ContextConfig.java:301)
		at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123)
		at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5048)
		at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
		... 27 more
15-May-2019 21:18:43.561 INFO [main] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["http-nio-8080"]
15-May-2019 21:18:43.561 INFO [main] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["https-openssl-nio-8443"]
15-May-2019 21:18:43.561 INFO [main] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["ajp-nio-8009"]
15-May-2019 21:18:43.561 INFO [main] org.apache.catalina.core.StandardService.stopInternal Stopping service [Catalina]
15-May-2019 21:18:48.651 WARNING [main] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [FelixResolver-1] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 java.base@11.0.3/jdk.internal.misc.Unsafe.park(Native Method)
 java.base@11.0.3/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
 java.base@11.0.3/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
 java.base@11.0.3/java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:458)
 java.base@11.0.3/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1053)
 java.base@11.0.3/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
 java.base@11.0.3/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
 java.base@11.0.3/java.lang.Thread.run(Thread.java:834)


I am so demoralized, and lost. I’ve run Adobe Cf, Blue Dragon, Rialo, and now Lucee - on Windows, OS X, Ubuntu 10 through 18.

This is the first time this has happened and I don’t understand it.

#2

Perhaps you are affected by this issue?
https://luceeserver.atlassian.net/browse/LDEV-2215

See the comments, you might be able to downgrade to Java 11.0.1 as a workaround. Otherwise there’s a fix in the Lucee 5.3.3.23 snapshot, however you’d want to test that before putting it into production.

1 Like
#3

Tried that last night on the test server. No go.

As soon as I try to have more than one host, log fills with errors.

#4

which version of Lucee?

#5

I was/am on 5.3.1.102. I tried the 5.3.3.31 snapshot as well.

#6

Starting process of cleaning out Java 11 on test server, back porting or installing by hand (whichever I have to do) to java 10.0.2. Of course, at some point I will want to move to 11. So the bigger question is why, if I have a valid install of Tomcat and Lucee multi-homed to 3 or 4 sites, why would that suddenly not be valid when Java is upgraded. And I understand that some classes may change. But the overall problem of java essentially saying “I’ll run with one host context plus the default, but not two or more” is not a problem I am qualified to solve.

#7

BTW, what about going to OpenJDK 12? Is that viable or only worse? I know 10.0.2 won’t receive updates, but since it’s less than 1 year old and is in the LTS bundle for an OS, I gotta wonder if maybe still OK. If not, then what about moving up to 12?

#8

Are you able to provide steps to reproduce the problem from scratch?
that’s probably what the Lucee dev team will need in order to address the problem.

Dunno about JDK 12, the moving target nature of JDK releases at the moment is confusing eh?

I’d say, definitely go ahead file a bug and link back to this thread

#9

OK. Not an expert on filing a bug, but will do my best to give info.

#10

don’t be so hard on yourself, aside from omitting the Lucee version, this bug report was great :slight_smile:

#11

Link to issue:

https://luceeserver.atlassian.net/browse/LDEV-2284

#12

Couple comments -

  1. You can have multiple JVMs on an Ubuntu box. 1 will be the default (usually the one with the highest version). Others will show up in /usr/lib/jvm/ and you can reference them directly by setting JAVA_HOME and/or referencing java from the specific folder, vs using the one in usr/bin.
  2. I’m still running Java 8 just about everywhere. Tomcat 9 lists Java 8 and up…

If it were me, I’d download the amazon corretto 8 deb, install it, and change the Lucee startup script (whatever you’re using) to use the specific JAVA_HOME and java binary to use the corretto VM, instead of the system default. And then start the server and verify the results. That’s pretty minimal, low risk, and may just resolve your issue.

(Of course, Azul Zulu, Adopt OpenJDK, or even openjdk packages from prior ubuntu releases are just as valid options)

2 Likes
#13

Joe, thanks!!! I am going to revisit your answer when I have a moment and look into Amazon’s corretto (for a variety of reasons).

For now, I just finished (about 1 PM eastern time) doing some testing of the test system, going back to 10.0.2 and have success which I will post in a few minutes.

#14

So, I have reverted back to 10.0.2 and installed Java manually under /opt

And, everything is back to normal.

However, now that I went that far, I decided to set up an alternative Java 12 as well, also under /opt and just swap out the java home for the different versions. My original problem was Java 11 (and still is), but I thought, hey, everything is back to normal with 10.0.2, let’s just try 12 for kicks and grins.

And, just like with 11, same problems.

Here is some of the catalina output that might be relevant for the Lucee team???

16-May-2019 13:28:51.172 INFO [main] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["http-nio-8080"]
16-May-2019 13:28:51.173 INFO [main] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["https-jsse-nio-8443"]
16-May-2019 13:28:51.173 INFO [main] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["ajp-nio-8009"]
16-May-2019 13:28:51.173 INFO [main] org.apache.catalina.core.StandardService.stopInternal Stopping service [Catalina]
16-May-2019 13:28:56.324 SEVERE [main] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [ROOT] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@7668892a]) and a value of type [lucee.commons.lang.types.RefBooleanImpl] (value [false]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
16-May-2019 13:28:56.328 SEVERE [main] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [ROOT] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@a83495d]) and a value of type [lucee.runtime.config.ConfigWebImpl] (value [lucee.runtime.config.ConfigWebImpl@7e83992]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
16-May-2019 13:28:56.332 INFO [main] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio-8080"]
16-May-2019 13:28:56.337 INFO [main] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["https-jsse-nio-8443"]
16-May-2019 13:28:56.338 INFO [main] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["ajp-nio-8009"]

#15

Does that mean the “Unknown protocol: jrt” errors are still happening after you downgraded to Java 11.0.1 and/or upgraded to the latest Lucee snapshot? Because this was the part that stood out to me the most and should have been resolved with those workarounds;

	Caused by: java.lang.IllegalStateException: Unknown protocol: jrt
		at org.apache.felix.framework.URLHandlersStreamHandlerProxy.hashCode(URLHandlersStreamHandlerProxy.java:224)
		at java.base/java.net.URL.hashCode(URL.java:957)
		at java.base/java.util.HashMap.hash(HashMap.java:339)
		at java.base/java.util.HashMap.containsKey(HashMap.java:591)
		at java.base/java.util.HashSet.contains(HashSet.java:204)
		at org.apache.tomcat.util.scan.StandardJarScanner.processURLs(StandardJarScanner.java:288)

Can you include the full logs instead of just a snippet? Sometimes the thing that is repeating in the log might be cause by some other earlier exception, so that underlying issue might need to be resolved first.

#16

I downgraded back to 10.0.2 to get everything back to normal.

However, I set up the install so that I can easily change versions in the future.

So, I could go back and try 11 on the test server and send you the log if you want. The only reason I did not include the full log is that it was over the limit for this forum (32,xxx characters is the limit).

Would you like me to do that? I still have 5.3.3.31 (I think) on the test server.

#17

Want to also ask those who are clearly more knowledgable than me… What are the big changes between OpenJDK 10.0.x and 11.x? (And 12 too for that matter). I mean, I have a clean catalina.log file (as in, no errors, info notices only), and all 3 Lucee sites running as multi-homed instances, as well as Tomcat apps all working great. Then, swap to 11 or 12 and boom, all these memory errors and nothing starts up. So, is this a problem with how the server.xml file specifies multiple hosts? Just really bewildered.

#18

The LDEV-2215 ticket said that when using Java 11.0.2+ the Felix issue with “Unknown protocol: jrt” should be resolved by either upgrading to 5.3.3.23-SNAPSHOT or downgrading to Java 11.0.1, so if that’s not the case it would be good to confirm it.

Or, perhaps that particular issue is fixed but there is another issue that needs to be solved, in which case we’d probably need to see the full logs to be able to do that. You could upload those logs to your new ticket if they don’t fit here in the forum, just be sure to include the Java version and the Lucee version that the logs are for, perhaps in the filename to make it clear. That would be a big help :slight_smile:

#19

OK, I’ve got some energy left, so I am working on this now and will post in a few minutes. Better to post here or on LDEV ticket?

1 Like
#20

Use your ticket for the logs I think, but feel free to put further discussions/troubleshooting here :slight_smile: