glassfish
  1. glassfish
  2. GLASSFISH-14269

[Perf] b26 High thread contention in orb code results in poor performance

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Critical Critical
    • Resolution: Fixed
    • Affects Version/s: 3.1
    • Fix Version/s: 3.1_ms07
    • Component/s: orb
    • Labels:
      None
    • Environment:

      Operating System: All
      Platform: All

    • Issuezilla Id:
      14,269
    • Tags:

      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)

        Issue Links

          Activity

          Hide
          Ken Cavanaugh added a comment -

          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.

          Show
          Ken Cavanaugh added a comment - 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.
          Hide
          Ken Cavanaugh added a comment -
              • Issue 14270 has been marked as a duplicate of this issue. ***
          Show
          Ken Cavanaugh added a comment - Issue 14270 has been marked as a duplicate of this issue. ***
          Hide
          Ken Cavanaugh added a comment -

          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.

          Show
          Ken Cavanaugh added a comment - 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.
          Hide
          Richard S. Hall added a comment -

          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().

          Show
          Richard S. Hall added a comment - 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().

            People

            • Assignee:
              Ken Cavanaugh
              Reporter:
              amitagarwal
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: