users@glassfish.java.net

Re: Urgent - EJB SSB Timeouts!

From: Adam Jenkins <adamjenkinstmpredirect_at_yahoo.com.au>
Date: Tue, 23 Jun 2009 22:48:02 -0700 (PDT)

by the way, I think whatever's happening is happening on the ejb server not the client, as I just tried to run the command line program below again and it didn't even get through the first loop, so JNDI on that server seems to have locked up

--- On Wed, 24/6/09, adamjenkinstmpredirect_at_yahoo.com.au <adamjenkinstmpredirect_at_yahoo.com.au> wrote:

> From: adamjenkinstmpredirect_at_yahoo.com.au <adamjenkinstmpredirect_at_yahoo.com.au>
> Subject: Re: Urgent - EJB SSB Timeouts!
> To: users_at_glassfish.dev.java.net
> Received: Wednesday, 24 June, 2009, 3:35 PM
>
>
> I have some more information regarding this problem if
> anyone can shed some light on things.  I know this is a
> long post, but it has steps to reproduce the error
> independent of my web code, so I'd really appreciate anyone
> wadding through it and any advice anyone could offer.
>
> First thing I did was turn on monitoring, to ensure that
> this wasn't a resource issue -- heaps of memory, so I
> progressed on to isolating the code.
>
> I took the code from the time task that runs in the web
> tier and pulled it out into a good old fashioned java main
> program and ran it from the command line...looping 10 times
> I ran the following...
>
>         System.out.println("running test");
>         for(int i = 0; i < 10; i++){
>             System.out.println("run " + i);
>             InitialContext remoteContext =
> RemoteContextLookup.lookup();
>             String opsJndi =
> "ejb/UnsecuredOperationsBean";
>             System.out.println("looking up ops");
>             UnsecuredOperationsRemote ops =
> (UnsecuredOperationsRemote)remoteContext.lookup(opsJndi);
>             System.out.println("executing method");
>             System.out.println("Response: " +
> ops.isReadyForReportGeneration(30000l));
>             System.out.println("finsihed run " + i);
>         }
>         System.out.println("Finished test");
>
>
>
> That ran fine...connected and executed the method 10
> times.
>
>
> So then, to simulate the timer task, I put a 20 minute
> sleep into it
>
>         System.out.println("running test");
>         for(int i = 0; i < 10; i++){
>             System.out.println("run " + i);
>             InitialContext remoteContext =
> RemoteContextLookup.lookup();
>             String opsJndi =
> "ejb/UnsecuredOperationsBean";
>             System.out.println("looking up ops");
>             UnsecuredOperationsRemote ops =
> (UnsecuredOperationsRemote)remoteContext.lookup(opsJndi);
>             System.out.println("executing method");
>             System.out.println("Response: " +
> ops.isReadyForReportGeneration(30000l));
>             System.out.println("finsihed run " + i);
>             System.out.println("Sleeping for 20
> minutes");
>
>             //make it sleep
> to simulate the timer task
>             Thread.sleep(1200000l);
>         }
>         System.out.println("Finished test");
>
>
> And I got the following output:
>
> running test
> run 0
> looking up ops
> executing method
> Response: false
> finsihed run 0
> Sleeping for 20 minutes
> run 1
> looking up ops
> 24/06/2009 15:19:19
> com.sun.corba.ee.impl.transport.CorbaResponseWaitingRoomImpl
> waitForResponse
> WARNING: "IOP00410219: (COMM_FAILURE) Communications
> timeout waiting for response.  Exceeded 1,800,000
> milliseconds"
> org.omg.CORBA.COMM_FAILURE:   vmcid:
> SUN  minor code: 219 completed: Maybe
>         at
> com.sun.corba.ee.impl.logging.ORBUtilSystemException.communicationsTimeoutWaitingForResponse(ORBUtilSystemException.java:3180)
>         at
> com.sun.corba.ee.impl.logging.ORBUtilSystemException.communicationsTimeoutWaitingForResponse(ORBUtilSystemException.java:3195)
>         at
> com.sun.corba.ee.impl.transport.CorbaResponseWaitingRoomImpl.waitForResponse(CorbaResponseWaitingRoomImpl.java:198)
>         at
> com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.waitForResponse(SocketOrChannelConnectionImpl.java:1196)
>         at
> com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.waitForResponse(CorbaMessageMediatorImpl.java:291)
>         at
> com.sun.corba.ee.impl.protocol.CorbaClientRequestDispatcherImpl.marshalingComplete1(CorbaClientRequestDispatcherImpl.java:389)
>         at
> com.sun.corba.ee.impl.protocol.CorbaClientRequestDispatcherImpl.marshalingComplete(CorbaClientRequestDispatcherImpl.java:357)
>         at
> com.sun.corba.ee.impl.protocol.CorbaClientDelegateImpl.invoke(CorbaClientDelegateImpl.java:219)
>         at
> com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.privateInvoke(StubInvocationHandlerImpl.java:192)
>         at
> com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.invoke(StubInvocationHandlerImpl.java:152)
>         at
> com.sun.corba.ee.impl.presentation.rmi.bcel.BCELStubBase.invoke(BCELStubBase.java:225)
>         at
> com.sun.ejb.codegen._GenericEJBHome_Generated_DynamicStub.create(com/sun/ejb/codegen/_GenericEJBHome_Generated_DynamicStub.java)
>         at
> sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>         at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
>         at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>         at
> java.lang.reflect.Method.invoke(Method.java:597)
>         at
> com.sun.ejb.EJBUtils.lookupRemote30BusinessObject(EJBUtils.java:372)
>         at
> com.sun.ejb.containers.RemoteBusinessObjectFactory.getObjectInstance(RemoteBusinessObjectFactory.java:74)
>         at
> javax.naming.spi.NamingManager.getObjectInstance(NamingManager.java:304)
>         at
> com.sun.enterprise.naming.SerialContext.lookup(SerialContext.java:414)
>         at
> javax.naming.InitialContext.lookup(InitialContext.java:392)
>         at
> scratchpad.Main.main(Main.java:105)
>
>
> So there seems to be some problem using a remote initial
> context with a delay in between.  I ran the same test
> calling remoteContext.close() after each use and it made no
> difference.  Interestingly, this one didn't even get a
> second run through the loop before it began timing out.
>
> The contents of the RemoteContext.lookup() method (that
> created the InitialContext) is below (note, I've replaced
> the host and port for security reasons):
>
>         Properties props = new
> Properties();
>        
> props.setProperty(Context.INITIAL_CONTEXT_FACTORY,
> "com.sun.enterprise.naming.SerialInitContextFactory");
>        
> props.setProperty(Context.PROVIDER_URL,"iiop://<<host>>:<<port>>");
>        
> props.setProperty("org.omg.CORBA.ORBInitialHost",
> "<<host>>");
>        
> props.setProperty("org.omg.CORBA.ORBServerHost",
> "<<host>>");
>        
> props.setProperty("org.omg.CORBA.ORBInitialPort",
> "<<port>>");
>         return new
> InitialContext(props);
>
> Any assistance would be really really appreciated. 
> I'm at the end of my knowledge at the moment :(
>
>
>
> --- On Wed, 24/6/09, Adam Jenkins <adamjenkinstmpredirect_at_yahoo.com.au>
> wrote:
>
> > From: Adam Jenkins <adamjenkinstmpredirect_at_yahoo.com.au>
> > Subject: Re: Urgent - EJB SSB Timeouts!
> > To: users_at_glassfish.dev.java.net
> > Received: Wednesday, 24 June, 2009, 9:21 AM
> >
> > >>But you are using an EJB for it anyway,
> right?
> >
> > No, we're doing the generation in the timer task on
> the web
> > tier (I'm using java.util.Timer, spawned by a context
> > listener on startup of the web container)...I didn't
> bother
> > using an enterprise scheduler as that was a bit of
> overkill
> > for a simple 20 minute recursive timer thread).  It
> has
> > to be done on the web tier as it generates html files
> on the
> > local system which get included into a JSP using
> c:import
> > (we have to generate them as they're waaaaaaay to big
> and
> > complex to generate dynamically).
> >
> > The EJB call is just to see if reports need to be
> > generated.  It checks some JMS queues and looks up
> some
> > db tables to see if there is a new bunch of batching
> data
> > that is ready to be processed and returns either a
> true or a
> > false...then the calling web tier timer task either
> does the
> > generation (using more ejb calls to get the data -- it
> never
> > gets this far) or sleeps for another 20 minutes.
> >
> > This morning I turned on monitoring on all the tiers
> just
> > to make sure it wasn't a memory issue -- heaps of
> free
> > memory, so that's not it.
> >
> > I did find the following warning in the ejb tier:
> >
> >
> [#|2009-06-24T07:35:47.578+1000|WARNING|sun-appserver2.1|javax.jms|_ThreadID=22;_ThreadName=iMQReadChannel-36;_RequestID=5f3d6e80-3240-442e-9e85-ac7c26ddf53f;|[I500]:
> > Caught JVM Exception: java.io.EOFException|#]
> >
> > The EJB is referencing a queue
> >
> >    
> > @Resource(mappedName="jms/QueueConnectionFactory")
> >     private QueueConnectionFactory
> > queueConnectionFactory;
> >
> > so I am investigating the theory that the SSB EJBs
> are
> > being created too fast for the message queue (LOCAL
> JMS)
> > when the ejb pool resizes...I notice that just before
> the
> > error occurs (10 minutes or so before) the pool
> creates a
> > bunch more EJBs and it's the next call that fails. 
> So
> > I've turned down all my values (creating less EJBs on
> pool
> > resize) to see if that makes any difference.  I'll
> have
> > an answer on that in about 20 minutes after I
> finishing
> > deploying a new version of the ear and war (with more
> > logging)
> >
> > Other than that I'm completely stumped :(
> >
> > --- On Wed, 24/6/09, Marina Vatkina <Marina.Vatkina_at_Sun.COM>
> > wrote:
> >
> > > From: Marina Vatkina <Marina.Vatkina_at_Sun.COM>
> > > Subject: Re: Urgent - EJB SSB Timeouts!
> > > To: users_at_glassfish.dev.java.net
> > > Received: Wednesday, 24 June, 2009, 9:00 AM
> > > Adam Jenkins wrote:
> > > > Yeah, you're correct....it's only one
> timer,
> > calling
> > > one SSB method every 20 minutes.
> > > >
> > > > I'm using the default number of
> connections,
> > > 1024.  My thread pool has 50 minimum, initial
> ejb
> > pool
> > > size of 5 (max 500, resize 20).  So there should
> be
> > > ample threads/ejbs
> > > >
> > > > No idea why it didn't show up in
> testing...we
> > recently
> > > went from v2ur2 up to v2.1...and to be honest,
> the
> > test
> > > system never really ran for over an hour at a
> time :)
> > > >
> > > > We use EJB Timer service for all our other
> > timing
> > > needs and that works fine, but this process
> > specifically
> > > generates files into the web directory that then
> are
> > > referenced from other jsps using c:import...so
> this is
> > the
> > > only timer task that has to run on the web tier.
> > >
> > > But you are using an EJB for it anyway, right? If
> yes,
> > why
> > > can't the EJB Timer
> > > service do the same job?
> > >
> > > If it can't, which JDK api are you using? EJB
> Timer
> > Service
> > > reschedules the JDK
> > > timer task for each call (vs. scheduling the
> task
> > with
> > > multiple expirations).
> > >
> > > Regards,
> > > -marina
> > > >
> > > > --- On Tue, 23/6/09, glassfish_at_javadesktop.org
> > > <glassfish_at_javadesktop.org>
> > > wrote:
> > > >
> > > >
> > > >>From: glassfish_at_javadesktop.org
> > > <glassfish_at_javadesktop.org>
> > > >>Subject: Re: Urgent - EJB SSB Timeouts!
> > > >>To: users_at_glassfish.dev.java.net
> > > >>Received: Tuesday, 23 June, 2009, 7:23
> AM
> > > >>Hi,
> > > >>
> > > >>OK, so you say you call the EJB every 20
> > minutes,
> > > that
> > > >>means 3 times in an hour. Do you call
> only one
> > EJB
> > > every 20
> > > >>minutes or several EJBs every 20
> minutes?
> > > >>I am actually just guessing but I think
> that
> > the
> > > problem is
> > > >>not that the name of your EJB is not
> found
> > but
> > > maybe rather
> > > >>that some limit on the naming context
> lookup
> > object
> > > was
> > > >>reached or that maybe there were not any
> > pooled
> > > EJBs free to
> > > >>service your request.
> > > >>Looking at a default domain.xml config of
> a
> > > Glassfish I can
> > > >>see that the max-connections to the ORB
> are
> > 1024.
> > > Sounds
> > > >>high. ;)
> > > >>Maybe you can give more information how
> many
> > EJBs
> > > are
> > > >>called how often. Can you imagine why
> this
> > > behaviour did not
> > > >>show on the test system?
> > > >>
> > > >>Cheers
> > > >>Chris.
> > > >>[Message sent by forum member 'chrjohn'
> > (chrjohn)]
> > > >>
> > > >>http://forums.java.net/jive/thread.jspa?messageID=352409
> > > >>
> > >
> >
> >>---------------------------------------------------------------------
> > > >>To unsubscribe, e-mail: users-unsubscribe_at_glassfish.dev.java.net
> > > >>For additional commands, e-mail: users-help_at_glassfish.dev.java.net
> > > >>
> > > >>
> > > >
> > > >
> > > >
> > > >       Access Yahoo!7 Mail on
> > > your mobile. Anytime. Anywhere.
> > > > Show me how: http://au.mobile.yahoo.com/mail
> > > >
> > > >
> > >
> >
> ---------------------------------------------------------------------
> > > > To unsubscribe, e-mail: users-unsubscribe_at_glassfish.dev.java.net
> > > > For additional commands, e-mail: users-help_at_glassfish.dev.java.net
> > > >
> > >
> > >
> > >
> >
> ---------------------------------------------------------------------
> > > To unsubscribe, e-mail: users-unsubscribe_at_glassfish.dev.java.net
> > > For additional commands, e-mail: users-help_at_glassfish.dev.java.net
> > >
> > >
> >
> >
> >       Access Yahoo!7 Mail on your mobile.
> > Anytime. Anywhere.
> > Show me how: http://au.mobile.yahoo.com/mail
> >
> >
> ---------------------------------------------------------------------
> > To unsubscribe, e-mail: users-unsubscribe_at_glassfish.dev.java.net
> > For additional commands, e-mail: users-help_at_glassfish.dev.java.net
> >
> >
>
>
>
>       Access Yahoo!7 Mail on your mobile.
> Anytime. Anywhere.
> Show me how: http://au.mobile.yahoo.com/mail
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe_at_glassfish.dev.java.net
> For additional commands, e-mail: users-help_at_glassfish.dev.java.net
>
> Access Yahoo!7 Mail on your mobile. Anytime. Anywhere. Show me how: http://au.mobile.yahoo.com/mail