Menu
▾
▴
RE: [Wrapper-user] Leif, please read: Tomcat NT JVM hung debug details
|
From: Marsh, R. <ral...@th...> - 2005-04-12 15:07:42
|
Thank you Leif. I'll play with the delay setting. While I try to figure =
out why the JVM keeps dying.
-----Original Message-----
From: wra...@li...
[mailto:wra...@li...]On Behalf Of Leif
Mortenson
Sent: Tuesday, April 12, 2005 12:25 AM
To: wra...@li...
Subject: Re: [Wrapper-user] Leif, please read: Tomcat NT JVM hung debug
details
Ralph,
Big apologies for the lack of a reply. It was unfortunately not=20
just to your questions.
There have been a lot of unanswered questions over the last couple=20
months. It is not
from a lack of interest but simply a complete and total lack of any free =
time as of late.
The Wrapper User mailing list has always consumes up to a couple hours a =
day of my
time. In general I enjoy answering the questions and making the related =
changes to
the Wrapper. But as of late even that time has not been there.
I have been trying to check the list when I have a few minutes and=20
then answer as
many questions, from newest going back, as I have time for. Most likely =
you just never
fell into one of those sessions and got passed over. Sorry about that. =
I understand that
it was probably frustrating. :-/ The goal is to get caught up and once =
again provide
a high level of support, hopefully soon. I know it has also been way=20
too long since
the last release. :-/
Anyway, on to your question.
On some platforms (Solaris) A port will remain bound for around 2=20
minutes after
the application that bound the port shuts down. From my past research=20
this is to
handle any stray packets that may keep coming in from clients.
As Joseph pointed out, this is not something that the Wrapper has=20
any direct
control over. Ideally you would rebind the port rather than doing a=20
simple bind
when the application restarts. This would require you to make some=20
changes to
Tomcat however and is not ideal.
A good workaround is for you to simply prevent the Wrapper from=20
restarting
the JVM so quickly by adding a 2 minute delay between the first JVM =
shutting
down and the new JVM being launched. You can do this with the following
property:
wrapper.restart.delay=3D130
http://wrapper.tanukisoftware.org/doc/english/prop-restart-delay.html
I would suggest waiting slightly longer than the 2 minute bind=20
timeout to make
sure that you don't have any sporadic errors, thus the 130 seconds. =20
You should
play around with the timeout as you may be able to get things working =
with a
shorter delay.
Thanks for the quality of your original question. My bad for not=20
getting around to it.
Cheers,
Leif
Marsh, Ralph wrote:
>Is this a difficult, stupid or uninteresting question I'm asking? I'm =
not accustomed to posting detailed descriptions of problems to lists =
multiple times (this is my 4th posting on this issue) and getting =
absolutely no response.
>
>If there is more detail required please let me know and I'll attempt to =
gather it.=20
>
>I simply need a high level analysis of this situation to determine what =
if any contribution the wrapper has in this situation, either to help or =
to cause it. If it has no potential to cause the problem, I will move =
on. If it can be configured to help the problem please indicate how. =
Thank you.
>
>Ralph
>
>-----Original Message-----
>From: wra...@li...
>[mailto:wra...@li...]On Behalf Of Marsh,
>Ralph
>Sent: Friday, April 01, 2005 3:17 PM
>To: wra...@li...
>Subject: [Wrapper-user] Tomcat NT JVM hung debug details
>
>
>I ran the wrapper with log output set to DEBUG. The logs indicate that =
the wrapper detected what it thought was a hung JVM, attempted to launch =
a new JVM, had a problem binding to port 8081, then shutdown everything. =
This is my recurring problem. I'm including the debug output below. =
Questions:
>
>1) Is it possible the wrapper incorrectly identifies the JVM as hung?
>2) If so, how/why? Is there a timeout setting that can be increased to =
force the wrapper to attempt communication with the JVM longer before =
giving up?
>3) In the log "ERROR | wrapper | 2005/04/01 14:30:08 | Java Virtual =
Machine did not exit on request, terminated" appears. It seems the =
wrapper is attempting to stop that hung JVM before launching a new one. =
Does "terminated" mean the JVM or the wrapper action was terminated? If =
it's the JVM, why is port 8081 not released? If it's the wrapper, why =
can't the JVM be killed?
>4) in general, if the JVM is really hung, what can create this state?
>
>Bottom line: it appears the wrapper is trying to recover a JVM in a bad =
state but it is failing. Are there any configuration settings I can =
modify to help the wrapper successfully recover or initialize a JVM? =
Thanks.
>
>Ralph
>=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
>DEBUG | wrapperp | 2005/04/01 14:29:26 | send a packet PING : ping
>INFO | jvm 1 | 2005/04/01 14:29:26 | Received a packet PING : ping
>INFO | jvm 1 | 2005/04/01 14:29:26 | Send a packet PING : ok
>DEBUG | wrapperp | 2005/04/01 14:29:26 | read a packet PING : ok
>DEBUG | wrapper | 2005/04/01 14:29:26 | Got ping response from JVM
>DEBUG | wrapperp | 2005/04/01 14:29:32 | send a packet PING : ping
>INFO | jvm 1 | 2005/04/01 14:29:32 | Received a packet PING : ping
>INFO | jvm 1 | 2005/04/01 14:29:32 | Send a packet PING : ok
>DEBUG | wrapperp | 2005/04/01 14:29:32 | read a packet PING : ok
>DEBUG | wrapper | 2005/04/01 14:29:32 | Got ping response from JVM
>DEBUG | wrapperp | 2005/04/01 14:29:38 | send a packet PING : ping
>DEBUG | wrapperp | 2005/04/01 14:29:44 | send a packet PING : ping
>DEBUG | wrapperp | 2005/04/01 14:29:50 | send a packet PING : ping
>DEBUG | wrapperp | 2005/04/01 14:29:56 | send a packet PING : ping
>DEBUG | wrapperp | 2005/04/01 14:30:02 | send a packet PING : ping
>ERROR | wrapper | 2005/04/01 14:30:08 | JVM appears hung: Timed out =
waiting for signal from JVM.
>ERROR | wrapper | 2005/04/01 14:30:08 | Java Virtual Machine did not =
exit on request, terminated
>STATUS | wrapper | 2005/04/01 14:30:14 | Launching a JVM...
>DEBUG | wrapper | 2005/04/01 14:30:14 | command: =
"C:\tools\j2sdk1.4.2\bin\java" -server -XX:+UseParNewGC =
-XX:MaxNewSize=3D24m -XX:NewSize=3D24m -XX:SurvivorRatio=3D128 =
-XX:+UseConcMarkSweepGC -XX:MaxTenuringThreshold=3D0 =
-XX:CMSInitiatingOccupancyFraction=3D60 =
-Djava.endorsed.dirs=3D../bin;../common/endorsed -Dcatalina.base=3D.. =
-Dcatalina.home=3D.. -Djava.io.tmpdir=3D../temp -Xms1200m -Xmx1200m =
-Djava.library.path=3D"../common/lib" -classpath =
"../common/lib/wrapper.jar;C:\tools\j2sdk1.4.2/lib/tools.jar;../bin/boots=
trap.jar" -Dwrapper.key=3D"NhcjD9wi11JZ8IY8" -Dwrapper.port=3D32000 =
-Dwrapper.debug=3D"TRUE" -Dwrapper.service=3D"TRUE" =
-Dwrapper.cpu.timeout=3D"10" -Dwrapper.jvmid=3D2 =
org.tanukisoftware.wrapper.WrapperStartStopApp =
org.apache.catalina.startup.Bootstrap 1 start =
org.apache.catalina.startup.Bootstrap true 1 stop
>DEBUG | wrapper | 2005/04/01 14:30:14 | Java Virtual Machine started =
(PID=3D6800)
>INFO | jvm 2 | 2005/04/01 14:30:14 | Wrapper Manager: JVM #2
>INFO | jvm 2 | 2005/04/01 14:30:14 | Wrapper Manager: Registering =
shutdown hook
>INFO | jvm 2 | 2005/04/01 14:30:14 | Wrapper Manager: Using =
wrapper
>INFO | jvm 2 | 2005/04/01 14:30:15 | Calling native initialization =
method.
>DEBUG | wrapper | 2005/04/01 14:30:15 | Pause reading child output to =
share cycles.
>DEBUG | wrapperp | 2005/04/01 14:30:15 | accepted a socket from =
127.0.0.1 on port 2035
>DEBUG | wrapperp | 2005/04/01 14:30:15 | read a packet KEY : =
NhcjD9wi11JZ8IY8
>DEBUG | wrapper | 2005/04/01 14:30:15 | Got key from JVM: =
NhcjD9wi11JZ8IY8
>DEBUG | wrapperp | 2005/04/01 14:30:15 | send a packet LOW_LOG_LEVEL : =
1
>DEBUG | wrapperp | 2005/04/01 14:30:15 | send a packet PING_TIMEOUT : =
30
>DEBUG | wrapper | 2005/04/01 14:30:15 | Pause reading socket data to =
share cycles.
>DEBUG | wrapper | 2005/04/01 14:30:15 | Start Application.
>DEBUG | wrapperp | 2005/04/01 14:30:15 | send a packet START : start
>INFO | jvm 2 | 2005/04/01 14:30:16 | Initializing WrapperManager =
native library.
>INFO | jvm 2 | 2005/04/01 14:30:16 | Java Executable: =
C:\tools\j2sdk1.4.2\bin\java.exe
>INFO | jvm 2 | 2005/04/01 14:30:16 | Java Version : 1.4.2-b28 =
Java HotSpot(TM) Server VM
>DEBUG | wrapper | 2005/04/01 14:30:16 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:16 | Java VM Vendor : Sun =
Microsystems Inc.
>INFO | jvm 2 | 2005/04/01 14:30:16 |=20
>INFO | jvm 2 | 2005/04/01 14:30:16 | Wrapper (Version 3.0.5)
>DEBUG | wrapper | 2005/04/01 14:30:16 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:16 |=20
>INFO | jvm 2 | 2005/04/01 14:30:16 | Open socket to wrapper...
>INFO | jvm 2 | 2005/04/01 14:30:16 | Opened Socket
>DEBUG | wrapper | 2005/04/01 14:30:17 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:17 | Send a packet KEY : =
NhcjD9wi11JZ8IY8
>INFO | jvm 2 | 2005/04/01 14:30:17 | =
handleSocket(Socket[addr=3D/127.0.0.1,port=3D32000,localport=3D2035])
>INFO | jvm 2 | 2005/04/01 14:30:17 | Received a packet =
LOW_LOG_LEVEL : 1
>DEBUG | wrapper | 2005/04/01 14:30:17 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:17 | Wrapper Manager: LowLogLevel =
from Wrapper is 1
>INFO | jvm 2 | 2005/04/01 14:30:17 | Received a packet =
PING_TIMEOUT : 30
>INFO | jvm 2 | 2005/04/01 14:30:17 | Wrapper Manager: PingTimeout =
from Wrapper is 30000
>INFO | jvm 2 | 2005/04/01 14:30:17 | Received a packet START : =
start
>INFO | jvm 2 | 2005/04/01 14:30:17 | calling listener.start()
>INFO | jvm 2 | 2005/04/01 14:30:17 | WrapperStartStopApp: =
start(args)
>INFO | jvm 2 | 2005/04/01 14:30:17 | WrapperStartStopApp: invoking =
start main method
>DEBUG | wrapper | 2005/04/01 14:30:17 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:18 | WrapperStartStopApp: =
start(args) end. Main Completed=3Dfalse, exitCode=3Dnull
>INFO | jvm 2 | 2005/04/01 14:30:18 | returned from =
listener.start()
>INFO | jvm 2 | 2005/04/01 14:30:18 | Send a packet STARTED :=20
>DEBUG | wrapperp | 2005/04/01 14:30:18 | read a packet STARTED :=20
>DEBUG | wrapper | 2005/04/01 14:30:18 | JVM signalled that it was =
started.
>DEBUG | wrapperp | 2005/04/01 14:30:18 | send a packet PING : ping
>INFO | jvm 2 | 2005/04/01 14:30:18 | Received a packet PING : ping
>INFO | jvm 2 | 2005/04/01 14:30:18 | Send a packet PING : ok
>DEBUG | wrapperp | 2005/04/01 14:30:18 | read a packet PING : ok
>DEBUG | wrapper | 2005/04/01 14:30:18 | Got ping response from JVM
>INFO | jvm 2 | 2005/04/01 14:30:20 | StandardEngine[null]: =
setJvmRoute=3Dtr2a
>INFO | jvm 2 | 2005/04/01 14:30:20 | 2005-04-01 14:30:20,671 ERROR =
[] org.apache.coyote.http11.Http11Protocol.init:152 - Error initializing =
endpoint
>INFO | jvm 2 | 2005/04/01 14:30:20 | java.net.BindException: =
Address already in use: JVM_Bind:8081
>INFO | jvm 2 | 2005/04/01 14:30:20 | at =
org.apache.tomcat.util.net.PoolTcpEndpoint.initEndpoint(PoolTcpEndpoint.j=
ava:280)
>INFO | jvm 2 | 2005/04/01 14:30:21 | at =
org.apache.coyote.http11.Http11Protocol.init(Http11Protocol.java:150)
>DEBUG | wrapper | 2005/04/01 14:30:21 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:21 | at =
org.apache.coyote.tomcat4.CoyoteConnector.initialize(CoyoteConnector.java=
:1117)
>INFO | jvm 2 | 2005/04/01 14:30:21 | at =
org.apache.catalina.core.StandardService.initialize(StandardService.java:=
579)
>INFO | jvm 2 | 2005/04/01 14:30:21 | at =
org.apache.catalina.core.StandardServer.initialize(StandardServer.java:22=
46)
>DEBUG | wrapper | 2005/04/01 14:30:21 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:21 | at =
org.apache.catalina.startup.Catalina.start(Catalina.java:511)
>INFO | jvm 2 | 2005/04/01 14:30:21 | at =
org.apache.catalina.startup.Catalina.execute(Catalina.java:400)
>INFO | jvm 2 | 2005/04/01 14:30:21 | at =
org.apache.catalina.startup.Catalina.process(Catalina.java:180)
>DEBUG | wrapper | 2005/04/01 14:30:21 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:22 | at =
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>INFO | jvm 2 | 2005/04/01 14:30:22 | at =
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java=
:39)
>DEBUG | wrapper | 2005/04/01 14:30:22 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:22 | at =
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorI=
mpl.java:25)
>INFO | jvm 2 | 2005/04/01 14:30:22 | at =
java.lang.reflect.Method.invoke(Method.java:324)
>INFO | jvm 2 | 2005/04/01 14:30:22 | at =
org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:203)
>INFO | jvm 2 | 2005/04/01 14:30:22 | at =
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>DEBUG | wrapper | 2005/04/01 14:30:22 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:22 | at =
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java=
:39)
>INFO | jvm 2 | 2005/04/01 14:30:22 | at =
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorI=
mpl.java:25)
>INFO | jvm 2 | 2005/04/01 14:30:22 | at =
java.lang.reflect.Method.invoke(Method.java:324)
>DEBUG | wrapper | 2005/04/01 14:30:22 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:22 | at =
org.tanukisoftware.wrapper.WrapperStartStopApp.run(WrapperStartStopApp.ja=
va:126)
>INFO | jvm 2 | 2005/04/01 14:30:23 | at =
java.lang.Thread.run(Thread.java:534)
>INFO | jvm 2 | 2005/04/01 14:30:23 | Catalina.start: =
LifecycleException: Protocol handler initialization failed: =
java.net.BindException: Address already in use: JVM_Bind:8081
>INFO | jvm 2 | 2005/04/01 14:30:23 | LifecycleException: Protocol =
handler initialization failed: java.net.BindException: Address already =
in use: JVM_Bind:8081
>DEBUG | wrapper | 2005/04/01 14:30:23 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:23 | at =
org.apache.coyote.tomcat4.CoyoteConnector.initialize(CoyoteConnector.java=
:1119)
>INFO | jvm 2 | 2005/04/01 14:30:23 | at =
org.apache.catalina.core.StandardService.initialize(StandardService.java:=
579)
>INFO | jvm 2 | 2005/04/01 14:30:23 | at =
org.apache.catalina.core.StandardServer.initialize(StandardServer.java:22=
46)
>DEBUG | wrapper | 2005/04/01 14:30:23 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:23 | at =
org.apache.catalina.startup.Catalina.start(Catalina.java:511)
>INFO | jvm 2 | 2005/04/01 14:30:23 | at =
org.apache.catalina.startup.Catalina.execute(Catalina.java:400)
>INFO | jvm 2 | 2005/04/01 14:30:23 | at =
org.apache.catalina.startup.Catalina.process(Catalina.java:180)
>DEBUG | wrapper | 2005/04/01 14:30:23 | Pause reading child output to =
share cycles.
>DEBUG | wrapperp | 2005/04/01 14:30:24 | send a packet PING : ping
>INFO | jvm 2 | 2005/04/01 14:30:24 | at =
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>INFO | jvm 2 | 2005/04/01 14:30:24 | at =
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java=
:39)
>INFO | jvm 2 | 2005/04/01 14:30:24 | at =
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorI=
mpl.java:25)
>INFO | jvm 2 | 2005/04/01 14:30:24 | at =
java.lang.reflect.Method.invoke(Method.java:324)
>DEBUG | wrapper | 2005/04/01 14:30:24 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:24 | at =
org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:203)
>INFO | jvm 2 | 2005/04/01 14:30:24 | at =
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>DEBUG | wrapper | 2005/04/01 14:30:24 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:24 | at =
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java=
:39)
>INFO | jvm 2 | 2005/04/01 14:30:25 | at =
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorI=
mpl.java:25)
>DEBUG | wrapper | 2005/04/01 14:30:25 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:25 | at =
java.lang.reflect.Method.invoke(Method.java:324)
>INFO | jvm 2 | 2005/04/01 14:30:25 | at =
org.tanukisoftware.wrapper.WrapperStartStopApp.run(WrapperStartStopApp.ja=
va:126)
>INFO | jvm 2 | 2005/04/01 14:30:25 | at =
java.lang.Thread.run(Thread.java:534)
>DEBUG | wrapper | 2005/04/01 14:30:25 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:25 | Catalina.stop: =
LifecycleException: This server has not yet been started
>INFO | jvm 2 | 2005/04/01 14:30:25 | Received a packet PING : ping
>DEBUG | wrapper | 2005/04/01 14:30:26 | Pause reading child output to =
share cycles.
>DEBUG | wrapperp | 2005/04/01 14:30:26 | read a packet PING : ok
>DEBUG | wrapper | 2005/04/01 14:30:26 | Got ping response from JVM
>DEBUG | wrapper | 2005/04/01 14:30:26 | Pause reading socket data to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:26 | LifecycleException: This =
server has not yet been started
>INFO | jvm 2 | 2005/04/01 14:30:26 | Send a packet PING : ok
>INFO | jvm 2 | 2005/04/01 14:30:26 | at =
org.apache.catalina.core.StandardServer.stop(StandardServer.java:2213)
>DEBUG | wrapper | 2005/04/01 14:30:26 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:26 | at =
org.apache.catalina.startup.Catalina.start(Catalina.java:543)
>INFO | jvm 2 | 2005/04/01 14:30:26 | at =
org.apache.catalina.startup.Catalina.execute(Catalina.java:400)
>INFO | jvm 2 | 2005/04/01 14:30:27 | at =
org.apache.catalina.startup.Catalina.process(Catalina.java:180)
>INFO | jvm 2 | 2005/04/01 14:30:27 | at =
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>INFO | jvm 2 | 2005/04/01 14:30:27 | at =
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java=
:39)
>INFO | jvm 2 | 2005/04/01 14:30:27 | at =
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorI=
mpl.java:25)
>DEBUG | wrapper | 2005/04/01 14:30:27 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:27 | at =
java.lang.reflect.Method.invoke(Method.java:324)
>INFO | jvm 2 | 2005/04/01 14:30:27 | at =
org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:203)
>INFO | jvm 2 | 2005/04/01 14:30:27 | at =
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>INFO | jvm 2 | 2005/04/01 14:30:27 | at =
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java=
:39)
>DEBUG | wrapper | 2005/04/01 14:30:27 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:27 | at =
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorI=
mpl.java:25)
>INFO | jvm 2 | 2005/04/01 14:30:27 | at =
java.lang.reflect.Method.invoke(Method.java:324)
>INFO | jvm 2 | 2005/04/01 14:30:27 | at =
org.tanukisoftware.wrapper.WrapperStartStopApp.run(WrapperStartStopApp.ja=
va:126)
>INFO | jvm 2 | 2005/04/01 14:30:27 | at =
java.lang.Thread.run(Thread.java:534)
>DEBUG | wrapper | 2005/04/01 14:30:27 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:28 | WrapperStartStopApp: start =
main method completed
>DEBUG | wrapperp | 2005/04/01 14:30:30 | send a packet PING : ping
>INFO | jvm 2 | 2005/04/01 14:30:30 | Received a packet PING : ping
>INFO | jvm 2 | 2005/04/01 14:30:30 | Send a packet PING : ok
>INFO | jvm 2 | 2005/04/01 14:30:30 | All non-daemon threads have =
stopped. Exiting.
>DEBUG | wrapper | 2005/04/01 14:30:30 | Pause reading child output to =
share cycles.
>DEBUG | wrapperp | 2005/04/01 14:30:30 | read a packet PING : ok
>DEBUG | wrapper | 2005/04/01 14:30:30 | Got ping response from JVM
>DEBUG | wrapperp | 2005/04/01 14:30:31 | read a packet STOP : 0
>DEBUG | wrapper | 2005/04/01 14:30:31 | JVM requested a shutdown. (0)
>DEBUG | wrapper | 2005/04/01 14:30:31 | wrapperStopProcess(0) called.
>DEBUG | wrapper | 2005/04/01 14:30:31 | Pause reading socket data to =
share cycles.
>DEBUG | wrapper | 2005/04/01 14:30:31 | Sending stop signal to JVM
>DEBUG | wrapperp | 2005/04/01 14:30:31 | send a packet STOP : NULL
>INFO | jvm 2 | 2005/04/01 14:30:31 | Send a packet STOP : 0
>INFO | jvm 2 | 2005/04/01 14:30:31 | Thread, Wrapper-Connection, =
handling the shutdown process.
>INFO | jvm 2 | 2005/04/01 14:30:31 | calling listener.stop()
>DEBUG | wrapper | 2005/04/01 14:30:31 | Pause reading child output to =
share cycles.
>INFO | jvm 2 | 2005/04/01 14:30:32 | WrapperStartStopApp: stop(0)
>INFO | jvm 2 | 2005/04/01 14:30:32 | WrapperStartStopApp: invoking =
stop main method
>INFO | jvm 2 | 2005/04/01 14:30:32 | WrapperStartStopApp: stop =
main method completed
>INFO | jvm 2 | 2005/04/01 14:30:32 | returned from listener.stop()
>DEBUG | wrapper | 2005/04/01 14:30:32 | Pause reading child output to =
share cycles.
>DEBUG | wrapperp | 2005/04/01 14:30:33 | read a packet STOPPED : 0
>DEBUG | wrapper | 2005/04/01 14:30:33 | JVM signalled that it was =
stopped.
>DEBUG | wrapperp | 2005/04/01 14:30:33 | socket read no code =
(closed?).
>INFO | jvm 2 | 2005/04/01 14:30:33 | Send a packet STOPPED : 0
>INFO | jvm 2 | 2005/04/01 14:30:33 | Closing socket.
>INFO | jvm 2 | 2005/04/01 14:30:33 | calling System.exit(0)
>DEBUG | wrapper | 2005/04/01 14:30:35 | JVM exited normally.
>STATUS | wrapper | 2005/04/01 14:30:35 | <-- Wrapper Stopped
> =20
>
>> -----Original Message-----
>>From: Marsh, Ralph =20
>>Sent: Friday, March 11, 2005 8:04 AM
>>To: 'wra...@li...'
>>Subject: RE: Tomcat NT JVM hung
>>
>>Any suggestions in beginning to diagnose our problem would be =
appreciated. Thank you.
>>
>> -----Original Message-----
>> From: Marsh, Ralph =20
>> Sent: Thursday, March 03, 2005 4:18 PM
>> To: 'wra...@li...'
>> Subject: Tomcat NT JVM hung
>>
>> We are running a Struts web app on Tomcat 4.1. We use the wrapper to =
run Tomcat as a service.
>>
>> Over the past 8 months, about once per month, the service has died. =
Within the past month the frequency of these events has gone up to about =
once per week.=20
>>
>> This leaves the web app dead in the water, the user receiving HTTP =
500 errors and us logging into the NT box and manually restarting the =
service. We have the wrapper.conf file set to output STATUS level =
messages to the log. In the log we see this:
>>
>> ERROR | wrapper | 2005/03/03 17:58:43 | JVM appears hung: Timed out =
waiting for signal from JVM.
>> ERROR | wrapper | 2005/03/03 17:58:43 | Java Virtual Machine did =
not exit on request, terminated
>> STATUS | wrapper | 2005/03/03 17:58:49 | Launching a JVM...>=20
>> STATUS | wrapper | 2005/03/03 17:59:03 | <-- Wrapper Stopped
>>
>> I have four questions:
>> 1) what can cause a JVM backing Tomcat to hang?
>> 2) how should I configure the wrapper to get the most useful logging =
information during these events? Running in DEBUG for a week/weeks will =
produce copious logs. If necessary, I'll do it, but is it necessary?
>> 3) isn't the wrapper supposed to recognize these hangs, gracefully =
kill the process then restart a new process? If so, what should I look =
at to determine why this is not happening in our case
>> 4) in the log output above what is going on between the third and =
forth entry? It appears a new JVM is launching then the wrapper stops =
everything. Why?
>>
>> Our complete wrapper.conf file is included below. Thank you.
>>
>> Ralph Marsh
>>
>> #********************************************************************
>> # Wrapper Properties
>> #********************************************************************
>> # Java Application
>> wrapper.java.command=3D%java_home%\bin\java
>>
>> # Java Main class. This class must implement the WrapperListener =
interface
>> # or guarantee that the WrapperManager class is initialized. Helper
>> # classes are provided to do this for you. See the Integration =
section
>> # of the documentation for details.
>> =
wrapper.java.mainclass=3Dorg.tanukisoftware.wrapper.WrapperStartStopApp
>>
>> # Java Classpath (include wrapper.jar) Add class path elements as
>> # needed starting from 1
>> wrapper.java.classpath.1=3D../common/lib/wrapper.jar
>> wrapper.java.classpath.2=3D%java_home%/lib/tools.jar
>> wrapper.java.classpath.3=3D../bin/bootstrap.jar
>>
>> # Java Library Path (location of Wrapper.DLL or libwrapper.so)
>> wrapper.java.library.path.1=3D../common/lib
>>
>> # Java Additional Parameters
>> wrapper.java.additional.1=3D-server
>> wrapper.java.additional.2=3D-XX:+UseParNewGC
>> wrapper.java.additional.3=3D-XX:MaxNewSize=3D24m
>> wrapper.java.additional.4=3D-XX:NewSize=3D24m
>> wrapper.java.additional.5=3D-XX:SurvivorRatio=3D128
>> wrapper.java.additional.6=3D-XX:+UseConcMarkSweepGC
>> wrapper.java.additional.7=3D-XX:MaxTenuringThreshold=3D0
>> wrapper.java.additional.8=3D-XX:CMSInitiatingOccupancyFraction=3D60
>> =
wrapper.java.additional.9=3D-Djava.endorsed.dirs=3D../bin;../common/endor=
sed
>> wrapper.java.additional.10=3D-Dcatalina.base=3D..
>> wrapper.java.additional.11=3D-Dcatalina.home=3D..
>> wrapper.java.additional.12=3D-Djava.io.tmpdir=3D../temp
>> =20
>> #wrapper.java.additional.13=3D-verbosegc
>> #wrapper.java.additional.14=3D-XX:+PrintGCTimeStamps
>> #wrapper.java.additional.15=3D-XX:+PrintGCDetails
>> #wrapper.java.additional.13=3D-XX:+PrintTenuringDistribution
>>
>>
>> #wrapper.java.additional.7=3D-verbosegc
>>
>> # Initial Java Heap Size (in MB)
>> wrapper.java.initmemory=3D1200
>>
>> # Maximum Java Heap Size (in MB)
>> wrapper.java.maxmemory=3D1200
>>
>> # Application parameters. Add parameters as needed starting from 1
>>
>> # The first application parameter is the name of the class whose main
>> # method is to be called when the application is launched. The class
>> # name is followed by the number of parameters to be passed to its =
main
>> # method. Then comes the actual parameters.
>> wrapper.app.parameter.1=3Dorg.apache.catalina.startup.Bootstrap
>> wrapper.app.parameter.2=3D1
>> wrapper.app.parameter.3=3Dstart
>>
>> # The start parameters are followed by the name of the class whose =
main
>> # method is to be called to stop the application. The stop class =
name
>> # is followed by a flag which controls whether or not the Wrapper =
should
>> # wait for all non daemon threads to complete before exiting the JVM.
>> # The flag is followed by the number of parameters to be passed to =
the
>> # stop class's main method. Finally comes the actual parameters.
>> wrapper.app.parameter.4=3Dorg.apache.catalina.startup.Bootstrap
>> wrapper.app.parameter.5=3Dtrue
>> wrapper.app.parameter.6=3D1
>> wrapper.app.parameter.7=3Dstop
>>
>> #********************************************************************
>> # Wrapper Logging Properties
>> #********************************************************************
>> # Format of output for the console. (See docs for formats)
>> wrapper.console.format=3DPM
>>
>> # Log Level for console output. (See docs for log levels)
>> wrapper.console.loglevel=3DINFO
>>
>> # Log file to use for wrapper output logging.
>> wrapper.logfile=3D../logs/wrapper.log
>>
>> # Format of output for the log file. (See docs for formats)
>> wrapper.logfile.format=3DLPTM
>>
>> # Log Level for log file output. (See docs for log levels)
>> wrapper.logfile.loglevel=3DSTATUS
>>
>> # Maximum size that the log file will be allowed to grow to before
>> # the log is rolled. Size is specified in bytes. The default value
>> # of 0, disables log rolling. May abbreviate with the 'k' (kb) or
>> # 'm' (mb) suffix. For example: 10m =3D 10 megabytes.
>> wrapper.logfile.maxsize=3D500k
>>
>> # Maximum number of rolled log files which will be allowed before old
>> # files are deleted. The default value of 0 implies no limit.
>> wrapper.logfile.maxfiles=3D0
>>
>> # Log Level for sys/event log output. (See docs for log levels)
>> wrapper.syslog.loglevel=3DNONE
>>
>> #********************************************************************
>> # Wrapper NT Service Properties
>> #********************************************************************
>> # WARNING - Do not modify any of these properties when an application
>> # using this configuration file has been installed as a service.
>> # Please uninstall the service before modifying this section. The
>> # service can then be reinstalled.
>>
>> # Name of the service
>> wrapper.ntservice.name=3Dtomcat-rights2a
>>
>> # Display name of the service
>> wrapper.ntservice.displayname=3Dtomcat-rights2a
>>
>> # Description of the service
>> wrapper.ntservice.description=3Dtomcat-rights2a
>>
>> # Service dependencies. Add dependencies as needed starting from 1
>> wrapper.ntservice.dependency.1=3D
>>
>> # Mode in which the service is installed. AUTO_START or DEMAND_START
>> wrapper.ntservice.starttype=3DAUTO_START
>>
>> # Allow the service to interact with the desktop.
>> wrapper.ntservice.interactive=3Dfalse
>>
>> =20
>>
-------------------------------------------------------
SF email is sponsored by - The IT Product Guide
Read honest & candid reviews on hundreds of IT Products from real users.
Discover which products truly live up to the hype. Start reading now.
http://ads.osdn.com/?ad_id=3D6595&alloc_id=3D14396&op=3Dclick
_______________________________________________
Wrapper-user mailing list
Wra...@li...
https://lists.sourceforge.net/lists/listinfo/wrapper-user
|
