| Author |
Message
|
| bdemar |
 Posted: Sat Sep 22, 2007 12:08 pm Post subject: Random lost of ability for MDB to retrieve message |
 |
|
Newbie
Joined: 22 Sep 2007
Posts: 6
|
Hi all,
I will try my best to describe this problem. I have been researching for about a week now and can't seem to get anywhere with it. So I'm reaching out 
Simplfied setup:
MQ Server:AIX box
Version info:
Name: WebSphere MQ
Version: 6.0.2.1
CMVC level: p600-201-070405
BuildType: IKAP - (Production)
Single Queue Manager with a few request/response local queues
I do have the KeepAlive=YES in the QM qm.ini file
**Please note that I have NO firewall in this setup***
Websphere Server:Aix
Websphere 5.1.1.12 on AIX
Java 1.4.2.5
I have the 6.0.2.1 MQ client installed here as well(According to the dspmqver command)
I have an websphere application setup with multiple MDB's each with its own MQ Connection factory, with min conn and session = 0, and max connections/session = 1(This was done to help debug).
Each listener(4 of em) is also set to max 1 session, and MaxMsg=1
The problem:
What happens is that I will startup the JVM, and test that MDB's are activated by through sample msg's(simple strings) onto the queues they are listening on. Of course this will cause an exception on the MDB's because they expect a certain format, but nevertheless it's all working. After an undetermined period of time(it varies but it is always 2-7 hrs). The MDB's will get the following exception pasted below, when trying to read in a msg. The wierd thing is that the listener is detecting that there is a new message, and it will try to kick off the onMessage() method but it just can't read the data/msg. That tells me the connection is working..right?
Once this error occurs the listener will restart, and try again..sometimes this works, but more often it doesnt. Once I restart the JVM the MDBs will process the messages right away. We have a few folks over here really pulling there hair out on this one... 
Error Stack trace:
9/22/07 10:09:40:159 CDT] 2e25b4d5 JMSExceptionL E WMSG0057E: Error on JMSConnection for MDB DupCheckMDB , JMSDestination jms/DupCheckRequest , JMS Linked Exception : com.ibm.mq.MQException: MQJE001: Completion Code 2, Reason 2009
at com.ibm.mq.jms.MQSession.consume(MQSession.java:2910)
at com.ibm.mq.jms.MQSession.run(MQSession.java:1537)
at com.ibm.ejs.jms.JMSSessionHandle.run(JMSSessionHandle.java:924)
at com.ibm.ejs.jms.listener.ServerSession.connectionConsumerOnMessage(ServerSession.java:752)
at com.ibm.ejs.jms.listener.ServerSession.onMessage(ServerSession.java:527)
at com.ibm.ejs.jms.listener.ServerSession.dispatch(ServerSession.java:494)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:85)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:5
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java(Compiled Code))
at java.lang.reflect.Method.invoke(Method.java(Compiled Code))
at com.ibm.ejs.jms.listener.ServerSessionDispatcher.dispatch(ServerSessionDispatcher.java:37)
at com.ibm.ejs.container.MDBWrapper.onMessage(MDBWrapper.java:91)
at com.ibm.ejs.container.MDBWrapper.onMessage(MDBWrapper.java:127)
at com.ibm.ejs.jms.listener.ServerSession.run(ServerSession.java:375)
at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java(Compiled Code)) |
|
| Back to top |
|
 |
