Is this a caching problem I am facing here?

[greiezer]

After deploying xpetstore-ejb.ear on a jboss-3.2.3RC1 - postgreSQL7.3 configuration, I was trying to place 4 orders.
But only the very first order succeeds, the subsequent 3 orders fail.
There is a one-to-many CMR between CustomerEJB and OrderEJB.

When I look at the db entries, I wonder why there only exists ONE entry with a no-empty foreign key for the relating customer.
Has that something to do with EJB instance caching?

xpetstore3.1.3=> SELECT * from t_order;
orderuid | orderdate | orderstatus | customer_fk
----------+------------------------------------+-----------------+-----------------
1 | 2003-11-30 04:16:20.126 | to-deliver |
2 | 2003-11-30 04:17:09.338 | pending |
3 | 2003-11-30 04:18:56.711 | pending |
4 | 2003-11-30 04:19:04.961 | pending | user1
(4 rows)

Order creation is done like this:
OrderEJB.java

/**
* @ejb.create-method
*/
public Integer ejbCreate( String userId, java.util.Date orderDate )
throws CreateException
{
int uid = 0;
try {
uid = UIDGeneratorUtil.getLocalHome().create().getUniqueId(COUNTER_NAME);
setOrderUId( new Integer( uid ) );
setOrderDate( orderDate );
setOrderStatus( xpetstore.domain.order.model.OrderStatus.PENDING );
}
catch( Exception e ) {
throw new EJBException( e );
}
return null;
}

public void ejbPostCreate( String userId, java.util.Date orderDate )
throws CreateException {
try {
CustomerLocal cst = CustomerUtil.getLocalHome( ).findByPrimaryKey( userId );
setCustomer( cst );
}
catch( Exception e ) {
throw new EJBException( e );
}
}

//-----------------------------------------

OrderProcessorMDB.java

Inside the onMessage() method for this bean, as said before, only the very first order get processed correctly.
Subsequent orders throw ObjectNotFoundException for the orderHome.findByPrimaryKey() call;
For debugging reasons I added a orderHome.findAll() method, which, when called inside onMessage(), sometimes returns a collection of component interfaces that IS NOT REPRESENTING the actual DB STATE.

After the 1. order was placed - orderHome.findAll() returned only 1 component interfaces
After the 2. order was placed - orderHome.findAll() returned only 1 component interfaces - 1 missing !
After the 3. order was placed - orderHome.findAll() returned only 2 component interfaces - 1 missing !
After the 4. order was placed - orderHome.findAll() returned only 3 component interfaces - 1 missing !

How is that?


================== log excerpts ==================

04:16:20,105 INFO [SignOnFilter] doFilter()
04:16:20,106 INFO [SignOnFilter] ...uri=createOrder.jspa
04:16:20,108 INFO [RequestProcessor] Processing a 'POST' for path '/createOrder'
04:16:20,112 DEBUG [ThreadPool] Getting new thread data
04:16:20,123 INFO [CreateOrderAction] execute()
04:16:20,161 INFO [STDOUT] ** [ OrderEJB ] ejbCreate()
04:16:20,352 INFO [STDOUT] ** [ OrderEJB ] ejbCreate() done
04:16:20,364 INFO [STDOUT] ** [ OrderEJB ] ejbPostCreate()
04:16:20,392 INFO [STDOUT] ** [ OrderEJB ] ejbPostCreate() done
04:16:20,395 DEBUG [Order] Executing SQL: UPDATE t_order SET customer_fk=? WHERE orderUId=?
04:16:20,398 DEBUG [Order] Rows affected = 1
04:16:20,500 INFO [STDOUT] sendToJMSQueue(java:comp/env/jms/queue/xpetstore/order,1,false)
04:16:20,642 INFO [STDOUT] OrderProcessorMDB.onMessage(org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : QUEUE.order
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:3-10701621805641
jmsTimeStamp : 1070162180564
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropertiesReadWrite:false
msgReadOnly : true
producerClientId: ID:3
}
})
04:16:20,648 DEBUG [Order#findAll] Executing SQL: SELECT t0_o.orderUId FROM t_order t0_o
04:16:20,653 DEBUG [OrderItem] Rows affected = 1
04:16:20,723 INFO [STDOUT] *** orderStubs.size()1
04:16:20,725 DEBUG [Order#findByPrimaryKey] Executing SQL: SELECT orderUId FROM t_order WHERE orderUId=?
04:16:20,729 DEBUG [Order] Executing SQL: SELECT orderDate, orderstatus, customer_fk FROM t_order WHERE (orderUId=?)
04:16:20,743 DEBUG [Customer] Executing SQL: SELECT firstname, lastname, email, telephone, language, street1, street2, city, state, zipcode, country, creditCardNumber, creditCardType, creditCardExpiryDate, account_fk FROM t_customer WHERE (userId=?)
04:16:20,777 INFO [STDOUT] sendToJMSQueue(java:comp/env/jms/queue/xpetstore/mail,xpetstore.services.mail.model.Email@eaf672,false)
04:16:20,848 INFO [STDOUT] MailerMDB.onMessage(org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : QUEUE.mail
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:4-10701621808281
jmsTimeStamp : 1070162180828
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropertiesReadWrite:false
msgReadOnly : true
producerClientId: ID:4
}
})
04:16:20,857 INFO [STDOUT] MailerMDB.send([e-mail],[Petstore] Order Confirmation,...)
04:16:21,066 WARN [TxConnectionManager] Prepare called on a local tx. Use of local transactions on a jta transaction with more than one branch may result in inconsistent data in some cases of failure.


