glassfish
  1. glassfish
  2. GLASSFISH-14348

[Perf] Thread waiting issue in corba code causes perf regression

    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,348
    • Tags:

      Description

      Tried nightly build b27-10_31_2010 after bug
      https://glassfish.dev.java.net/issues/show_bug.cgi?id=14269 got resolved. I
      don't see the reported issue in GLASSFISH-14269 but now I see plenty of threads are
      waiting in following codepath.
      This still causes quite a bit of regression from b25.

      java.lang.Thread.State: WAITING (parking)
      at sun.misc.Unsafe.park(Native Method)

      • parking to wait for <0x00002aaac2080668> (a
        java.util.concurrent.locks.ReentrantReadWriteLock$FairSync)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
        at
        java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:747)
        at
        java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:778)
        at
        java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1114)
        at
        java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:807)
        at com.sun.corba.ee.impl.oa.poa.POAManagerImpl.exit(POAManagerImpl.java:690)
        at com.sun.corba.ee.impl.oa.poa.POAImpl.exit(POAImpl.java:1694)
        at
        com.sun.corba.ee.impl.protocol.ServantCacheLocalCRDBase.updateCachedInfo(ServantCacheLocalCRDBase.java:99)
        at
        com.sun.corba.ee.impl.protocol.ServantCacheLocalCRDBase.getCachedInfo(ServantCacheLocalCRDBase.java:77)
      • locked <0x00002aabafef6f50> (a
        com.sun.corba.ee.impl.protocol.FullServantCacheLocalCRDImpl)
        at
        com.sun.corba.ee.impl.protocol.FullServantCacheLocalCRDImpl.internalPreinvoke(FullServantCacheLocalCRDImpl.java:64)
        at
        com.sun.corba.ee.impl.protocol.LocalClientRequestDispatcherBase.servant_preinvoke(LocalClientRequestDispatcherBase.java:240)
        at
        com.sun.corba.ee.impl.protocol.CorbaClientDelegateImpl.servant_preinvoke(CorbaClientDelegateImpl.java:544)
        at
        com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.privateInvoke(StubInvocationHandlerImpl.java:218)
        at
        com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.invoke(StubInvocationHandlerImpl.java:152)
        at
        com.sun.corba.ee.impl.presentation.rmi.codegen.CodegenStubBase.invoke(CodegenStubBase.java:227)
        at trade._MySession_DynamicStub.getHandle(trade/_MySession_DynamicStub.java)
        at trade_client.TradeServletAction.doLogin(TradeServletAction.java:619)
        at
        trade_client.TradeScenarioServlet.performTask(TradeScenarioServlet.java:224)
        at trade_client.TradeScenarioServlet.doGet(TradeScenarioServlet.java:72)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:735)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:848)
        at
        org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1522)
        at
        org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:281)
        at
        org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
        at
        org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:655)
        at
        org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:595)
        at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:98)
        at
        com.sun.enterprise.web.PESessionLockingStandardPipeline.invoke(PESessionLockingStandardPipeline.java:91)
        at
        org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:162)
        at
        org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:326)
        at
        org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:227)
        at
        com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:170)
        at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:817)
        at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:718)
        at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1007)
        at
        com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:225)
        at
        com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137)
        at
        com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104)
        at
        com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90)
        at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:79)
        at
        com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54)

        Issue Links

          Activity

          Hide
          Ken Cavanaugh added a comment -

          The POAManagerImpl.exit code is taking the writeLock too often: it should
          only do this if there actually are waiters for the state change, which only
          happens when a POAManager state change operation is called. As this is very
          rare, the lock is not normally needed.

          Show
          Ken Cavanaugh added a comment - The POAManagerImpl.exit code is taking the writeLock too often: it should only do this if there actually are waiters for the state change, which only happens when a POAManager state change operation is called. As this is very rare, the lock is not normally needed.
          Hide
          Ken Cavanaugh added a comment -

          Fix integrated in GF 3.1 rev 42400 (ORB version 3.1.0-b012).

          Show
          Ken Cavanaugh added a comment - Fix integrated in GF 3.1 rev 42400 (ORB version 3.1.0-b012).
          Hide
          Ken Cavanaugh added a comment -

          Forgot to update the status.

          Show
          Ken Cavanaugh added a comment - Forgot to update the status.
          Hide
          amitagarwal added a comment -

          I still the same issue.

          Here are the stack trace,

          1)
          java.lang.Thread.State: WAITING (parking)
          at sun.misc.Unsafe.park(Native Method)

          • parking to wait for <0x00002aaabd904070> (a
            java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
            at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
            at
            java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811)
            at
            java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:842)
            at
            java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1178)
            at
            java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:807)
            at com.sun.corba.ee.impl.oa.poa.POAImpl.lock(POAImpl.java:346)
            at com.sun.corba.ee.impl.oa.poa.POAImpl.find_POA(POAImpl.java:927)
            at com.sun.corba.ee.impl.oa.poa.POAFactory.find(POAFactory.java:224)
            at
            com.sun.corba.ee.impl.protocol.ServantCacheLocalCRDBase.updateCachedInfo(ServantCacheLocalCRDBase.java:86)
            at
            com.sun.corba.ee.impl.protocol.ServantCacheLocalCRDBase.getCachedInfo(ServantCacheLocalCRDBase.java:77)
          • locked <0x00002aab8b9f7f10> (a
            com.sun.corba.ee.impl.protocol.FullServantCacheLocalCRDImpl)
            at
            com.sun.corba.ee.impl.protocol.FullServantCacheLocalCRDImpl.internalPreinvoke(FullServantCacheLocalCRDImpl.java:64)
            at
            com.sun.corba.ee.impl.protocol.LocalClientRequestDispatcherBase.servant_preinvoke(LocalClientRequestDispatcherBase.java:240)
            at
            com.sun.corba.ee.impl.protocol.CorbaClientDelegateImpl.servant_preinvoke(CorbaClientDelegateImpl.java:544)
            at
            com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.privateInvoke(StubInvocationHandlerImpl.java:218)
            at
            com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.invoke(StubInvocationHandlerImpl.java:152)
            at
            com.sun.corba.ee.impl.presentation.rmi.codegen.CodegenStubBase.invoke(CodegenStubBase.java:227)

          2)
          java.lang.Thread.State: WAITING (parking)
          at sun.misc.Unsafe.park(Native Method)

          • parking to wait for <0x00002aaac190ba60> (a
            java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
            at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
            at
            java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811)
            at
            java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:842)
            at
            java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1178)
            at
            java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:807)
            at com.sun.corba.ee.impl.oa.poa.POAImpl.lock(POAImpl.java:346)
            at com.sun.corba.ee.impl.oa.poa.POAImpl.find_POA(POAImpl.java:927)
            at
            com.sun.corba.ee.impl.oa.rfm.ReferenceFactoryManagerImpl.createReference(ReferenceFactoryManagerImpl.java:546)
            at
            com.sun.corba.ee.impl.oa.rfm.ReferenceFactoryImpl.createReference(ReferenceFactoryImpl.java:62)
            at
            org.glassfish.enterprise.iiop.impl.POARemoteReferenceFactory._createRef(POARemoteReferenceFactory.java:439)
            at
            org.glassfish.enterprise.iiop.impl.POARemoteReferenceFactory.createRef(POARemoteReferenceFactory.java:402)
            at
            org.glassfish.enterprise.iiop.impl.POARemoteReferenceFactory.createRemoteReference(POARemoteReferenceFactory.java:366)
            at
            com.sun.ejb.containers.EntityContainer.getEJBObjectStub(EntityContainer.java:1819)
            at com.sun.ejb.containers.EntityContainer.postFind(EntityContainer.java:920)
            at
            com.sun.ejb.containers.EntityContainer.invokeFindByPrimaryKey(EntityContainer.java:815)
            at
            com.sun.ejb.containers.EJBHomeInvocationHandler.invoke(EJBHomeInvocationHandler.java:306)
            at $Proxy179.findByPrimaryKey(Unknown Source)
            at sun.reflect.GeneratedMethodAccessor98.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.presentation.rmi.StubInvocationHandlerImpl.privateInvoke(StubInvocationHandlerImpl.java:241)
            at
            com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.invoke(StubInvocationHandlerImpl.java:152)
            at
            com.sun.corba.ee.impl.presentation.rmi.codegen.CodegenStubBase.invoke(CodegenStubBase.java:227)
          Show
          amitagarwal added a comment - I still the same issue. Here are the stack trace, 1) java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) parking to wait for <0x00002aaabd904070> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:842) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1178) at java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:807) at com.sun.corba.ee.impl.oa.poa.POAImpl.lock(POAImpl.java:346) at com.sun.corba.ee.impl.oa.poa.POAImpl.find_POA(POAImpl.java:927) at com.sun.corba.ee.impl.oa.poa.POAFactory.find(POAFactory.java:224) at com.sun.corba.ee.impl.protocol.ServantCacheLocalCRDBase.updateCachedInfo(ServantCacheLocalCRDBase.java:86) at com.sun.corba.ee.impl.protocol.ServantCacheLocalCRDBase.getCachedInfo(ServantCacheLocalCRDBase.java:77) locked <0x00002aab8b9f7f10> (a com.sun.corba.ee.impl.protocol.FullServantCacheLocalCRDImpl) at com.sun.corba.ee.impl.protocol.FullServantCacheLocalCRDImpl.internalPreinvoke(FullServantCacheLocalCRDImpl.java:64) at com.sun.corba.ee.impl.protocol.LocalClientRequestDispatcherBase.servant_preinvoke(LocalClientRequestDispatcherBase.java:240) at com.sun.corba.ee.impl.protocol.CorbaClientDelegateImpl.servant_preinvoke(CorbaClientDelegateImpl.java:544) at com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.privateInvoke(StubInvocationHandlerImpl.java:218) at com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.invoke(StubInvocationHandlerImpl.java:152) at com.sun.corba.ee.impl.presentation.rmi.codegen.CodegenStubBase.invoke(CodegenStubBase.java:227) 2) java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) parking to wait for <0x00002aaac190ba60> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:842) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1178) at java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:807) at com.sun.corba.ee.impl.oa.poa.POAImpl.lock(POAImpl.java:346) at com.sun.corba.ee.impl.oa.poa.POAImpl.find_POA(POAImpl.java:927) at com.sun.corba.ee.impl.oa.rfm.ReferenceFactoryManagerImpl.createReference(ReferenceFactoryManagerImpl.java:546) at com.sun.corba.ee.impl.oa.rfm.ReferenceFactoryImpl.createReference(ReferenceFactoryImpl.java:62) at org.glassfish.enterprise.iiop.impl.POARemoteReferenceFactory._createRef(POARemoteReferenceFactory.java:439) at org.glassfish.enterprise.iiop.impl.POARemoteReferenceFactory.createRef(POARemoteReferenceFactory.java:402) at org.glassfish.enterprise.iiop.impl.POARemoteReferenceFactory.createRemoteReference(POARemoteReferenceFactory.java:366) at com.sun.ejb.containers.EntityContainer.getEJBObjectStub(EntityContainer.java:1819) at com.sun.ejb.containers.EntityContainer.postFind(EntityContainer.java:920) at com.sun.ejb.containers.EntityContainer.invokeFindByPrimaryKey(EntityContainer.java:815) at com.sun.ejb.containers.EJBHomeInvocationHandler.invoke(EJBHomeInvocationHandler.java:306) at $Proxy179.findByPrimaryKey(Unknown Source) at sun.reflect.GeneratedMethodAccessor98.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.presentation.rmi.StubInvocationHandlerImpl.privateInvoke(StubInvocationHandlerImpl.java:241) at com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.invoke(StubInvocationHandlerImpl.java:152) at com.sun.corba.ee.impl.presentation.rmi.codegen.CodegenStubBase.invoke(CodegenStubBase.java:227)
          Hide
          Ken Cavanaugh added a comment -

          Both of the new lock contention issues have the same cause: exclusive write
          locking in POAImpl.find_POA. I can fix that, but please note that this is
          a different issue than was originally reported. That's OK: we are using
          this issue generically for any corba trade2 perf issue. But we need to find
          a way to turn around fixes for this faster than once a week or so. What we
          are doing here is finding issues one after another, because one issue
          masks another.

          A question: why are these issues showing up now? In most case, I haven't
          changed the code since GF 2.1.

          I'll fix this in the morning. Currently that means a new ORB integration
          into the current GF 3.1, which will take at least 3 hours elapsed time.

          Show
          Ken Cavanaugh added a comment - Both of the new lock contention issues have the same cause: exclusive write locking in POAImpl.find_POA. I can fix that, but please note that this is a different issue than was originally reported. That's OK: we are using this issue generically for any corba trade2 perf issue. But we need to find a way to turn around fixes for this faster than once a week or so. What we are doing here is finding issues one after another, because one issue masks another. A question: why are these issues showing up now? In most case, I haven't changed the code since GF 2.1. I'll fix this in the morning. Currently that means a new ORB integration into the current GF 3.1, which will take at least 3 hours elapsed time.
          Hide
          Ken Cavanaugh added a comment -

          The common path through POA_find (the case where the POA already exists)
          now only requires a read lock, so that should fix this performance issue.
          Integrated into GF 3.1 rev 42781.

          Show
          Ken Cavanaugh added a comment - The common path through POA_find (the case where the POA already exists) now only requires a read lock, so that should fix this performance issue. Integrated into GF 3.1 rev 42781.

            People

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

              Dates

              • Created:
                Updated:
                Resolved: