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-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