04:17:09,330 INFO [SignOnFilter] doFilter()
04:17:09,332 INFO [SignOnFilter] ...uri=createOrder.jspa
04:17:09,333 INFO [RequestProcessor] Processing a 'POST' for path '/createOrder'
04:17:09,336 INFO [CreateOrderAction] execute()
04:17:09,339 INFO [STDOUT] ** [ OrderEJB ] ejbCreate()
04:17:09,349 INFO [STDOUT] ** [ OrderEJB ] ejbCreate() done
04:17:09,359 INFO [STDOUT] ** [ OrderEJB ] ejbPostCreate()
04:17:09,383 INFO [STDOUT] ** [ OrderEJB ] ejbPostCreate() done
04:17:09,421 INFO [STDOUT] sendToJMSQueue(java:comp/env/jms/queue/xpetstore/order,2,false)
04:17:09,467 INFO [STDOUT] OrderProcessorMDB.onMessage(org.jboss.mq.SpyObjectMessage {
04:17:09,474 INFO [STDOUT] *** orderStubs.size()1
04:17:09,475 DEBUG [Order#findByPrimaryKey] Executing SQL: SELECT orderUId FROM t_order WHERE orderUId=?
04:17:09,479 INFO [STDOUT] Unable to proceed the order[2]
04:17:09,481 ERROR [STDERR] javax.ejb.ObjectNotFoundException: No such entity!


04:18:56,831 INFO [STDOUT] *** orderStubs.size()2
04:18:56,832 DEBUG [Order#findByPrimaryKey] Executing SQL: SELECT orderUId FROM t_order WHERE orderUId=?
04:18:56,836 INFO [STDOUT] Unable to proceed the order[3]
04:18:56,838 ERROR [STDERR] javax.ejb.ObjectNotFoundException: No such entity!


04:19:05,084 INFO [STDOUT] *** orderStubs.size()3
04:19:05,086 DEBUG [Order#findByPrimaryKey] Executing SQL: SELECT orderUId FROM t_order WHERE orderUId=?
04:19:05,090 INFO [STDOUT] Unable to proceed the order[4]
04:19:05,091 ERROR [STDERR] javax.ejb.ObjectNotFoundException: No such entity!

[greiezer]

OK, figured out the first part of my question by my self.
Because of a typo "target=multiple" instead of "target-multiple", xdoclet generated a One-to-One relationship
instead of the desired one-to-many CMR between CustomerEJB and OrderEJB.
/**
* @ejb.interface-method
* @ejb.relation
* name="order-customer"
* role-name="order-belongs_to-customer"
* target-ejb="Customer"
* target-role-name="customer-has-orders"
* target-multiple="yes"

Now the db looks like I expect it to be.

But I still can not figure out the solution to the second problem.
The session bean method, which created the order sends a msg to a JMS-queue and returns and after that the corresponding transaction ends.
Some time later the OrderProcessorMDB gets the msg and, among other things, modifies the before created order.
Here do I get the "ObjectNotFoundException" for orderHome.findByPrimaryKey().
But there is an order with the corresponding PK in the database.
I simply don't get!
Any ideas?

Thanks, Andreas