openjpa-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Albert Lee (JIRA)" <j...@apache.org>
Subject [jira] Commented: (OPENJPA-366) InternalException thrown in BrokerImpl.endOperation
Date Fri, 21 Sep 2007 15:43:50 GMT

    [ https://issues.apache.org/jira/browse/OPENJPA-366?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12529474
] 

Albert Lee commented on OPENJPA-366:
------------------------------------

An update to this issue:

1) The test scenario is a simple Sale - 1toM - Order processing
2) A EJB 2.1 stateless session bean StationBean is used to drive the Sale. It uses JSE style
access to JPA functions.

    public void ejbCreate() throws javax.ejb.CreateException {
        ut = (UserTransaction) getSessionContext().getUserTransaction();
        saleFactory = Persistence.createEntityManagerFactory("StationSale");
        saleManager = saleFactory.createEntityManager();
    }
  
3) This bean has a getListOrder() method returns Vector<Order>.

    public Vector getListOrders(int saleid) throws Exception {
        String methodName = "getListOrders";
        Vector v = new Vector();
        try {
            ut.begin();
            saleManager.joinTransaction();
            Sale sl = saleManager.find(Sale.class, saleid);
            if (sl != null) {
                saleManager.refresh(sl);
                Collection c = sl.getOrders();
                if (c != null) {
                    Iterator ids = c.iterator();
                    while (ids.hasNext()) {
                        Order o = (Order) ids.next();
                        if (o != null) {
                            v.add(o);
                        }
                    }
                }
                ut.commit();
            } else {
                throw new Exception("getListOrders, Unable to find Sale , returned null for
saleid = "  + saleid);
            }
        } catch (Exception e1) {
            ut.rollback();
            throw e1;
        }
        return v;
    }
    
4) A test driver accesses the StationBean in multiple clients under heavy load. As a result,
the observed exception as report in the original comment occurs.
5) Re-run the test with "openjpa.Multithreaded=true" property resolved the problem. It is
due to the fact that this property installed a ReentrantLock in the BrokerImpl to synchronize
multiple invocations to the same BrokerImpl.
6) After further analysis of the problem, the following stacks revealed the sources of the
multiple invocations to the same broker:

   >>> Thread 1 : Thread[ORB.thread.pool : 3,5,main]
 java.lang.Exception: curThread=Thread[ORB.thread.pool : 3,5,main]:lock={noLock}:threadCnt=2:_operationCount=0
   at org.apache.openjpa.kernel.BrokerImpl.beginOperation(BrokerImpl.java:1723)
   at org.apache.openjpa.kernel.BrokerImpl.newObjectId(BrokerImpl.java:1060)
   at org.apache.openjpa.kernel.DelegatingBroker.newObjectId(DelegatingBroker.java:252)
   at org.apache.openjpa.persistence.EntityManagerImpl.find(EntityManagerImpl.java:347)
   at com.ibm.svt.shoppingcartModule.stationstore.StationStoreSessionBean.getListOrders(StationStoreSessionBean.java:603)
   at com.ibm.svt.shoppingcartModule.stationstore.EJSRemoteStatelessStationStoreSession_5a5c538c.getListOrders(Unknown
Source)
   at com.ibm.svt.shoppingcartModule.stationstore._EJSRemoteStatelessStationStoreSession_5a5c538c_Tie.getListOrders(_EJSRemoteStatelessStationStoreSession_5a5c538c_Tie.java:244)
   at com.ibm.svt.shoppingcartModule.stationstore._EJSRemoteStatelessStationStoreSession_5a5c538c_Tie._invoke(_EJSRemoteStatelessStationStoreSession_5a5c538c_Tie.java:100)
   at com.ibm.CORBA.iiop.ServerDelegate.dispatchInvokeHandler(ServerDelegate.java:613)
   at com.ibm.CORBA.iiop.ServerDelegate.dispatch(ServerDelegate.java:466)
   at com.ibm.rmi.iiop.ORB.process(ORB.java:503)
   at com.ibm.CORBA.iiop.ORB.process(ORB.java:1553)
   at com.ibm.rmi.iiop.Connection.respondTo(Connection.java:2680)
   at com.ibm.rmi.iiop.Connection.doWork(Connection.java:2554)
   at com.ibm.rmi.iiop.WorkUnitImpl.doWork(WorkUnitImpl.java:62)
   at com.ibm.ejs.oa.pool.PooledThread.run(ThreadPool.java:118)
   at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1469)

   >>> Thread 2 : Thread[ORB.thread.pool : 2,5,main]
 java.lang.Exception: curThread=Thread[ORB.thread.pool : 2,5,main]:lock={noLock}:threadCnt=1:_operationCount=0
   at org.apache.openjpa.kernel.BrokerImpl.beginOperation(BrokerImpl.java:1723)
   at org.apache.openjpa.kernel.BrokerImpl.isActive(BrokerImpl.java:1683)
   at org.apache.openjpa.kernel.StateManagerImpl.load(StateManagerImpl.java:352)
   at org.apache.openjpa.kernel.DetachManager.preDetach(DetachManager.java:156)
   at org.apache.openjpa.kernel.DetachManager.preSerialize(DetachManager.java:91)
   at org.apache.openjpa.kernel.StateManagerImpl.serializing(StateManagerImpl.java:1310)
   at com.ibm.svt.shoppingcartModule.storeEntities.Order.pcSerializing(Order.java)
   at com.ibm.svt.shoppingcartModule.storeEntities.Order.writeObject(Order.java)
   at sun.reflect.GeneratedMethodAccessor57.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   at java.lang.reflect.Method.invoke(Method.java:615)
   at com.ibm.rmi.io.IIOPOutputStream.invokeObjectWriter(IIOPOutputStream.java:966)
   at com.ibm.rmi.io.IIOPOutputStream.outputObject(IIOPOutputStream.java:1002)
   at com.ibm.rmi.io.IIOPOutputStream.writeSerializable(IIOPOutputStream.java:1050)
   at com.ibm.rmi.io.IIOPOutputStream.simpleWriteObjectInternal(IIOPOutputStream.java:427)
   at com.ibm.rmi.io.IIOPOutputStream.simpleWriteObjectLoop(IIOPOutputStream.java:455)
   at com.ibm.rmi.io.IIOPOutputStream.defaultWriteObjectDelegate(IIOPOutputStream.java:566)
   at com.ibm.rmi.io.OutputStreamHook.defaultWriteObject(OutputStreamHook.java:132)
   at java.util.Vector.writeObject(Vector.java:869)
   at sun.reflect.GeneratedMethodAccessor10.invoke(Unknown Source)
   at java.util.Vector.writeObject(Vector.java:869)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   at sun.reflect.GeneratedMethodAccessor10.invoke(Unknown Source)
   at java.lang.reflect.Method.invoke(Method.java:615)
   at com.ibm.rmi.io.IIOPOutputStream.invokeObjectWriter(IIOPOutputStream.java:966)
   at com.ibm.rmi.io.IIOPOutputStream.outputObject(IIOPOutputStream.java:1002)
   at com.ibm.rmi.io.IIOPOutputStream.writeSerializable(IIOPOutputStream.java:1050)
   at com.ibm.rmi.io.IIOPOutputStream.simpleWriteObjectInternal(IIOPOutputStream.java:427)
   at com.ibm.rmi.io.IIOPOutputStream.simpleWriteObjectLoop(IIOPOutputStream.java:455)
   at com.ibm.rmi.io.IIOPOutputStream.simpleWriteObject(IIOPOutputStream.java:512)
   at com.ibm.rmi.io.ValueHandlerImpl.writeValue(ValueHandlerImpl.java:159)
   at com.ibm.rmi.iiop.CDROutputStream.write_value(CDROutputStream.java:1477)
   at com.ibm.rmi.iiop.CDROutputStream.write_value(CDROutputStream.java:1497)
   at com.ibm.rmi.iiop.CDROutputStream.write_value(CDROutputStream.java:1459)
   at com.ibm.svt.shoppingcartModule.stationstore._EJSRemoteStatelessStationStoreSession_5a5c538c_Tie.getListOrders(_EJSRemoteStatelessStationStoreSession_5a5c538c_Tie.java:256)
   at com.ibm.svt.shoppingcartModule.stationstore._EJSRemoteStatelessStationStoreSession_5a5c538c_Tie._invoke(_EJSRemoteStatelessStationStoreSession_5a5c538c_Tie.java:100)
   at com.ibm.CORBA.iiop.ServerDelegate.dispatchInvokeHandler(ServerDelegate.java:613)
   at com.ibm.CORBA.iiop.ServerDelegate.dispatch(ServerDelegate.java:466)
   at com.ibm.rmi.iiop.ORB.process(ORB.java:503)
   at com.ibm.CORBA.iiop.ORB.process(ORB.java:1553)
   at com.ibm.rmi.iiop.Connection.respondTo(Connection.java:2680)
   at com.ibm.rmi.iiop.Connection.doWork(Connection.java:2554)
   at com.ibm.rmi.iiop.WorkUnitImpl.doWork(WorkUnitImpl.java:62)
   at com.ibm.ejs.oa.pool.PooledThread.run(ThreadPool.java:118)
   at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1469)

