Re: [Wrapper-user] Wrapper fails to start after JVM timeout - Needs server reboot to fix

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

Justin,
The problem starts when the backend socket gets closed somehow.  It is
a loopback socket so this should not be happening unless it is being
closed explicitly
---
INFO   | jvm 1    | 2010/06/01 08:37:00 | Closed socket:
java.net.SocketException: Software caused connection abort: recv
failed
INFO   | jvm 1    | 2010/06/01 08:37:00 | Closing socket.
---
Do have any ideas as to what on your system could have closed the socket?

The first time, the Wrapper process was listening on port 32001, but
when its connection with the JVM is lost, it is switching over and
starts listening on port 32002 instead.  At this point, it would be
impossible for the JVM to reconnect so the JVM ends up being killed as
unresponsive:
---
ERROR  | wrapper  | 2010/06/01 08:42:04 | JVM appears hung: Timed out
waiting for signal from JVM.
ERROR  | wrapper  | 2010/06/01 08:42:04 | JVM did not exit on request,
terminated
---

The Wrapper is then restarting the JVM correctly.  But the second JVM
instance is failing with an application level error:
---
INFO   | jvm 2    | 2010/06/01 08:42:11 | Received error while
starting the application.
INFO   | jvm 2    | 2010/06/01 08:42:11 |
org.springframework.beans.factory.BeanCreationException: Error
creating bean with name 'discoveryService' defined in class path
resource [jps-config.xml]: Invocation of init method failed; nested
exception is org.omg.CORBA.COMM_FAILURE: An exception was thrown while
waiting for a reply from the peer.  vmcid: 0x0  minor code: 0
completed: No
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1337)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:473)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory$1.run(AbstractAutowireCapableBeanFactory.java:409)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
java.security.AccessController.doPrivileged(Native Method)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:380)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:264)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:221)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:261)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:185)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:164)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:423)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:729)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:381)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.context.support.ClassPathXmlApplicationContext.<init>(ClassPathXmlApplicationContext.java:139)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.context.support.ClassPathXmlApplicationContext.<init>(ClassPathXmlApplicationContext.java:83)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.framework.services.bootstrap.SASRemoteServices.main(SASRemoteServices.java:63)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
java.lang.reflect.Method.invoke(Unknown Source)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.tanukisoftware.wrapper.WrapperSimpleApp.run(WrapperSimpleApp.java:240)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
java.lang.Thread.run(Unknown Source)
INFO   | jvm 2    | 2010/06/01 08:42:11 | Caused by:
org.omg.CORBA.COMM_FAILURE: An exception was thrown while waiting for
a reply from the peer.  vmcid: 0x0  minor code: 0  completed: No
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.iom.orb.brg.Engine.waitForReply(Engine.java:1869)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.iom.orb.brg.Engine.sendRequest(Engine.java:805)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.iom.orb.brg.RequestImpl.invoke(RequestImpl.java:33)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.meta.SASOMI._portable_stub_IOMI.DoRequest(_portable_stub_IOMI.java:569)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.services.deployment.OMRMetadataSource.getMetadata(OMRMetadataSource.java:1091)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.services.deployment.OMRMetadataSource.getMetadataToDeployServices(OMRMetadataSource.java:1018)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.services.deployment.ServiceLoader.deployServices(ServiceLoader.java:846)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.services.deployment.PlatformServices.startLocalServices(PlatformServices.java:524)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.services.deployment.PlatformServices.startServices(PlatformServices.java:479)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.services.deployment.CorePlatformServices.startServices(CorePlatformServices.java:153)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.framework.services.PlatformDiscoveryServiceFactoryBean.afterPropertiesSet(PlatformDiscoveryServiceFactoryBean.java:100)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1368)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1334)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	... 21 more
INFO   | jvm 2    | 2010/06/01 08:42:11 | Caused by:
java.io.IOException: An established connection was aborted by the
software in your host machine
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
sun.nio.ch.SocketDispatcher.read0(Native Method)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
sun.nio.ch.SocketDispatcher.read(Unknown Source)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
sun.nio.ch.IOUtil.readIntoNativeBuffer(Unknown Source)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
sun.nio.ch.IOUtil.read(Unknown Source)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
sun.nio.ch.SocketChannelImpl.read(Unknown Source)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.iom.orb.brg.Engine.readFully(Engine.java:5812)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.iom.orb.brg.Engine.readClearTextPacket(Engine.java:4486)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.iom.orb.brg.Engine.recvPacket(Engine.java:4338)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.iom.orb.brg.Engine.listen(Engine.java:2290)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	at
com.sas.iom.orb.brg.Engine.waitForReply(Engine.java:1894)
INFO   | jvm 2    | 2010/06/01 08:42:11 | 	... 33 more
---

>From the final cause, it looks like the HOST that your application is
connecting to is killing the connection for some reason.  Possibly
there is a session that needs to be reset somehow when the first JVM
instance has failed.    I am not able to help out directly with this
as I am not familiar with what your application is doing at the point
of failure.  If you could explain it a bit then I might have some
ideas or you.

We will run some tests on the latest versions of the Wrapper to see if
we can reproduce the original problem where the JVM fails to reconnect
its socket.   I'll post back when we have an update on the results of
the tests.  The version of the Wrapper you are using, 3.2.3, is over 4
years old and is no longer directly support.  I would suggest
upgrading to a more recent version as there have been a lot of issues
fixed, and improvements made over the years.

Cheers,
Leif

On Tue, Jun 1, 2010 at 11:30 AM, Justin Maguire <jma...@gm...> wrote:
> Hello,
>
> I am currently having an issue with my wrapper.exe starting. I have found
> that this starts okay first time around and can be restarted when needed,
> but if the JVM ping timeout is hit and is killed all attempts to start the
> wrapper service fail.
>
> I have made sure there are no java processes running but have ended up
> needing to restart the server to get teh wrapper service to start back up. I
> have attached a debug log but are at a loss as to why this is happening.
>
> I am okay with the wrapper restarting due to the JVM being unresponsive but
> I am concerned over the inability for it to recover without a server reboot.
>
>
> Any help or hints with this issue will be greatly appreciated!
>
>
>
> Thanks,
> Justin