[GLASSFISH-14269] [Perf] b26 High thread contention in orb code results in poor performance Created: 28/Oct/10  Updated: 03/Dec/12  Resolved: 02/Nov/10

Status: Closed
Project: glassfish
Component/s: orb
Affects Version/s: 3.1
Fix Version/s: 3.1_ms07

Type: Bug Priority: Critical
Reporter: amitagarwal Assignee: Ken Cavanaugh
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: All
Platform: All


Issue Links:
Dependency
blocks GLASSFISH-13573 [PERF] Huge regression with trade2 be... Closed
blocks GLASSFISH-14348 [Perf] Thread waiting issue in corba ... Closed
Issuezilla Id: 14,269
Tags: PSRBUG

 Description   

We have observed high thread contention in the following code path while running
Trade2 benchmark against latest promoted build b26. This results in a really
significant regression (90% lower). Unless this bug is fixed there is no point
running perf tests. This will show up in all the benchmarks we run.

Here is the stack trace,

java.lang.Thread.State: BLOCKED (on object monitor)
at
com.sun.corba.ee.impl.osgi.loader.OSGIListener.getBundleForClass(OSGIListener.java:313)

  • waiting to lock <0x00002aaab426ab90> (a java.lang.Class for
    com.sun.corba.ee.impl.osgi.loader.OSGIListener)
    at
    com.sun.corba.ee.impl.osgi.loader.OSGIListener.access$000(OSGIListener.java:77)
    at
    com.sun.corba.ee.impl.osgi.loader.OSGIListener$ClassCodeBaseHandlerImpl.loadClass(OSGIListener.java:211)
    at
    com.sun.corba.ee.impl.encoding.CDRInputStream_1_0.getClassFromString(CDRInputStream_1_0.java:2256)
    at
    com.sun.corba.ee.impl.encoding.CDRInputStream_1_0.read_value(CDRInputStream_1_0.java:1095)
    at
    com.sun.corba.ee.impl.encoding.CDRInputStream_1_0.read_value(CDRInputStream_1_0.java:935)
    at
    com.sun.corba.ee.impl.encoding.CDRInputStream_1_0.read_abstract_interface(CDRInputStream_1_0.java:928)
    at
    com.sun.corba.ee.impl.encoding.CDRInputStream_1_0.read_abstract_interface(CDRInputStream_1_0.java:918)
    at
    com.sun.corba.ee.impl.encoding.CDRInputObject.read_abstract_interface(CDRInputObject.java:557)
    at
    com.sun.corba.ee.impl.io.IIOPInputStream.readObjectDelegate(IIOPInputStream.java:391)
    at
    com.sun.corba.ee.impl.io.IIOPInputStream.readObjectOverride(IIOPInputStream.java:544)
    at java.io.ObjectInputStream.readObject(ObjectInputStream.java:345)
    at java.util.Hashtable.readObject(Hashtable.java:859)
    at sun.reflect.GeneratedMethodAccessor105.invoke(Unknown Source)
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at
    com.sun.corba.ee.impl.io.IIOPInputStream.invokeObjectReader(IIOPInputStream.java:1830)
    at
    com.sun.corba.ee.impl.io.IIOPInputStream.inputObject(IIOPInputStream.java:1205)
    at
    com.sun.corba.ee.impl.io.IIOPInputStream.simpleReadObject(IIOPInputStream.java:425)
    at
    com.sun.corba.ee.impl.io.ValueHandlerImpl.readValueInternal(ValueHandlerImpl.java:308)
    at
    com.sun.corba.ee.impl.io.ValueHandlerImpl.readValue(ValueHandlerImpl.java:274)
    at
    com.sun.corba.ee.impl.encoding.CDRInputStream_1_0.readRMIIIOPValueType(CDRInputStream_1_0.java:1015)
    at
    com.sun.corba.ee.impl.encoding.CDRInputStream_1_0.read_value(CDRInputStream_1_0.java:1121)
    at
    com.sun.corba.ee.impl.encoding.CDRInputStream_1_0.read_value(CDRInputStream_1_0.java:935)
    at
    com.sun.corba.ee.impl.encoding.CDRInputObject.read_value(CDRInputObject.java:525)
    at
    com.sun.corba.ee.impl.copyobject.ORBStreamObjectCopierImpl.copy(ORBStreamObjectCopierImpl.java:78)
    at
    com.sun.corba.ee.impl.copyobject.ORBStreamObjectCopierImpl.copy(ORBStreamObjectCopierImpl.java:65)
    at
    com.sun.corba.ee.impl.orbutil.copyobject.FallbackObjectCopierImpl.copy(FallbackObjectCopierImpl.java:69)
    at
    com.sun.corba.ee.impl.orbutil.copyobject.FallbackObjectCopierImpl.copy(FallbackObjectCopierImpl.java:59)
    at com.sun.corba.ee.impl.javax.rmi.CORBA.Util.copyObject(Util.java:768)
    at
    com.sun.corba.ee.impl.presentation.rmi.DynamicMethodMarshallerImpl.copyResult(DynamicMethodMarshallerImpl.java:473)
    at
    com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.privateInvoke(StubInvocationHandlerImpl.java:246)
    at
    com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.invoke(StubInvocationHandlerImpl.java:155)
    at
    com.sun.corba.ee.impl.presentation.rmi.codegen.CodegenStubBase.invoke(CodegenStubBase.java:227)
    at trade._Quote_DynamicStub._copyFromEJB(trade/_Quote_DynamicStub.java)
    at
    com.ibm.ivj.ejb.runtime.AbstractEntityAccessBean.refreshCopyHelper(AbstractEntityAccessBean.java:277)


 Comments   
Comment by Richard S. Hall [ 28/Oct/10 ]

This doesn't appear to have anything to do with OSGi, so I'll remove that from
the summary.

It looks like it might be possible to use a copy-on-write map to eliminate the
need to do locking in OSGIListener.getBundleForClass().

Comment by Ken Cavanaugh [ 28/Oct/10 ]

The construction of the InvocationHandler in WrapperGenerator should
include the getLogger call, rather than calling getLogger in every call to
a logging method. In addition, I'll probably add a flag to avoid calling
the log method inside the OSGIListener.loadClass method unless some debugging
is enabled.

Comment by Ken Cavanaugh [ 28/Oct/10 ]
      • Issue 14270 has been marked as a duplicate of this issue. ***
Comment by Ken Cavanaugh [ 28/Oct/10 ]

I just checked in ORB version 3.1.0-b011 for GlassFish, in svn rev 42273.
This should fix this problem. There are two changes:

1. I moved the lookup of the Logger outside of the body of the InvocationHandler.
The logger is fixed per exception class, so this is only needed once.
The logger should now be created in the static initializer (in this case) of
the ORBUtilSystemException class.

2. I also added a debug flag in OSGIListener to avoid the wrapper calls
completely in the getCodebase method, since this method is called MANY
times per invocation when unmarshaling complex data types.

You can either wait for a nightly build, or get the ORB jars from maven
to try this on b26.

Generated at Tue Feb 09 08:01:54 UTC 2016 using JIRA 6.2.3#6260-sha1:63ef1d6dac3f4f4d7db4c1effd405ba38ccdc558.