FS#33372 - [tomcat7] systemd service starting problems

Attached to Project: Arch Linux
Opened by Aleksey Ilyin (darkgin) - Saturday, 12 January 2013, 12:35 GMT
Last edited by Guillaume ALAUX (galaux) - Thursday, 21 February 2013, 19:44 GMT
Task Type Bug Report
Category Packages: Extra
Status Closed
Assigned To Guillaume ALAUX (galaux)
Architecture All
Severity Low
Priority Normal
Reported Version
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 2
Private No

Details

tomcat7 is very unstable in starting service (systemd). After reboot is starts with out problems in my case 50/50... I can stop running service and then start after 3-5 attempts (systemctl start tomcat7).
Here is an example output:

[root@arch-tomcat ~]# systemctl status tomcat7
tomcat7.service - Tomcat 7 servlet container
Loaded: loaded (/usr/lib/systemd/system/tomcat7.service; enabled)
Active: active (running) since Пт, 2013-01-11 13:34:53 MSK; 1 day and 2h ago
Process: 443 ExecStop=/usr/bin/jsvc -pidfile /var/run/tomcat7.pid -stop org.apache.catalina.startup.Bootstrap (code=exited, status=0/SUCCESS)
Process: 615 ExecStart=/usr/bin/jsvc -Dcatalina.home=${CATALINA_HOME} -Dcatalina.base=${CATALINA_BASE} -Djava.io.tmpdir=/var/tmp/tomcat7/temp -cp /usr/share/java/commons-daemon.jar:/usr/share/java/eclipse-ecj.jar:${CATALINA_HOME}/bin/bootstrap.jar:${CATALINA_HOME}/bin/tomcat-juli.jar -user tomcat -java-home ${TOMCAT_JAVA_HOME} -wait 10 -pidfile /var/run/tomcat7.pid -errfile /var/log/tomcat7/catalina.err -outfile /var/log/tomcat7/catalina.out $CATALINA_OPTS org.apache.catalina.startup.Bootstrap (code=exited, status=0/SUCCESS)
Main PID: 619 (jsvc)
CGroup: name=systemd:/system/tomcat7.service
├─618 jsvc.exec -Dcatalina.home=/usr/share/tomcat7 -Dcatalina.base=/usr/share/tomcat7 -Djava.io.tmpdir=/var/tmp/tomcat7/temp -cp /usr/share/java/commons-daemon.jar:/usr/share/j...
└─619 jsvc.exec -Dcatalina.home=/usr/share/tomcat7 -Dcatalina.base=/usr/share/tomcat7 -Djava.io.tmpdir=/var/tmp/tomcat7/temp -cp /usr/share/java/commons-daemon.jar:/usr/share/j...

янв 11 13:34:50 arch-tomcat systemd[1]: Starting Tomcat 7 servlet container...
янв 11 13:34:53 arch-tomcat systemd[1]: Started Tomcat 7 servlet container.
[root@arch-tomcat ~]# systemctl restart tomcat7
Job for tomcat7.service failed. See 'systemctl status tomcat7.service' and 'journalctl -xn' for details.
[root@arch-tomcat ~]# systemctl status tomcat7
tomcat7.service - Tomcat 7 servlet container
Loaded: loaded (/usr/lib/systemd/system/tomcat7.service; enabled)
Active: failed (Result: exit-code) since Сб, 2013-01-12 16:12:45 MSK; 3s ago
Process: 969 ExecStop=/usr/bin/jsvc -pidfile /var/run/tomcat7.pid -stop org.apache.catalina.startup.Bootstrap (code=exited, status=0/SUCCESS)
Process: 976 ExecStart=/usr/bin/jsvc -Dcatalina.home=${CATALINA_HOME} -Dcatalina.base=${CATALINA_BASE} -Djava.io.tmpdir=/var/tmp/tomcat7/temp -cp /usr/share/java/commons-daemon.jar:/usr/share/java/eclipse-ecj.jar:${CATALINA_HOME}/bin/bootstrap.jar:${CATALINA_HOME}/bin/tomcat-juli.jar -user tomcat -java-home ${TOMCAT_JAVA_HOME} -wait 10 -pidfile /var/run/tomcat7.pid -errfile /var/log/tomcat7/catalina.err -outfile /var/log/tomcat7/catalina.out $CATALINA_OPTS org.apache.catalina.startup.Bootstrap (code=exited, status=1/FAILURE)
Main PID: 619
CGroup: name=systemd:/system/tomcat7.service

