Re: [Wrapper-user] Wrapper restart failed

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

Paul,
    Looking at the logs you sent, I am trying to figure out exactly what 
caused the JVM to
shutdown?   As you said your server was restarted, but is that the 
reason why the JVM
shutdown?
    If the Wrapper had received a SHUTDOWN event from the system then 
there should
have been a STATUS level message with the following text:

STATUS | wrapper | Machine is shutting down.

    From the stack trace, it looks like the JVM received a system 
control event which in
turn caused the WrapperStartStopApp to shutdown the JVM and Wrapper.   
Without
the debug output, I can't tell you exactly what the signal was.  LOGOFF 
events are
ignored, so it must have been a SHUTDOWN event.  Because the JVM was running
as a service it could not have received a CTRL-C or CLOSE event.

    It looks like you had been experiencing OutOfMemory errors.   When 
the JVM
tried to shutdown, it correctly called your stop class's main method.  
But that class
then attempted to start a new thread.  This failed due to another 
OutOfMemory
error within your code.
    The exception was thrown all the way back up to the 
WrapperStartStopApp's
stop method.  When it caught this, it was wrapped in an 
InvocationTargetException.
This stack trace was correctly displayed.
    The code then went on to show the usage for the class.  This may be 
what was
confusing you.    Looking at the source again.  I don't think there are 
any cases
where the usage should be shown at this point.  I've remove it for the 
next version.

Cheers,
Leif

Paul Casanova wrote:

>
>
>Hi everyone,
>
>Had a strange one yesterday - the Wrapper normally restarts our app
>beautifully if it crashes - but yesterday it failed with the following from
>the wrapper log:
>
>INFO   | jvm 1    | 2004/08/05 14:01:52 | java.lang.OutOfMemoryError:
>unable to create new native thread
>INFO   | jvm 1    | 2004/08/05 14:01:52 |       at
>java.lang.Thread.start(Native Method)
>INFO   | jvm 1    | 2004/08/05 14:01:52 |       at
>sun.rmi.transport.tcp.TCPChannel.free(TCPChannel.java:286)
>INFO   | jvm 1    | 2004/08/05 14:01:52 |       at
>sun.rmi.server.UnicastRef.invoke(UnicastRef.java:143)
>INFO   | jvm 1    | 2004/08/05 14:01:52 |       at
>rcis.client.GI001RcisClient_Stub.isAlive(Unknown Source)
>INFO   | jvm 1    | 2004/08/05 14:01:52 |       at
>rcis.admin.AA002LoggedInUser.isAlive(AA002UserAccessServer.java:1778)
>INFO   | jvm 1    | 2004/08/05 14:01:52 |       at
>rcis.admin.AA002UserAccessServer.checkAlive(AA002UserAccessServer.java:460)
>INFO   | jvm 1    | 2004/08/05 14:01:52 |       at
>rcis.admin.AA002UserAccessServer.run(AA002UserAccessServer.java:957)
>INFO   | jvm 1    | 2004/08/05 14:01:52 |       at
>java.lang.Thread.run(Thread.java:479)
>INFO   | jvm 1    | 2004/08/05 14:03:14 | java.lang.OutOfMemoryError:
>unable to create new native thread
>INFO   | jvm 1    | 2004/08/05 14:03:14 |       at
>java.lang.Thread.start(Native Method)
>INFO   | jvm 1    | 2004/08/05 14:03:14 |       at
>sun.rmi.transport.tcp.TCPChannel.free(TCPChannel.java:286)
>INFO   | jvm 1    | 2004/08/05 14:03:14 |       at
>sun.rmi.server.UnicastRef.free(UnicastRef.java:429)
>INFO   | jvm 1    | 2004/08/05 14:03:14 |       at
>sun.rmi.server.UnicastRef.done(UnicastRef.java:449)
>INFO   | jvm 1    | 2004/08/05 14:03:14 |       at
>sun.rmi.transport.DGCImpl_Stub.dirty(Unknown Source)
>INFO   | jvm 1    | 2004/08/05 14:03:14 |       at
>sun.rmi.transport.DGCClient$EndpointEntry.makeDirtyCall(DGCClient.java:318)
>INFO   | jvm 1    | 2004/08/05 14:03:14 |       at
>sun.rmi.transport.DGCClient$EndpointEntry.access$1500(DGCClient.java:136)
>INFO   | jvm 1    | 2004/08/05 14:03:14 |       at
>sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread.run(DGCClient.java:529)
>INFO   | jvm 1    | 2004/08/05 14:03:14 |       at
>java.lang.Thread.run(Thread.java:479)
>INFO   | jvm 1    | 2004/08/05 14:03:24 |
>rcis.infra.GI002RcisRuntimeException: Failed to update accident
>(42004024365) while Recalculating Calculated Fields
>INFO   | jvm 1    | 2004/08/05 14:03:24 |       at
>rcis.coder.CA001AccidentDb.updateAccident(CA001AccidentDb.java:931)
>INFO   | jvm 1    | 2004/08/05 14:03:24 |       at
>rcis.coder.CA001AccidentServer.doAccidentUpdate(CA001AccidentServer.java:293)
>INFO   | jvm 1    | 2004/08/05 14:03:24 |       at
>rcis.coder.CA001AccidentServer.execute(CA001AccidentServer.java:105)
>INFO   | jvm 1    | 2004/08/05 14:03:24 |       at
>java.lang.reflect.Method.invoke(Native Method)
>INFO   | jvm 1    | 2004/08/05 14:03:24 |       at
>sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:236)
>INFO   | jvm 1    | 2004/08/05 14:03:24 |       at
>sun.rmi.transport.Transport$1.run(Transport.java:147)
>INFO   | jvm 1    | 2004/08/05 14:03:24 |       at
>java.security.AccessController.doPrivileged(Native Method)
>INFO   | jvm 1    | 2004/08/05 14:03:24 |       at
>sun.rmi.transport.Transport.serviceCall(Transport.java:143)
>INFO   | jvm 1    | 2004/08/05 14:03:24 |       at
>sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:460)
>INFO   | jvm 1    | 2004/08/05 14:03:24 |       at
>sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:701)
>INFO   | jvm 1    | 2004/08/05 14:03:24 |       at
>java.lang.Thread.run(Thread.java:479)
>INFO   | jvm 1    | 2004/08/05 14:10:22 |
>rcis.infra.GI002RcisRuntimeException: Failed to update accident
>(42004023209) while deleting accident details
>INFO   | jvm 1    | 2004/08/05 14:10:22 |       at
>rcis.coder.CA001AccidentDb.updateAccident(CA001AccidentDb.java:931)
>INFO   | jvm 1    | 2004/08/05 14:10:22 |       at
>rcis.coder.CA001AccidentServer.doAccidentUpdate(CA001AccidentServer.java:293)
>INFO   | jvm 1    | 2004/08/05 14:10:22 |       at
>rcis.coder.CA001AccidentServer.execute(CA001AccidentServer.java:105)
>INFO   | jvm 1    | 2004/08/05 14:10:22 |       at
>java.lang.reflect.Method.invoke(Native Method)
>INFO   | jvm 1    | 2004/08/05 14:10:22 |       at
>sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:236)
>INFO   | jvm 1    | 2004/08/05 14:10:22 |       at
>sun.rmi.transport.Transport$1.run(Transport.java:147)
>INFO   | jvm 1    | 2004/08/05 14:10:22 |       at
>java.security.AccessController.doPrivileged(Native Method)
>INFO   | jvm 1    | 2004/08/05 14:10:22 |       at
>sun.rmi.transport.Transport.serviceCall(Transport.java:143)
>INFO   | jvm 1    | 2004/08/05 14:10:22 |       at
>sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:460)
>INFO   | jvm 1    | 2004/08/05 14:10:22 |       at
>sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:701)
>INFO   | jvm 1    | 2004/08/05 14:10:22 |       at
>java.lang.Thread.run(Thread.java:479)
>INFO   | jvm 1    | 2004/08/05 14:36:06 | Encountered an error running stop
>main: java.lang.reflect.InvocationTargetException
>INFO   | jvm 1    | 2004/08/05 14:36:06 |
>java.lang.reflect.InvocationTargetException: java.lang.OutOfMemoryError:
>unable to create new native thread
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>java.lang.Thread.start(Native Method)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>sun.rmi.transport.DGCClient$EndpointEntry.<init>(DGCClient.java:213)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>sun.rmi.transport.DGCClient$EndpointEntry.lookup(DGCClient.java:185)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>sun.rmi.transport.DGCClient.registerRefs(DGCClient.java:103)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>sun.rmi.transport.ConnectionInputStream.registerRefs(ConnectionInputStream.java:78)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>sun.rmi.transport.StreamRemoteCall.releaseInputStream(StreamRemoteCall.java:126)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>sun.rmi.transport.StreamRemoteCall.done(StreamRemoteCall.java:267)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>sun.rmi.server.UnicastRef.done(UnicastRef.java:452)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>sun.rmi.registry.RegistryImpl_Stub.lookup(Unknown Source)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>java.rmi.Naming.lookup(Naming.java:79)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>rcis.infra.serverControl.GA001RCISMainServer.main(GA001RCISMainServer.java:63)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>java.lang.reflect.Method.invoke(Native Method)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>org.tanukisoftware.wrapper.WrapperStartStopApp.stop(WrapperStartStopApp.java:277)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>org.tanukisoftware.wrapper.WrapperManager.stopInner(WrapperManager.java:1903)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>org.tanukisoftware.wrapper.WrapperManager.stop(WrapperManager.java:1470)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>org.tanukisoftware.wrapper.WrapperStartStopApp.controlEvent(WrapperStartStopApp.java:357)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>org.tanukisoftware.wrapper.WrapperManager.controlEvent(WrapperManager.java:1982)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>org.tanukisoftware.wrapper.WrapperManager.access$1700(WrapperManager.java:232)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |       at
>org.tanukisoftware.wrapper.WrapperManager$2.run(WrapperManager.java:655)
>INFO   | jvm 1    | 2004/08/05 14:36:06 |
>INFO   | jvm 1    | 2004/08/05 14:36:06 | WrapperStartStopApp Usage:
>INFO   | jvm 1    | 2004/08/05 14:36:06 |   java
>org.tanukisoftware.wrapper.WrapperStartStopApp {start_class}
>{start_arg_count} [start_arguments] {stop_class} {stop_wait}
>{stop_arg_count} [stop_arguments]
>INFO   | jvm 1    | 2004/08/05 14:36:06 |
>INFO   | jvm 1    | 2004/08/05 14:36:06 | Where:
>INFO   | jvm 1    | 2004/08/05 14:36:06 |   start_class:     The fully
>qualified class name to run to start the
>INFO   | jvm 1    | 2004/08/05 14:36:06 |                    application.
>INFO   | jvm 1    | 2004/08/05 14:36:06 |   start_arg_count: The number of
>arguments to be passed to the start class's
>INFO   | jvm 1    | 2004/08/05 14:36:06 |                    main method.
>INFO   | jvm 1    | 2004/08/05 14:36:06 |   stop_class:      The fully
>qualified class name to run to stop the
>INFO   | jvm 1    | 2004/08/05 14:36:06 |                    application.
>INFO   | jvm 1    | 2004/08/05 14:36:06 |   stop_wait:       When stopping,
>should the Wrapper wait for all threads to
>INFO   | jvm 1    | 2004/08/05 14:36:06 |                    complete
>before exiting (true/false).
>INFO   | jvm 1    | 2004/08/05 14:36:06 |   stop_arg_count:  The number of
>arguments to be passed to the stop class's
>INFO   | jvm 1    | 2004/08/05 14:36:06 |                    main method.
>INFO   | jvm 1    | 2004/08/05 14:36:06 |   app_parameters:  The parameters
>that would normally be passed to the
>INFO   | jvm 1    | 2004/08/05 14:36:06 |                    application.
>STATUS | wrapper  | 2004/08/05 14:36:07 | <-- Wrapper Stopped
>STATUS | wrapper  | 2004/08/05 14:39:26 | --> Wrapper Started as Service
>STATUS | wrapper  | 2004/08/05 14:39:27 | Launching a JVM...
>
>Where the Wrapper started again a few minutes later was due to the server
>being rebooted.  I upgraded to 3.1.1 last night - does anyone know what may
>have caused the Wrapper restarting to fail?
>
>Regards,
>
>Paul Casanova
>  
>