| Author |
Message
|
| mdfaraz |
 Posted: Thu Aug 04, 2011 10:20 am Post subject: MQ Tivoli Monitoring - MQ Backout effect on Msg put times |
 |
|
Novice
Joined: 31 Mar 2010
Posts: 19
Location: Houston, TX
|
Hi,
I wanted to know the effect of a queue manager backout on the put date time attributes of a message. If an application reads a message under a sync point and later Back outs the transaction what happens behind the scenes.
Say the current queue depth = 20 at 1PM with the last message arriving at 12.59. At this point, my Tivoli monitor shows a 'last put' on this queue as 12.59.
1.05 - An application connects, reads under a syncpoint - current queue depth becomes 19, then after a few minutes(1.07 PM), the application backs out the transaction, so the queue depth goes back to 20. But what I see is the LastPut time on this queue as changed to 1.07PM.
Is this what happens?
I wanted my Tivoli monitor to alert if no message was put in the last 2 hours(last put time > currtime-2), but if the application behaves this way(connect, read, backout) in a never ending loop, Tivoli always thinks messages are being put in the queue and doesn't raise an alert.
Is there a better way to determine the last put time on a queue.
Also, if the first message is read and backed out, does it go back to the first position? or does a subsequent get now read the 2nd message? |
|
| Back to top |
|
 |
| Vitor |
| Posted: Thu Aug 04, 2011 10:56 am Post subject: Re: MQ Tivoli Monitoring - MQ Backout effect on Msg put time |
|
|
Grand High Poobah
Joined: 11 Nov 2005
Posts: 26093
Location: Texas, USA
|
| mdfaraz wrote: |
| Is there a better way to determine the last put time on a queue. |
The queue monitoring statistics would seem to be an option:
| Quote: |
| Queue statistics messages contain information relating to the activity of a queue during a configured interval. The information includes the number of messages put on, and retrieved from, the queue, and the total number of bytes processed by a queue |
| mdfaraz wrote: |
| Also, if the first message is read and backed out, does it go back to the first position? or does a subsequent get now read the 2nd message? |
Once the message has been rolled back onto the queue, it's just like it was the first time it was put. So all other things being equal it'll be read off again the next time the application does a get & the 2nd message will never be read off (the "poison" message scenario often discussed here).
Well behaved applications contain code to determine the message they've just got off the queue is a repeat offender and act accordingly. Strategies to act accordingly also often discussed.
_________________
Honesty is the best policy.
Insanity is the best defence. |
|
| Back to top |
|
|
| bruce2359 |
| Posted: Thu Aug 04, 2011 11:00 am Post subject: Re: MQ Tivoli Monitoring - MQ Backout effect on Msg put time |
|
|
Poobah
Joined: 05 Jan 2008
Posts: 9469
Location: US: west coast, almost. Otherwise, enroute.
|
| mdfaraz wrote: |
Hi,
I wanted to know the effect of a queue manager backout on the put date time attributes of a message. If an application reads a message under a sync point and later Back outs the transaction what happens behind the scenes. |
A message MQGET within syncpoint is marked as not-consumable, AND remains untouched (un-altered) in the queue until commit. A message rolled back (backout) is merely marked as consumable, and is otherwise un-altered.
_________________
I like deadlines. I like to wave as they pass by.
ב''ה
Lex Orandi, Lex Credendi, Lex Vivendi. As we Worship, So we Believe, So we Live. |
|
| Back to top |
|
|
| mdfaraz |
| Posted: Thu Aug 04, 2011 11:55 am Post subject: |
|
|
Novice
Joined: 31 Mar 2010
Posts: 19
Location: Houston, TX
|
Thanks for your replies guys,
Couple comments -
The queue monitoring statistics aren't of much help as the read/backout done by the app has an unintended consequence. It seems that the queue statistics(shown in Tivoli) are showing that for the particular queue, n messages have been read and n have been put even though no messages were put or read. This is affecting the TimeToZero statistic as it thinks messages are being processed whereas they are not.
It's good that the put date/time is not affected. makes life easy. |
|
| Back to top |
|
|
| Vitor |
| Posted: Thu Aug 04, 2011 12:05 pm Post subject: |
|
|
Grand High Poobah
Joined: 11 Nov 2005
Posts: 26093
Location: Texas, USA
|
1) How have you got Tivoli configured to handle the reset of queue stats?
2) Is the application in question doing an actual rollback or putting the message back on the original queue in the event of error? I know that's a silly thing for an application to do, but so is getting stuck in a poison message loop when it's so easily preventable. This get-then-put would explain why you see the LastPutTime changing in the example you quoted from 12:59 to 1:07.
_________________
Honesty is the best policy.
Insanity is the best defence. |
|
| Back to top |
|
|
| bruce2359 |
| Posted: Thu Aug 04, 2011 12:11 pm Post subject: |
|
|
Poobah
Joined: 05 Jan 2008
Posts: 9469
Location: US: west coast, almost. Otherwise, enroute.
|
2) More specifically, is the consuming app doing a destructive MQGET (outside syncpoint), then doing an MQPUT to "restore" the message to the same queue? Meaning NOT using MQBACK? Is the app setting the put time/date?
Vitor: seems like I'm not the only person to have seen such an application.  Go figure.
_________________
I like deadlines. I like to wave as they pass by.
ב''ה
Lex Orandi, Lex Credendi, Lex Vivendi. As we Worship, So we Believe, So we Live. |
|
| Back to top |
|
|
| Vitor |
| Posted: Thu Aug 04, 2011 12:19 pm Post subject: |
|
|
Grand High Poobah
Joined: 11 Nov 2005
Posts: 26093
Location: Texas, USA
|
| bruce2359 wrote: |
| Vitor: seems like I'm not the only person to have seen such an application. Go figure. |
You work with WMQ as long as I have, you get to see everything.
Until you start on a new site and discover completely original weirdness.
_________________
Honesty is the best policy.
Insanity is the best defence. |
|
| Back to top |
|
|
| mdfaraz |
| Posted: Thu Aug 04, 2011 12:37 pm Post subject: |
|
|
Novice
Joined: 31 Mar 2010
Posts: 19
Location: Houston, TX
|
| The application reads the message under syncpoint and then issues a Queue Manager.backout(). It does not put it back. |
|
| Back to top |
|
|
| bruce2359 |
| Posted: Thu Aug 04, 2011 1:46 pm Post subject: |
|
|
Poobah
Joined: 05 Jan 2008
Posts: 9469
Location: US: west coast, almost. Otherwise, enroute.
|
| mdfaraz wrote: |
| The application reads the message under syncpoint and then issues a Queue Manager.backout(). It does not put it back. |
Does the backout throw any errors? Is the backout being code executed?
_________________
I like deadlines. I like to wave as they pass by.
ב''ה
Lex Orandi, Lex Credendi, Lex Vivendi. As we Worship, So we Believe, So we Live. |
|
| Back to top |
|
|
| mdfaraz |
| Posted: Thu Aug 04, 2011 1:54 pm Post subject: |
|
|
Novice
Joined: 31 Mar 2010
Posts: 19
Location: Houston, TX
|
Yes, it is code executed. the app reads a message and updates a sql DB. In this case, the DB was experiencing issues, so the app would backout the MQ operations(as it should).
So you guys are suggesting that backing out should not affect the 'Last Message Put' Queue statistic? I think I see the opposite behavior but need to look closely.
My main goal was to determine if messages are not being continuously read by an app and raise an alert. I was thinking that the 'last put message' stat would have helped but looks like it doesn't in the case where the app is not able to process messages and constantly backing out. |
|
| Back to top |
|
|
| bruce2359 |
| Posted: Thu Aug 04, 2011 2:08 pm Post subject: |
|
|
Poobah
Joined: 05 Jan 2008
Posts: 9469
Location: US: west coast, almost. Otherwise, enroute.
|
| mdfaraz wrote: |
Yes, it is code executed. the app reads a message and updates a sql DB. In this case, the DB was experiencing issues, so the app would backout the MQ operations(as it should).
So you guys are suggesting that backing out should not affect the 'Last Message Put' Queue statistic? I think I see the opposite behavior but need to look closely.
My main goal was to determine if messages are not being continuously read by an app and raise an alert. I was thinking that the 'last put message' stat would have helped but looks like it doesn't in the case where the app is not able to process messages and constantly backing out. |
If your app backs out the first message in the queue, for whatever reason - including a db2 insert fail, it is still the first message in the queue.
The next instance of the app will get the exact same message, encounter the db2 insert failure, backout the UofW - the exact same result - looking like a "poison message loop."
I'd expect to see the get count rise. Does it? I'd expect to see the backout count rise. Does it?
_________________
I like deadlines. I like to wave as they pass by.
ב''ה
Lex Orandi, Lex Credendi, Lex Vivendi. As we Worship, So we Believe, So we Live. |
|
| Back to top |
|
|
| mdfaraz |
| Posted: Thu Aug 04, 2011 2:17 pm Post subject: |
|
|
Novice
Joined: 31 Mar 2010
Posts: 19
Location: Houston, TX
|
The 'Messages Put' and 'Messages Read' both seem to increase. I guess it is because the app read the message 50 times causing Messages Read = 50 and later backed out so 'Messages Put' became 50.
I had set an alert when 'Time to Zero' stat wud go up beyond a value. But in this case it showed Equal Get and Put Rates as it was completely misled by the scenario above. I did not check the backout count |
|
| Back to top |
|
|
| bruce2359 |
| Posted: Thu Aug 04, 2011 2:33 pm Post subject: |
|
|
Poobah
Joined: 05 Jan 2008
Posts: 9469
Location: US: west coast, almost. Otherwise, enroute.
|
Ignore for a moment the mqget, the db2 insert, and the mqback, does the app do any mqputs?
If so, then the mqback restores the message mqget'd, AND deletes the message mqput - if both are done in the same UofW?
This would explain the mqput and mqget counts rising.
_________________
I like deadlines. I like to wave as they pass by.
ב''ה
Lex Orandi, Lex Credendi, Lex Vivendi. As we Worship, So we Believe, So we Live. |
|
| Back to top |
|
|
| Vitor |
| Posted: Fri Aug 05, 2011 4:28 am Post subject: |
|
|
Grand High Poobah
Joined: 11 Nov 2005
Posts: 26093
Location: Texas, USA
|
| mdfaraz wrote: |
| The 'Messages Put' and 'Messages Read' both seem to increase. I guess it is because the app read the message 50 times causing Messages Read = 50 and later backed out so 'Messages Put' became 50 |
That's not the real problem here.
| mdfaraz wrote: |
| I did not check the backout count |
If the message was read and backed out 50 times, it sounds like the application doesn't check it either. The application should check the count, make a determination if it wants to try again and at some point dump the message to an error queue rather than back it out.
The logic you're describing here is fine for transitory problems, but imagine if the db problem was that this message caused a duplicate key condition? The message would roll indefinately and inhibit the processing of other messages.
_________________
Honesty is the best policy.
Insanity is the best defence. |
|
| Back to top |
|
|
|
|