7) Thread #1 is doing the normal em.find processing and hits the BrokerImpl.beginOperation().
8) Thread #2 has completed the em.find processing and the Vector<Order> is collected
properly in the getListOrder() method. ORB/CORBA is trying to serialize the return Vector<Order>
back to the remote client.
9) During this processing, it is getting back to openjpa to serialize an Order in the returning
collection:

   at org.apache.openjpa.kernel.StateManagerImpl.serializing(StateManagerImpl.java:1310)
   at com.ibm.svt.shoppingcartModule.storeEntities.Order.pcSerializing(Order.java)
   at com.ibm.svt.shoppingcartModule.storeEntities.Order.writeObject(Order.java)
   at sun.reflect.GeneratedMethodAccessor57.invoke(Unknown Source)

10) The EJB container guarantees a different StationBean instance is invoked from getListOrders()
method call which initiated from different threads/clients, and since the em in each StationBean
instance is obtained independently from Persistence class, we can concluded the em.find()
in each bean invocation must use a different broker for the em.find() call.
11) Therefore we suspect somehow a incorrect broker (same broker used by Thread #1) is used
during the pcSerializing invocation in Thread #2.
12) Another supporting fact for the hypothesis is we have observed scenario where there are
up to 6 threads accessing the same BrokerImpl. Out of these call stacks, there is always only
one thread exhibits the same stack pattern as in Thread #1 and the other threads have the
Thread #2 call stack pattern.


Questions:
1) What is(are) the conditions (e.g. openjpa features/property) that trigger the Order.pcSerializing()
processing? I wrote a simplier test that mimic the test case and was unable to drive the Order.pcSerializing()
method call.
2) How is the Order.pcSerilizing() determine which BrokerImpl to use to perform the serialization?
3) Any suggestings or insight into how to identify the culprit of this problem?

Any help on this matter is greatly appreciated.
Albert Lee.

> InternalException thrown in BrokerImpl.endOperation
> ---------------------------------------------------
>
>                 Key: OPENJPA-366
>                 URL: https://issues.apache.org/jira/browse/OPENJPA-366
>             Project: OpenJPA
>          Issue Type: Bug
>          Components: kernel
>    Affects Versions: 1.0.0
>         Environment: All platforms
>            Reporter: Albert Lee
>            Assignee: Albert Lee
>             Fix For: 1.0.1, 1.1.0
>
>
> Under heavy load during stress test, the following exception is observed:
> <openjpa-1.0.0-SNAPSHOT-r420667:570288M fatal general error> org.apache.openjpa.persistence.PersistenceException:
null
>         at org.apache.openjpa.kernel.BrokerImpl.endOperation(BrokerImpl.java:1728)
>         at org.apache.openjpa.kernel.BrokerImpl.isActive(BrokerImpl.java:1676)
>         at org.apache.openjpa.kernel.DelegatingBroker.isActive(DelegatingBroker.java:420)
>         at org.apache.openjpa.persistence.EntityManagerImpl.isActive(EntityManagerImpl.java:502)
>         at org.apache.openjpa.persistence.PersistenceExceptions$2.translate(PersistenceExceptions.java:66)
>         at org.apache.openjpa.kernel.DelegatingBroker.translate(DelegatingBroker.java:110)
>         at org.apache.openjpa.kernel.DelegatingBroker.newObjectId(DelegatingBroker.java:262)
>         at org.apache.openjpa.persistence.EntityManagerImpl.find(EntityManagerImpl.java:347)
>         at com.ibm.svt.shoppingcartModule.stationstore.StationStoreSessionBean.getListOrders(StationStoreSessionBean.java:603)
>         at com.ibm.svt.shoppingcartModule.stationstore.EJSRemoteStatelessStationStoreSession_5a5c538c.getListOrders(Unknown
Source)
>         at com.ibm.svt.shoppingcartModule.stationstore._EJSRemoteStatelessStationStoreSession_5a5c538c_Tie.getListOrders(_EJSRemoteStatelessStationStoreSession_5a5c538c_Tie.java:244)
>         at com.ibm.svt.shoppingcartModule.stationstore._EJSRemoteStatelessStationStoreSession_5a5c538c_Tie._invoke(_EJSRemoteStatelessStationStoreSession_5a5c538c_Tie.java:100)
>         at com.ibm.CORBA.iiop.ServerDelegate.dispatchInvokeHandler(ServerDelegate.java:613)
>         at com.ibm.CORBA.iiop.ServerDelegate.dispatch(ServerDelegate.java:466)
>         at com.ibm.rmi.iiop.ORB.process(ORB.java:503)
>         at com.ibm.CORBA.iiop.ORB.process(ORB.java:1553)
>         at com.ibm.rmi.iiop.Connection.respondTo(Connection.java:2680)
>         at com.ibm.rmi.iiop.Connection.doWork(Connection.java:2554)
>         at com.ibm.rmi.iiop.WorkUnitImpl.doWork(WorkUnitImpl.java:62)
>         at com.ibm.ejs.oa.pool.PooledThread.run(ThreadPool.java:118)
>         at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1469)
> [8/31/07 22:45:26:265 EDT] 000000c1 SystemOut     O   MDD Translating exception: <openjpa-0.0.0-r420667:570288
fatal internal error> org.apache.openjpa.util.InternalException: null
> [8/31/07 22:45:26:265 EDT] 000000c1 SystemErr     R   <openjpa-0.0.0-r420667:570288
fatal internal error> org.apache.openjpa.util.InternalException: null
> [8/31/07 22:45:26:265 EDT] 000000c1 SystemErr     R   	at org.apache.openjpa.kernel.BrokerImpl.endOperation(BrokerImpl.java:1728)
> After some investigation, it was determined that the internal exception is caused by
>              if (_operationCount < 1)
>                 throw new InternalException();
> in BrokerImpl.endOperation();
> We believe the cause of the problem is a lock() method call is missing in the endOperation()
>     public boolean endOperation() {
>         lock();   <<<<<  This is the missing lock() call since BrokerImpl.java
was created
>         try {
>             if (_operationCount == 1 && (_autoDetach & DETACH_NONTXREAD)
!= 0
>                 && (_flags & FLAG_ACTIVE) == 0) {
>                 detachAllInternal(null);
>             }
>             if (_operationCount < 1)
>                 throw new InternalException();
>             return _operationCount == 1;
>         } catch (OpenJPAException ke) {
>             throw ke;
>         } catch (RuntimeException re) {
>             throw new GeneralException(re);
>         } finally {
>             _operationCount--;
>             if (_operationCount == 0)
>                 _operating.clear();
>             unlock();
>         }
>     }
> Once we have done more tests and verify the fix, I'll submit a patch for this problem.
> If anyone doesn't think this is the solution. please response.
> Albert Lee.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


Mime
View raw message