янв 12 16:12:25 arch-tomcat systemd[1]: Starting Tomcat 7 servlet container...
янв 12 16:12:45 arch-tomcat systemd[1]: Failed to start Tomcat 7 servlet container.
янв 12 16:12:45 arch-tomcat systemd[1]: Unit tomcat7.service entered failed state
[root@arch-tomcat ~]# systemctl restart tomcat7
Job for tomcat7.service failed. See 'systemctl status tomcat7.service' and 'journalctl -xn' for details.
[root@arch-tomcat ~]# systemctl start tomcat7
Job for tomcat7.service failed. See 'systemctl status tomcat7.service' and 'journalctl -xn' for details.
[root@arch-tomcat ~]# systemctl start tomcat7
Job for tomcat7.service failed. See 'systemctl status tomcat7.service' and 'journalctl -xn' for details.
[root@arch-tomcat ~]# systemctl start tomcat7
Job for tomcat7.service failed. See 'systemctl status tomcat7.service' and 'journalctl -xn' for details.
[root@arch-tomcat tomcat7]# systemctl start tomcat7
[root@arch-tomcat tomcat7]# systemctl status tomcat7
tomcat7.service - Tomcat 7 servlet container
Loaded: loaded (/usr/lib/systemd/system/tomcat7.service; enabled)
Active: active (running) since Сб, 2013-01-12 16:22:10 MSK; 17s ago
Process: 969 ExecStop=/usr/bin/jsvc -pidfile /var/run/tomcat7.pid -stop org.apache.catalina.startup.Bootstrap (code=exited, status=0/SUCCESS)
Process: 1244 ExecStart=/usr/bin/jsvc -Dcatalina.home=${CATALINA_HOME} -Dcatalina.base=${CATALINA_BASE} -Djava.io.tmpdir=/var/tmp/tomcat7/temp -cp /usr/share/java/commons-daemon.jar:/usr/share/java/eclipse-ecj.jar:${CATALINA_HOME}/bin/bootstrap.jar:${CATALINA_HOME}/bin/tomcat-juli.jar -user tomcat -java-home ${TOMCAT_JAVA_HOME} -wait 10 -pidfile /var/run/tomcat7.pid -errfile /var/log/tomcat7/catalina.err -outfile /var/log/tomcat7/catalina.out $CATALINA_OPTS org.apache.catalina.startup.Bootstrap (code=exited, status=0/SUCCESS)
Main PID: 1248 (jsvc)
CGroup: name=systemd:/system/tomcat7.service
├─1247 jsvc.exec -Dcatalina.home=/usr/share/tomcat7 -Dcatalina.base=/usr/share/tomcat7 -Djava.io.tmpdir=/var/tmp/tomcat7/temp -cp /usr/share/java/commons-daemon.jar:/usr/share/...
└─1248 jsvc.exec -Dcatalina.home=/usr/share/tomcat7 -Dcatalina.base=/usr/share/tomcat7 -Djava.io.tmpdir=/var/tmp/tomcat7/temp -cp /usr/share/java/commons-daemon.jar:/usr/share/...

янв 12 16:22:07 arch-tomcat systemd[1]: Starting Tomcat 7 servlet container...
янв 12 16:22:10 arch-tomcat systemd[1]: Started Tomcat 7 servlet container.

and it finally started after few attempts.

Any one has some kind of problem?
PS: in catalina.err i have something like this(on fails):

INFO: Starting Servlet Engine: Apache Tomcat/7.0.34
янв 12, 2013 4:20:59 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive /var/lib/tomcat7/webapps/ROOT.war
янв 12, 2013 4:21:00 PM oc.cms.ContextListener contextInitialized
INFO: ContextListener::contextInitialized
Service exit with a return value of 143

tomcat6 works perfect.
This task depends upon