| fjb_saper |
| Posted: Sat Sep 22, 2007 6:44 pm Post subject: |
|
|
Grand High Poobah
Joined: 18 Nov 2003
Posts: 20756
Location: LI,NY
|
Do you have a firewall timeout < channel heartbeat for the qcf? 
_________________
MQ & Broker admin |
|
| Back to top |
|
|
| bdemar |
| Posted: Sun Sep 23, 2007 11:37 am Post subject: |
|
|
Newbie
Joined: 22 Sep 2007
Posts: 6
|
There is NO firewall involved in this setup at all...
I'm pretty sure my session connection is going stale still some how. Let me give a real example of what's going on here. I have 2 mdbs with there own connection factory and all they do is process an xml using the SAX libs(mdb1 listening on queue1 , mdb2 listening on queue2).
I will put a test message on the queue1 kicking of the onMessage() for mdb1. MDB1 will then throw an exception cause of course my test msg is not a proper xml file. This is fine, I know it at least received the msg. During this time i intentionally put NO messages on queue2, so mdb2 will NEVER grab a connection and a session.
I will then wait for a period of 5-7 hours.
After the time is up, I will try again to put the test msg string on queue1. It will give me the MQJE001: Completion Code 2, Reason 2009 error.
I now then try to put a test msg on queue2(note this is the first time I'm doing this in this test). mdb2 will grab a connection and session and it will get the message! Now of course I will only have about 5-7 hours if there is no inactivity on queue2 for this mdb2 to still work before it starts giving me the 2009 errors.
Please also note that mdb1 and mdb2 are practically the same code base, and i'm NOT sending any messages out here to mq as well...
Any ideas?? I'm so stumped.... |
|
| Back to top |
|
|
| fjb_saper |
| Posted: Sun Sep 23, 2007 5:37 pm Post subject: |
|
|
Grand High Poobah
Joined: 18 Nov 2003
Posts: 20756
Location: LI,NY
|
Read up on MDB and poison message as well as backout queues.
I'd say working as designed.
An MDB has a retry limit and is generally part of a transactional process => poison messages are rolled back and retryied until EITHER of the following happens:
- The MDB retry limit has been reached
- The queue's backout threshold has been reached
Remember that only in WAS are those events handled automatically. You will have to code for them in any other environment.
Ideally you should have MDB retry > Queue BOTHRESH > 0
Enjoy
_________________
MQ & Broker admin |
|
| Back to top |
|
|
| bdemar |
| Posted: Sun Sep 23, 2007 6:40 pm Post subject: |
|
|
Newbie
Joined: 22 Sep 2007
Posts: 6
|
Yes, I do know how websphere will normally handle poisoned messages. These messages are NOT considered poisoned, as the app will get it and process it(it will just throw an exception and discard the message, which is what we want for this scenario). Our problem is the message will never, GET to the application, for the MDB to even process. I have taken some more traces at the websphere level (pasted below). This is again telling me that somehow my communcation to MQ is getting all messed up.
[9/23/07 19:51:40:652 CDT] 598b2bd4 JMS_WASTraceA d com.ibm.mq.MQv6InternalCommunications IOException occured during send. The soc
ket connection was
probably broken by the other party.
[9/23/07 19:51:40:653 CDT] 598b2bd4 JMS_WASTraceA d com.ibm.mq.MQv6InternalCommunications java.net.SocketException: Broken pipe
[9/23/07 19:51:40:653 CDT] 598b2bd4 JMS_WASTraceA < com.ibm.mq.MQv6InternalCommunications send (via exception) Exit
[9/23/07 19:51:40:653 CDT] 598b2bd4 JMS_WASTraceA > com.ibm.mqservices.MQInternalException MQException constructor(cc, rc, source, m
sgid) Entry
[9/23/07 19:51:40:653 CDT] 598b2bd4 JMS_WASTraceA d com.ibm.mqservices.MQInternalException @(#) javabase/com/ibm/mq/MQException.ja
va, java, j600, j600-201-061220 1.83.1.5 06/11/24 14:29:39
[9/23/07 19:51:40:653 CDT] 598b2bd4 JMS_WASTraceA d com.ibm.mqservices.MQInternalException cc = 2
[9/23/07 19:51:40:653 CDT] 598b2bd4 JMS_WASTraceA d com.ibm.mqservices.MQInternalException rc = 2009
[9/23/07 19:51:40:653 CDT] 598b2bd4 JMS_WASTraceA d com.ibm.mqservices.MQInternalException source = null
[9/23/07 19:51:40:653 CDT] 598b2bd4 JMS_WASTraceA d com.ibm.mqservices.MQInternalException msgId = 44
[9/23/07 19:51:40:653 CDT] 598b2bd4 JMS_WASTraceA d com.ibm.mqservices.MQInternalException Explanation is 'MQJE001: An MQException
occurred: Completion Code 2, Reason 2009
MQJE003: IO error transmitting message buffer' |
|
| Back to top |
|
|
| fjb_saper |
| Posted: Sun Sep 23, 2007 7:06 pm Post subject: |
|
|
Grand High Poobah
Joined: 18 Nov 2003
Posts: 20756
Location: LI,NY
|
Open a PMR. Make sure you have the right patch level on WAS.
You may have to upgrade to WAS 6.x
I remember when we were running WAS 5.0x and MQ 5.3 CSD4 we needed to get to the right patch level of WAS for JMS to work correctly..
If it helps ... if you go to MQ 6.0.2.2 you can use the Resource Adapter (JCA).
Enjoy
_________________
MQ & Broker admin |
|
| Back to top |
|
|
| bdemar |
| Posted: Mon Sep 24, 2007 8:49 am Post subject: |
|
|
Newbie
Joined: 22 Sep 2007
Posts: 6
|
Anybody else have any ideas on this?
As a side question, when an MDB onMessage() gets kicked off. The listener thread will grab a connection from the associated MQ Conn factory, and then it will grab a session. Once the mdb is done reading, will the listener will still hold the connection, but it is supposed to close out the session. I dont think this is happening, can anybody think of reasons why the listener won't close out the session? |
|
| Back to top |
|
|
| fjb_saper |
| Posted: Mon Sep 24, 2007 12:05 pm Post subject: |
|
|
Grand High Poobah
Joined: 18 Nov 2003
Posts: 20756
Location: LI,NY
|
| bdemar wrote: |
Anybody else have any ideas on this?
As a side question, when an MDB onMessage() gets kicked off. The listener thread will grab a connection from the associated MQ Conn factory, and then it will grab a session. Once the mdb is done reading, will the listener will still hold the connection, but it is supposed to close out the session. I dont think this is happening, can anybody think of reasons why the listener won't close out the session? |
There is a little red book about JMS Topology. Read it! It will tell you the min number of connections your qcf needs to support for the setup to work....
Enjoy
_________________
MQ & Broker admin |
|
| Back to top |
|
|
| bdemar |
| Posted: Mon Sep 24, 2007 8:54 pm Post subject: |
|
|
Newbie
Joined: 22 Sep 2007
Posts: 6
|
Already, been there and done that... I know the connection stays open for the life the listener, but the session is supposed to be closed automatically. The connection leak trace is still showing it as open though. I'm not sure if this is normal...
Here is a trace.log excerpt with the conn leak info..
this WWW sites has more info on conn leak info as well:
http://www-1.ibm.com/support/docview.wss?fdoc=aimwas&rs=180&uid=swg21203225
From the info below you can see the session is there and still active(it states for 900 secs). The sessions should close right? All my mdb does in the onMessage is simply read the msg and parse it...
Connection Leak Logic Information:
MCWrapper id 4c60dc8 Managed connection com.ibm.ejs.jms.JMSManagedQueueSession@6aed8dc8
physical session = com.ibm.mq.jms.MQQueueSession@7dcc8dc8
session type = NON_TRANSACTED_SESSION
acknowledge mode = AUTO_ACKNOWLEDGE
enlisted = false
open session handles = [com.ibm.ejs.jms.JMSQueueSessionHandle@93c8dc8]
managed session factory = com.ibm.ejs.jms.JMSManagedQueueSessionFactory@2a960ddc State:STATE_ACTIVE_INUSE Thread Id: 51c60dda Thread Name: MQQueueAgent (DLOSFRD.LQ.REQUEST) Handle count 1
Start time inuse Mon Sep 24 23:30:27 CDT 2007 Time inuse 900 (seconds)
Last allocation time Mon Sep 24 23:30:27 CDT 2007
getConnection stack trace information:
t com.ibm.ejs.j2c.ConnectionManager.allocateConnection(ConnectionManager.java:568)
at com.ibm.ejs.jms.JMSQueueConnectionHandle.createListenerQueueSession(JMSQueueConnectionHandle.java:286)
at com.ibm.ejs.jms.listener.ServerSession.<init>(ServerSession.java:218)
at com.ibm.ejs.jms.listener.ServerSessionPool.getServerSession(ServerSessionPool.java:408)
at com.ibm.mq.jms.MQConnectionConsumer$MQConnectionConsumerMRH.deliverNow(MQConnectionConsumer.java:211)
at com.ibm.mq.jms.MQConnectionConsumer$MQConnectionConsumerMRH.endDeliver(MQConnectionConsumer.java:119)
at com.ibm.mq.jms.MQConnectionConsumer$MQConnectionConsumerMRH.handleMessageReference(MQConnectionConsumer.java:147)
at com.ibm.mq.jms.MQConnectionBrowser.deliver(MQConnectionBrowser.java:736)
at com.ibm.mq.jms.MQQueueAgentThread.deliverMsgRef(MQQueueAgentThread.java:839)
at com.ibm.mq.jms.MQQueueAgentThread.processMessage(MQQueueAgentThread.java:638)
at com.ibm.mq.jms.MQQueueAgentThread.run(MQQueueAgentThread.java:1723)
at java.lang.Thread.run(Thread.java:570) |
|
| Back to top |
|
|
| fjb_saper |
| Posted: Tue Sep 25, 2007 2:35 am Post subject: |
|
|
Grand High Poobah
Joined: 18 Nov 2003
Posts: 20756
Location: LI,NY
|
| Quote: |
open session handles = [com.ibm.ejs.jms.JMSQueueSessionHandle@93c8dc8]
managed session factory = com.ibm.ejs.jms.JMSManagedQueueSessionFactory@2a960ddc State:STATE_ACTIVE_INUSE Thread Id: 51c60dda Thread Name: MQQueueAgent (DLOSFRD.LQ.REQUEST) Handle count 1 |
OK so why should the session close if it is still active?
You forget that in the MDB model any time a message could be received. So the session stays active for the lifetime of the MDB. Stop the MDB and the session will get released... Remember that the model relies on a standard...
Now if you suspect a true connection leak you need to open a PMR on it.
And check that you are on the latest fix packs not just for MQ but for WAS too.
Enjoy
_________________
MQ & Broker admin |
|
| Back to top |
|
|
|
|
