Re: [Wrapper-user] more on problems with filters- restart never works

SourceForge Headquarters 1320 Columbia Street Suite 310 San Diego, CA 92101 +1 (858) 422-6466

I am not calling wrapper.stop anywhere.. I only call wrapper.restart();
I do have some places in the code that issue System.exit(0) or  
System.exit(1)...however, I have ignore system events set....

My one question here-- I remember reading that you said there was a  
problem w/ restarts after a system.exit(1)..  and that you said that  
was fixed
in your current checked in code.. I am running from a build I did of  
your code in CVS as of 3/1/04.

I expect a System.exit(1) is being issued in these cases.. I will try  
converting that in my internal code to use an exit code of 0.. I had  
already made that change
in the wrapperSimpleApp and saw no difference in behavior.

is the system.exit(1) bug still lingering ??

thanks
Jennifer
On Mar 6, 2004, at 6:34 AM, Leif Mortenson wrote:

> Jennifer,
>    Sorry to keep you waiting.  Busy week.
>
>    I tried this out and everything seems to be working correctly for  
> me.  From your log
> output, it looks like restart triggers get fired several times in  
> rapid succession.  I tested
> this and the Wrapper appears to be handling that correctly.  Once the  
> restart has
> started, additional restart requests are correctly ignored.
>
>    I think the problem is the following lines from your output:
> INFO   | jvm 7    | 2004/02/26 19:32:59 | Send a packet STOP : 0
> DEBUG  | wrapperp | 2004/02/26 19:32:59 | read a packet STOP : 0
> DEBUG  | wrapper  | 2004/02/26 19:32:59 | JVM requested a shutdown. (0)
> DEBUG  | wrapper  | 2004/02/26 19:32:59 | wrapperStopProcess(0) called.
>
>    Are you sure you are not calling System.exit or  
> WrapperManager.stop() someplace
> in your code?  If so that will override the restart request and cause  
> the Wrapper to
> shutdown.
>
>    If you call System.exit, you will get the following in your log  
> output.  System.exit
> triggers a Shutdown Hook, which you have disabled, so I don't think  
> this what is
> happening:
>
> INFO   | jvm 1    | main    | 2004/03/06 23:27:15 | Wrapper Manager:  
> ShutdownHook started
> INFO   | jvm 1    | main    | 2004/03/06 23:27:15 | Send a packet STOP  
> : 0
> DEBUG  | wrapperp | main    | 2004/03/06 23:27:15 | read a packet STOP  
> : 0
> DEBUG  | wrapper  | main    | 2004/03/06 23:27:15 | JVM requested a  
> shutdown. (0)
> DEBUG  | wrapper  | main    | 2004/03/06 23:27:15 |  
> wrapperStopProcess(0) called.
> DEBUG  | wrapper  | main    | 2004/03/06 23:27:15 | Sending stop  
> signal to JVM
> DEBUG  | wrapperp | main    | 2004/03/06 23:27:15 | send a packet STOP  
> : NULL
>
>    A call you WrapperManager.stop(0) on the other hand, looks like the  
> following.  This is
> exactly what is showing up in your log:
>
> INFO   | jvm 1    | main    | 2004/03/06 23:29:06 | Send a packet STOP  
> : 0
> DEBUG  | wrapperp | main    | 2004/03/06 23:29:06 | read a packet STOP  
> : 0
> DEBUG  | wrapper  | main    | 2004/03/06 23:29:06 | JVM requested a  
> shutdown. (0)
> DEBUG  | wrapper  | main    | 2004/03/06 23:29:06 |  
> wrapperStopProcess(0) called.
> DEBUG  | wrapper  | main    | 2004/03/06 23:29:06 | Sending stop  
> signal to JVM
> DEBUG  | wrapperp | main    | 2004/03/06 23:29:06 | send a packet STOP  
> : NULL
>
>    Let me know if you don't think that is the cause or have questions  
> about to use
> the filters.
>
> Cheers,
> Leif
>
> Jennifer Kolar wrote:
>
>> Leif,
>>
>> It appears that I never have a successful FILTER based restart.  I  
>> have no problem getting restarts when I call WrapperManager.restart()  
>> internally.. however--
>> if there is an exception that I didn't catch that a filter matches,  
>> then I never get a successful restart. I have had each of the  
>> following filters triggered always with the same result.
>>
>> I noticed that there was a recent email (Patrick Woodworth 1/23/2004)  
>>  where another person was having similiar problems and he found  
>> disabling the shutdown hooks to be a soln for him.. I've had that  
>> disabled this whole time and  don't see any difference.
>>
>>
>> Here are my filter settings from my conf file.
>>
>>      
>> wrapper.filter.trigger.1=com.singingfish.werkflow.processors.Processor 
>> Exception
>>     wrapper.filter.action.1=RESTART
>>
>>     wrapper.filter.trigger.2=java.lang.Error
>>     wrapper.filter.action.2=RESTART
>>
>>     wrapper.filter.trigger.3=java.lang.OutOfMemoryError
>>     wrapper.filter.action.3=RESTART
>>
>>
>> I also have these set if it provides any help..  ( I have tried  
>> playing around w/ different startup timeouts and invocation times and  
>> it seems to make no difference)
>>
>>     wrapper.jvm_exit.timeout=30
>>     wrapper.cpu.timeout=10
>>     wrapper.ping.timeout=300
>>     wrapper.ping.interval=5
>>     wrapper.restart.delay=1
>>     wrapper.max_failed_invocations=3
>>     wrapper.successful_invocation_time=10
>>     wrapper.startup.timeout=30
>>     wrapper.request_thread_dump_on_failed_jvm_exit=FALSE
>>     wrapper.ignore_signals=TRUE
>>     wrapper.disable_shutdown_hook=TRUE
>>
>> And again, here is the result I see whenever a filter is triggered:
>>
>>
>> *STATUS | wrapper  | 2004/02/26 19:32:59 | Filter trigger matched.   
>> Restarting JVM.*
>> *DEBUG  | wrapper  | 2004/02/26 19:32:59 | wrapperRestartProcess()  
>> called*
>> ... (stuff from my stacktrack)
>> *STATUS | wrapper  | 2004/02/26 19:32:59 | Filter trigger matched.   
>> Restarting JVM.*
>> *DEBUG  | wrapper  | 2004/02/26 19:32:59 | wrapperRestartProcess()  
>> called.  (IGNORED)*
>> INFO   | jvm 7    | 2004/02/26 19:32:59 | java.lang.Error:  
>> com.singingfish.werkflow.processors.ProcessorException: Unexpected  
>> exception in cracker
>> *STATUS | wrapper  | 2004/02/26 19:32:59 | Filter trigger matched.   
>> Restarting JVM.*
>> *DEBUG  | wrapper  | 2004/02/26 19:32:59 | wrapperRestartProcess()  
>> called.  (IGNORED)*
>> ... (stuff from my stack track)
>> INFO   | jvm 7    | 2004/02/26 19:32:59 | Send a packet STOP : 0
>> DEBUG  | wrapperp | 2004/02/26 19:32:59 | read a packet STOP : 0
>> DEBUG  | wrapper  | 2004/02/26 19:32:59 | JVM requested a shutdown.  
>> (0)
>> DEBUG  | wrapper  | 2004/02/26 19:32:59 | wrapperStopProcess(0)  
>> called.
>> DEBUG  | wrapper  | 2004/02/26 19:32:59 | Sending stop signal to JVM
>> DEBUG  | wrapperp | 2004/02/26 19:32:59 | send a packet STOP : NULL
>> INFO   | jvm 7    | 2004/02/26 19:32:59 | Received a packet STOP :
>> INFO   | jvm 7    | 2004/02/26 19:33:00 | Thread,  
>> WrapperSimpleAppMain, handling the shutdown process.
>> INFO   | jvm 7    | 2004/02/26 19:33:00 | calling listener.stop()
>> INFO   | jvm 7    | 2004/02/26 19:33:00 | WrapperSimpleApp: stop(0)
>> INFO   | jvm 7    | 2004/02/26 19:33:00 | returned from  
>> listener.stop()
>> INFO   | jvm 7    | 2004/02/26 19:33:00 | Send a packet STOPPED : 0
>> DEBUG  | wrapperp | 2004/02/26 19:33:00 | read a packet STOPPED : 0
>> DEBUG  | wrapper  | 2004/02/26 19:33:00 | JVM signalled that it was  
>> stopped.
>> INFO   | jvm 7    | 2004/02/26 19:33:00 | Closing socket.
>> DEBUG  | wrapperp | 2004/02/26 19:33:00 | socket read no code  
>> (closed?).
>> INFO   | jvm 7    | 2004/02/26 19:33:00 | calling System.exit(0)
>> INFO   | jvm 7    | 2004/02/26 19:33:00 | Server daemon shut down
>> DEBUG  | wrapper  | 2004/02/26 19:33:00 | JVM exited normally.
>> STATUS | wrapper  | 2004/02/26 19:33:01 | <-- Wrapper Stopped
>> STATUS | wrapper  | 2004/02/26 19:36:28 | CrackerAgent3 removed.
>>
>>
>> in comparison-- a normal restart has the following ...
>>
>>
>> INFO   | jvm 6    | 2004/02/26 19:31:48 | 2004-02-26 19:31:48,107  
>> DEBUG [WrapperSimpleAppMain] WerkflowAgent             -  
>> WerkflowEngine requested VM restart (null). Shutting down...
>> INFO   | jvm 6    | 2004/02/26 19:31:48 | Send a packet RESTART :  
>> restart
>> DEBUG  | wrapperp | 2004/02/26 19:31:48 | read a packet RESTART :  
>> restart
>> STATUS | wrapper  | 2004/02/26 19:31:48 | JVM requested a restart.
>> DEBUG  | wrapper  | 2004/02/26 19:31:48 | wrapperRestartProcess()  
>> called.
>> DEBUG  | wrapper  | 2004/02/26 19:31:48 | Sending stop signal to JVM
>> DEBUG  | wrapperp | 2004/02/26 19:31:48 | send a packet STOP : NULL
>> INFO   | jvm 6    | 2004/02/26 19:31:48 | Received a packet STOP :
>> INFO   | jvm 6    | 2004/02/26 19:31:49 | Thread,  
>> WrapperSimpleAppMain, handling the shutdown process.
>> INFO   | jvm 6    | 2004/02/26 19:31:49 | calling listener.stop()
>> INFO   | jvm 6    | 2004/02/26 19:31:49 | WrapperSimpleApp: stop(0)
>> INFO   | jvm 6    | 2004/02/26 19:31:49 | returned from  
>> listener.stop()
>> INFO   | jvm 6    | 2004/02/26 19:31:49 | Send a packet STOPPED : 0
>> DEBUG  | wrapperp | 2004/02/26 19:31:49 | read a packet STOPPED : 0
>> DEBUG  | wrapper  | 2004/02/26 19:31:49 | JVM signalled that it was  
>> stopped.
>> INFO   | jvm 6    | 2004/02/26 19:31:49 | Closing socket.
>> DEBUG  | wrapperp | 2004/02/26 19:31:49 | socket read no code  
>> (closed?).
>> INFO   | jvm 6    | 2004/02/26 19:31:50 | calling System.exit(0)
>> INFO   | jvm 6    | 2004/02/26 19:31:50 | Server daemon shut down
>> DEBUG  | wrapper  | 2004/02/26 19:31:50 | JVM exited normally.
>> STATUS | wrapper  | 2004/02/26 19:31:52 | Launching a JVM...
>> DEBUG  | wrapper  | 2004/02/26 19:31:52 | command:  
>> "C:\WINNT\system32\java.exe"  
>> -Dcom.singingfish.core.utils.config.dir=c:/sf/config  
>> -Duser.dir=C:\aolrun -Dsun.rmi.loader.logLevel=VERBOSE  
>> -Dsun.rmi.server.logLevel=VERBOSE  
>> -Dsun.rmi.transport.logLevel=VERBOSE  
>> -Dsun.rmi.transport.tcp.logLevel=VERBOSE  
>> -Dsun.rmi.transport.proxy.logLevel=VERBOSE -Xms3m -Xmx96m  
>> -Djava.library.path="c:/sf/lib;c:/winnt;c:/winnt/system32;c:/ 
>> j2sdk1.4.2_02/bin" -classpath  
>> "c:/sf/java/classes;c:/sf/java/jars/commons-logging-1.0.3/commons- 
>> logging.jar;c:/sf/java/jars/jakarta-log4j-1.2.8/dist/lib/log4j 
>> -1.2.8.jar;c:/sf/java/jars/jakarta-oro-2.0.4/jakarta-oro-2.0.4.jar;c: 
>> /sf/java/jars/quicktime_6_5/QTJava.zip;c:/sf/java/jars/xerces-1_3_1/ 
>> xerces.jar;c:/sf/java/jars/toplink/TOPLink.jar;c:/sf/java/jars/ 
>> toplink/Tools.jar;c:/sf/java/jars/toplink/TOPLinkX.jar;c:/sf/java/ 
>> jars/oracle_jdbc_9_2_03/ojdbc14.jar;c:/sf/java/jars/commons- 
>> httpclient-2.0/commons-httpclient-2.0-final.jar"  
>> -Dwrapper.key="VRxfE5Fd856GSIaF" -Dwrapper.port=32013  
>> -Dwrapper.debug="TRUE" -Dwrapper.ignore_signals="TRUE"  
>> -Dwrapper.service="TRUE" -Dwrapper.disable_shutdown_hook="TRUE"  
>> -Dwrapper.cpu.timeout="10" -Dwrapper.jvmid=7  
>> org.tanukisoftware.wrapper.WrapperSimpleApp  
>> com.singingfish.werkflow.agent.WerkflowAgent  
>> c:/sf/config/workflow/specs/cracker.spec CrackerAgent3
>> DEBUG  | wrapper  | 2004/02/26 19:31:52 | Java Virtual Machine  
>> started (PID=9244)
>> INFO   | jvm 7    | 2004/02/26 19:31:52 | Wrapper Manager: JVM #7
>> INFO   | jvm 7    | 2004/02/26 19:31:52 | Wrapper Manager: Using  
>> wrapper
>> INFO   | jvm 7    | 2004/02/26 19:31:52 | Calling native  
>> initialization method.
>> INFO   | jvm 7    | 2004/02/26 19:31:52 | Initializing WrapperManager  
>> native library.
>> INFO   | jvm 7    | 2004/02/26 19:31:52 | Java Executable:  
>> C:\WINNT\system32\java.exe
>> INFO   | jvm 7    | 2004/02/26 19:31:52 | Java Version   :  
>> 1.4.2_02-b03 Java HotSpot(TM) Client VM
>> INFO   | jvm 7    | 2004/02/26 19:31:52 | Java VM Vendor : Sun  
>> Microsystems Inc.
>> INFO   | jvm 7    | 2004/02/26 19:31:52 |
>> INFO   | jvm 7    | 2004/02/26 19:31:52 | Wrapper (Version 3.0.5)
>> INFO   | jvm 7    | 2004/02/26 19:31:52 |
>> INFO   | jvm 7    | 2004/02/26 19:31:52 | Open socket to wrapper  
>> attempted on port 32013...
>> INFO   | jvm 7    | 2004/02/26 19:31:52 | Opened Socket to port 3242
>> INFO   | jvm 7    | 2004/02/26 19:31:52 | Send a packet KEY :  
>> VRxfE5Fd856GSIaF
>> INFO   | jvm 7    | 2004/02/26 19:31:52 |  
>> handleSocket(Socket[addr=/127.0.0.1,port=32013,localport=3242])
>> DEBUG  | wrapperp | 2004/02/26 19:31:52 | accepted a socket from  
>> 127.0.0.1 on port 3242
>> DEBUG  | wrapperp | 2004/02/26 19:31:52 | read a packet KEY :  
>> VRxfE5Fd856GSIaF
>> DEBUG  | wrapper  | 2004/02/26 19:31:52 | Got key from JVM:  
>> VRxfE5Fd856GSIaF
>> DEBUG  | wrapperp | 2004/02/26 19:31:52 | send a packet LOW_LOG_LEVEL  
>> : 1
>> DEBUG  | wrapperp | 2004/02/26 19:31:52 | send a packet PING_TIMEOUT  
>> : 300
>> DEBUG  | wrapper  | 2004/02/26 19:31:52 | Start Application.
>> ....
>
>
>
>
> -------------------------------------------------------
> This SF.Net email is sponsored by: IBM Linux Tutorials
> Free Linux tutorial presented by Daniel Robbins, President and CEO of
> GenToo technologies. Learn everything from fundamentals to system
> administration.http://ads.osdn.com/?ad_id=1470&alloc_id=3638&op=click
> _______________________________________________
> Wrapper-user mailing list
> Wra...@li...
> https://lists.sourceforge.net/lists/listinfo/wrapper-user