Closed by  Guillaume ALAUX (galaux)
Thursday, 21 February 2013, 19:44 GMT
Reason for closing:  Fixed
Additional comments about closing:  Fixed in 7.0.37-1
Comment by Aleksey Ilyin (darkgin) - Saturday, 12 January 2013, 12:39 GMT
Apache Tomcat/7.0.34 (the same situation was some previous versions)
Comment by Peter Mitchell (peppa) - Friday, 18 January 2013, 19:47 GMT
I have noticed this as well. I suspect the cause may be the service timing out because of a 10 second timeout set in the systemd service configuration file, however I haven't had the chance to investigate exactly why it occasionally times out. It seems a fix could be to simply remove the timeout parameter (-wait 10) from the service configuration file.
Comment by Aleksey Ilyin (darkgin) - Saturday, 19 January 2013, 13:07 GMT
Here is a discussion on similar problem https://bbs.archlinux.org/viewtopic.php?id=154099
Comment by Peter Mitchell (peppa) - Sunday, 20 January 2013, 13:35 GMT
It appears this problem does indeed stem from the jsvc 10 second timeout setting (it will actually wait for 20 seconds due to an implementation detail in jsvc). Tomcat will generate a session identifier on startup using SecureRandom, which can be a slow operation depending on available entropy. If startup takes longer than 20 seconds, the jsvc process will send a SIGTERM to it's Tomcat child process, which in turn will return with an exit status of 143, and systemd reporting the service failed.

This could be fixed by either removing the wait parameter from the systemd configuration file (in which case the service would be running successfully as far as systemd is concerned regardless of the actual status of Tomcat), or increase it's value to something sufficiently large to allow SecureRandom enough time to collect entropy for number generation (or possibly to give slow starting servlets more time to start up).
Comment by Guillaume ALAUX (galaux) - Tuesday, 22 January 2013, 09:19 GMT
Aleksey: could you please try what Peter suggests and report back if it solves your issue?

To do so you could just:
cp /lib/systemd/system/tomcat7.service /etc/systemd/system/

Then edit /etc/systemd/system/tomcat7.service to remove the "-wait 10" line. You may need to reload daemon service files with this:
systemctl --system daemon-reload

Thanks
Comment by Aleksey Ilyin (darkgin) - Tuesday, 22 January 2013, 09:37 GMT
Guillaume, just have tried. It seems to work fine. Many starts\stops, restart work fine after removing "wait".
I noticed some lines in the log:

[root@arch-tomcat tomcat7]# grep SecureRandom catalina.err
янв 11, 2013 1:33:46 PM org.apache.catalina.util.SessionIdGenerator createSecureRandom
INFO: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [17,938] milliseconds.
янв 22, 2013 1:27:09 PM org.apache.catalina.util.SessionIdGenerator createSecureRandom
INFO: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [23,570] milliseconds.
янв 22, 2013 1:31:28 PM org.apache.catalina.util.SessionIdGenerator createSecureRandom
INFO: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [22,792] milliseconds.

So for me generation of SecureRandom takes about 20 seconds, exactly what Peter was talking about.
Comment by Guillaume ALAUX (galaux) - Tuesday, 22 January 2013, 09:47 GMT
All right! It sounds fair to get rid of this param as the timeout definitly depends on the user's webapps and server.
I will fix it but it should only come with the next tomcat6 and tomcat7 Arch packages.
Comment by Aleksey Ilyin (darkgin) - Tuesday, 22 January 2013, 10:04 GMT
offtopic: Is there any way to prevent tomcat7 overwriting /var/lib/tomcat7/webapps/ROOT folder after each update? I have to delete it every update and redeploy ROOT.war.
Comment by Guillaume ALAUX (galaux) - Thursday, 21 February 2013, 14:36 GMT
Sorry: did not see your comment.

ROOT.war? I assume this is one of your war: you should not put it here. You should NOT touch anything in dir ROOT. Just in case you did this so that your tomcat could serve your app as the root of your domain (ie "http://example.com/") then you just need to put your war in the webapps dir and use an empty "path" as context as explained here http://tomcat.apache.org/tomcat-7.0-doc/config/context.html#Context_Parameters

Loading...