|
From: Ramakrishna Bv S. <ram...@in...> - 2008-02-11 05:19:35
|
Hi Leif Mortenson,
Thank you for quick response. Please check my answers in Blue for the
questions.
Please find the attachment for the log.
(See attached file: wrapperLog.txt)
I have checked the logs on other days as well , this issue is occuring but
for the recovery time is less, please check the log below:
INFO | jvm 9 | 2008/02/10 01:28:46 | Send a packet PING : ok
DEBUG | wrapperp | 2008/02/10 01:28:46 | read a packet PING : ok
DEBUG | wrapper | 2008/02/10 01:28:46 | Got ping response from JVM
DEBUG | wrapperp | 2008/02/10 01:28:50 | send a packet PING : ping
INFO | jvm 9 | 2008/02/10 01:28:50 | Received a packet PING : ping
INFO | jvm 9 | 2008/02/10 01:28:50 | Send a packet PING : ok
DEBUG | wrapperp | 2008/02/10 01:28:50 | read a packet PING : ok
DEBUG | wrapper | 2008/02/10 01:28:50 | Got ping response from JVM
DEBUG | wrapperp | 2008/02/10 01:28:54 | send a packet PING : ping
DEBUG | wrapper | 2008/02/10 01:29:25 | ServiceControlHandler(4)
DEBUG | wrapperp | 2008/02/10 01:29:25 | send a packet
SERVICE_CONTROL_CODE : 4
DEBUG | wrapperp | 2008/02/10 01:29:25 | socket send failed. (10053)
DEBUG | wrapper | 2008/02/10 01:29:25 | SERVICE_CONTROL_INTERROGATE
INFO | jvm 9 | 2008/02/10 01:29:25 | Read Timed out. (Last Ping was
30300 milliseconds ago)
INFO | jvm 9 | 2008/02/10 01:29:25 | Wrapper Manager: The Wrapper code
did not ping the JVM for 30 seconds. Quit and let the Wrapper resynch.
INFO | jvm 9 | 2008/02/10 01:29:25 | Send a packet RESTART : restart
INFO | jvm 9 | 2008/02/10 01:29:25 | Thread, Wrapper-Connection,
handling the shutdown process.
INFO | jvm 9 | 2008/02/10 01:29:25 | calling listener.stop()
INFO | jvm 9 | 2008/02/10 01:29:25 | Waiting for WrapperListener.stop
runner thread to complete.
INFO | jvm 9 | 2008/02/10 01:29:25 | WrapperListener.stop runner
thread started.
INFO | jvm 9 | 2008/02/10 01:29:25 | WrapperSimpleApp: stop(1)
INFO | jvm 9 | 2008/02/10 01:29:25 | WrapperListener.stop runner
thread stopped.
INFO | jvm 9 | 2008/02/10 01:29:25 | returned from listener.stop() ->
1
INFO | jvm 9 | 2008/02/10 01:29:25 | shutdownJVM(1)
Thread:Wrapper-Connection
INFO | jvm 9 | 2008/02/10 01:29:25 | Send a packet STOPPED : 1
INFO | jvm 9 | 2008/02/10 01:29:25 | Closing socket.
INFO | jvm 9 | 2008/02/10 01:29:25 | calling System.exit(1)
INFO | jvm 9 | 2008/02/10 01:29:25 | 2008-02-10 01:29:23,188
|INFO|SequencerTool|shutting down
INFO | jvm 9 | 2008/02/10 01:29:25 | 2008-02-10 01:29:23,266
|INFO|SequencerTool|ok.
INFO | jvm 9 | 2008/02/10 01:29:25 | 2008-02-10 01:29:23,266
|INFO|SequencerTool|stopped.
DEBUG | wrapperp | 2008/02/10 01:29:25 | server listening on port 32002.
INFO | wrapper | 2008/02/10 01:29:25 | Wrapper Process has not received
any CPU time for 30 seconds. Extending timeouts.
DEBUG | wrapper | 2008/02/10 01:29:25 | JVM process exited with a code of
1, setting the wrapper exit code to 1.
ERROR | wrapper | 2008/02/10 01:29:25 | JVM exited unexpectedly.
DEBUG | wrapper | 2008/02/10 01:29:25 | ServiceControlHandler(4)
DEBUG | wrapperp | 2008/02/10 01:29:25 | socket not open, so packet not
sent SERVICE_CONTROL_CODE : 4
DEBUG | wrapper | 2008/02/10 01:29:25 | SERVICE_CONTROL_INTERROGATE
DEBUG | wrapper | 2008/02/10 01:29:25 | Waiting 5 seconds before
launching another JVM.
DEBUG | wrapper | 2008/02/10 01:29:29 | Classpath element,
wrapper.java.classpath.10, does not exist: ../classes
STATUS | wrapper | 2008/02/10 01:29:29 | Launching a JVM...
_________________________________________________________________________________________________
INFO | jvm 7 | 2008/02/06 02:31:49 | Received a packet
SERVICE_CONTROL_CODE : 4
INFO | jvm 7 | 2008/02/06 02:31:49 | ServiceControlCode from Wrapper
with code 4
DEBUG | wrapperp | 2008/02/06 02:31:49 | send a packet PING : ping
INFO | jvm 7 | 2008/02/06 02:31:49 | Received a packet PING : ping
INFO | jvm 7 | 2008/02/06 02:31:49 | Send a packet PING : ok
DEBUG | wrapperp | 2008/02/06 02:31:50 | read a packet PING : ok
DEBUG | wrapper | 2008/02/06 02:31:50 | Got ping response from JVM
DEBUG | wrapperp | 2008/02/06 02:31:54 | send a packet PING : ping
INFO | jvm 7 | 2008/02/06 02:31:54 | Received a packet PING : ping
INFO | jvm 7 | 2008/02/06 02:31:54 | Send a packet PING : ok
DEBUG | wrapperp | 2008/02/06 02:31:54 | read a packet PING : ok
DEBUG | wrapper | 2008/02/06 02:31:54 | Got ping response from JVM
DEBUG | wrapperp | 2008/02/06 02:31:58 | send a packet PING : ping
DEBUG | wrapper | 2008/02/06 02:32:50 | ServiceControlHandler(4)
DEBUG | wrapperp | 2008/02/06 02:32:50 | send a packet
SERVICE_CONTROL_CODE : 4
DEBUG | wrapperp | 2008/02/06 02:32:50 | socket send failed. (10053)
DEBUG | wrapper | 2008/02/06 02:32:50 | SERVICE_CONTROL_INTERROGATE
DEBUG | wrapper | 2008/02/06 02:32:50 | ServiceControlHandler(4)
DEBUG | wrapperp | 2008/02/06 02:32:50 | socket not open, so packet not
sent SERVICE_CONTROL_CODE : 4
DEBUG | wrapper | 2008/02/06 02:32:50 | SERVICE_CONTROL_INTERROGATE
INFO | jvm 7 | 2008/02/06 02:32:50 | Read Timed out. (Last Ping was
30400 milliseconds ago)
INFO | jvm 7 | 2008/02/06 02:32:50 | Wrapper Manager: The Wrapper code
did not ping the JVM for 30 seconds. Quit and let the Wrapper resynch.
INFO | jvm 7 | 2008/02/06 02:32:50 | Send a packet RESTART : restart
INFO | jvm 7 | 2008/02/06 02:32:50 | Thread, Wrapper-Connection,
handling the shutdown process.
INFO | jvm 7 | 2008/02/06 02:32:50 | calling listener.stop()
INFO | jvm 7 | 2008/02/06 02:32:50 | Waiting for WrapperListener.stop
runner thread to complete.
INFO | jvm 7 | 2008/02/06 02:32:50 | WrapperListener.stop runner
thread started.
INFO | jvm 7 | 2008/02/06 02:32:50 | WrapperSimpleApp: stop(1)
INFO | jvm 7 | 2008/02/06 02:32:50 | WrapperListener.stop runner
thread stopped.
INFO | jvm 7 | 2008/02/06 02:32:50 | returned from listener.stop() ->
1
INFO | jvm 7 | 2008/02/06 02:32:50 | shutdownJVM(1)
Thread:Wrapper-Connection
INFO | jvm 7 | 2008/02/06 02:32:50 | Send a packet STOPPED : 1
INFO | jvm 7 | 2008/02/06 02:32:50 | Closing socket.
INFO | jvm 7 | 2008/02/06 02:32:50 | calling System.exit(1)
INFO | jvm 7 | 2008/02/06 02:32:50 | 2008-02-06 02:32:26,750
|INFO|SequencerTool|shutting down
DEBUG | wrapperp | 2008/02/06 02:32:50 | server listening on port 32002.
INFO | wrapper | 2008/02/06 02:32:50 | Wrapper Process has not received
any CPU time for 51 seconds. Extending timeouts.
DEBUG | wrapper | 2008/02/06 02:32:50 | JVM process exited with a code of
1, setting the wrapper exit code to 1.
ERROR | wrapper | 2008/02/06 02:32:50 | JVM exited unexpectedly.
DEBUG | wrapper | 2008/02/06 02:32:50 | Waiting 5 seconds before
launching another JVM.
DEBUG | wrapper | 2008/02/06 02:32:54 | Classpath element,
wrapper.java.classpath.10, does not exist: ../classes
STATUS | wrapper | 2008/02/06 02:32:54 | Launching a JVM...
Best Regards,
Ram
IBM Global Services India Pvt. Ltd.
Mindspace, Survey No 64, APIIC Software Layout,
Hi-tech City, Hyderabad -500 081
INDIA
Phone: +91-40-66956756
Leif Mortenson
<leif@tanukisoftw
are.com> To
Sent by: wra...@li...
wrapper-user-boun cc
ce...@li...
orge.net Subject
Re: [Wrapper-user] Issue with
wrapper
02/08/2008 01:17
PM
Please respond to
wrapper-user@list
s.sourceforge.net
Ramakrishna,
According to the log, the backend socket between the Wrapper and
Java process was somehow closed. The Wrapper is failing saying
that it can no longer communicate with the JVM. It keeps going
though because the JVM process is still running.
The JVM then gives up after around 30 seconds because it has not
received any communications from the Wrapper for that long. This
is a safety feature to shut the JVM process down just in case the
Wrapper process should ever crash.
Once the Wrapper detects that the JVM is shutdown, it is correctly
restarting the JVM.
The question is why is the backend socket being closed? This is not
a problem I have ever seen or heard of in the past. Is anything else
in the log file earlier than what you sent?
How easy is this to reproduce?
A: We cannot reproduce.
Does it always happen at the same time?
A: No,it does not happen at the sametime.
Is it possible that some other application on your system is closing
the socket?
A:Can't say whether someother application on the system might be trying to
close the socket.Another two applications are running on the same machine
with wrapper having same configuration.
Is your system under load at the time of this reset?
A: Yes, it was under load.
Does your Java application respond during the 30 seconds between
the socket being closed and the JVM shutting itself down?
A: Can't answer
Cheers,
Leif
Ramakrishna Bv Sanku wrote:
>
> Hi All,
>
> I came across a issue with wrapper, the Wrapper is getting degraded
> for sometime and getting into normal state after some time. Please
> check the wrapper log below.
>
> Can anyone help me and provide a solution, how can this be rectified.
>
> *Information from the wrapper log*
> WrapperManager class initialized by thread: main Using classloader:
> sun.misc.Launcher$AppClassLoader@27e3570f
> ...............
> Wrapper (Version 3.2.3) http://wrapper.tanukisoftware.org
> ...............
>
> Extract from wrapper log
>
> DEBUG | wrapper | 2008/02/08 01:40:42 | ServiceControlHandler(4)
> DEBUG | wrapperp | 2008/02/08 01:40:42 | send a packet
> SERVICE_CONTROL_CODE : 4
> DEBUG | wrapperp | 2008/02/08 01:40:42 | socket send failed. (10053)
> DEBUG | wrapper | 2008/02/08 01:40:42 | SERVICE_CONTROL_INTERROGATE
> DEBUG | wrapper | 2008/02/08 01:40:42 | ServiceControlHandler(4)
> DEBUG | wrapperp | 2008/02/08 01:40:42 | socket not open, so packet
> not sent SERVICE_CONTROL_CODE : 4
> DEBUG | wrapper | 2008/02/08 01:40:42 | SERVICE_CONTROL_INTERROGATE
> INFO | jvm 8 | 2008/02/08 01:40:42 | Read Timed out. (Last Ping
> was 30600 milliseconds ago)
> INFO | jvm 8 | 2008/02/08 01:40:42 | Wrapper Manager: The Wrapper
> code did not ping the JVM for 30 seconds. Quit and let the Wrapper
> resynch.
> INFO | jvm 8 | 2008/02/08 01:40:42 | Send a packet RESTART : restart
> INFO | jvm 8 | 2008/02/08 01:40:42 | Thread, Wrapper-Connection,
> handling the shutdown process.
> INFO | jvm 8 | 2008/02/08 01:40:42 | calling listener.stop()
> INFO | jvm 8 | 2008/02/08 01:40:42 | Waiting for
> WrapperListener.stop runner thread to complete.
> INFO | jvm 8 | 2008/02/08 01:40:42 | WrapperListener.stop runner
> thread started.
> INFO | jvm 8 | 2008/02/08 01:40:42 | WrapperSimpleApp: stop(1)
> INFO | jvm 8 | 2008/02/08 01:40:42 | WrapperListener.stop runner
> thread stopped.
> INFO | jvm 8 | 2008/02/08 01:40:42 | returned from
> listener.stop() -> 1
> INFO | jvm 8 | 2008/02/08 01:40:42 | shutdownJVM(1)
> Thread:Wrapper-Connection
> INFO | jvm 8 | 2008/02/08 01:40:42 | Send a packet STOPPED : 1
> INFO | jvm 8 | 2008/02/08 01:40:42 | Closing socket.
> INFO | jvm 8 | 2008/02/08 01:40:42 | calling System.exit(1)
> INFO | jvm 8 | 2008/02/08 01:40:42 | 2008-02-08
> 01:40:22,031|INFO|SequencerTool|shutting down
> DEBUG | wrapperp | 2008/02/08 01:40:42 | server listening on port 32002.
> DEBUG | wrapper | 2008/02/08 01:40:42 | ServiceControlHandler(4)
> DEBUG | wrapperp | 2008/02/08 01:40:42 | socket not open, so packet
> not sent SERVICE_CONTROL_CODE : 4
> DEBUG | wrapper | 2008/02/08 01:40:42 | SERVICE_CONTROL_INTERROGATE
> INFO | wrapper | 2008/02/08 01:40:42 | Wrapper Process has not
> received any CPU time for 48 seconds. Extending timeouts.
> DEBUG | wrapper | 2008/02/08 01:40:42 | JVM process exited with a
> code of 1, setting the wrapper exit code to 1.
> ERROR | wrapper | 2008/02/08 01:40:42 | JVM exited unexpectedly.
> DEBUG | wrapper | 2008/02/08 01:40:42 | Waiting 5 seconds before
> launching another JVM.
> DEBUG | wrapper | 2008/02/08 01:40:46 | Classpath element,
> wrapper.java.classpath.10, does not exist: ../classes
> STATUS | wrapper | 2008/02/08 01:40:46 | Launching a JVM...
> NONE | wrapper | 2008/02/08 01:40:46 | command:
> "D:\IBM\WBIServer\jre\bin\java.exe"
> -Dsequencer.context=AU04QWS130DCA32
> -Dsequencer.logs=d:\wppaup\runtime\var\sequencer\logs
> -Drepository.directory=D:\IBM\Sequencer -Djava.library.path="./lib"
> -classpath
>
"./lib/wrapper.jar;./lib/commons-collections-3.1.jar;./lib/commons-lang-2.1.jar;./lib/commons-logging-1.0.4.jar;./lib/commons-net-1.4.1.jar;./lib/jakarta-oro.jar;./lib/log4j-1.2.7.jar;./lib/spring.jar;./lib/velocity-1.4.jar;../classes;./lib/sequencer.jar"
> -Dwrapper.key="2ZXzPWYAZ6Ry7obW" -Dwrapper.port=32002
> -Dwrapper.jvm.port.min=31000 -Dwrapper.jvm.port.max=31999
> -Dwrapper.debug="TRUE" -Dwrapper.pid=2508 -Dwrapper.version="3.2.3"
> -Dwrapper.native_library="wrapper" -Dwrapper.service="TRUE"
> -Dwrapper.cpu.timeout="10" -Dwrapper.jvmid=9
> org.tanukisoftware.wrapper.WrapperSimpleApp SequencerTool LOOP
> DEBUG | wrapper | 2008/02/08 01:40:46 | JVM started (PID=9500)
-------------------------------------------------------------------------
This SF.net email is sponsored by: Microsoft
Defy all challenges. Microsoft(R) Visual Studio 2008.
http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/
_______________________________________________
Wrapper-user mailing list
Wra...@li...
https://lists.sourceforge.net/lists/listinfo/wrapper-user
|