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/14 20:05:11 UTC
trying to deploy oscar (was Re: how to tune cacheMaxSize )
<#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: 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