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,
One more question.  Do you have any AntiVirus SW installed on this
server?  I found the following post which points to McAfee as the
cause:
http://forums.sun.com/thread.jspa?threadID=430179&start=0  (Post at
Nov 2, 2006 2:13 AM)

This next post talks about it being a possible memory problem.  What
is the memory situation on your server?  I don' see anything else that
points to a memory issue however.
http://stackoverflow.com/questions/1461460

I was also looking farther down into your logs.
When you manually restart the Wrapper at 2010/06/01 10:25:18 it is
then starting up normally, opening a connection back to the Wrapper,
and successfully sending data.  But then the first packet that the
Wrapper tries to send to the JVM fails.  This process repeats 5 times
until the Wrapper gives up on starting the JVM.  Could you please
confirm whether or not this wrapper start was before or after you
restarted your server?

You get the same problem again when starting the Wrapper at 2010/06/01
10:26:47, 2010/06/01 10:27:41, 2010/06/01 10:37:04, and 2010/06/01
10:40:04.

When you start it up at 2010/06/01 10:51:50, however, it works fine.
Was this after you restarted your physical server?

Cheers,
Leif

On Tue, Jun 1, 2010 at 12:00 PM, Leif Mortenson
<lei...@ta...> wrote:
> 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