Dear all,
I've created a sample EAR to illustrate the problem. Could anyone let me know if the problem is reproducible somewhere else?
1) Create the table
CREATE TABLE COUNTER
(
COUNTERID NUMBER,
COUNTER NUMBER
);
2) Create the sequence "CREATE SEQUENCE COUNTER_SEQ"
3) Create a JMS Connection factory named "jms/ConnectionFactory"
4) Create a JMS Queue named "jms/TestQueue"
5) Adapt the persitence.xml to point to your database
6) The EAR contains 2 beans.
- A SLSB named "ejb/DataStore"
- A MDB that binds to "jms/TestQueue"
7) Set the log level "com.imtf.atlas.ulysse.sandbox" to FINEST
8) Then run the test "com.imtf.atlas.ulysse.sandbox.test.jms.JmsDeliveryBeforeDb".The test will
call 100 times the SLSB. The test uses the key "test-20" to display messages in the server.log
but you can change it easily. Sometimes the 100 calls are properly processed, however if I run it
a couple of time, I always get a few errors after some time.
My environment is Oracle 10 Enterprise, Glassfish V2UR2 with Hibernate 3.
The SLSB will insert one row in the table Counter and set the counter value to 0. It then sends a JMS message
with the counter primary key. When the message is delivered, the value of the counter is updated to 1. If entity is not
found I get a NPE, because manager.find(...) returns null.
After I have run the test, I get for instance:
1) grep "test-020" server.log | wc -l
100
This shows that the 100 messages were correctly deliverey
2) SELECT counter, COUNT(*) FROM counter GROUP BY counter;
COUNTER|COUNT
1 |98
0 |2
This shows that 2 messages were not properly processed.
3) grep "test-020" * | grep Error
server.log:[#|2009-06-26T15:26:55.268+0200|SEVERE|sun-appserver9.1|com.imtf.atlas.ulysse.sandbox.mdb.DataStoreMDB|_ThreadID=40;_ThreadName=p: thread-pool-1; w: 37;_RequestID=d908eb68-4cc0-4546-976e-ebb72d537cb3;|Error while processing message [batch=test-020,id=2735]|#]
server.log:[#|2009-06-26T15:26:58.624+0200|SEVERE|sun-appserver9.1|com.imtf.atlas.ulysse.sandbox.mdb.DataStoreMDB|_ThreadID=39;_ThreadName=p: thread-pool-1; w: 38;_RequestID=d22420b3-a2a2-4f59-9c3d-7bab242e9975;|Error while processing message [batch=test-020,id=2792]|#]
This shows the two message delivery that failed and the corresponding counter PK.
4) If I check in the sever.log, I see the NPE which indicates that the entity was not yet committed in database at the time the message was processed.
12808 [#|2009-06-26T15:26:58.624+0200|SEVERE|sun-appserver9.1|com.imtf.atlas.ulysse.sandbox.mdb.DataStoreMDB|_ThreadID=39;_ThreadName=p: thread-pool-1; w: 38;_RequestID=d22420b3-a2a2-4f59-9c3d-7bab242e9975;|Error while processing message [batch=test-020,id=2792]|#]
12809
12810 [#|2009-06-26T15:26:58.625+0200|WARNING|sun-appserver9.1|javax.enterprise.system.stream.err|_ThreadID=39;_ThreadName=p: thread-pool-1; w: 38;_Request ID=d22420b3-a2a2-4f59-9c3d-7bab242e9975;|
12811 java.lang.NullPointerException
12812 at com.imtf.atlas.ulysse.sandbox.mdb.DataStoreMDB.onMessage(DataStoreMDB.java:65)
12813 at sun.reflect.GeneratedMethodAccessor639.invoke(Unknown Source)
12814 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
12815 at java.lang.reflect.Method.invoke(Method.java:585)
12816 at com.sun.enterprise.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1067)
12817 at com.sun.enterprise.security.SecurityUtil.invoke(SecurityUtil.java:176)
12818 at com.sun.ejb.containers.BaseContainer.invokeTargetBeanMethod(BaseContainer.java:2895)
12819 at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:3986)
12820 at com.sun.ejb.containers.MessageBeanContainer.deliverMessage(MessageBeanContainer.java:1111)
12821 at com.sun.ejb.containers.MessageBeanListenerImpl.deliverMessage(MessageBeanListenerImpl.java:74)
12822 at com.sun.enterprise.connectors.inflow.MessageEndpointInvocationHandler.invoke(MessageEndpointInvocationHandler.java:179)
12823 at $Proxy299.onMessage(Unknown Source)
12824 at com.sun.messaging.jms.ra.OnMessageRunner.run(OnMessageRunner.java:258)
12825 at com.sun.enterprise.connectors.work.OneWork.doWork(OneWork.java:76)
12826 at com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:555)
12827 |#]
[Message sent by forum member 'ewernli' (ewernli)]
http://forums.java.net/jive/thread.jspa?messageID=353154