[jboss-dev] Possible blocker with jboss-cl 2.2.0.Alpha1
Jaikiran Pai
jpai at redhat.com
Mon Feb 8 03:00:48 EST 2010
Here's a bit of background about the testcase that's hanging and what i
have so far been able to understand about this issue. The testcase
that's hanging is this one
http://anonsvn.jboss.org/repos/jbossas/projects/ejb3/trunk/testsuite/src/test/java/org/jboss/ejb3/test/ejbthree1116/unit/ContainerShutdownTestCase.java
The testcase does numerous deploy/undeploy cycles of a EJB3 .jar
deployment and in between these deploy/undeploy cycles, looks up and
performs operations on the bean. With jbcl 2.0.0-Alpha-1 (which is is AS
trunk), the testcase hangs consistently. The client side (JVM where the
JUnit test runs) shows this threaddump (posting only the relevant bit,
if anyone wants to see the entire dump let me know):
[junit] "main" prio=10 tid=0x0000000044c91000 nid=0x616c runnable
[0x000000004136b000]
[junit] java.lang.Thread.State: RUNNABLE
[junit] at java.net.SocketInputStream.socketRead0(Native Method)
[junit] at
java.net.SocketInputStream.read(SocketInputStream.java:129)
[junit] at
java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
[junit] at
java.io.BufferedInputStream.read(BufferedInputStream.java:237)
[junit] - locked <0x00002aaab38dbdb8> (a
java.io.BufferedInputStream)
[junit] at
java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2249)
[junit] at
java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2429)
[junit] at
java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2499)
[junit] at
java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2571)
[junit] at
java.io.ObjectInputStream.read(ObjectInputStream.java:820)
[junit] at
org.jboss.remoting.transport.socket.MicroSocketClientInvoker.readVersion(MicroSocketClientInvoker.java:1342)
[junit] at
org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:895)
[junit] at
org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:167)
[junit] at org.jboss.remoting.Client.invoke(Client.java:1927)
[junit] at org.jboss.remoting.Client.invoke(Client.java:770)
[junit] at
org.jboss.aspects.remoting.InvokeRemoteInterceptor.invoke(InvokeRemoteInterceptor.java:60)
[junit] at
org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
[junit] at
org.jboss.ejb3.proxy.impl.remoting.IsLocalProxyFactoryInterceptor.invoke(IsLocalProxyFactoryInterceptor.java:104)
[junit] at
org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
[junit] at
org.jboss.aspects.remoting.PojiProxy.invoke(PojiProxy.java:62)
[junit] at $Proxy1.createProxyBusiness(Unknown Source)
[junit] at
org.jboss.ejb3.proxy.impl.objectfactory.session.SessionProxyObjectFactory.createProxy(SessionProxyObjectFactory.java:129)
[junit] at
org.jboss.ejb3.proxy.impl.objectfactory.session.stateful.StatefulSessionProxyObjectFactory.getProxy(StatefulSessionProxyObjectFactory.java:64)
[junit] at
org.jboss.ejb3.proxy.impl.objectfactory.ProxyObjectFactory.getObjectInstance(ProxyObjectFactory.java:161)
[junit] at
javax.naming.spi.NamingManager.getObjectInstance(NamingManager.java:304)
[junit] at
org.jnp.interfaces.NamingContext.getObjectInstance(NamingContext.java:1483)
[junit] at
org.jnp.interfaces.NamingContext.getObjectInstanceWrapFailure(NamingContext.java:1500)
[junit] at
org.jnp.interfaces.NamingContext.lookup(NamingContext.java:824)
[junit] at
org.jnp.interfaces.NamingContext.lookup(NamingContext.java:688)
[junit] at
javax.naming.InitialContext.lookup(InitialContext.java:392)
[junit] at
org.jboss.ejb3.test.ejbthree1116.unit.ContainerShutdownTestCase.testConcurrentCreate(ContainerShutdownTestCase.java:262)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
Method)
[junit] at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at junit.framework.TestCase.runTest(TestCase.java:168)
[junit] at junit.framework.TestCase.runBare(TestCase.java:134)
[junit] at junit.framework.TestResult$1.protect(TestResult.java:110)
[junit] at
junit.framework.TestResult.runProtected(TestResult.java:128)
[junit] at junit.framework.TestResult.run(TestResult.java:113)
[junit] at junit.framework.TestCase.run(TestCase.java:124)
[junit] at junit.framework.TestSuite.runTest(TestSuite.java:232)
[junit] at junit.framework.TestSuite.run(TestSuite.java:227)
[junit] at junit.framework.TestSuite.runTest(TestSuite.java:232)
[junit] at junit.framework.TestSuite.run(TestSuite.java:227)
[junit] at
junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
[junit] at junit.extensions.TestSetup$1.protect(TestSetup.java:23)
[junit] at
junit.framework.TestResult.runProtected(TestResult.java:128)
[junit] at junit.extensions.TestSetup.run(TestSetup.java:27)
[junit] at
org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
[junit] at
org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
[junit] at
org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
As can be seen, the testcase does a lookup of a bean which internally
results in a JBoss Remoting call. From the looks of it, the remoting
call does a SocketInputStream read with timeout = 0 (i.e. indefinite
timeout). The client side hang is just a side-effect of what has
happened on the server (see below).
On the server side, the remoting ServerThread which is trying to write
out data to the socket stream runs into errors with classloading
(specifically classes present in rt.jar run into problems during
classloading):
2010-02-05 23:26:29,357 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
org.jboss.threads.QueueExecutor.access$100(QueueExecutor.java:45)
2010-02-05 23:26:29,357 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
org.jboss.threads.QueueExecutor$Worker.run(QueueExecutor.java:821)
2010-02-05 23:26:29,357 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.lang.Thread.run(Thread.java:619)
2010-02-05 23:26:29,357 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
org.jboss.threads.JBossThread.run(JBossThread.java:122)
2010-02-05 23:26:29,357 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) message =
delegator->JBossMessage[5183201567768876]:NON-PERSISTENT, deliveryId=0
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) Exception in thread
"WorkerThread#44[127.0.0.1:41558]" java.lang.NoClassDefFoundError:
java/lang/String
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.lang.Class.getDeclaredMethods0(Native Method)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.lang.Class.privateGetDeclaredMethods(Class.java:2427)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.lang.Class.getDeclaredMethod(Class.java:1935)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.io.ObjectStreamClass.getPrivateMethod(ObjectStreamClass.java:1382)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.io.ObjectStreamClass.access$1700(ObjectStreamClass.java:52)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.io.ObjectStreamClass$2.run(ObjectStreamClass.java:438)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.security.AccessController.doPrivileged(Native Method)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.io.ObjectStreamClass.<init>(ObjectStreamClass.java:413)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.io.ObjectStreamClass.lookup(ObjectStreamClass.java:310)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1106)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:326)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
org.jboss.aop.joinpoint.InvocationResponse.writeExternal(InvocationResponse.java:100)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.io.ObjectOutputStream.writeExternalData(ObjectOutputStream.java:1421)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1390)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1150)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1509)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1474)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1392)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1150)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:326)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
org.jboss.remoting.serialization.impl.java.JavaSerializationManager.sendObjectVersion2_2(JavaSerializationManager.java:120)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
org.jboss.remoting.serialization.impl.java.JavaSerializationManager.sendObject(JavaSerializationManager.java:95)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
org.jboss.remoting.marshal.serializable.SerializableMarshaller.write(SerializableMarshaller.java:120)
2010-02-05 23:26:29,358 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
org.jboss.remoting.transport.socket.ServerThread.versionedWrite(ServerThread.java:1049)
2010-02-05 23:26:29,359 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
org.jboss.remoting.transport.socket.ServerThread.completeInvocation(ServerThread.java:807)
2010-02-05 23:26:29,359 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:721)
2010-02-05 23:26:29,359 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:548)
2010-02-05 23:26:29,359 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:234)
2010-02-05 23:26:29,359 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) Caused by:
java.lang.ClassNotFoundException: Class not found java.lang.String
2010-02-05 23:26:29,359 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
org.jboss.classloader.spi.base.BaseClassLoader.loadClassFromDomain(BaseClassLoader.java:892)
2010-02-05 23:26:29,359 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
org.jboss.classloader.spi.base.BaseClassLoader.doLoadClass(BaseClassLoader.java:522)
2010-02-05 23:26:29,359 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
org.jboss.classloader.spi.base.BaseClassLoader.loadClass(BaseClassLoader.java:467)
2010-02-05 23:26:29,359 ERROR [STDERR]
(WorkerThread#44[127.0.0.1:41558]) at
java.lang.ClassLoader.loadClass(ClassLoader.java:252)
The CNFE is actually a NCDFE (see the stacktrace). It's *not* always
with java.lang.String, sometimes it's with java.lang.reflect.Method and
sometimes with a sun.* class. But all these classes are the ones present
in rt.jar. Because of this exception, the ServerThread isn't able to
write out the data and the client side (JUnit) just keeps waiting.
There's also another different issue i see with this exception
stacktrace. It appears to me that something is eating/messing up the
exception stacktrace. One reason why i think so is because the exception
stacktrace being logged appears to be a result of System.err.prinltn
rather than a logger.error (notice the STDERR instead of the logger
class name). I also think that this isn't really the entire exception
stacktrace. But that's a different issue i guess. The important thing is
why is this thread running into issues trying to load something from rt.jar.
regards,
-Jaikiran
Brian Stansberry wrote:
> Thanks, Jaikiran. I'm forwarding this to the jboss-dev list for
> greater visibility.
>
> The EJB3 team is seeing consistent failures where a server thread is
> unable to load classes from rt.jar. These occur in a test where a
> remote client makes requests against a service that is concurrently
> being undeployed. Failure is quite similar to what is seen at
> https://jira.jboss.org/jira/browse/JBAS-7688 and previously mentioned
> on this list.[1]
>
> I've elevated JBAS-7688 to Blocker; we'll have to get comfortable
> early next week that this isn't due to the jboss-cl 2.2.0.Alpha1
> upgrade, fix jboss-cl 2.2.0, or roll back AS trunk to 2.0.8.GA.
>
> [1]
> http://lists.jboss.org/pipermail/jboss-development/2010-February/015693.html
>
>
> On 02/06/2010 09:24 AM, Jaikiran Pai wrote:
>> I switched one of the jobs (which i have been using for testing) on Mike
>> to 2.0.8.GA of jbcl and haven't seen this hang in those. However, the
>> other job which is using 2.2.0.Alpha1 is consistently hanging with the
>> same exception being thrown. I have tried to reproduce this locally, but
>> haven't been able to do so (i.e. the test runs fine with 2.2.0.Alpha1 on
>> my local setup).
>>
>> The exception stacktrace (as Carlo posted earlier) seems to be
>> originating from a remoting thread which is doing some marshalling and
>> running into CNFE (all these CNFE classes so far have been the ones
>> residing in rt.jar). I took a thread dump of the server, at the time
>> when Mike was hung during this testcase - couldn't find anything useful
>> in there. Perhaps, i should be taking a thread dump of the JVM on the
>> client (the JUnit testcase), to see what it is waiting on. At the same
>> time, David mentions[1] that:
>>
>> "I hypothesize that the classloader is (sometimes) being destroyed
>> before the thread gets going, causing it to be unable to load anything
>> at all."
>>
>> I'll see if i can figure out:
>>
>> 1) Whether that statement applies to this testcase too
>> 2) Why this happens specifically in this testcase
>>
>>
>>
>> [1]
>> http://lists.jboss.org/pipermail/jboss-development/2010-February/015694.html
>>
>>
>>
>> regards,
>> -Jaikiran
>> Brian Stansberry wrote:
>>> On 02/04/2010 12:18 PM, Jaikiran Pai wrote:
>>>> Mike is running into this again
>>>> http://mike.lab.bos.redhat.com:8380/hudson/job/EJB3_1-1.0.3-JBoss-AS-6.x-tests-ejb3/3/console
>>>>
>>>>
>>>>
>>>>
>>>> The https://jira.jboss.org/jira/browse/EJBTHREE-1982 has linked
>>>> JBKERNEL-86 as one of the problems. JBKERNEL-86 is marked as fixed in
>>>> 2.2.0.alpha-4 of MC kernel. The current AS trunk has 2.2.0-alpha-5.
>>>> But
>>>> we are still seeing the same hang. So i guess there's more to it.
>>>> Looking at the logs (attached) i don't see an explicit OOM, but i
>>>> do see
>>>> signs of it (like CNFE on a com.sun.* class after numerous deploys).
>>>
>>> On the face of it that sounds like a different problem. Occam's razor
>>> say's it's not, but a CNFE seems like a different beast than a memory
>>> leak.
>>>
>>> Possibly the CNFE is due to the jboss-cl upgrade to 2.2.0.Alpha1? See
>>> https://jira.jboss.org/jira/browse/JBAS-7688 for another issue where
>>> after that change classes in rt.jar weren't available.
>>>
>>> The AS should run fine w/ it's jboss-cl moved back to 2.0.8.GA, so
>>> this theory is testable.
>>
>
>
More information about the jboss-development
mailing list