You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Michael Richardson <mc...@sandelman.ca> on 2021/08/12 15:05:21 UTC
how to tune cacheMaxSize
I am trying to deploy OSCAR-EMR in a new location (for my wife's office),
with better encryption and database replication. We have an existing
bare-metal instance running that her boss assembled. It's fragile, but it
runs.
In both ubuntu 18.04 and devuan beowulf VMs, I can start up tomcat9
and openjdk (8 or 11) and talk to the tomcat9-admin interface.
I then deploy the oscar.war to /var/lib/tomcat19/webapps, and observe
in htop that I get 5-6 threads that get very busy, as it extracts the app.
Then, port 8080 stops responding. And also I see new connections just stall.
I wind up with two threads of java each chewing 100% of the CPU.
strace on it doesn't help, telling me that it looks like 32-bit code.
I think that the JIT might confuse it. Are these threads doing I/O or system
calls? I can't tell.
(I can see the new connections stalling in netstat -tan, with unprocessed
bytes in the recv Q)
If I stop the java processes, and restart them, then they seem to continue
the "deploy", even if I have removed the oscar.war and
/var/lib/tomcat19/webcaps/oscar directory. Clearly something else remembers
it. When that happens, I get *no output* in catalina.out.
And _apt-get purge tomcat9_, and re-install, gets me back to the start, but I'd
like to understand where the deploy is being recorded and how I can undo only
that.
I will get one message that I am trying to look at the cacheMaxSize
value in /etc/tomcat9/context.xml.
<dang, that log file got deleted>
My question is, if the cacheMaxSize is too small, will it lead to some kind
of continual cache replacement where it never actually starts up?
If so, is there some debug that would let me estimate what an appropriate
cache size is? The running machine has:
<Resources cachingAllowed="true" cacheMaxSize="100000" />
(I initially suspected the whole /dev/random issue, so I moved the TLS
to a proxy-pass Apache, but also I have virtio /dev/random, and I also
ln /dev/urandom to /dev/random just in case...)
--
] Never tell me the odds! | ipv6 mesh networks [
] Michael Richardson, Sandelman Software Works | IoT architect [
] mcr@sandelman.ca http://www.sandelman.ca/ | ruby on rails [
Re: how to tune cacheMaxSize
Posted by Michael Richardson <mc...@sandelman.ca>.
Thank you for the reply.
Christopher Schultz <ch...@christopherschultz.net> wrote:
> On 8/12/21 11:05, Michael Richardson wrote:
>> I am trying to deploy OSCAR-EMR
> Wow, that still exists? I remember more than a decade ago being asked
> to integrate a product at $work with that thing as a demo. We never
> did, because the market seemed not to really exist. I see you are in
> Canada. I know OSCAR same from McMaster University. Does it have a good
> ecosystem and install base in CA?
Yes, it's still quite popular among many Ontario (and I'm told BC) doctors,
because it has good integration with the provincial billing system. Doctor
like it because the price appears right, and doctors don't get rich by
spending money.
There are a number of support companies that install it, but my experience
(via my wife) is that their do a rather poor job of installation.
No understanding of database encryption, replication, or even how to enable https.
There seems to be developer still working on it, according to the bitbucket
git commit lot. But, the public community around it seems to have died, as
far as I can tell.
>> I then deploy the oscar.war to /var/lib/tomcat19/webapps, and observe
>> in htop that I get 5-6 threads that get very busy, as it extracts the
>> app.
> Hmm. I wouldn't expect more than 1 thread to get busy extracting that
> application.
Sure, that's what I figured too.
>> If I stop the java processes, and restart them, then they seem to
>> continue the "deploy", even if I have removed the oscar.war and
>> /var/lib/tomcat19/webcaps/oscar directory. Clearly something else
>> remembers it. When that happens, I get *no output* in catalina.out.
> What makes you think those threads are continuing to deploy the WAR
> file? If the WAR file is missing, deployment would be most
> difficult. When you remove the WAR file, are you also removing the
> exploded-WAR-directory that Tomcat creates during the deployment of the
> WAR?
Yes, I also remove the exploded WAR-directory, and also the oscar.properties.
>> (I initially suspected the whole /dev/random issue, so I moved the TLS
>> to a proxy-pass Apache, but also I have virtio /dev/random, and I also
>> ln /dev/urandom to /dev/random just in case...)
> Okay, I don't mean to sound mean, but it sounds like you have no idea
> what's going on, here. There are probably several issues, but let's
> start with the first one: what are those threads doing at 100% CPU.
I am not a JAVA/Tomcat guy.
I do Rails for 15 years, postgres, maintain tcpdump and IPsec, and still
occasionally debug kernel issues. But, mostly I write and implement IoT
security RFCs.
> You don't have a /dev/random problem, because really nobody has that
> problem anymore. Also, the /dev/random problem manifests as a "hung"
> server with *zero* CPU usage.
Yes, I noticed that egd setting is no more. I mention this to be clear that
I'd debugged that.
> Reset your environment back to the beginning: fresh Tomcat, no log
> files, no WAR deployed or anything like that. Start up Tomcat and make
> sure everything looks good so far. Then deploy the WAR file and let
> everything go to hell. After things settle down and you are in your "2
> threads eating the CPU" situation, do the following:
> 1. Grab the log file in CATALINA_BASE/logs/catalina.out (or similar)
> 2. Take a thread-dump of the running JVM[1]
Before doing the purge, I have tried kill -3 as instructed, and gotten
nothing (no output to catalina.out).
I am resetting now, and I'll kill -3 just after the war deploy.
--
] Never tell me the odds! | ipv6 mesh networks [
] Michael Richardson, Sandelman Software Works | IoT architect [
] mcr@sandelman.ca http://www.sandelman.ca/ | ruby on rails [
Re: trying to deploy oscar (was Re: how to tune cacheMaxSize )
Posted by Michael Richardson <mc...@sandelman.ca>.
I grabbed apache-tomcat-9.0.52.tar.gz from
https://downloads.apache.org/tomcat/tomcat-9/v9.0.52/bin/apache-tomcat-9.0.52.tar.gz
I unpacked it to /opt/apache-tomcat-9.0.52.tar.gz.
I uninstalled tomcat9 (purged, and rm -rf /var/lib/tomcat/webapps)
I tweaked CATALINA_HOME and JRE_HOME appropriately.
I ran $CATALINA_HOME/bin/start.sh. As root, which clearly was a mistake.
I thought it would su, but clearly I should start it as mortal user.
Perhaps there is a better script, but clearly the tomcat package took care of that.
(I wouldn't want to run it as root in production at all)
Before fixing that mistake, I notice:
PID USER PRI NI VIRT RES SHR S CPU% MEM% TIME+ Command
6246 root 20 0 3417M 37392 17752 S 201. 0.9 22:34.04 /usr/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties -Djava.util.logging.manag
6252 root 20 0 3417M 37392 17752 R 100. 0.9 11:10.02 /usr/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties -Djava.util.logging.manag
6247 root 20 0 3417M 37392 17752 R 100. 0.9 11:15.75 /usr/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties -Djava.util.logging.manag
oscar-serv03-[~] root 55 #ls -l /opt/apache-tomcat-9.0.52/logs
total 0
-rw-r----- 1 root root 0 Aug 16 20:34 catalina.2021-08-16.log
-rw-r----- 1 root root 0 Aug 16 20:34 catalina.out
-rw-r----- 1 root root 0 Aug 16 20:34 host-manager.2021-08-16.log
-rw-r----- 1 root root 0 Aug 16 20:34 localhost.2021-08-16.log
-rw-r----- 1 root root 0 Aug 16 20:34 manager.2021-08-16.log
I've done nothing. No deploy. Of course, the manager is included, so
perhaps it is compiling or deploying that?
Port 8080 not open:
oscar-serv03-[~] root 56 #netstat -tan
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address Foreign Address State
tcp 0 0 127.0.0.53:53 0.0.0.0:* LISTEN
tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN
tcp 0 0 192.168.2.13:22 192.168.2.3:56962 ESTABLISHED
tcp 0 0 192.168.2.13:22 192.168.2.3:56968 ESTABLISHED
tcp6 0 0 :::22 :::* LISTEN
oscar-serv03-[~] mcr 10002 %free
total used free shared buff/cache available
Mem: 4030104 169540 2835356 792 1025208 3603084
Swap: 1048572 0 1048572
So, 169M of ~4G used. No swapping. Lots of ram free.
--
] Never tell me the odds! | ipv6 mesh networks [
] Michael Richardson, Sandelman Software Works | IoT architect [
] mcr@sandelman.ca http://www.sandelman.ca/ | ruby on rails [
Re: trying to deploy oscar (was Re: how to tune cacheMaxSize )
Posted by Christopher Schultz <ch...@christopherschultz.net>.
Michael,
On 8/14/21 16:05, Michael Richardson wrote:
>
> <#secure method=pgpmime mode=sign>
>
> Extracts of log, full log at URL below. 18k.
>
> 14-Aug-2021 17:16:43.821 INFO [Catalina-utility-1] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/var/lib/tomcat9/webapps/oscar.war]
> 14-Aug-2021 17:16:44.005 SEVERE [Catalina-utility-1] org.apache.catalina.startup.ContextConfig.beforeStart Exception fixing docBase for context [/oscar]
> java.util.zip.ZipException: zip END header not found
> ...
>
> 14-Aug-2021 17:16:45.464 SEVERE [Catalina-utility-1] org.apache.catalina.startup.HostConfig.deployWAR Error deploying web application archive [/var/lib/tomcat9/webapps/oscar.war]
> java.lang.IllegalStateException: Error starting child
> at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:716)
> ...
>
That certainly looks bad. Are you building OSCAR yourself, or is it
pre-built? I'm assuming that all local customizations are done using
separate config files or in the database, right? Can you get a fresh
copy of the oscar.war file?
> 14-Aug-2021 17:16:45.506 INFO [Catalina-utility-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/var/lib/tomcat9/webapps/oscar.war] has finished in [1,684] ms
That's nice and fast.
> 14-Aug-2021 17:16:55.661 INFO [Catalina-utility-2] org.apache.catalina.startup.HostConfig.undeploy Undeploying context [/oscar]
> 14-Aug-2021 17:16:58.286 INFO [Catalina-utility-2] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/var/lib/tomcat9/webapps/oscar.war]
Strange that it's deploying, then undeploying, then deploying again. Is
it possible that there are weird file timestamps? Maybe something in the
future?
> My guess is that the cp oscar.war /var/lib/tomcat9/webapps hadn't actually
> finished yet when it tried to deploy it.
That can definitely break things. If you are going to drop a WAR file on
Tomcat, make sure that either Tomcat isn't running, or you are using the
Manager web application to upload-and-deploy the WAR file which protects
you from deploying mid-copy.
> So the first 1.684ms attempt fails,
> and then it tried again. (Times are UTC)
>
> oscar-serv03-[~] root 30 #netstat -tan
> Active Internet connections (servers and established)
> Proto Recv-Q Send-Q Local Address Foreign Address State
> tcp 0 0 127.0.0.53:53 0.0.0.0:* LISTEN
> tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN
> tcp 0 0 127.0.0.1:3306 0.0.0.0:* LISTEN
> tcp 0 0 192.168.2.13:22 192.168.2.3:56896 ESTABLISHED
> tcp 0 0 192.168.2.13:22 192.168.2.3:56898 ESTABLISHED
> tcp6 0 0 :::22 :::* LISTEN
> tcp6 0 0 :::8080 :::* LISTEN
>
> So the port is open, so I attempt to visit the /manage URL
>
> oscar-serv03-[~] root 31 #netstat -tan
> Active Internet connections (servers and established)
> Proto Recv-Q Send-Q Local Address Foreign Address State
> tcp 0 0 127.0.0.53:53 0.0.0.0:* LISTEN
> tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN
> tcp 0 0 127.0.0.1:3306 0.0.0.0:* LISTEN
> tcp 0 0 192.168.2.13:22 192.168.2.3:56896 ESTABLISHED
> tcp 0 0 192.168.2.13:22 192.168.2.3:56898 ESTABLISHED
> tcp6 0 0 :::22 :::* LISTEN
> tcp6 0 0 :::8080 :::* LISTEN
> tcp6 559 0 192.168.2.9:8080 192.168.2.3:37486 ESTABLISHED
>
> And it just stalls.
Is there anything between Tomcat and your web browser? Like a reverse
proxy, firewall, etc.? What URL are you trying to hit?
> I went to eat lunch and watch TV, so waited a few hours, and it's the same
> afterwards. Note that it never told me that it had finished deploying this
> war.
>
> I've tried kill-3 repeatedly, on the main PID of the process, and gotten no output.
Anything in the other log files?
Instead of kill -3, what if you use the "jstack" utility and provide the
PID of the running process? (You'll want to provide the PID of the
parent JVM process, not a specific thread.)
-chris
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
trying to deploy oscar (was Re: how to tune cacheMaxSize )
Posted by Michael Richardson <mc...@sandelman.ca>.
<#secure method=pgpmime mode=sign>
Extracts of log, full log at URL below. 18k.
14-Aug-2021 17:16:43.821 INFO [Catalina-utility-1] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/var/lib/tomcat9/webapps/oscar.war]
14-Aug-2021 17:16:44.005 SEVERE [Catalina-utility-1] org.apache.catalina.startup.ContextConfig.beforeStart Exception fixing docBase for context [/oscar]
java.util.zip.ZipException: zip END header not found
...
14-Aug-2021 17:16:45.464 SEVERE [Catalina-utility-1] org.apache.catalina.startup.HostConfig.deployWAR Error deploying web application archive [/var/lib/tomcat9/webapps/oscar.war]
java.lang.IllegalStateException: Error starting child
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:716)
...
14-Aug-2021 17:16:45.506 INFO [Catalina-utility-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/var/lib/tomcat9/webapps/oscar.war] has finished in [1,684] ms
14-Aug-2021 17:16:55.661 INFO [Catalina-utility-2] org.apache.catalina.startup.HostConfig.undeploy Undeploying context [/oscar]
14-Aug-2021 17:16:58.286 INFO [Catalina-utility-2] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/var/lib/tomcat9/webapps/oscar.war]
My guess is that the cp oscar.war /var/lib/tomcat9/webapps hadn't actually
finished yet when it tried to deploy it. So the first 1.684ms attempt fails,
and then it tried again. (Times are UTC)
oscar-serv03-[~] root 30 #netstat -tan
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address Foreign Address State
tcp 0 0 127.0.0.53:53 0.0.0.0:* LISTEN
tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN
tcp 0 0 127.0.0.1:3306 0.0.0.0:* LISTEN
tcp 0 0 192.168.2.13:22 192.168.2.3:56896 ESTABLISHED
tcp 0 0 192.168.2.13:22 192.168.2.3:56898 ESTABLISHED
tcp6 0 0 :::22 :::* LISTEN
tcp6 0 0 :::8080 :::* LISTEN
So the port is open, so I attempt to visit the /manage URL
oscar-serv03-[~] root 31 #netstat -tan
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address Foreign Address State
tcp 0 0 127.0.0.53:53 0.0.0.0:* LISTEN
tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN
tcp 0 0 127.0.0.1:3306 0.0.0.0:* LISTEN
tcp 0 0 192.168.2.13:22 192.168.2.3:56896 ESTABLISHED
tcp 0 0 192.168.2.13:22 192.168.2.3:56898 ESTABLISHED
tcp6 0 0 :::22 :::* LISTEN
tcp6 0 0 :::8080 :::* LISTEN
tcp6 559 0 192.168.2.9:8080 192.168.2.3:37486 ESTABLISHED
And it just stalls.
I went to eat lunch and watch TV, so waited a few hours, and it's the same
afterwards. Note that it never told me that it had finished deploying this
war.
I've tried kill-3 repeatedly, on the main PID of the process, and gotten no output.
Complete log is now at:
https://www.sandelman.ca/tmp/terapia9/catalina.2021-08-14.log-2
--
] Never tell me the odds! | ipv6 mesh networks [
] Michael Richardson, Sandelman Software Works | IoT architect [
] mcr@sandelman.ca http://www.sandelman.ca/ | ruby on rails [
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: how to tune cacheMaxSize
Posted by Michael Richardson <mc...@sandelman.ca>.
Christopher Schultz <ch...@christopherschultz.net> wrote:
> That's quite a long time (1643381ms), and the timestamps match-up.
> So you tried to get a thread-dump during this 27-minute period and the
> process simply wouldn't respond?
Correct.
> It is during this 27-minute period that the CPU is pegged?
Correct.
> Do you see anything in the kernel logs? Like dmesg.log or kernel.log or
> whatever Ubuntu logs to?
Nothing.
> Well, the application deployment(s) are happening somewhat quickly. 13
> seconds is a long time IMO to wait for manager and the other rather trivial
> web applications to load, but that points to something more like a slow disk
> or CPU or something.
I can investigate this a bit.
I spent several days this week cleaning out a data center, so some different
hardware has come my way. Perhaps I'll try that out.
Re: how to tune cacheMaxSize
Posted by Christopher Schultz <ch...@christopherschultz.net>.
Michael,
On 8/19/21 21:34, Michael Richardson wrote:
>
> Aha. Well, I left it running after the last email and went on to more
> important things. Then the window just jumped:
>
> The previous log line:
> 20-Aug-2021 01:02:42.315 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 1.1.1 11 Sep 2018]
>
> Then it acted on the ^\ I had sent. And then it printed:
> Could it have spent that time initializing OpenSSL?
It's possible, but not super-likely:
> 20-Aug-2021 01:02:42.083 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/opt/apache-tomcat-9.0.52/temp
> 20-Aug-2021 01:02:42.210 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent An older version [1.2.21] of the Apache Tomcat Native library is installed, while Tomcat recommends a minimum version of [1.2.30]
> 20-Aug-2021 01:02:42.213 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded Apache Tomcat Native library [1.2.21] using APR version [1.6.3].
> 20-Aug-2021 01:02:42.215 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true], UDS [false].
> 20-Aug-2021 01:02:42.217 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
> 20-Aug-2021 01:02:42.315 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 1.1.1 11 Sep 2018]
All of the above logs are printed within s fraction of a second of each
other. OpenSSL initialization is taking essentially zero time.
> 20-Aug-2021 01:29:58.867 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
> 20-Aug-2021 01:29:59.917 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [1643381] milliseconds
That's quite a long time (1643381ms), and the timestamps match-up.
So you tried to get a thread-dump during this 27-minute period and the
process simply wouldn't respond?
It is during this 27-minute period that the CPU is pegged?
Do you see anything in the kernel logs? Like dmesg.log or kernel.log or
whatever Ubuntu logs to?
> 20-Aug-2021 01:30:01.832 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
> 20-Aug-2021 01:30:01.837 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/9.0.52]
> 20-Aug-2021 01:30:01.997 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/apache-tomcat-9.0.52/webapps/manager]
> 20-Aug-2021 01:30:06.559 WARNING [main] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [248] milliseconds.
> 20-Aug-2021 01:30:07.109 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/apache-tomcat-9.0.52/webapps/manager] has finished in [5,111] ms
> 20-Aug-2021 01:30:07.117 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/apache-tomcat-9.0.52/webapps/examples]
> 20-Aug-2021 01:30:12.192 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/apache-tomcat-9.0.52/webapps/examples] has finished in [5,074] ms
> 20-Aug-2021 01:30:12.195 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/apache-tomcat-9.0.52/webapps/docs]
> 20-Aug-2021 01:30:12.449 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/apache-tomcat-9.0.52/webapps/docs] has finished in [253] ms
> 20-Aug-2021 01:30:12.451 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/apache-tomcat-9.0.52/webapps/ROOT]
> 20-Aug-2021 01:30:12.697 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/apache-tomcat-9.0.52/webapps/ROOT] has finished in [245] ms
> 20-Aug-2021 01:30:12.700 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/apache-tomcat-9.0.52/webapps/host-manager]
> 20-Aug-2021 01:30:12.990 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/apache-tomcat-9.0.52/webapps/host-manager] has finished in [290] ms
> 20-Aug-2021 01:30:13.095 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
> 20-Aug-2021 01:30:13.254 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in [13333] milliseconds
Well, the application deployment(s) are happening somewhat quickly. 13
seconds is a long time IMO to wait for manager and the other rather
trivial web applications to load, but that points to something more like
a slow disk or CPU or something.
-chris
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: how to tune cacheMaxSize
Posted by Michael Richardson <mc...@sandelman.ca>.
Aha. Well, I left it running after the last email and went on to more
important things. Then the window just jumped:
The previous log line:
20-Aug-2021 01:02:42.315 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 1.1.1 11 Sep 2018]
Then it acted on the ^\ I had sent. And then it printed:
Could it have spent that time initializing OpenSSL?
20-Aug-2021 01:29:58.867 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
20-Aug-2021 01:29:59.917 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [1643381] milliseconds
20-Aug-2021 01:30:01.832 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
20-Aug-2021 01:30:01.837 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/9.0.52]
20-Aug-2021 01:30:01.997 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/apache-tomcat-9.0.52/webapps/manager]
20-Aug-2021 01:30:06.559 WARNING [main] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [248] milliseconds.
20-Aug-2021 01:30:07.109 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/apache-tomcat-9.0.52/webapps/manager] has finished in [5,111] ms
20-Aug-2021 01:30:07.117 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/apache-tomcat-9.0.52/webapps/examples]
20-Aug-2021 01:30:12.192 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/apache-tomcat-9.0.52/webapps/examples] has finished in [5,074] ms
20-Aug-2021 01:30:12.195 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/apache-tomcat-9.0.52/webapps/docs]
20-Aug-2021 01:30:12.449 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/apache-tomcat-9.0.52/webapps/docs] has finished in [253] ms
20-Aug-2021 01:30:12.451 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/apache-tomcat-9.0.52/webapps/ROOT]
20-Aug-2021 01:30:12.697 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/apache-tomcat-9.0.52/webapps/ROOT] has finished in [245] ms
20-Aug-2021 01:30:12.700 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/apache-tomcat-9.0.52/webapps/host-manager]
20-Aug-2021 01:30:12.990 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/apache-tomcat-9.0.52/webapps/host-manager] has finished in [290] ms
20-Aug-2021 01:30:13.095 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
20-Aug-2021 01:30:13.254 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in [13333] milliseconds
--
] Never tell me the odds! | ipv6 mesh networks [
] Michael Richardson, Sandelman Software Works | IoT architect [
] mcr@sandelman.ca http://www.sandelman.ca/ | ruby on rails [
Re: how to tune cacheMaxSize
Posted by Michael Richardson <mc...@sandelman.ca>.
This time, I didn't start screen, htop, etc.
I got *two* stack traces, which I'll paste below.
Then some messages finally show up (after, I guess the core was finished
booting), and then no more stack traces, and 100% cpu thread is back.
near the end, you'll see this message:
20-Aug-2021 01:02:42.210 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent An older version [1.2.21] of the Apache Tomcat Native library is installed, while Tomcat recommends a minimum version of [1.2.30]
I think it is referring to:
/usr/lib/x86_64-linux-gnu/libtcnative-1.so.0.2.21
I don't see such a library included with apache-tomcat-9.0.52.
I see that it's from libtcnative, and I could get source from http://tomcat.apache.org/native-doc/
I could remove the system version and replace it with the upstream version
via source if you thought it was worth trying.
tomcat@oscar-serv03:/home/mcr$ $CATALINA_HOME/bin/catalina.sh run
Using CATALINA_BASE: /opt/apache-tomcat-9.0.52
Using CATALINA_HOME: /opt/apache-tomcat-9.0.52
Using CATALINA_TMPDIR: /opt/apache-tomcat-9.0.52/temp
Using JRE_HOME: /usr/lib/jvm/java-11-openjdk-amd64
Using CLASSPATH: /opt/apache-tomcat-9.0.52/bin/bootstrap.jar:/opt/apache-tomcat-9.0.52/bin/tomcat-juli.jar
Using CATALINA_OPTS:
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.base/java.util=ALL-UNNAMED --add-opens=java.base/java.util.concurrent=ALL-UNNAMED --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
^\2021-08-20 01:02:33
Full thread dump OpenJDK 64-Bit Server VM (11.0.11+9-Ubuntu-0ubuntu2.18.04 mixed mode, sharing):
Threads class SMR info:
_java_thread_list=0x00007fa6dc1492a0, length=9, elements={
0x00007fa6dc017000, 0x00007fa6dc0c1000, 0x00007fa6dc0c3000, 0x00007fa6dc0c8800,
0x00007fa6dc0ca800, 0x00007fa6dc0cd000, 0x00007fa6dc0cf000, 0x00007fa6dc0d1000,
0x00007fa6dc147800
}
"main" #1 prio=5 os_prio=0 cpu=1880.69ms elapsed=1.84s tid=0x00007fa6dc017000 nid=0x59e runnable [0x00007fa6e4e93000]
java.lang.Thread.State: RUNNABLE
at java.lang.invoke.VarHandles.makeFieldHandle(java.base@11.0.11/VarHandles.java:63)
at java.lang.invoke.MethodHandles$Lookup.getFieldVarHandleCommon(java.base@11.0.11/MethodHandles.java:2416)
at java.lang.invoke.MethodHandles$Lookup.getFieldVarHandle(java.base@11.0.11/MethodHandles.java:2376)
at java.lang.invoke.MethodHandles$Lookup.findVarHandle(java.base@11.0.11/MethodHandles.java:1516)
at java.util.concurrent.atomic.AtomicBoolean.<clinit>(java.base@11.0.11/AtomicBoolean.java:57)
at java.io.RandomAccessFile.<init>(java.base@11.0.11/RandomAccessFile.java:74)
at java.io.RandomAccessFile.<init>(java.base@11.0.11/RandomAccessFile.java:214)
at java.util.zip.ZipFile$Source.<init>(java.base@11.0.11/ZipFile.java:1285)
at java.util.zip.ZipFile$Source.get(java.base@11.0.11/ZipFile.java:1251)
at java.util.zip.ZipFile$CleanableResource.<init>(java.base@11.0.11/ZipFile.java:732)
at java.util.zip.ZipFile$CleanableResource.get(java.base@11.0.11/ZipFile.java:849)
at java.util.zip.ZipFile.<init>(java.base@11.0.11/ZipFile.java:247)
at java.util.zip.ZipFile.<init>(java.base@11.0.11/ZipFile.java:177)
at java.util.jar.JarFile.<init>(java.base@11.0.11/JarFile.java:348)
at jdk.internal.loader.URLClassPath$JarLoader.getJarFile(java.base@11.0.11/URLClassPath.java:813)
at jdk.internal.loader.URLClassPath$JarLoader$1.run(java.base@11.0.11/URLClassPath.java:758)
at jdk.internal.loader.URLClassPath$JarLoader$1.run(java.base@11.0.11/URLClassPath.java:751)
at java.security.AccessController.doPrivileged(java.base@11.0.11/Native Method)
at jdk.internal.loader.URLClassPath$JarLoader.ensureOpen(java.base@11.0.11/URLClassPath.java:750)
at jdk.internal.loader.URLClassPath$JarLoader.<init>(java.base@11.0.11/URLClassPath.java:725)
at jdk.internal.loader.URLClassPath$3.run(java.base@11.0.11/URLClassPath.java:493)
at jdk.internal.loader.URLClassPath$3.run(java.base@11.0.11/URLClassPath.java:476)
at java.security.AccessController.doPrivileged(java.base@11.0.11/Native Method)
at jdk.internal.loader.URLClassPath.getLoader(java.base@11.0.11/URLClassPath.java:475)
at jdk.internal.loader.URLClassPath.getLoader(java.base@11.0.11/URLClassPath.java:444)
- locked <0x00000000c6517e68> (a jdk.internal.loader.URLClassPath)
at jdk.internal.loader.URLClassPath.getResource(java.base@11.0.11/URLClassPath.java:313)
at jdk.internal.loader.BuiltinClassLoader.findClassOnClassPathOrNull(java.base@11.0.11/BuiltinClassLoader.java:695)
at jdk.internal.loader.BuiltinClassLoader.loadClassOrNull(java.base@11.0.11/BuiltinClassLoader.java:621)
- locked <0x00000000c640e0c0> (a java.lang.Object)
at jdk.internal.loader.BuiltinClassLoader.loadClass(java.base@11.0.11/BuiltinClassLoader.java:579)
at jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(java.base@11.0.11/ClassLoaders.java:178)
at java.lang.ClassLoader.loadClass(java.base@11.0.11/ClassLoader.java:522)
at java.net.URL.lookupViaProperty(java.base@11.0.11/URL.java:1286)
at java.net.URL.getURLStreamHandler(java.base@11.0.11/URL.java:1441)
at java.net.URL.<init>(java.base@11.0.11/URL.java:451)
at jdk.internal.loader.URLClassPath$JarLoader.<init>(java.base@11.0.11/URLClassPath.java:719)
at jdk.internal.loader.URLClassPath$3.run(java.base@11.0.11/URLClassPath.java:493)
at jdk.internal.loader.URLClassPath$3.run(java.base@11.0.11/URLClassPath.java:476)
at java.security.AccessController.doPrivileged(java.base@11.0.11/Native Method)
at jdk.internal.loader.URLClassPath.getLoader(java.base@11.0.11/URLClassPath.java:475)
at jdk.internal.loader.URLClassPath.getLoader(java.base@11.0.11/URLClassPath.java:444)
- locked <0x00000000c6517e68> (a jdk.internal.loader.URLClassPath)
at jdk.internal.loader.URLClassPath.getResource(java.base@11.0.11/URLClassPath.java:313)
at jdk.internal.loader.BuiltinClassLoader.findClassOnClassPathOrNull(java.base@11.0.11/BuiltinClassLoader.java:695)
at jdk.internal.loader.BuiltinClassLoader.loadClassOrNull(java.base@11.0.11/BuiltinClassLoader.java:621)
- locked <0x00000000c640bd90> (a java.lang.Object)
at jdk.internal.loader.BuiltinClassLoader.loadClass(java.base@11.0.11/BuiltinClassLoader.java:579)
at jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(java.base@11.0.11/ClassLoaders.java:178)
at java.lang.ClassLoader.loadClass(java.base@11.0.11/ClassLoader.java:522)
at java.lang.Class.forName0(java.base@11.0.11/Native Method)
at java.lang.Class.forName(java.base@11.0.11/Class.java:398)
at sun.launcher.LauncherHelper.loadMainClass(java.base@11.0.11/LauncherHelper.java:760)
at sun.launcher.LauncherHelper.checkAndLoadMain(java.base@11.0.11/LauncherHelper.java:655)
"Reference Handler" #2 daemon prio=10 os_prio=0 cpu=5.58ms elapsed=1.15s tid=0x00007fa6dc0c1000 nid=0x5a5 waiting on condition [0x00007fa6c41ec000]
java.lang.Thread.State: RUNNABLE
at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.11/Native Method)
at java.lang.ref.Reference.processPendingReferences(java.base@11.0.11/Reference.java:241)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.11/Reference.java:213)
"Finalizer" #3 daemon prio=8 os_prio=0 cpu=12.17ms elapsed=1.15s tid=0x00007fa6dc0c3000 nid=0x5a6 in Object.wait() [0x00007fa6bc13e000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.11/Native Method)
- waiting on <0x00000000c65024d8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000000c65024d8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:176)
at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.11/Finalizer.java:170)
"Signal Dispatcher" #4 daemon prio=9 os_prio=0 cpu=3.23ms elapsed=1.03s tid=0x00007fa6dc0c8800 nid=0x5a7 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Service Thread" #5 daemon prio=9 os_prio=0 cpu=1.47ms elapsed=1.03s tid=0x00007fa6dc0ca800 nid=0x5a8 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" #6 daemon prio=9 os_prio=0 cpu=434.20ms elapsed=1.02s tid=0x00007fa6dc0cd000 nid=0x5a9 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Compiling: 95 4 java.lang.String::hashCode (49 bytes)
"C1 CompilerThread0" #8 daemon prio=9 os_prio=0 cpu=622.41ms elapsed=1.02s tid=0x00007fa6dc0cf000 nid=0x5aa waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
"Sweeper thread" #9 daemon prio=9 os_prio=0 cpu=1.32ms elapsed=1.02s tid=0x00007fa6dc0d1000 nid=0x5ab runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Common-Cleaner" #10 daemon prio=8 os_prio=0 cpu=3.59ms elapsed=0.42s tid=0x00007fa6dc147800 nid=0x5ac in Object.wait() [0x00007fa6aefe2000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.11/Native Method)
- waiting on <0x00000000c65dd2f0> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000000c65dd2f0> (a java.lang.ref.ReferenceQueue$Lock)
at jdk.internal.ref.CleanerImpl.run(java.base@11.0.11/CleanerImpl.java:148)
at java.lang.Thread.run(java.base@11.0.11/Thread.java:829)
at jdk.internal.misc.InnocuousThread.run(java.base@11.0.11/InnocuousThread.java:134)
"VM Thread" os_prio=0 cpu=58.88ms elapsed=1.24s tid=0x00007fa6dc0be800 nid=0x5a4 runnable
"GC Thread#0" os_prio=0 cpu=7.92ms elapsed=1.77s tid=0x00007fa6dc02f800 nid=0x59f runnable
"G1 Main Marker" os_prio=0 cpu=104.26ms elapsed=1.75s tid=0x00007fa6dc04b000 nid=0x5a0 runnable
"G1 Conc#0" os_prio=0 cpu=0.90ms elapsed=1.75s tid=0x00007fa6dc04c800 nid=0x5a1 runnable
"G1 Refine#0" os_prio=0 cpu=71.75ms elapsed=1.73s tid=0x00007fa6dc090800 nid=0x5a2 runnable
"G1 Young RemSet Sampling" os_prio=0 cpu=72.69ms elapsed=1.73s tid=0x00007fa6dc092000 nid=0x5a3 runnable
"VM Periodic Task Thread" os_prio=0 cpu=3.24ms elapsed=0.22s tid=0x00007fa6dc14b800 nid=0x5ad waiting on condition
JNI global refs: 5, weak refs: 0
Heap
garbage-first heap total 65536K, used 1736K [0x00000000c2800000, 0x0000000100000000)
region size 1024K, 2 young (2048K), 0 survivors (0K)
Metaspace used 267K, capacity 4491K, committed 4864K, reserved 1056768K
class space used 20K, capacity 388K, committed 512K, reserved 1048576K
20-Aug-2021 01:02:41.563 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name: Apache Tomcat/9.0.52
20-Aug-2021 01:02:41.628 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built: Jul 31 2021 04:12:17 UTC
20-Aug-2021 01:02:41.631 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 9.0.52.0
20-Aug-2021 01:02:41.634 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name: Linux
20-Aug-2021 01:02:41.639 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version: 5.4.0-81-generic
20-Aug-2021 01:02:41.642 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture: amd64
20-Aug-2021 01:02:41.645 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home: /usr/lib/jvm/java-11-openjdk-amd64
20-Aug-2021 01:02:41.648 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version: 11.0.11+9-Ubuntu-0ubuntu2.18.04
20-Aug-2021 01:02:41.651 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor: Ubuntu
20-Aug-2021 01:02:41.655 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE: /opt/apache-tomcat-9.0.52
20-Aug-2021 01:02:41.659 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME: /opt/apache-tomcat-9.0.52
^\ PRESSED AGAIN HERE.
2021-08-20 01:02:41
Full thread dump OpenJDK 64-Bit Server VM (11.0.11+9-Ubuntu-0ubuntu2.18.04 mixed mode, sharing):
Threads class SMR info:
_java_thread_list=0x00007fa678002210, length=11, elements={
0x00007fa6dc017000, 0x00007fa6dc0c1000, 0x00007fa6dc0c3000, 0x00007fa6dc0c8800,
0x00007fa6dc0ca800, 0x00007fa6dc0cd000, 0x00007fa6dc0cf000, 0x00007fa6dc0d1000,
0x00007fa6dc147800, 0x00007fa6dc197800, 0x00007fa6dc1ae800
}
"main" #1 prio=5 os_prio=0 cpu=9286.35ms elapsed=10.15s tid=0x00007fa6dc017000 nid=0x59e waiting on condition [0x00007fa6e4e97000]
java.lang.Thread.State: RUNNABLE
at jdk.internal.loader.BuiltinClassLoader.loadClassOrNull(java.base@11.0.11/BuiltinClassLoader.java:591)
- locked <0x00000000c655e398> (a java.lang.Object)
at jdk.internal.loader.BuiltinClassLoader.loadClass(java.base@11.0.11/BuiltinClassLoader.java:579)
at jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(java.base@11.0.11/ClassLoaders.java:178)
at java.lang.ClassLoader.loadClass(java.base@11.0.11/ClassLoader.java:576)
- locked <0x00000000c6567c60> (a java.lang.Object)
at java.lang.ClassLoader.loadClass(java.base@11.0.11/ClassLoader.java:522)
at org.apache.catalina.startup.VersionLoggerListener.log(VersionLoggerListener.java:113)
at org.apache.catalina.startup.VersionLoggerListener.lifecycleEvent(VersionLoggerListener.java:83)
at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123)
at org.apache.catalina.util.LifecycleBase.setStateInternal(LifecycleBase.java:423)
- locked <0x00000000c2adbdc0> (a org.apache.catalina.core.StandardServer)
at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:135)
- locked <0x00000000c2adbdc0> (a org.apache.catalina.core.StandardServer)
at org.apache.catalina.startup.Catalina.load(Catalina.java:724)
at org.apache.catalina.startup.Catalina.load(Catalina.java:746)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.11/Native Method)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.11/NativeMethodAccessorImpl.java:62)
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.11/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.11/Method.java:566)
at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:305)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:475)
"Reference Handler" #2 daemon prio=10 os_prio=0 cpu=8.95ms elapsed=9.41s tid=0x00007fa6dc0c1000 nid=0x5a5 waiting on condition [0x00007fa6c41ec000]
java.lang.Thread.State: RUNNABLE
at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.11/Native Method)
at java.lang.ref.Reference.processPendingReferences(java.base@11.0.11/Reference.java:241)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.11/Reference.java:213)
"Finalizer" #3 daemon prio=8 os_prio=0 cpu=12.17ms elapsed=9.41s tid=0x00007fa6dc0c3000 nid=0x5a6 in Object.wait() [0x00007fa6bc13e000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.11/Native Method)
- waiting on <0x00000000c2add258> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000000c2add258> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:176)
at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.11/Finalizer.java:170)
"Signal Dispatcher" #4 daemon prio=9 os_prio=0 cpu=8.19ms elapsed=9.29s tid=0x00007fa6dc0c8800 nid=0x5a7 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Service Thread" #5 daemon prio=9 os_prio=0 cpu=1.47ms elapsed=9.29s tid=0x00007fa6dc0ca800 nid=0x5a8 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" #6 daemon prio=9 os_prio=0 cpu=5346.30ms elapsed=9.29s tid=0x00007fa6dc0cd000 nid=0x5a9 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Compiling: 906 4 java.lang.StringBuilder::append (8 bytes)
"C1 CompilerThread0" #8 daemon prio=9 os_prio=0 cpu=6346.69ms elapsed=9.29s tid=0x00007fa6dc0cf000 nid=0x5aa runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Compiling: 909 s 3 java.lang.Throwable::fillInStackTrace (29 bytes)
"Sweeper thread" #9 daemon prio=9 os_prio=0 cpu=1.32ms elapsed=9.29s tid=0x00007fa6dc0d1000 nid=0x5ab runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Common-Cleaner" #10 daemon prio=8 os_prio=0 cpu=14.84ms elapsed=8.70s tid=0x00007fa6dc147800 nid=0x5ac in Object.wait() [0x00007fa6aefe2000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.11/Native Method)
- waiting on <0x00000000c2935048> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000000c2935048> (a java.lang.ref.ReferenceQueue$Lock)
at jdk.internal.ref.CleanerImpl.run(java.base@11.0.11/CleanerImpl.java:148)
at java.lang.Thread.run(java.base@11.0.11/Thread.java:829)
at jdk.internal.misc.InnocuousThread.run(java.base@11.0.11/InnocuousThread.java:134)
"AsyncFileHandlerWriter-931919113" #13 daemon prio=5 os_prio=0 cpu=87.53ms elapsed=7.64s tid=0x00007fa6dc197800 nid=0x5ae runnable [0x00007fa6ae9b5000]
java.lang.Thread.State: RUNNABLE
at java.lang.ClassLoader$NativeLibrary.load0(java.base@11.0.11/Native Method)
at java.lang.ClassLoader$NativeLibrary.load(java.base@11.0.11/ClassLoader.java:2442)
at java.lang.ClassLoader$NativeLibrary.loadLibrary(java.base@11.0.11/ClassLoader.java:2498)
- locked <0x00000000c291b320> (a java.util.HashSet)
at java.lang.ClassLoader.loadLibrary0(java.base@11.0.11/ClassLoader.java:2694)
at java.lang.ClassLoader.loadLibrary(java.base@11.0.11/ClassLoader.java:2648)
at java.lang.Runtime.loadLibrary0(java.base@11.0.11/Runtime.java:830)
at java.lang.System.loadLibrary(java.base@11.0.11/System.java:1873)
at java.lang.management.ManagementFactory.lambda$static$8(java.management@11.0.11/ManagementFactory.java:1020)
at java.lang.management.ManagementFactory$$Lambda$57/0x00000008400b8840.run(java.management@11.0.11/Unknown Source)
at java.security.AccessController.doPrivileged(java.base@11.0.11/Native Method)
at java.lang.management.ManagementFactory.<clinit>(java.management@11.0.11/ManagementFactory.java:1019)
at org.apache.juli.OneLineFormatter.getThreadName(OneLineFormatter.java:241)
- locked <0x00000000c2a34ae8> (a java.lang.Object)
at org.apache.juli.OneLineFormatter.format(OneLineFormatter.java:139)
at org.apache.juli.FileHandler.publish(FileHandler.java:292)
at org.apache.juli.AsyncFileHandler.publishInternal(AsyncFileHandler.java:146)
at org.apache.juli.AsyncFileHandler$LogEntry.flush(AsyncFileHandler.java:185)
at org.apache.juli.AsyncFileHandler$LoggerThread.run(AsyncFileHandler.java:161)
"FileHandlerLogFilesCleaner-1" #14 daemon prio=5 os_prio=0 cpu=364.13ms elapsed=6.85s tid=0x00007fa6dc1ae800 nid=0x5af waiting on condition [0x00007fa6ae8b6000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.11/Native Method)
- parking to wait for <0x00000000c2a35b10> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.11/LockSupport.java:194)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.11/AbstractQueuedSynchronizer.java:2081)
at java.util.concurrent.LinkedBlockingQueue.take(java.base@11.0.11/LinkedBlockingQueue.java:433)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.11/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.11/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.11/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.11/Thread.java:829)
"VM Thread" os_prio=0 cpu=198.35ms elapsed=9.53s tid=0x00007fa6dc0be800 nid=0x5a4 runnable
"GC Thread#0" os_prio=0 cpu=305.32ms elapsed=10.05s tid=0x00007fa6dc02f800 nid=0x59f runnable
"GC Thread#1" os_prio=0 cpu=275.07ms elapsed=1.29s tid=0x00007fa6a4001000 nid=0x5b1 runnable
"G1 Main Marker" os_prio=0 cpu=104.26ms elapsed=10.04s tid=0x00007fa6dc04b000 nid=0x5a0 runnable
"G1 Conc#0" os_prio=0 cpu=0.90ms elapsed=10.04s tid=0x00007fa6dc04c800 nid=0x5a1 runnable
"G1 Refine#0" os_prio=0 cpu=137.32ms elapsed=10.01s tid=0x00007fa6dc090800 nid=0x5a2 runnable
"G1 Refine#1" os_prio=0 cpu=35.09ms elapsed=1.10s tid=0x00007fa6b4001000 nid=0x5b2 runnable
"G1 Young RemSet Sampling" os_prio=0 cpu=158.77ms elapsed=10.02s tid=0x00007fa6dc092000 nid=0x5a3 runnable
"VM Periodic Task Thread" os_prio=0 cpu=53.59ms elapsed=8.51s tid=0x00007fa6dc14b800 nid=0x5ad waiting on condition
JNI global refs: 8, weak refs: 0
Heap
garbage-first heap total 65536K, used 4243K [0x00000000c2800000, 0x0000000100000000)
region size 1024K, 2 young (2048K), 1 survivors (1024K)
Metaspace used 5331K, capacity 6964K, committed 7168K, reserved 1056768K
class space used 557K, capacity 739K, committed 768K, reserved 1048576K
20-Aug-2021 01:02:42.050 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.lang=ALL-UNNAMED
20-Aug-2021 01:02:42.054 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.io=ALL-UNNAMED
20-Aug-2021 01:02:42.056 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.util=ALL-UNNAMED
20-Aug-2021 01:02:42.058 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.util.concurrent=ALL-UNNAMED
20-Aug-2021 01:02:42.060 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
20-Aug-2021 01:02:42.065 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
20-Aug-2021 01:02:42.067 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
20-Aug-2021 01:02:42.070 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
20-Aug-2021 01:02:42.072 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
20-Aug-2021 01:02:42.074 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
20-Aug-2021 01:02:42.076 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
20-Aug-2021 01:02:42.078 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/opt/apache-tomcat-9.0.52
20-Aug-2021 01:02:42.081 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/opt/apache-tomcat-9.0.52
20-Aug-2021 01:02:42.083 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/opt/apache-tomcat-9.0.52/temp
20-Aug-2021 01:02:42.210 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent An older version [1.2.21] of the Apache Tomcat Native library is installed, while Tomcat recommends a minimum version of [1.2.30]
20-Aug-2021 01:02:42.213 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded Apache Tomcat Native library [1.2.21] using APR version [1.6.3].
20-Aug-2021 01:02:42.215 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true], UDS [false].
20-Aug-2021 01:02:42.217 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
20-Aug-2021 01:02:42.315 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 1.1.1 11 Sep 2018]
^\
{dead}
Re: how to tune cacheMaxSize
Posted by Michael Richardson <mc...@sandelman.ca>.
Christopher Schultz <ch...@christopherschultz.net> wrote:
>> 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.base/java.util=ALL-UNNAMED --add-opens=java.ba
>> se/java.util.concurrent=ALL-UNNAMED --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
>> ^Z
>> [1]+ Stopped $CATALINA_HOME/bin/catalina.sh run
> How long did you wait before hitting CTRL-Z there?
at least 5 minutes.
>> tomcat@oscar-serv03:/opt/apache-tomcat-9.0.52$ bg
>> [1]+ $CATALINA_HOME/bin/catalina.sh run &
> Well, now things are complicated because you backgrounded the process.
Well, either it tries to write to stdout and gets blocked (and suspended) on
SIGTOUT, or it doesn't.
Background processes still get to write to stdout by default.
--
] Never tell me the odds! | ipv6 mesh networks [
] Michael Richardson, Sandelman Software Works | IoT architect [
] mcr@sandelman.ca http://www.sandelman.ca/ | ruby on rails [
Re: how to tune cacheMaxSize
Posted by Christopher Schultz <ch...@christopherschultz.net>.
Michael,
On 8/19/21 20:35, Michael Richardson wrote:
>
> try #1. Now rebooting VM.
>
> Christopher Schultz <ch...@christopherschultz.net> wrote:
> > 1. Stop Tomcat, clear all logs, delete your oscar.war file and the exploded
> > directory in CATALINA_BASE/webapps/oscar (or wherever your appBase points
> > to).
> > 2. Copy your oscar.war file into appBase, making sure that operation
> > completes
> > 3. Start Tomcat, but like this instead of what you usually do:
>
> > $ sudo -iu tomcatuser
> > $ $CATALINA_BASE/bin/catalina.sh run
>
> I have not done #2. I figure it should start up correctly, right?
> My $CATALINA_BASE/webapps contains:
>
> oscar-serv03-[/opt/apache-tomcat-9.0.52/webapps] root 7 #ls -lta
> total 28
> drwxr-x--- 6 tomcat root 4096 Aug 16 20:28 manager/
> drwxr-x--- 6 tomcat root 4096 Aug 16 20:28 host-manager/
> drwxr-x--- 7 tomcat root 4096 Aug 16 20:28 examples/
> drwxr-x--- 15 tomcat root 4096 Aug 16 20:28 docs/
> drwxr-x--- 3 tomcat root 4096 Aug 16 20:28 ROOT/
> drwxr-xr-x 9 tomcat root 4096 Aug 16 20:28 ../
> drwxr-x--- 7 tomcat root 4096 Jul 31 04:12 ./
>
> tomcat@oscar-serv03:/opt/apache-tomcat-9.0.52$ $CATALINA_HOME/bin/catalina.sh run
> Using CATALINA_BASE: /opt/apache-tomcat-9.0.52
> Using CATALINA_HOME: /opt/apache-tomcat-9.0.52
> Using CATALINA_TMPDIR: /opt/apache-tomcat-9.0.52/temp
> Using JRE_HOME: /usr/lib/jvm/java-11-openjdk-amd64
> Using CLASSPATH: /opt/apache-tomcat-9.0.52/bin/bootstrap.jar:/opt/apache-tomcat-9.0.52/bin/tomcat-juli.jar
> Using CATALINA_OPTS:
> 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.base/java.util=ALL-UNNAMED --add-opens=java.ba
> se/java.util.concurrent=ALL-UNNAMED --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
> ^Z
> [1]+ Stopped $CATALINA_HOME/bin/catalina.sh run
How long did you wait before hitting CTRL-Z there?
> tomcat@oscar-serv03:/opt/apache-tomcat-9.0.52$ bg
> [1]+ $CATALINA_HOME/bin/catalina.sh run &
Well, now things are complicated because you backgrounded the process.
> futzing with right options to ps to show threads:
>
> tomcat 30113 30053 30113 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30117 98 17 00:28 pts/3 00:01:15 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30118 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30119 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30120 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30121 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30122 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30123 7 17 00:28 pts/3 00:00:05 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30124 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30125 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30126 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30127 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30128 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30129 1 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30130 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30131 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
> tomcat 30113 30053 30132 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
>
> No logs.
> ^\ nothing.
> ^C nothing.
The logs are in the stdout of the process you put into the background.
> Needs yee-old kill-9 to exit.
As expected (on my part).
Leave the process running in the foreground and look at the logs it
produces.
I would have expected to see information about the <Connector>s
initializing and stuff like that on stdout. Nothing ever came out?
-chris
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: how to tune cacheMaxSize
Posted by Michael Richardson <mc...@sandelman.ca>.
try #1. Now rebooting VM.
Christopher Schultz <ch...@christopherschultz.net> wrote:
> 1. Stop Tomcat, clear all logs, delete your oscar.war file and the exploded
> directory in CATALINA_BASE/webapps/oscar (or wherever your appBase points
> to).
> 2. Copy your oscar.war file into appBase, making sure that operation
> completes
> 3. Start Tomcat, but like this instead of what you usually do:
> $ sudo -iu tomcatuser
> $ $CATALINA_BASE/bin/catalina.sh run
I have not done #2. I figure it should start up correctly, right?
My $CATALINA_BASE/webapps contains:
oscar-serv03-[/opt/apache-tomcat-9.0.52/webapps] root 7 #ls -lta
total 28
drwxr-x--- 6 tomcat root 4096 Aug 16 20:28 manager/
drwxr-x--- 6 tomcat root 4096 Aug 16 20:28 host-manager/
drwxr-x--- 7 tomcat root 4096 Aug 16 20:28 examples/
drwxr-x--- 15 tomcat root 4096 Aug 16 20:28 docs/
drwxr-x--- 3 tomcat root 4096 Aug 16 20:28 ROOT/
drwxr-xr-x 9 tomcat root 4096 Aug 16 20:28 ../
drwxr-x--- 7 tomcat root 4096 Jul 31 04:12 ./
tomcat@oscar-serv03:/opt/apache-tomcat-9.0.52$ $CATALINA_HOME/bin/catalina.sh run
Using CATALINA_BASE: /opt/apache-tomcat-9.0.52
Using CATALINA_HOME: /opt/apache-tomcat-9.0.52
Using CATALINA_TMPDIR: /opt/apache-tomcat-9.0.52/temp
Using JRE_HOME: /usr/lib/jvm/java-11-openjdk-amd64
Using CLASSPATH: /opt/apache-tomcat-9.0.52/bin/bootstrap.jar:/opt/apache-tomcat-9.0.52/bin/tomcat-juli.jar
Using CATALINA_OPTS:
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.base/java.util=ALL-UNNAMED --add-opens=java.ba
se/java.util.concurrent=ALL-UNNAMED --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
^Z
[1]+ Stopped $CATALINA_HOME/bin/catalina.sh run
tomcat@oscar-serv03:/opt/apache-tomcat-9.0.52$ bg
[1]+ $CATALINA_HOME/bin/catalina.sh run &
futzing with right options to ps to show threads:
tomcat 30113 30053 30113 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30117 98 17 00:28 pts/3 00:01:15 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30118 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30119 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30120 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30121 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30122 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30123 7 17 00:28 pts/3 00:00:05 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30124 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30125 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30126 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30127 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30128 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30129 1 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30130 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30131 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
tomcat 30113 30053 30132 0 17 00:28 pts/3 00:00:00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/opt/apache-tomcat-9.0.52/conf/logging.properties
No logs.
^\ nothing.
^C nothing.
Needs yee-old kill-9 to exit.
--
] Never tell me the odds! | ipv6 mesh networks [
] Michael Richardson, Sandelman Software Works | IoT architect [
] mcr@sandelman.ca http://www.sandelman.ca/ | ruby on rails [
Re: how to tune cacheMaxSize
Posted by Christopher Schultz <ch...@christopherschultz.net>.
Michael,
On 8/19/21 21:37, Michael Richardson wrote:
> Let's deploy the oscar.war, what's the worst that can happen?
>
> 20-Aug-2021 01:36:10.129 WARNING [Catalina-utility-1] org.apache.catalina.webresources.Cache.getResource Unable to add the resource at [/WEB-INF/classes/oscar/ocan/testdata/ocan_v1.0.1.xml] to the cache for web application [/oscar] because there was insufficient free space available after evicting expired cache entries - consider increasing the maximum size of the cache
> ... repeated many times.
>
> This was among the original message that lead to this original subject line.
Hmm. Given that file name, it looks like the OSCAR WAR file ships with
testing data inside of it. Tomcat tries to cache items which is why you
are getting this warning.
For now, I think you can safely ignore these warnings. They will only
(negatively) affect the performance of your Tomcat/OSCAR deployment, but
they shouldn't break anything.
The maximum cache size is set by default to 10MiB. If you have more RAM,
feel free to increase that number as high as you feel is appropriate.
-chris
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: how to tune cacheMaxSize
Posted by Michael Richardson <mc...@sandelman.ca>.
Let's deploy the oscar.war, what's the worst that can happen?
20-Aug-2021 01:36:10.129 WARNING [Catalina-utility-1] org.apache.catalina.webresources.Cache.getResource Unable to add the resource at [/WEB-INF/classes/oscar/ocan/testdata/ocan_v1.0.1.xml] to the cache for web application [/oscar] because there was insufficient free space available after evicting expired cache entries - consider increasing the maximum size of the cache
... repeated many times.
This was among the original message that lead to this original subject line.
--
] Never tell me the odds! | ipv6 mesh networks [
] Michael Richardson, Sandelman Software Works | IoT architect [
] mcr@sandelman.ca http://www.sandelman.ca/ | ruby on rails [
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: how to tune cacheMaxSize
Posted by Christopher Schultz <ch...@christopherschultz.net>.
Michael,
On 8/17/21 12:31, Michael Richardson wrote:
>
> Christopher Schultz <ch...@christopherschultz.net> wrote:
> > Not at all. EC2 is entirely reasonable for such purposes. Amazon will
> > even grant you a signed BAA if you ask for one.
>
> Canada is not the US, and OHIP has rules differently than others.
True, but several Quebecois Universities doesn't seem to have a problem
with Amazon Montreal. :)
> And the clinic would like to survive having our third-world telco go down.
LOL. At first, I was thinking "Amazon US" was the "third-world telco",
then it occurred to me that you meant your own connection :)
> >> No, I'm not building myself. There is an oscar.deb, which btw,
> >> results in the same 100%.
>
> > Okay, good. Does OSCAR distribute the .deb file? I'm ... weirdly
> > surprised by that.
>
> OSCAR has a .deb that tries to be all singing, all dancing.
> It's not the only solution.
Well, privately-distributed .deb files are really just a "help" to
system admins, as long as the admin agrees with everything the packager
has done. It sounds like the .deb package is really built for dev-test
and not for production. Shame. You should ask them to offer both.
> >> It also does other stuff like configure mariadb locally (which I don't
> >> want).
>
> > Interesting. You want control over your own database, or you don't want
> > the db to be local (e.g. you want a remote db)?
>
> Exactly.
>
> >> This is the only time I've seen this error, I've also used the manager
> >> web application before.
>
> > Hmm. Same error there? Or same 100% CPU circumstances there?
>
> Same 100% CPU.
>
> >> I tried that. It says something about there being no socket open. My
> >> impression is that "jstack" was an Oracle Java only tool.
>
> > Nope, it's in all of the OpenJDK builds. You might need a "JDK" instead
> > of a"JRE".
>
> okay, I'll try again and post the result.
>
> > When you issue "kill -3", the thread dump should appear on stdout,
> > which should be captured in logs/catalina.[date].log. If that's not
> > happening, then I'm a bit confused...
>
> It's not happening.
/me is confused.
> > Okay, try this:
>
> > 1. Stop Tomcat, clear all logs, delete your oscar.war file and the
> > exploded directory in CATALINA_BASE/webapps/oscar (or wherever your
> > appBase points to). 2. Copy your oscar.war file into appBase, making
> > sure that operation completes 3. Start Tomcat, but like this instead of
> > what you usually do:
>
> > $ sudo -iu tomcatuser $ $CATALINA_BASE/bin/catalina.sh run
>
> > That "run" is important: it will run Tomcat in the current console
> > instead of in the background as a service. You'll get stdout directly
> > on your console, no log files to worry about.
>
> okay.
The suspense is killing me.
BTW I'd be happy to continue helping-out via this mailing list for free,
at least until I get busy or lose interest. I'm also happy to consult
off-list for NOT free if you need that kind of attention. I have some
experience with production health care systems running on Tomcat +
MySQL/MariaDB.
-chris
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: how to tune cacheMaxSize
Posted by Michael Richardson <mc...@sandelman.ca>.
Christopher Schultz <ch...@christopherschultz.net> wrote:
> Not at all. EC2 is entirely reasonable for such purposes. Amazon will
> even grant you a signed BAA if you ask for one.
Canada is not the US, and OHIP has rules differently than others.
And the clinic would like to survive having our third-world telco go down.
>> No, I'm not building myself. There is an oscar.deb, which btw,
>> results in the same 100%.
> Okay, good. Does OSCAR distribute the .deb file? I'm ... weirdly
> surprised by that.
OSCAR has a .deb that tries to be all singing, all dancing.
It's not the only solution.
>> It also does other stuff like configure mariadb locally (which I don't
>> want).
> Interesting. You want control over your own database, or you don't want
> the db to be local (e.g. you want a remote db)?
Exactly.
>> This is the only time I've seen this error, I've also used the manager
>> web application before.
> Hmm. Same error there? Or same 100% CPU circumstances there?
Same 100% CPU.
>> I tried that. It says something about there being no socket open. My
>> impression is that "jstack" was an Oracle Java only tool.
> Nope, it's in all of the OpenJDK builds. You might need a "JDK" instead
> of a"JRE".
okay, I'll try again and post the result.
> When you issue "kill -3", the thread dump should appear on stdout,
> which should be captured in logs/catalina.[date].log. If that's not
> happening, then I'm a bit confused...
It's not happening.
> Okay, try this:
> 1. Stop Tomcat, clear all logs, delete your oscar.war file and the
> exploded directory in CATALINA_BASE/webapps/oscar (or wherever your
> appBase points to). 2. Copy your oscar.war file into appBase, making
> sure that operation completes 3. Start Tomcat, but like this instead of
> what you usually do:
> $ sudo -iu tomcatuser $ $CATALINA_BASE/bin/catalina.sh run
> That "run" is important: it will run Tomcat in the current console
> instead of in the background as a service. You'll get stdout directly
> on your console, no log files to worry about.
okay.
--
] Never tell me the odds! | ipv6 mesh networks [
] Michael Richardson, Sandelman Software Works | IoT architect [
] mcr@sandelman.ca http://www.sandelman.ca/ | ruby on rails [
Re: how to tune cacheMaxSize
Posted by Christopher Schultz <ch...@christopherschultz.net>.
Michael,
On 8/19/21 20:57, Michael Richardson wrote:
> Login to freshly booted machine. I told my xterm to log it.
>
> {The file is at: https://www.sandelman.ca/tmp/terapia9/xterm-25216.txt
> (contains xterm/ANSI codes)
> Use https://github.com/nikushi/slowcat or
> https://www.sandelman.ca/mcr/slowcat.c < file
> or equivalent to watch the results. (If there is a better tool that is more
> available, tell me. In 35 years of Unix, I never found one. Yeah, it's a bit
> painful to watch even at 100 characters/s. At 1000/s it goes by too fast.
> Use a window 200 x 77 or larger. Next time without htop)}
I have always used tail -f to watch log files.
> Summary:
>
> This time I got the stack trace the first time.
> Imagine my surprise, I wasn't ready to catch it.
> A second ^\ did nothing. I will repeat in a moment from a fresh start.
^\ should produce a thread dump each tie you do it. If you do two in a
row, they look the same so maybe you didn't notice the duplicated output?
> Copy and pasting from the screen back scroll. It looks like it's thread #1,
> in org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:445).
> It looks like it is spin-locking on a mutex, and then after the dump, it gets
> a SEGV.
Ruh roh. That's ... really unusual. Do you trust your hardware? I've
only seen one or two legitimate JVM crashes in all my years of Java.
SIGSEGV and SIGBUS usually have me firing-up memtest86 in short order.
> Full thread dump OpenJDK 64-Bit Server VM (11.0.11+9-Ubuntu-0ubuntu2.18.04 mixed mode, sharing):
>
> Threads class SMR info:
> _java_thread_list=0x00007f1178004e60, length=11, elements={
> 0x00007f11dc017000, 0x00007f11dc0c1000, 0x00007f11dc0c3000, 0x00007f11dc0c8800,
> 0x00007f11dc0ca800, 0x00007f11dc0cd000, 0x00007f11dc0cf000, 0x00007f11dc0d1000,
> 0x00007f11dc14f800, 0x00007f11dc19f800, 0x00007f11dc1b6800
> }
>
> "main" #1 prio=5 os_prio=0 cpu=5336.28ms elapsed=6.38s tid=0x00007f11dc017000 nid=0x59f runnable [0x00007f11e55ea000]
> java.lang.Thread.State: RUNNABLE
> at org.apache.catalina.startup.Bootstrap.init(Bootstrap.java:275)
> at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:445)
> - locked <0x00000000c62dffd0> (a java.lang.Object)
>
> "Reference Handler" #2 daemon prio=10 os_prio=0 cpu=5.76ms elapsed=5.37s tid=0x00007f11dc0c1000 nid=0x5a6 waiting on condition [0x00007f11bc13e000]
> java.lang.Thread.State: RUNNABLE
> at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.11/Native Method)
> at java.lang.ref.Reference.processPendingReferences(java.base@11.0.11/Reference.java:241)
> at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.11/Reference.java:213)
>
> "Finalizer" #3 daemon prio=8 os_prio=0 cpu=11.45ms elapsed=5.36s tid=0x00007f11dc0c3000 nid=0x5a7 in Object.wait() [0x00007f11a7ffe000]
> java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(java.base@11.0.11/Native Method)
> - waiting on <0x00000000c65024d8> (a java.lang.ref.ReferenceQueue$Lock)
> at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:155)
> - waiting to re-lock in wait() <0x00000000c65024d8> (a java.lang.ref.ReferenceQueue$Lock)
> at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:176)
> at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.11/Finalizer.java:170)
>
> Signal Dispatcher" #4 daemon prio=9 os_prio=0 cpu=2.47ms elapsed=5.22s tid=0x00007f11dc0c8800 nid=0x5a8 waiting on condition [0x0000000000000000]
> java.lang.Thread.State: RUNNABLE
>
> "Service Thread" #5 daemon prio=9 os_prio=0 cpu=2.46ms elapsed=5.22s tid=0x00007f11dc0ca800 nid=0x5a9 runnable [0x0000000000000000]
> java.lang.Thread.State: RUNNABLE
>
> "C2 CompilerThread0" #6 daemon prio=9 os_prio=0 cpu=2242.87ms elapsed=5.22s tid=0x00007f11dc0cd000 nid=0x5aa waiting on condition [0x0000000000000000]
> java.lang.Thread.State: RUNNABLE
> No compile task
>
> "C1 CompilerThread0" #8 daemon prio=9 os_prio=0 cpu=3343.57ms elapsed=5.22s tid=0x00007f11dc0cf000 nid=0x5ab runnable [0x0000000000000000]
> java.lang.Thread.State: RUNNABLE
> Compiling: 541 ! 3 java.util.jar.JarFile::checkForSpecialAttributes (163 bytes)
>
> "Sweeper thread" #9 daemon prio=9 os_prio=0 cpu=1.89ms elapsed=5.22s tid=0x00007f11dc0d1000 nid=0x5ac runnable [0x0000000000000000]
> java.lang.Thread.State: RUNNABLE
>
>
> "Common-Cleaner" #10 daemon prio=8 os_prio=0 cpu=2.70ms elapsed=4.62s tid=0x00007f11dc14f800 nid=0x5ad in Object.wait() [0x00007f11a76e1000]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(java.base@11.0.11/Native Method)
> - waiting on <0x00000000c65dd3d0> (a java.lang.ref.ReferenceQueue$Lock)
> at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:155)
> - waiting to re-lock in wait() <0x00000000c65dd3d0> (a java.lang.ref.ReferenceQueue$Lock)
> at jdk.internal.ref.CleanerImpl.run(java.base@11.0.11/CleanerImpl.java:148)
> at java.lang.Thread.run(java.base@11.0.11/Thread.java:829)
> at jdk.internal.misc.InnocuousThread.run(java.base@11.0.11/InnocuousThread.java:134)
>
> "AsyncFileHandlerWriter-931919113" #13 daemon prio=5 os_prio=0 cpu=30.64ms elapsed=3.19s tid=0x00007f11dc19f800 nid=0x5af waiting on condition [0x00007f11a70b6000]
> java.lang.Thread.State: TIMED_WAITING (parking)
> at jdk.internal.misc.Unsafe.park(java.base@11.0.11/Native Method)
> - parking to wait for <0x00000000c6497fb0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.11/LockSupport.java:234)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(java.base@11.0.11/AbstractQueuedSynchronizer.java:2123)
> at java.util.concurrent.LinkedBlockingDeque.pollFirst(java.base@11.0.11/LinkedBlockingDeque.java:513)
> at java.util.concurrent.LinkedBlockingDeque.poll(java.base@11.0.11/LinkedBlockingDeque.java:675)
> at org.apache.juli.AsyncFileHandler$LoggerThread.run(AsyncFileHandler.java:159)
>
> "FileHandlerLogFilesCleaner-1" #14 daemon prio=5 os_prio=0 cpu=480.27ms elapsed=2.28s tid=0x00007f11dc1b6800 nid=0x5b0 waiting on condition [0x00007f11a6fb5000]
> java.lang.Thread.State: WAITING (parking)
> at jdk.internal.misc.Unsafe.park(java.base@11.0.11/Native Method)
> - parking to wait for <0x00000000c6497918> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(java.base@11.0.11/LockSupport.java:194)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.11/AbstractQueuedSynchronizer.java:2081)
> at java.util.concurrent.LinkedBlockingQueue.take(java.base@11.0.11/LinkedBlockingQueue.java:433)
> at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.11/ThreadPoolExecutor.java:1054)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.11/ThreadPoolExecutor.java:1114)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.11/ThreadPoolExecutor.java:628)
> at java.lang.Thread.run(java.base@11.0.11/Thread.java:829)
>
> "VM Thread" os_prio=0 cpu=82.49ms elapsed=5.54s tid=0x00007f11dc0be800 nid=0x5a5 runnable
>
> "GC Thread#0" os_prio=0 cpu=13.87ms elapsed=6.24s tid=0x00007f11dc02f800 nid=0x5a0 runnable
>
> "G1 Main Marker" os_prio=0 cpu=102.83ms elapsed=6.22s tid=0x00007f11dc04b000 nid=0x5a1 runnable
>
> "G1 Conc#0" os_prio=0 cpu=0.94ms elapsed=6.22s tid=0x00007f11dc04c800 nid=0x5a2 runnable
>
> "G1 Refine#0" os_prio=0 cpu=88.47ms elapsed=6.20s tid=0x00007f11dc090800 nid=0x5a3 runnable
>
> "G1 Young RemSet Sampling" os_prio=0 cpu=126.93ms elapsed=6.20s tid=0x00007f11dc092000 nid=0x5a4 runnable
> "VM Periodic Task Thread" os_prio=0 cpu=25.32ms elapsed=4.26s tid=0x00007f11dc153800 nid=0x5ae waiting on condition
> JNI global refs: 8, weak refs: 0
>
> Heap
> garbage-first heap total 65536K, used 5832K [0x00000000c2800000, 0x0000000100000000)
> region size 1024K, 7 young (7168K), 0 survivors (0K)
> Metaspace used 1835K, capacity 5133K, committed 5504K, reserved 1056768K
> class space used 196K, capacity 529K, committed 640K, reserved 1048576K
Zero request-processing threads are running. Zero protocol handlers,
accepter, etc. threads are running. It's like Tomcat didn't even attempt
to start.
> #
> # A fatal error has been detected by the Java Runtime Environment:
> #
> # SIGSEGV (0xb) at pc=0x00007f11c4e3f7a2, pid=1435, tid=1439
> #
> # JRE version: OpenJDK Runtime Environment (11.0.11+9) (build 11.0.11+9-Ubuntu-0ubuntu2.18.04)
> # Java VM: OpenJDK 64-Bit Server VM (11.0.11+9-Ubuntu-0ubuntu2.18.04, mixed mode, sharing, tiered, compressed oops, g1 gc, linux-amd64)
> # Problematic frame:
> # J 189 c1 jdk.internal.org.objectweb.asm.ClassWriter.get(Ljdk/internal/org/objectweb/asm/Item;)Ljdk/internal/org/objectweb/asm/Item; java.base@11.0.11 (49 bytes) @ 0x00007f11c4e3f7a2 [0x00007f11c4e3f760+0x0000000000000042]
> #
> # Core dump will be written. Default location: Core dumps may be processed with "/usr/share/apport/apport %p %s %c %d %P %E" (or dumping to /home/mcr/core.1435)
> #
> # An error report file with more information is saved as:
> # /tmp/hs_err_pid1435.log
> Compiled method (c1) 8162 272 3 jdk.internal.org.objectweb.asm.ClassWriter::newUTF8 (70 bytes)
> total in heap [0x00007f11c4e64a90,0x00007f11c4e651b0] = 1824
> relocation [0x00007f11c4e64c08,0x00007f11c4e64c98] = 144
> main code [0x00007f11c4e64ca0,0x00007f11c4e64f80] = 736
> stub code [0x00007f11c4e64f80,0x00007f11c4e65010] = 144
> metadata [0x00007f11c4e65010,0x00007f11c4e65028] = 24
> scopes data [0x00007f11c4e65028,0x00007f11c4e650a0] = 120
> scopes pcs [0x00007f11c4e650a0,0x00007f11c4e65180] = 224
> dependencies [0x00007f11c4e65180,0x00007f11c4e65188] = 8
> nul chk table [0x00007f11c4e65188,0x00007f11c4e651b0] = 40
> Compiled method (c1) 8233 272 3 jdk.internal.org.objectweb.asm.ClassWriter::newUTF8 (70 bytes)
> total in heap [0x00007f11c4e64a90,0x00007f11c4e651b0] = 1824
> relocation [0x00007f11c4e64c08,0x00007f11c4e64c98] = 144
> main code [0x00007f11c4e64ca0,0x00007f11c4e64f80] = 736
> stub code [0x00007f11c4e64f80,0x00007f11c4e65010] = 144
> metadata [0x00007f11c4e65010,0x00007f11c4e65028] = 24
> scopes data [0x00007f11c4e65028,0x00007f11c4e650a0] = 120
> scopes pcs [0x00007f11c4e650a0,0x00007f11c4e65180] = 224
> dependencies [0x00007f11c4e65180,0x00007f11c4e65188] = 8
> nul chk table [0x00007f11c4e65188,0x00007f11c4e651b0] = 40
> Could not load hsdis-amd64.so; library not loadable; PrintAssembly is disabled
> #
> # If you would like to submit a bug report, please visit:
> # https://bugs.launchpad.net/ubuntu/+source/openjdk-lts
> #
Is this the hardware you have been using for a while, or something new?
Can you run a hardware test on it?
-chris
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: how to tune cacheMaxSize
Posted by Michael Richardson <mc...@sandelman.ca>.
Login to freshly booted machine. I told my xterm to log it.
{The file is at: https://www.sandelman.ca/tmp/terapia9/xterm-25216.txt
(contains xterm/ANSI codes)
Use https://github.com/nikushi/slowcat or
https://www.sandelman.ca/mcr/slowcat.c < file
or equivalent to watch the results. (If there is a better tool that is more
available, tell me. In 35 years of Unix, I never found one. Yeah, it's a bit
painful to watch even at 100 characters/s. At 1000/s it goes by too fast.
Use a window 200 x 77 or larger. Next time without htop)}
Summary:
This time I got the stack trace the first time.
Imagine my surprise, I wasn't ready to catch it.
A second ^\ did nothing. I will repeat in a moment from a fresh start.
Copy and pasting from the screen back scroll. It looks like it's thread #1,
in org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:445).
It looks like it is spin-locking on a mutex, and then after the dump, it gets
a SEGV.
Full thread dump OpenJDK 64-Bit Server VM (11.0.11+9-Ubuntu-0ubuntu2.18.04 mixed mode, sharing):
Threads class SMR info:
_java_thread_list=0x00007f1178004e60, length=11, elements={
0x00007f11dc017000, 0x00007f11dc0c1000, 0x00007f11dc0c3000, 0x00007f11dc0c8800,
0x00007f11dc0ca800, 0x00007f11dc0cd000, 0x00007f11dc0cf000, 0x00007f11dc0d1000,
0x00007f11dc14f800, 0x00007f11dc19f800, 0x00007f11dc1b6800
}
"main" #1 prio=5 os_prio=0 cpu=5336.28ms elapsed=6.38s tid=0x00007f11dc017000 nid=0x59f runnable [0x00007f11e55ea000]
java.lang.Thread.State: RUNNABLE
at org.apache.catalina.startup.Bootstrap.init(Bootstrap.java:275)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:445)
- locked <0x00000000c62dffd0> (a java.lang.Object)
"Reference Handler" #2 daemon prio=10 os_prio=0 cpu=5.76ms elapsed=5.37s tid=0x00007f11dc0c1000 nid=0x5a6 waiting on condition [0x00007f11bc13e000]
java.lang.Thread.State: RUNNABLE
at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.11/Native Method)
at java.lang.ref.Reference.processPendingReferences(java.base@11.0.11/Reference.java:241)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.11/Reference.java:213)
"Finalizer" #3 daemon prio=8 os_prio=0 cpu=11.45ms elapsed=5.36s tid=0x00007f11dc0c3000 nid=0x5a7 in Object.wait() [0x00007f11a7ffe000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.11/Native Method)
- waiting on <0x00000000c65024d8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000000c65024d8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:176)
at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.11/Finalizer.java:170)
Signal Dispatcher" #4 daemon prio=9 os_prio=0 cpu=2.47ms elapsed=5.22s tid=0x00007f11dc0c8800 nid=0x5a8 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Service Thread" #5 daemon prio=9 os_prio=0 cpu=2.46ms elapsed=5.22s tid=0x00007f11dc0ca800 nid=0x5a9 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" #6 daemon prio=9 os_prio=0 cpu=2242.87ms elapsed=5.22s tid=0x00007f11dc0cd000 nid=0x5aa waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
"C1 CompilerThread0" #8 daemon prio=9 os_prio=0 cpu=3343.57ms elapsed=5.22s tid=0x00007f11dc0cf000 nid=0x5ab runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Compiling: 541 ! 3 java.util.jar.JarFile::checkForSpecialAttributes (163 bytes)
"Sweeper thread" #9 daemon prio=9 os_prio=0 cpu=1.89ms elapsed=5.22s tid=0x00007f11dc0d1000 nid=0x5ac runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Common-Cleaner" #10 daemon prio=8 os_prio=0 cpu=2.70ms elapsed=4.62s tid=0x00007f11dc14f800 nid=0x5ad in Object.wait() [0x00007f11a76e1000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.11/Native Method)
- waiting on <0x00000000c65dd3d0> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000000c65dd3d0> (a java.lang.ref.ReferenceQueue$Lock)
at jdk.internal.ref.CleanerImpl.run(java.base@11.0.11/CleanerImpl.java:148)
at java.lang.Thread.run(java.base@11.0.11/Thread.java:829)
at jdk.internal.misc.InnocuousThread.run(java.base@11.0.11/InnocuousThread.java:134)
"AsyncFileHandlerWriter-931919113" #13 daemon prio=5 os_prio=0 cpu=30.64ms elapsed=3.19s tid=0x00007f11dc19f800 nid=0x5af waiting on condition [0x00007f11a70b6000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.11/Native Method)
- parking to wait for <0x00000000c6497fb0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.11/LockSupport.java:234)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(java.base@11.0.11/AbstractQueuedSynchronizer.java:2123)
at java.util.concurrent.LinkedBlockingDeque.pollFirst(java.base@11.0.11/LinkedBlockingDeque.java:513)
at java.util.concurrent.LinkedBlockingDeque.poll(java.base@11.0.11/LinkedBlockingDeque.java:675)
at org.apache.juli.AsyncFileHandler$LoggerThread.run(AsyncFileHandler.java:159)
"FileHandlerLogFilesCleaner-1" #14 daemon prio=5 os_prio=0 cpu=480.27ms elapsed=2.28s tid=0x00007f11dc1b6800 nid=0x5b0 waiting on condition [0x00007f11a6fb5000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.11/Native Method)
- parking to wait for <0x00000000c6497918> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.11/LockSupport.java:194)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.11/AbstractQueuedSynchronizer.java:2081)
at java.util.concurrent.LinkedBlockingQueue.take(java.base@11.0.11/LinkedBlockingQueue.java:433)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.11/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.11/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.11/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.11/Thread.java:829)
"VM Thread" os_prio=0 cpu=82.49ms elapsed=5.54s tid=0x00007f11dc0be800 nid=0x5a5 runnable
"GC Thread#0" os_prio=0 cpu=13.87ms elapsed=6.24s tid=0x00007f11dc02f800 nid=0x5a0 runnable
"G1 Main Marker" os_prio=0 cpu=102.83ms elapsed=6.22s tid=0x00007f11dc04b000 nid=0x5a1 runnable
"G1 Conc#0" os_prio=0 cpu=0.94ms elapsed=6.22s tid=0x00007f11dc04c800 nid=0x5a2 runnable
"G1 Refine#0" os_prio=0 cpu=88.47ms elapsed=6.20s tid=0x00007f11dc090800 nid=0x5a3 runnable
"G1 Young RemSet Sampling" os_prio=0 cpu=126.93ms elapsed=6.20s tid=0x00007f11dc092000 nid=0x5a4 runnable
"VM Periodic Task Thread" os_prio=0 cpu=25.32ms elapsed=4.26s tid=0x00007f11dc153800 nid=0x5ae waiting on condition
JNI global refs: 8, weak refs: 0
Heap
garbage-first heap total 65536K, used 5832K [0x00000000c2800000, 0x0000000100000000)
region size 1024K, 7 young (7168K), 0 survivors (0K)
Metaspace used 1835K, capacity 5133K, committed 5504K, reserved 1056768K
class space used 196K, capacity 529K, committed 640K, reserved 1048576K
#
# A fatal error has been detected by the Java Runtime Environment:
#
# SIGSEGV (0xb) at pc=0x00007f11c4e3f7a2, pid=1435, tid=1439
#
# JRE version: OpenJDK Runtime Environment (11.0.11+9) (build 11.0.11+9-Ubuntu-0ubuntu2.18.04)
# Java VM: OpenJDK 64-Bit Server VM (11.0.11+9-Ubuntu-0ubuntu2.18.04, mixed mode, sharing, tiered, compressed oops, g1 gc, linux-amd64)
# Problematic frame:
# J 189 c1 jdk.internal.org.objectweb.asm.ClassWriter.get(Ljdk/internal/org/objectweb/asm/Item;)Ljdk/internal/org/objectweb/asm/Item; java.base@11.0.11 (49 bytes) @ 0x00007f11c4e3f7a2 [0x00007f11c4e3f760+0x0000000000000042]
#
# Core dump will be written. Default location: Core dumps may be processed with "/usr/share/apport/apport %p %s %c %d %P %E" (or dumping to /home/mcr/core.1435)
#
# An error report file with more information is saved as:
# /tmp/hs_err_pid1435.log
Compiled method (c1) 8162 272 3 jdk.internal.org.objectweb.asm.ClassWriter::newUTF8 (70 bytes)
total in heap [0x00007f11c4e64a90,0x00007f11c4e651b0] = 1824
relocation [0x00007f11c4e64c08,0x00007f11c4e64c98] = 144
main code [0x00007f11c4e64ca0,0x00007f11c4e64f80] = 736
stub code [0x00007f11c4e64f80,0x00007f11c4e65010] = 144
metadata [0x00007f11c4e65010,0x00007f11c4e65028] = 24
scopes data [0x00007f11c4e65028,0x00007f11c4e650a0] = 120
scopes pcs [0x00007f11c4e650a0,0x00007f11c4e65180] = 224
dependencies [0x00007f11c4e65180,0x00007f11c4e65188] = 8
nul chk table [0x00007f11c4e65188,0x00007f11c4e651b0] = 40
Compiled method (c1) 8233 272 3 jdk.internal.org.objectweb.asm.ClassWriter::newUTF8 (70 bytes)
total in heap [0x00007f11c4e64a90,0x00007f11c4e651b0] = 1824
relocation [0x00007f11c4e64c08,0x00007f11c4e64c98] = 144
main code [0x00007f11c4e64ca0,0x00007f11c4e64f80] = 736
stub code [0x00007f11c4e64f80,0x00007f11c4e65010] = 144
metadata [0x00007f11c4e65010,0x00007f11c4e65028] = 24
scopes data [0x00007f11c4e65028,0x00007f11c4e650a0] = 120
scopes pcs [0x00007f11c4e650a0,0x00007f11c4e65180] = 224
dependencies [0x00007f11c4e65180,0x00007f11c4e65188] = 8
nul chk table [0x00007f11c4e65188,0x00007f11c4e651b0] = 40
Could not load hsdis-amd64.so; library not loadable; PrintAssembly is disabled
#
# If you would like to submit a bug report, please visit:
# https://bugs.launchpad.net/ubuntu/+source/openjdk-lts
#
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: how to tune cacheMaxSize
Posted by Christopher Schultz <ch...@christopherschultz.net>.
Michael,
On 8/16/21 16:14, Michael Richardson wrote:
>
> Christopher Schultz <ch...@christopherschultz.net> wrote:
> > Okay, all that looks fine to me, except the "9.0.16" part. That version
> > is *very/8 old. I see you are running Ubuntu: are you running the
> > latest release? That 9.0.16 number if rinning a bell about an older
> > release which was capped at 9.0.16. YOu might want to consider
> > upgrading everything once you figure all of this out. No need to muddy
> > the waters quite, yet, though.
>
> Ubuntu 18.04. I shall look for a ppa with newer tomcat.
> It's a VM, I could go to Core 20.
Okay. We can get to that, later, but it's probably a good idea since
it's probably nearing EOL. (I didn't bother checking.)
> > A few more things:
>
> > 1. It takes 12 seconds to initialize the server? That seems
> > ... slow. Is this on Amazon? What instance type? The memory size
> > 3.75GiB is ringing a bell, too.
>
> I could go to 8G for the VM if you think that's relevant.
> My reading is that I'm not even using 1G of ram at this point.
Nah, it's not important. But if it were an EC2 VM it's entirely possible
that you are simply asking too much of it and the slowness/100% CPU is
just "it's trying to do too much work."
> No, it's not in Amazon. It's a Dell Xeon workstation in the basement of my
> wife's clinic. Patient record confidentiality would probably contraindicate EC2 :-)
Not at all. EC2 is entirely reasonable for such purposes. Amazon will
even grant you a signed BAA if you ask for one.
> > 2. You shouldn't have the "docs"
> > project depployed on a production system.
>
> I installed it there to grep/read them, then decided that I'd install
> that on my desktop.
Okay, no problem. As long as you know what you are doing. Often, seeing
the "docs" application deployed means (somewhat ironically) "someone
didn't read the documentation for going to production."
> > 3. I don't see any message
> > "Deploying deployment descriptor blah/blah/oscar/blah"
>
> Yes, exactly.
Hmm.
> Christopher Schultz <ch...@christopherschultz.net> wrote:
> >> 14-Aug-2021 17:16:45.464 SEVERE [Catalina-utility-1]
> >> org.apache.catalina.startup.HostConfig.deployWAR Error deploying web
> >> application archive [/var/lib/tomcat9/webapps/oscar.war]
> >> java.lang.IllegalStateException: Error starting child at
> >> org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:716)
> >> ...
> >>
>
> > That certainly looks bad. Are you building OSCAR yourself, or is it
> > pre-built? I'm assuming that all local customizations are done using
> > separate config files or in the database, right? Can you get a fresh
> > copy of the oscar.war file?
>
> No, I'm not building myself.
> There is an oscar.deb, which btw, results in the same 100%.
Okay, good. Does OSCAR distribute the .deb file? I'm ... weirdly
surprised by that.
> It also does other stuff like configure mariadb locally (which I don't want).
Interesting. You want control over your own database, or you don't want
the db to be local (e.g. you want a remote db)?
> But, I've used the oscar.war from that deb, and also the oscar.war which
> is on the bare-metal version that is running.
Okay.
> >> 14-Aug-2021 17:16:45.506 INFO [Catalina-utility-1]
> >> org.apache.catalina.startup.HostConfig.deployWAR Deployment of web
> >> application archive [/var/lib/tomcat9/webapps/oscar.war] has finished
> >> in [1,684] ms
>
> > That's nice and fast.
>
> No, it's in error.
:) I was mostly joking.
> >> 14-Aug-2021 17:16:55.661 INFO [Catalina-utility-2]
> >> org.apache.catalina.startup.HostConfig.undeploy Undeploying context
> >> [/oscar] 14-Aug-2021 17:16:58.286 INFO [Catalina-utility-2]
> >> org.apache.catalina.startup.HostConfig.deployWAR Deploying web
> >> application archive [/var/lib/tomcat9/webapps/oscar.war]
>
> > Strange that it's deploying, then undeploying, then deploying again. Is
> > it possible that there are weird file timestamps? Maybe something in
> > the future?
>
> I think that the cp of the 220M oscar.war hasn't completed when it starts
> that first deploy. That's why the ZIP error.
>
> >> My guess is that the cp oscar.war /var/lib/tomcat9/webapps hadn't
> >> actually finished yet when it tried to deploy it.
>
> > That can definitely break things. If you are going to drop a WAR file
> > on Tomcat, make sure that either Tomcat isn't running, or you are using
> > the Manager web application to upload-and-deploy the WAR file which
> > protects you from deploying mid-copy.
>
> This is the only time I've seen this error, I've also used the manager web
> application before.
Hmm. Same error there? Or same 100% CPU circumstances there?
> >> So the port is open, so I attempt to visit the /manage URL
> >>
> >> oscar-serv03-[~] root 31 #netstat -tan Active Internet connections
> >> (servers and established) Proto Recv-Q Send-Q Local Address Foreign
> >> Address State tcp 0 0 127.0.0.53:53 0.0.0.0:* LISTEN tcp 0 0
> >> 0.0.0.0:22 0.0.0.0:* LISTEN tcp 0 0 127.0.0.1:3306 0.0.0.0:* LISTEN
> >> tcp 0 0 192.168.2.13:22 192.168.2.3:56896 ESTABLISHED tcp 0 0
> >> 192.168.2.13:22 192.168.2.3:56898 ESTABLISHED tcp6 0 0 :::22 :::*
> >> LISTEN tcp6 0 0 :::8080 :::* LISTEN tcp6 559 0 192.168.2.9:8080
> >> 192.168.2.3:37486 ESTABLISHED
> >>
> >> And it just stalls.
>
> > Is there anything between Tomcat and your web browser? Like a reverse
> > proxy, firewall, etc.? What URL are you trying to hit?
>
> I have an ssh -L 8080:192.168.2.9:8080 tunnel from my desktop.
> There is nothing else in between.
>
> >> I went to eat lunch and watch TV, so waited a few hours, and it's the
> >> same afterwards. Note that it never told me that it had finished
> >> deploying this war.
> >>
> >> I've tried kill-3 repeatedly, on the main PID of the process, and
> >> gotten no output.
>
> > Anything in the other log files?
>
> Nope.
>
> > Instead of kill -3, what if you use the "jstack" utility and provide
> > the PID of the running process? (You'll want to provide the PID of the
> > parent JVM process, not a specific thread.)
>
> I tried that. It says something about there being no socket open.
> My impression is that "jstack" was an Oracle Java only tool.
Nope, it's in all of the OpenJDK builds. You might need a "JDK" instead
of a"JRE".
When you issue "kill -3", the thread dump should appear on stdout, which
should be captured in logs/catalina.[date].log. If that's not happening,
then I'm a bit confused...
Okay, try this:
1. Stop Tomcat, clear all logs, delete your oscar.war file and the
exploded directory in CATALINA_BASE/webapps/oscar (or wherever your
appBase points to).
2. Copy your oscar.war file into appBase, making sure that operation
completes
3. Start Tomcat, but like this instead of what you usually do:
$ sudo -iu tomcatuser
$ $CATALINA_BASE/bin/catalina.sh run
That "run" is important: it will run Tomcat in the current console
instead of in the background as a service. You'll get stdout directly on
your console, no log files to worry about.
Watch everything try to start up. See what happens, obviously,
specifically with oscar.war.
If you hit that 100% CPU (checking via another ssh connection, of
course), then in the Tomcat connection you can press CTRL-\ on your
keyboard to send a SIGQUIT to the current program (the JVM). That should
generate a thread dump right on that console. Feel free to paste the
entire thing into a post to this mailing list.
-chris
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: how to tune cacheMaxSize
Posted by Michael Richardson <mc...@sandelman.ca>.
Christopher Schultz <ch...@christopherschultz.net> wrote:
> Okay, all that looks fine to me, except the "9.0.16" part. That version
> is *very/8 old. I see you are running Ubuntu: are you running the
> latest release? That 9.0.16 number if rinning a bell about an older
> release which was capped at 9.0.16. YOu might want to consider
> upgrading everything once you figure all of this out. No need to muddy
> the waters quite, yet, though.
Ubuntu 18.04. I shall look for a ppa with newer tomcat.
It's a VM, I could go to Core 20.
> A few more things:
> 1. It takes 12 seconds to initialize the server? That seems
> ... slow. Is this on Amazon? What instance type? The memory size
> 3.75GiB is ringing a bell, too.
I could go to 8G for the VM if you think that's relevant.
My reading is that I'm not even using 1G of ram at this point.
No, it's not in Amazon. It's a Dell Xeon workstation in the basement of my
wife's clinic. Patient record confidentiality would probably contraindicate EC2 :-)
> 2. You shouldn't have the "docs"
> project depployed on a production system.
I installed it there to grep/read them, then decided that I'd install that on my desktop.
> 3. I don't see any message
> "Deploying deployment descriptor blah/blah/oscar/blah"
Yes, exactly.
Christopher Schultz <ch...@christopherschultz.net> wrote:
>> 14-Aug-2021 17:16:45.464 SEVERE [Catalina-utility-1]
>> org.apache.catalina.startup.HostConfig.deployWAR Error deploying web
>> application archive [/var/lib/tomcat9/webapps/oscar.war]
>> java.lang.IllegalStateException: Error starting child at
>> org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:716)
>> ...
>>
> That certainly looks bad. Are you building OSCAR yourself, or is it
> pre-built? I'm assuming that all local customizations are done using
> separate config files or in the database, right? Can you get a fresh
> copy of the oscar.war file?
No, I'm not building myself.
There is an oscar.deb, which btw, results in the same 100%.
It also does other stuff like configure mariadb locally (which I don't want).
But, I've used the oscar.war from that deb, and also the oscar.war which
is on the bare-metal version that is running.
>> 14-Aug-2021 17:16:45.506 INFO [Catalina-utility-1]
>> org.apache.catalina.startup.HostConfig.deployWAR Deployment of web
>> application archive [/var/lib/tomcat9/webapps/oscar.war] has finished
>> in [1,684] ms
> That's nice and fast.
No, it's in error.
>> 14-Aug-2021 17:16:55.661 INFO [Catalina-utility-2]
>> org.apache.catalina.startup.HostConfig.undeploy Undeploying context
>> [/oscar] 14-Aug-2021 17:16:58.286 INFO [Catalina-utility-2]
>> org.apache.catalina.startup.HostConfig.deployWAR Deploying web
>> application archive [/var/lib/tomcat9/webapps/oscar.war]
> Strange that it's deploying, then undeploying, then deploying again. Is
> it possible that there are weird file timestamps? Maybe something in
> the future?
I think that the cp of the 220M oscar.war hasn't completed when it starts
that first deploy. That's why the ZIP error.
>> My guess is that the cp oscar.war /var/lib/tomcat9/webapps hadn't
>> actually finished yet when it tried to deploy it.
> That can definitely break things. If you are going to drop a WAR file
> on Tomcat, make sure that either Tomcat isn't running, or you are using
> the Manager web application to upload-and-deploy the WAR file which
> protects you from deploying mid-copy.
This is the only time I've seen this error, I've also used the manager web
application before.
>> So the port is open, so I attempt to visit the /manage URL
>>
>> oscar-serv03-[~] root 31 #netstat -tan Active Internet connections
>> (servers and established) Proto Recv-Q Send-Q Local Address Foreign
>> Address State tcp 0 0 127.0.0.53:53 0.0.0.0:* LISTEN tcp 0 0
>> 0.0.0.0:22 0.0.0.0:* LISTEN tcp 0 0 127.0.0.1:3306 0.0.0.0:* LISTEN
>> tcp 0 0 192.168.2.13:22 192.168.2.3:56896 ESTABLISHED tcp 0 0
>> 192.168.2.13:22 192.168.2.3:56898 ESTABLISHED tcp6 0 0 :::22 :::*
>> LISTEN tcp6 0 0 :::8080 :::* LISTEN tcp6 559 0 192.168.2.9:8080
>> 192.168.2.3:37486 ESTABLISHED
>>
>> And it just stalls.
> Is there anything between Tomcat and your web browser? Like a reverse
> proxy, firewall, etc.? What URL are you trying to hit?
I have an ssh -L 8080:192.168.2.9:8080 tunnel from my desktop.
There is nothing else in between.
>> I went to eat lunch and watch TV, so waited a few hours, and it's the
>> same afterwards. Note that it never told me that it had finished
>> deploying this war.
>>
>> I've tried kill-3 repeatedly, on the main PID of the process, and
>> gotten no output.
> Anything in the other log files?
Nope.
> Instead of kill -3, what if you use the "jstack" utility and provide
> the PID of the running process? (You'll want to provide the PID of the
> parent JVM process, not a specific thread.)
I tried that. It says something about there being no socket open.
My impression is that "jstack" was an Oracle Java only tool.
--
] Never tell me the odds! | ipv6 mesh networks [
] Michael Richardson, Sandelman Software Works | IoT architect [
] mcr@sandelman.ca http://www.sandelman.ca/ | ruby on rails [
Re: how to tune cacheMaxSize
Posted by Christopher Schultz <ch...@christopherschultz.net>.
Michael,
On 8/14/21 11:56, Michael Richardson wrote:
>
> Thank you for the reply.
>
> Christopher Schultz <ch...@christopherschultz.net> wrote:
> > On 8/12/21 11:05, Michael Richardson wrote:
> >> I am trying to deploy OSCAR-EMR
>
>> Wow, that still exists? I remember more than a decade ago being
>> asked to integrate a product at $work with that thing as a demo.
>> We never did, because the market seemed not to really exist. I see
>> you are in Canada. I know OSCAR same from McMaster University. Does
>> it have a good ecosystem and install base in CA? >
> Yes, it's still quite popular among many Ontario (and I'm told BC)
> doctors, because it has good integration with the provincial billing
> system. Doctor like it because the price appears right, and doctors
> don't get rich by spending money. >
> There are a number of support companies that install it, but my
> experience (via my wife) is that their do a rather poor job of
> installation. No understanding of database encryption, replication,
> or even how to enable https.
That's ... really bad.
> There seems to be developer still working on it, according to the
> bitbucket git commit lot. But, the public community around it seems
> to have died, as far as I can tell.
That's a shame. As I have discovered through years of working with ASF
and other projects, the community is far more important than the actual
product itself. A good community can fix a bad product, but the reverse
is not true. I am a member of other communities where the project
ignores the community, which is also Not Good. Not naming any names. :)
On 8/14/21 12:53, Michael Richardson wrote:
> This time, after apt-get purge tomcat9 and re-install, I seem to be in 100%
> CPU before I've deployed oscar or even updated the tomcat-users.xml to
> enable the manager login.
>
> HTOP view attached at bottom.
> (4 virtual CPUs, 4G of ram. KVM VM running ubuntu 18.04, on a server running
> ubuntu core 20)
>
> oscar-serv03-[~] root 276 #netstat -tan
> Active Internet connections (servers and established)
> Proto Recv-Q Send-Q Local Address Foreign Address State
> tcp 0 0 127.0.0.53:53 0.0.0.0:* LISTEN
> tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN
> tcp 0 0 127.0.0.1:3306 0.0.0.0:* LISTEN
> tcp 0 0 192.168.2.13:22 192.168.2.3:56874 ESTABLISHED
> tcp 0 0 192.168.2.13:22 192.168.2.3:56556 ESTABLISHED
> tcp6 2 0 :::8080 :::* LISTEN
> tcp6 0 0 :::22 :::* LISTEN
> tcp6 747 0 192.168.2.9:8080 192.168.2.3:37450 CLOSE_WAIT
> tcp6 489 0 192.168.2.9:8080 192.168.2.3:37452 ESTABLISHED
>
> I find it weird that I have no catalina.out file:
>
> oscar-serv03-[~] root 274 #ls -l /var/log/tomcat9
> total 8
> -rw-r----- 1 tomcat tomcat 5233 Aug 14 16:38 catalina.2021-08-14.log
> -rw-r----- 1 tomcat tomcat 0 Aug 14 16:37 localhost.2021-08-14.log
> -rw-r----- 1 tomcat tomcat 0 Aug 14 16:38 localhost_access_log.2021-08-14.txt
You must be running usingh jsvc, which creates the catalina.[date].log
file instead. No worries, there.
> I include cataline.2021-08-14.log here.
> Also now at: https://www.sandelman.ca/tmp/terapia9/catalina.2021-08-14.log
>
> ubuntu says that I have a new kernel and I should reboot, so I'll do another
> purge, reboot, and then reinstall again.
>
> 14-Aug-2021 16:38:02.279 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name: Apache Tomcat/9.0.16 (Ubuntu)
> 14-Aug-2021 16:38:02.302 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built: Sep 11 2019 19:47:51 UTC
> 14-Aug-2021 16:38:02.320 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 9.0.16.0
> 14-Aug-2021 16:38:02.343 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name: Linux
> 14-Aug-2021 16:38:02.345 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version: 5.4.0-80-generic
> 14-Aug-2021 16:38:02.348 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture: amd64
> 14-Aug-2021 16:38:02.374 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home: /usr/lib/jvm/java-11-openjdk-amd64
> 14-Aug-2021 16:38:02.380 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version: 11.0.11+9-Ubuntu-0ubuntu2.18.04
> 14-Aug-2021 16:38:02.382 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor: Ubuntu
> 14-Aug-2021 16:38:02.384 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE: /var/lib/tomcat9
> 14-Aug-2021 16:38:02.385 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME: /usr/share/tomcat9
> 14-Aug-2021 16:38:02.472 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.lang=ALL-UNNAMED
> 14-Aug-2021 16:38:02.478 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.io=ALL-UNNAMED
> 14-Aug-2021 16:38:02.499 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
> 14-Aug-2021 16:38:02.501 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.properties
> 14-Aug-2021 16:38:02.504 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
> 14-Aug-2021 16:38:02.509 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.awt.headless=true
> 14-Aug-2021 16:38:02.512 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:+UseG1GC
> 14-Aug-2021 16:38:02.513 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
> 14-Aug-2021 16:38:02.529 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
> 14-Aug-2021 16:38:02.531 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
> 14-Aug-2021 16:38:02.532 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
> 14-Aug-2021 16:38:02.534 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/var/lib/tomcat9
> 14-Aug-2021 16:38:02.536 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/share/tomcat9
> 14-Aug-2021 16:38:02.537 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/tmp
> 14-Aug-2021 16:38:02.551 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded APR based Apache Tomcat Native library [1.2.21] using APR version [1.6.3].
> 14-Aug-2021 16:38:02.553 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
> 14-Aug-2021 16:38:02.554 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
> 14-Aug-2021 16:38:02.676 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 1.1.1 11 Sep 2018]
> 14-Aug-2021 16:38:03.322 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
> 14-Aug-2021 16:38:04.066 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [12,268] milliseconds
> 14-Aug-2021 16:38:05.601 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
> 14-Aug-2021 16:38:05.621 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/9.0.16 (Ubuntu)]
> 14-Aug-2021 16:38:05.760 INFO [main] org.apache.catalina.startup.HostConfig.deployDescriptor Deploying deployment descriptor [/etc/tomcat9/Catalina/localhost/docs.xml]
> 14-Aug-2021 16:38:06.052 WARNING [main] org.apache.catalina.startup.HostConfig.deployDescriptor The path attribute with value [/docs] in deployment descriptor [/etc/tomcat9/Catalina/localhost/docs.xml] has been ignored
Okay, all that looks fine to me, except the "9.0.16" part. That version
is *very/8 old. I see you are running Ubuntu: are you running the latest
release? That 9.0.16 number if rinning a bell about an older release
which was capped at 9.0.16. YOu might want to consider upgrading
everything once you figure all of this out. No need to muddy the waters
quite, yet, though.
A few more things:
1. It takes 12 seconds to initialize the server? That seems ... slow. Is
this on Amazon? What instance type? The memory size 3.75GiB is ringing a
bell, too.
2. You shouldn't have the "docs" project depployed on a production system.
3. I don't see any message "Deploying deployment descriptor
blah/blah/oscar/blah"
> PID USER PRI NI VIRT RES SHR S CPU% MEM% TIME+ Command
> 28648 tomcat 20 0 4011M 112M 32844 S 110. 2.9 9:59.52 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28660 tomcat 20 0 4011M 112M 32844 R 101. 2.9 8:32.93 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28679 tomcat 20 0 4011M 112M 32844 S 7.5 2.9 0:40.84 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28701 tomcat 20 0 4011M 112M 32844 S 0.6 2.9 0:03.08 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28760 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:02.59 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28695 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:17.27 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28696 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:14.38 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28665 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.50 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28746 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.44 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28700 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.01 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28702 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.16 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28669 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.11 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28691 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.01 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28668 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.15 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28716 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.40 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28666 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.08 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28667 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28689 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28693 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28694 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28697 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28747 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
> 28758 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
Sure looks like 100% CPU usage. I wonder what is happening.
-chris
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: how to tune cacheMaxSize
Posted by Michael Richardson <mc...@sandelman.ca>.
This time, after apt-get purge tomcat9 and re-install, I seem to be in 100%
CPU before I've deployed oscar or even updated the tomcat-users.xml to
enable the manager login.
HTOP view attached at bottom.
(4 virtual CPUs, 4G of ram. KVM VM running ubuntu 18.04, on a server running
ubuntu core 20)
oscar-serv03-[~] root 276 #netstat -tan
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address Foreign Address State
tcp 0 0 127.0.0.53:53 0.0.0.0:* LISTEN
tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN
tcp 0 0 127.0.0.1:3306 0.0.0.0:* LISTEN
tcp 0 0 192.168.2.13:22 192.168.2.3:56874 ESTABLISHED
tcp 0 0 192.168.2.13:22 192.168.2.3:56556 ESTABLISHED
tcp6 2 0 :::8080 :::* LISTEN
tcp6 0 0 :::22 :::* LISTEN
tcp6 747 0 192.168.2.9:8080 192.168.2.3:37450 CLOSE_WAIT
tcp6 489 0 192.168.2.9:8080 192.168.2.3:37452 ESTABLISHED
I find it weird that I have no catalina.out file:
oscar-serv03-[~] root 274 #ls -l /var/log/tomcat9
total 8
-rw-r----- 1 tomcat tomcat 5233 Aug 14 16:38 catalina.2021-08-14.log
-rw-r----- 1 tomcat tomcat 0 Aug 14 16:37 localhost.2021-08-14.log
-rw-r----- 1 tomcat tomcat 0 Aug 14 16:38 localhost_access_log.2021-08-14.txt
I include cataline.2021-08-14.log here.
Also now at: https://www.sandelman.ca/tmp/terapia9/catalina.2021-08-14.log
ubuntu says that I have a new kernel and I should reboot, so I'll do another
purge, reboot, and then reinstall again.
14-Aug-2021 16:38:02.279 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name: Apache Tomcat/9.0.16 (Ubuntu)
14-Aug-2021 16:38:02.302 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built: Sep 11 2019 19:47:51 UTC
14-Aug-2021 16:38:02.320 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 9.0.16.0
14-Aug-2021 16:38:02.343 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name: Linux
14-Aug-2021 16:38:02.345 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version: 5.4.0-80-generic
14-Aug-2021 16:38:02.348 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture: amd64
14-Aug-2021 16:38:02.374 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home: /usr/lib/jvm/java-11-openjdk-amd64
14-Aug-2021 16:38:02.380 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version: 11.0.11+9-Ubuntu-0ubuntu2.18.04
14-Aug-2021 16:38:02.382 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor: Ubuntu
14-Aug-2021 16:38:02.384 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE: /var/lib/tomcat9
14-Aug-2021 16:38:02.385 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME: /usr/share/tomcat9
14-Aug-2021 16:38:02.472 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.lang=ALL-UNNAMED
14-Aug-2021 16:38:02.478 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.io=ALL-UNNAMED
14-Aug-2021 16:38:02.499 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
14-Aug-2021 16:38:02.501 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.properties
14-Aug-2021 16:38:02.504 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
14-Aug-2021 16:38:02.509 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.awt.headless=true
14-Aug-2021 16:38:02.512 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:+UseG1GC
14-Aug-2021 16:38:02.513 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
14-Aug-2021 16:38:02.529 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
14-Aug-2021 16:38:02.531 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
14-Aug-2021 16:38:02.532 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
14-Aug-2021 16:38:02.534 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/var/lib/tomcat9
14-Aug-2021 16:38:02.536 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/share/tomcat9
14-Aug-2021 16:38:02.537 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/tmp
14-Aug-2021 16:38:02.551 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded APR based Apache Tomcat Native library [1.2.21] using APR version [1.6.3].
14-Aug-2021 16:38:02.553 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
14-Aug-2021 16:38:02.554 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
14-Aug-2021 16:38:02.676 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 1.1.1 11 Sep 2018]
14-Aug-2021 16:38:03.322 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
14-Aug-2021 16:38:04.066 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [12,268] milliseconds
14-Aug-2021 16:38:05.601 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
14-Aug-2021 16:38:05.621 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/9.0.16 (Ubuntu)]
14-Aug-2021 16:38:05.760 INFO [main] org.apache.catalina.startup.HostConfig.deployDescriptor Deploying deployment descriptor [/etc/tomcat9/Catalina/localhost/docs.xml]
14-Aug-2021 16:38:06.052 WARNING [main] org.apache.catalina.startup.HostConfig.deployDescriptor The path attribute with value [/docs] in deployment descriptor [/etc/tomcat9/Catalina/localhost/docs.xml] has been ignored
1 [|||||||| 8.6%] Tasks: 45, 68 thr; 2 running
2 [ 0.0%] Load average: 1.46 1.27 0.97
3 [||| 2.7%] Uptime: 2 days, 16:59:14
4 [|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||100.0%]
Mem[||||||||||||||||||||||||||||||||||||||||||||||||||||||| 308M/3.84G]
Swp[| 1.75M/1024M]
PID USER PRI NI VIRT RES SHR S CPU% MEM% TIME+ Command
28648 tomcat 20 0 4011M 112M 32844 S 110. 2.9 9:59.52 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28660 tomcat 20 0 4011M 112M 32844 R 101. 2.9 8:32.93 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28679 tomcat 20 0 4011M 112M 32844 S 7.5 2.9 0:40.84 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28701 tomcat 20 0 4011M 112M 32844 S 0.6 2.9 0:03.08 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28760 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:02.59 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28695 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:17.27 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28696 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:14.38 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28665 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.50 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28746 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.44 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28700 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.01 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28702 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.16 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28669 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.11 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28691 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.01 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28668 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.15 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28716 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.40 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28666 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.08 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28667 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28689 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28693 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28694 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28697 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28747 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
28758 tomcat 20 0 4011M 112M 32844 S 0.0 2.9 0:00.00 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.proper
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: how to tune cacheMaxSize
Posted by Christopher Schultz <ch...@christopherschultz.net>.
Michael,
On 8/12/21 11:05, Michael Richardson wrote:
> I am trying to deploy OSCAR-EMR
Wow, that still exists? I remember more than a decade ago being asked to
integrate a product at $work with that thing as a demo. We never did,
because the market seemed not to really exist. I see you are in Canada.
I know OSCAR same from McMaster University. Does it have a good
ecosystem and install base in CA?
> in a new location (for my wife's office), with better encryption and
> database replication. We have an existing bare-metal instance
> running that her boss assembled. It's fragile, but it runs.
>
> In both ubuntu 18.04 and devuan beowulf VMs, I can start up tomcat9
> and openjdk (8 or 11) and talk to the tomcat9-admin interface.
>
> I then deploy the oscar.war to /var/lib/tomcat19/webapps, and observe
> in htop that I get 5-6 threads that get very busy, as it extracts the app.
Hmm. I wouldn't expect more than 1 thread to get busy extracting that
application.
> Then, port 8080 stops responding. And also I see new connections just stall.
>
> I wind up with two threads of java each chewing 100% of the CPU.
> strace on it doesn't help, telling me that it looks like 32-bit code.
> I think that the JIT might confuse it. Are these threads doing I/O or system
> calls? I can't tell.
>
> (I can see the new connections stalling in netstat -tan, with unprocessed
> bytes in the recv Q)
>
> If I stop the java processes, and restart them, then they seem to continue
> the "deploy", even if I have removed the oscar.war and
> /var/lib/tomcat19/webcaps/oscar directory. Clearly something else remembers
> it. When that happens, I get *no output* in catalina.out.
What makes you think those threads are continuing to deploy the WAR
file? If the WAR file is missing, deployment would be most difficult.
When you remove the WAR file, are you also removing the
exploded-WAR-directory that Tomcat creates during the deployment of the WAR?
> And _apt-get purge tomcat9_, and re-install, gets me back to the start, but I'd
> like to understand where the deploy is being recorded and how I can undo only
> that.
>
> I will get one message that I am trying to look at the cacheMaxSize
> value in /etc/tomcat9/context.xml.
> <dang, that log file got deleted>
>
> My question is, if the cacheMaxSize is too small, will it lead to some kind
> of continual cache replacement where it never actually starts up?
> If so, is there some debug that would let me estimate what an appropriate
> cache size is? The running machine has:
> <Resources cachingAllowed="true" cacheMaxSize="100000" />
>
> (I initially suspected the whole /dev/random issue, so I moved the TLS
> to a proxy-pass Apache, but also I have virtio /dev/random, and I also
> ln /dev/urandom to /dev/random just in case...)
Okay, I don't mean to sound mean, but it sounds like you have no idea
what's going on, here. There are probably several issues, but let's
start with the first one: what are those threads doing at 100% CPU.
You don't have a /dev/random problem, because really nobody has that
problem anymore. Also, the /dev/random problem manifests as a "hung"
server with *zero* CPU usage.
Reset your environment back to the beginning: fresh Tomcat, no log
files, no WAR deployed or anything like that. Start up Tomcat and make
sure everything looks good so far. Then deploy the WAR file and let
everything go to hell. After things settle down and you are in your "2
threads eating the CPU" situation, do the following:
1. Grab the log file in CATALINA_BASE/logs/catalina.out (or similar)
2. Take a thread-dump of the running JVM[1]
Sanitize the files in whatever way is necessary and post them back to
this mailing list and we'll take a look.
-chris
[1]
https://cwiki.apache.org/confluence/display/TOMCAT/HowTo#HowTo-HowdoIobtainathreaddumpofmyrunningwebapp?
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: how to tune cacheMaxSize
Posted by Michael Richardson <mc...@sandelman.ca>.
Michael Richardson <mc...@sandelman.ca> wrote:
> Then, port 8080 stops responding. And also I see new connections just
> stall.
to be clear, this is what I mean:
oscar-serv03-[~] root 213 #netstat -tan
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address Foreign Address State
tcp 0 0 127.0.0.53:53 0.0.0.0:* LISTEN
tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN
tcp 0 0 127.0.0.1:3306 0.0.0.0:* LISTEN
tcp 0 0 192.168.2.13:22 192.168.2.3:56556 ESTABLISHED
tcp6 1 0 :::8080 :::* LISTEN
tcp6 0 0 :::22 :::* LISTEN
tcp6 699 0 192.168.2.9:8080 192.168.2.3:37404 ESTABLISHED
{192.168.2.3:37404 is an ssh port forward from my desktop.
I wish stupid ISP had IPv6}
The process is clearly too busy to bother calling accept(2).
htop says:
PID USER PRI NI VIRT RES SHR S CPU% MEM% TIME+ Command
11266 tomcat 20 0 3746M 169M 21252 S 201. 4.3 7:31.82 /usr/lib/jvm/java-8-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.propert
11283 tomcat 20 0 3746M 169M 21252 R 100. 4.3 3:13.27 /usr/lib/jvm/java-8-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.propert
11285 tomcat 20 0 3746M 169M 21252 R 100. 4.3 3:13.77 /usr/lib/jvm/java-8-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.propert
...and a bunch of 0% threads.
oscar-serv03-[~] root 218 #strace -p 11266
strace: Process 11266 attached
futex(0x7fa28312b9d0, FUTEX_WAIT, 11273, NULL^Cstrace: Process 11266 detached
<detached ...>
oscar-serv03-[~] root 219 #strace -p 11283 2>&1 | sed 10q
strace: Process 11283 attached
sched_yield() = 0
sched_yield() = 0
sched_yield() = 0
sched_yield() = 0
sched_yield() = 0
sched_yield() = 0
sched_yield() = 0
sched_yield() = 0
sched_yield() = 0
...forever...
oscar-serv03-[~] root 220 #strace -p 11285 2>&1 | sed 10q
strace: Process 11285 attached
strace: [ Process PID=11285 runs in x32 mode. ]
^C
I guess some JIT codes to 32-bit rather than amd64 codes?
--
] Never tell me the odds! | ipv6 mesh networks [
] Michael Richardson, Sandelman Software Works | IoT architect [
] mcr@sandelman.ca http://www.sandelman.ca/ | ruby on rails [