| Author |
Message
|
| celtic_bhoy |
 Posted: Fri Aug 04, 2006 2:03 pm Post subject: Pub Sub - Migrated to 6 from 5.3 not working |
 |
|
Newbie
Joined: 04 Aug 2006
Posts: 8
|
Hi Folks,
We have recently migrated to 6.0.1.1 from 5.3.. We are using a pub sub model on a standalone java client.. but for some strange reason the subscriber seems not be responding after having processing x number of messages.. it seems that either our java program has hanged or that there is an issue with MQ v6, it looks like it has lost its subscription even though there are loads of messages on the topic. When we try and kill our process we see a an MQException that says unable to commit MQMessages during a close. When looking at the messages on the MQJExplorer we can see that messages have being put back on to queue.. it seems that the messages have not being committed.. we have our code working in a production enviroment for 4 yrs.. and now we are up the creek without a paddle..
any ideas or has anyone seen this...
thanks
danny |
|
| Back to top |
|
 |
| jefflowrey |
| Posted: Fri Aug 04, 2006 3:27 pm Post subject: |
|
|
Grand Poobah
Joined: 16 Oct 2002
Posts: 19981
|
I'd say you need to fix your code.
_________________
I am *not* the model of the modern major general. |
|
| Back to top |
|
|
| celtic_bhoy |
| Posted: Thu Aug 10, 2006 6:19 am Post subject: More info |
|
|
Newbie
Joined: 04 Aug 2006
Posts: 8
|
Hi Folks,
Still stumped on this jefflowrey, I have enabled trace on MQ and see the following exception from the trace
03:28:35 [1155047315376] Thread: asyncDelivery0 <== MQSESSIONClient::MQGET (MQMsg2)() exit
03:28:35 [1155047315376] Thread: asyncDelivery0, Object: com.ibm.mq.MQSPIQueue@1a1399 Message is 4096 bytes long.
03:28:35 [1155047315376] Thread: asyncDelivery0, Object: com.ibm.mq.jms.MQJMSMessage@1c7980c Using reference to buffer for byte array
03:28:35 [1155047315376] Thread: asyncDelivery0, Object: com.ibm.mq.MQSPIQueue@1a1399 getMsg2Int completed with cc=2, rc=2003)
03:28:35 [1155047315376] Thread: asyncDelivery0, Object: com.ibm.mq.MQSPIQueue@1a1399 <== getMsg2Int() exit
03:28:35 [1155047315376] Thread: asyncDelivery0, Object: com.ibm.mq.MQException: MQJE001: Completion Code 2, Reason 2003 ==> MQException constructor(cc, rc, source)() entry
03:28:35 [1155047315376] Thread: asyncDelivery0, Object: com.ibm.mq.MQException: MQJE001: Completion Code 2, Reason 2003 @(#) javabase/com/ibm/mq/MQException.java, java, j000, j000-L050401 1.83 05/03/31 13:33:57
03:28:35 [1155047315376] Thread: asyncDelivery0, Object: com.ibm.mq.MQException: MQJE001: Completion Code 2, Reason 2003 cc = 2
03:28:35 [1155047315376] Thread: asyncDelivery0, Object: com.ibm.mq.MQException: MQJE001: Completion Code 2, Reason 2003 rc = 2003
03:28:35 [1155047315376] Thread: asyncDelivery0, Object: com.ibm.mq.MQException: MQJE001: Completion Code 2, Reason 2003 source = com.ibm.mq.MQSPIQueue@1a1399
03:28:35 [1155047315376] Thread: asyncDelivery0, Object: com.ibm.mq.MQException: MQJE001: Completion Code 2, Reason 2003 <== MQException constructor() exit
03:28:35 [1155047315376] Thread: asyncDelivery0, Object: com.ibm.mq.MQSPIQueueManager@12aea3e ==> errorOccurred() entry
03:28:35 [1155047315376] Thread: asyncDelivery0 ==> ReasonCodeInfo::getReasonCodeCategory() entry
03:28:35 [1155047315376] Thread: asyncDelivery0 <== ReasonCodeInfo::getReasonCodeCategory() exit
03:28:35 [1155047315376] Thread: asyncDelivery0, Object: com.ibm.mq.MQSPIQueueManager@12aea3e <== errorOccurred() exit
03:28:35 [1155047315376] Thread: asyncDelivery0, Object: com.ibm.mq.MQSPIQueue@1a1399 <== getMsg2 (via exception)() exit
03:28:35 [1155047315376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSubscriber@139e351 MQException thrown while getting message:
03:28:35 [1155047315376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSubscriber@139e351 getMessage() com.ibm.mq.MQException exception caught: MQJE001: Completion Code 2, Reason 2003
com.ibm.mq.MQException: MQJE001: Completion Code 2, Reason 2003
at com.ibm.mq.MQQueue.getMsg2(MQQueue.java:1070)
at com.ibm.mq.jms.MQMessageConsumer.getMessage(MQMessageConsumer.java:3194)
at com.ibm.mq.jms.MQMessageConsumer.receiveAsync(MQMessageConsumer.java:2773)
at com.ibm.mq.jms.contact admin.run(contact admin.java:406)
at java.lang.Thread.run(Thread.java:534)
03:28:35 [1155047315376] [asyncDelivery0] com.ibm.mq.jms.services.psk.MessageCatalogue@1d056de ==> getMessage(0)() entry
03:28:35 [1155047315376] [asyncDelivery0] com.ibm.mq.jms.services.psk.MessageCatalogue@1d056de <== getMessage(0)() exit
03:28:35 [1155047315376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSubscriber@139e351 leaving via Exception
03:28:35 [1155047315376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSubscriber@139e351 <== getMessage() exit
03:28:35 [1155047315376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSubscriber@139e351 Throwing javax.jms.JMSException: MQJMS2002: failed to get message from MQ queue
03:28:35 [1155047315376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSubscriber@139e351 <== receiveAsync() exit
03:28:35 [1155047315376] [asyncDelivery0] com.ibm.mq.jms.MQTopicConnection@10fd7f6 ==> deliverException() entry
03:28:35 [1155047315376] [asyncDelivery0] com.ibm.mq.jms.MQTopicConnection@10fd7f6 <== deliverException() exit
03:28:35 [1155047315376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 ==> isStarted() entry
03:28:35 [1155047315376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 <== isStarted() exit
return=true
03:28:40 [1155047320376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 ==> isStarted() entry
03:28:40 [1155047320376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 <== isStarted() exit
return=true
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 ==> isStarted() entry
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 <== isStarted() exit
return=true
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 ==> isStarted() entry
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 <== isStarted() exit
return=true
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 ==> isStarted() entry
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 <== isStarted() exit
return=true
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 ==> isStarted() entry
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 <== isStarted() exit
return=true
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 ==> isStarted() entry
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 <== isStarted() exit
return=true
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 ==> isStarted() entry
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 <== isStarted() exit
return=true
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 ==> isStarted() entry
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 <== isStarted() exit
return=true
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 ==> isStarted() entry
03:28:45 [1155047325376] [asyncDelivery0] com.ibm.mq.jms.MQTopicSession@11756a4 <== isStarted() exit
return=true
From trace you can see that it continously goes into the isStarted after the exception was thrown.. This is why I think we cant see any more messages..its as if MQ is in a endless loop
Any ideas
Thanks
Danny |
|
| Back to top |
|
|
| Vitor |
| Posted: Thu Aug 10, 2006 6:24 am Post subject: |
|
|
Grand High Poobah
Joined: 11 Nov 2005
Posts: 26093
Location: Texas, USA
|
2003 = MQRC_BACKED_OUT
Sounds like a poison message to me, hence your loop.
_________________
Honesty is the best policy.
Insanity is the best defence. |
|
| Back to top |
|
|
| celtic_bhoy |
| Posted: Thu Aug 10, 2006 6:44 am Post subject: |
|
|
Newbie
Joined: 04 Aug 2006
Posts: 8
|
Hi vitor,
I have replaced the MQseries 6 jars with 5.3 and I get no problem, what so ever, so I cant see how its a poison message. How would I know if its a poison message
Thanks
Danny |
|
| Back to top |
|
|
| Vitor |
| Posted: Thu Aug 10, 2006 6:53 am Post subject: |
|
|
Grand High Poobah
Joined: 11 Nov 2005
Posts: 26093
Location: Texas, USA
|
A poison message is one that's being backed out and retried in an endless loop; my analysis is based solely on the reason code. It can be identified by the backout count in the message being greater than zero. Clearly something's upsetting your Java between 5.3 & 6.0 - how does the application deal with the poison message scenario? Do you have a backout queue and threshold defined?
_________________
Honesty is the best policy.
Insanity is the best defence. |
|
| Back to top |
|
|
| celtic_bhoy |
| Posted: Thu Aug 10, 2006 7:51 am Post subject: |
|
|
Newbie
Joined: 04 Aug 2006
Posts: 8
|
Hi Vitor,
Yes, I have a back out queue defined and the threshold set to 1. Its very weird because I have to stop the application and when it restarts, it works fine for x number of messages and it goes again
Any ideas
Thanks
Danny |
|
| Back to top |
|
|
| Vitor |
| Posted: Thu Aug 10, 2006 8:15 am Post subject: |
|
|
Grand High Poobah
Joined: 11 Nov 2005
Posts: 26093
Location: Texas, USA
|
So how does the application react when it detects a poision message? Is there any consistency in how many messages it processes before it fails? If stopped, do you just restart it and it then happily processes the message it's been apparently looping on?
Are you using native MQ libraries or JMS? Is it possible that the message object is not being reset properly so that the next get fails, or that the commit fails so you get stuck in a single unit of work going round and round?
Disclaimer - I am not now nor I have I ever been a good Java programmer so I could be talking rubbish.
_________________
Honesty is the best policy.
Insanity is the best defence. |
|
| Back to top |
|
|
| celtic_bhoy |
| Posted: Thu Aug 10, 2006 8:49 am Post subject: |
|
|
Newbie
Joined: 04 Aug 2006
Posts: 8
|
I am unable to see anything in bo queue. I am using JMS libraries, when it appartently "hangs" , i just restart the app and it processes the message , untill a x amount of messages are processed..
I even tried to attached an Exception Listener onto the MQTopicConnection but that doesnt generate any exceptions...
I am really stumped on this
Danny |
|
| Back to top |
|
|
| Vitor |
| Posted: Thu Aug 10, 2006 11:52 pm Post subject: |
|
|
Grand High Poobah
Joined: 11 Nov 2005
Posts: 26093
Location: Texas, USA
|
Please see Disclaimer above...!
The best I can do is agree with jefflowrey - your code needs fixing! There's clearly nothing wrong with the message per se or it would fail again after the app was restarted. Likewise nothing fundamentally wrong with the infrastructure for the same reason.
If you can replace the 6.0 jars with the 5.3 jars and remove the problem there's clearly a difference between the MQ implementaion of JMS between the 2 versions. If it was something serious, I think someone would have noticed by now. My best guess (and I emphasise that word with another reference to the disclaimer) is that your code in some way employs a "feature" in the 5.3 version that's been fixed in the 6.0. You need to go back, trace through the code and see what it's doing.
Other options would be a PMR with IBM, but they tend to be reluctant to debug code & your MQ code is not a fault with MQ, or to wait for a better Java person than me to respond to your post. There are a lot of them... 
_________________
Honesty is the best policy.
Insanity is the best defence. |
|
| Back to top |
|
|
| celtic_bhoy |
| Posted: Fri Aug 11, 2006 4:28 am Post subject: |
|
|
Newbie
Joined: 04 Aug 2006
Posts: 8
|
Hi Vitor,
Found the problem, it was to do with the log space... I checked the AMQERR01.LOG and found that we were getting transactions rollback..
I just increase the log space and its up and running...
thanks for your ideas
Regards
Danny |
|
| Back to top |
|
|
| Vitor |
| Posted: Fri Aug 11, 2006 4:45 am Post subject: |
|
|
Grand High Poobah
Joined: 11 Nov 2005
Posts: 26093
Location: Texas, USA
|
Ah, no space to log the message so it's rolled back. 
You might want to think about how many transactions you have under syncpoint before committing..... 
_________________
Honesty is the best policy.
Insanity is the best defence. |
|
| Back to top |
|
|
| celtic_bhoy |
| Posted: Mon Aug 14, 2006 3:20 am Post subject: |
|
|
Newbie
Joined: 04 Aug 2006
Posts: 8
|
Hi Folks,
Can anyone tell me is there a difference in the commiting scenario between 5.3 and 6. i.e. when does a commit get called in a non transacted aplication.
When migrated to 6 jars we were getting problems with log space issues, it seems that no space to log the message(So we increase our primary and secondary logs and the problem went away, are we just masking the problem adn not fixing the real problem). but when we use the 5.3 jars against MQSeries 6 it has no problems, there are no log problems whats so ever. I find this very strange and would like to understand why it works like that. Our app is non transacted and uses auto-acknowledge
Question : does a message commit in jms when the onmessage is finished?
Question : Can we explicity call commit on a session in a non transacted application?(I tried but get an MQJMS1019 error)
Question : Does uncommitted maxium messages have any relationship to logging.
Is there a link to find out the difference between the 5.3 jars and 6 jars?
Regards
Danny |
|
| Back to top |
|
|
| fjb_saper |
| Posted: Mon Aug 14, 2006 12:45 pm Post subject: |
|
|
Grand High Poobah
Joined: 18 Nov 2003
Posts: 20756
Location: LI,NY
|
| celtic_bhoy wrote: |
Question : does a message commit in jms when the onmessage is finished? |
Only in the appserver when the onmessage method is transacted and set up with "required new"(as it should be). In a standalone jms app you will need to make it transacted (qc.createSession(true, Session.AUTO_ACKNOWLEDGE)) and explicitly commit the session. That is you will need to pass the session object to the listener...
| celtic_bhoy wrote: |
Question : Can we explicity call commit on a session in a non transacted application?(I tried but get an MQJMS1019 error) |
I doubt very much so. Unless you are in a standalone app and have set the session to be transacted and allow commit (see above).
| celtic_bhoy wrote: |
| Question : Does uncommitted maxium messages have any relationship to logging. |
It depends. Evidently yes because this is all accross the queue manager. Evidently no because both values are not linked.
So
- Yes: all uncommitted messages will also be in the log if they are persistent
- No: all uncommitted messages are not persistent. You may run out of log space but still be well within the # of uncommitted messages
You may have run out of number of uncommitted messages and still have lots of log space available...
| celtic_bhoy wrote: |
Regards
Danny |
Enjoy
_________________
MQ & Broker admin |
|
| Back to top |
|
|
| jefflowrey |
| Posted: Mon Aug 14, 2006 12:52 pm Post subject: |
|
|
Grand Poobah
Joined: 16 Oct 2002
Posts: 19981
|
| fjb_saper wrote: |
- Yes: all uncommitted messages will also be in the log if they are persistent
- No: all uncommitted messages are not persistent. You may run out of log space but still be well within the # of uncommitted messages
You may have run out of number of uncommitted messages and still have lots of log space available...
|
c. You have too many messages in a single transaction in the first place
_________________
I am *not* the model of the modern major general. |
|
| Back to top |
|
|
|
|
