Author |
Message
|
satyaannareddy |
Posted: Wed Nov 10, 2010 6:29 am Post subject: MQ_Wait is getting reset after reading first message |
|
|
Newbie
Joined: 09 Nov 2010 Posts: 9
|
We are using MQ 7
and have got java adaptors to perform MQ get and MQ put.
these Java adaptors have got a public method where we are setting all the GMO options including the waittime to 30000
--> setting gmo options --> Thread run method --> MQ get method
a thread run method is calling MQ Get method to read the message
we have got two different kind of message that use the same code.
one of these messages works fine with recognising the wait time properly
the other one reads the wait time first time fine and on all subsequent gets it just loops without waiting. some how the waittime or the gmo options are reset to default.
any suggestions on how this can happen.
code:-
Code: |
private final int monitorPeriod = 30000;
public Worker(String id, String qMgrName, String requestQName, String replyQName, String url, boolean diagnosticOn, boolean lifespan, MQAdapterLog log) throws MQAdapterException
{
try
{
qMgr = new MQQueueManager(qMgrName);
int openOptions = MQConstants.MQOO_INPUT_AS_Q_DEF + MQConstants.MQOO_INQUIRE;
requestQueue = qMgr.accessQueue(requestQName, openOptions, null, null, null);
openOptions = MQConstants.MQOO_OUTPUT;
replyQueue = qMgr.accessQueue(replyQName, openOptions, null, null, null);
}
catch (MQException e)
{
throw new MQAdapterException(this, e.getMessage());
}
gmo.options = MQConstants.MQGMO_WAIT + MQConstants.MQGMO_SYNCPOINT + MQConstants.MQGMO_FAIL_IF_QUIESCING + MQConstants.MQGMO_CONVERT;
gmo.waitInterval = monitorPeriod;
pmo.options = MQConstants.MQPMO_SYNCPOINT;
}
public void run()
{
while (keepRunning())
{
try
{
String requestMsg = waitMQ();
if (keepRunning() && requestMsg != null)
{
String replyMsg = null;
replyMsg = doHTTPPost(requestMsg);
replyToMQ(replyMsg);
commitOrBackout(COMMIT);
}
else if (requestMsg == null)
{
//do nothing
}
}
catch (MQAdapterException e)
{
e.logError();
commitOrBackout(BACKOUT);
}
}
try
{
log.logError(2099, "Thread is shutting down");
commitOrBackout(BACKOUT);
requestQueue.close();
replyQueue.close();
}
catch (Exception e)
{
// not a lot we can do here
}
}
private String waitMQ() throws MQAdapterException
{
String msgData = null;
try
{
messageReceived.clearMessage();
messageReceived.messageId = MQConstants.MQMI_NONE;
messageReceived.correlationId = MQConstants.MQCI_NONE;
requestQueue.get(messageReceived,gmo);
log.logTrace(threadId,"received a message");
if (messageReceived.backoutCount > backoutThreshold)
{
backoutMessage(messageReceived);
}
else
{
//do something
}
}
catch (MQException e)
{
if(e.reasonCode == 2161) // queue manager is quiescing
{
commitOrBackout(BACKOUT);
shutdown();
throw new MQAdapterException(this, "Stopping thread as Queue Manager is quiescing");
}
if (e.reasonCode == 2033)
{
log.logTrace(threadId,"Exception While reading empty Queue: "+requestQueue);
}
else
{
log.logError(2010, "Error retrieving MQ Message from queue");
throw new MQAdapterException(this, e.getMessage());
}
}
catch (IOException e)
{
log.logError(2011, "General error in recieved Message");
throw new MQAdapterException(this, e.getMessage());
}
return msgData;
} |
Last edited by satyaannareddy on Thu Nov 11, 2010 2:47 am; edited 2 times in total |
|
Back to top |
|
 |
bruce2359 |
Posted: Wed Nov 10, 2010 7:50 am Post subject: |
|
|
 Poobah
Joined: 05 Jan 2008 Posts: 9471 Location: US: west coast, almost. Otherwise, enroute.
|
GMO waitinterval doesn't impose an absolute wait until the 300000 has passed. Rather, waitinterval specifies how long the get with wait should wait if NO messages exist or arrive on the queue.
If another message is in the queue, there will be no wait - the app will be presented with the message immediately. _________________ 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 |
|
 |
satyaannareddy |
Posted: Wed Nov 10, 2010 7:56 am Post subject: |
|
|
Newbie
Joined: 09 Nov 2010 Posts: 9
|
thanks Bruce for the reply
yeah I do understand that wait process.
But in one of our case its not waiting even when there are no messages in the queue.
where as its behaving properly in another message (with diff queue) |
|
Back to top |
|
 |
bruce2359 |
Posted: Wed Nov 10, 2010 8:03 am Post subject: |
|
|
 Poobah
Joined: 05 Jan 2008 Posts: 9471 Location: US: west coast, almost. Otherwise, enroute.
|
Quote: |
But in one of our case its not waiting ... |
What does it do if it's not waiting for another message? How do you know it's not waiting? What symptom do you see?
If it is not waiting, then either:
1) there is a message that satisfies the get; or
2) waitinterval was not specified _________________ 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 |
|
 |
satyaannareddy |
Posted: Wed Nov 10, 2010 8:08 am Post subject: |
|
|
Newbie
Joined: 09 Nov 2010 Posts: 9
|
Bruce
Sorry my mistake I have added a bit wrong method in there...
will correct now
yes we have got waitinterval specified as 30000 secs as constant
and incase of message where this value is resetting for some reason on its own its looping and trying to connect very often like every 2-5 milli secs and causing the CPU to go 100% and crash. |
|
Back to top |
|
 |
bruce2359 |
Posted: Wed Nov 10, 2010 8:12 am Post subject: |
|
|
 Poobah
Joined: 05 Jan 2008 Posts: 9471 Location: US: west coast, almost. Otherwise, enroute.
|
Please be specific. What crashed? The cpu? The LPAR? The qmgr? The application?
What symptom (do not use 'crash' to describe this)? An error message like 'out of resources?' A ReasonCode? What? _________________ 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 |
|
 |
satyaannareddy |
Posted: Wed Nov 10, 2010 8:32 am Post subject: |
|
|
Newbie
Joined: 09 Nov 2010 Posts: 9
|
Sorry for being very vague.
Its actually the CPU that crashed.
as I have kept mentioning, one type of message and queue set get this waitInterval correctly as 30000 Ms and process accordingly, where as another set (Message a bit larger message and different Queue) using the same code get it correctly for the first time and then this waitTime is reset to 0secs after that.
this is working fine when I am defining the gmo options within the waitMQ() method and setting the waitInterval every time.
but as you appretiate that a little overhead on the system to define variable within a Loop which runs so often.
 |
|
Back to top |
|
 |
bruce2359 |
Posted: Wed Nov 10, 2010 8:45 am Post subject: |
|
|
 Poobah
Joined: 05 Jan 2008 Posts: 9471 Location: US: west coast, almost. Otherwise, enroute.
|
Quote: |
Sorry for being very vague. Its actually the CPU that crashed. |
This is still very vague. More annoying is that it is not a technical and/or precise description of what did or did not happen. We can only guess as to what you mean; and subsequently, we can only speculate as to cause (if any) and effect (if any).
What exactly do you mean by crashed? Did the physical box tip over, and literally crash?
What symptom did the application display (as in ReasonCode, dump, etc.)?
Do you believe that your app was the cause of the crash? Or the victim of the crash? Or just a coincidence?
How do you know that the waitinterval was reset to zero? Did you display the value before the get call? _________________ 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 |
|
 |
satyaannareddy |
Posted: Wed Nov 10, 2010 9:23 am Post subject: |
|
|
Newbie
Joined: 09 Nov 2010 Posts: 9
|
bruce2359 wrote: |
Quote: |
Sorry for being very vague. Its actually the CPU that crashed. |
This is still very vague. More annoying is that it is not a technical and/or precise description of what did or did not happen. We can only guess as to what you mean; and subsequently, we can only speculate as to cause (if any) and effect (if any).
What exactly do you mean by crashed? Did the physical box tip over, and literally crash?
What symptom did the application display (as in ReasonCode, dump, etc.)?
Do you believe that your app was the cause of the crash? Or the victim of the crash? Or just a coincidence?
How do you know that the waitinterval was reset to zero? Did you display the value before the get call? |
Ok I take back all my Crash wording it is will not help to resolve this issue in any way.
But the key point here is that the MQget is being triggered so often that its causing the 100% CPU utilisation.
And to answer your questions about how i know that its application that is causing this
Yes I can see that in the logs, I can also see the option 2033 returned by MQ when no messages.
As I have already said this MQget is executed few hundred times every sec (again I can see from my logs)
and I do know that GMO options are being reset after the first run as I am displaying them (again from my logs)
 |
|
Back to top |
|
 |
bruce2359 |
Posted: Wed Nov 10, 2010 9:43 am Post subject: |
|
|
 Poobah
Joined: 05 Jan 2008 Posts: 9471 Location: US: west coast, almost. Otherwise, enroute.
|
2033 is the ReasonCode returned to the application when there is no message (that matches the app requirements) in the queue. This is not an error. Think of 2033 as end of file - but slightly different - read below.
One possibility is that after the initial get from the queue, the MQMD is now populated with MessageId and CorrelId (from the most-recently consumed message); and that the app is attempting to get another message with matching MessageId and CorrelId values.
Given that these two MD fields are (nearly always) unique, the app would continue to get with wait (which would not wait if there are any messages in the queue), and return a 2033 since there is no message matching the message previously consumed.
This behavior would look like what you describe - 100% (unending) utilization by the app.
Ensure that the application initializes the MQMD for the incoming message to whatever values are appropriate. _________________ 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 |
|
 |
satyaannareddy |
Posted: Wed Nov 10, 2010 9:58 am Post subject: |
|
|
Newbie
Joined: 09 Nov 2010 Posts: 9
|
Thanks for the reply Bruce
Yeah I am handling the reason code 2033 as deemed and not treating it as any error or exception.
Also I am re initializing the message and correlation id to default values
Code: |
messageReceived.clearMessage();
messageReceived.messageId = MQConstants.MQMI_NONE;
messageReceived.correlationId = MQConstants.MQCI_NONE; |
Please see my original post for complete code.
100% CPU as I know is due to large number of MQGets on the Queue.
The problem is the discrepency the same code is showing for two different kind of messages.
the only difference is one of the messages (one not behaving properly) is a bit larger than other (that behaves perfectly fine). |
|
Back to top |
|
 |
bruce2359 |
Posted: Wed Nov 10, 2010 10:06 am Post subject: |
|
|
 Poobah
Joined: 05 Jan 2008 Posts: 9471 Location: US: west coast, almost. Otherwise, enroute.
|
Quote: |
is a bit larger than other |
One coding suggestion: use the logical name associated with a ReasonCode, like MQRC_NO_MESSAGE_AVAIALBLE. This makes reading the code much easier.
What is the size difference between messages where the app works, and messages where the app misbehaves?
Is it possible that the app buffer for the message is too big for the message?
[edit]
Add to your error log the count of backouts/commits; then include your error log in your next post. I'm pondering if you are in a backout/get/backout/get looooooop. _________________ 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 |
|
 |
satyaannareddy |
Posted: Wed Nov 10, 2010 10:25 am Post subject: |
|
|
Newbie
Joined: 09 Nov 2010 Posts: 9
|
Thanks for the suggestion. I accept its easier reading the logica name than reading the code.
The large message is not even 10KB in size.
The message is not at all big but compared to the one thats working is big.
its like 5 times larger.
Please note the below log is before I have started logging the Reason code. so you can see the log code from the catch here.
Code: |
THREAD0:2010/11/09 10:00:47:
Reply
********************
reply message here
*********************
THREAD0:2010/11/09 10:00:47:Lifespan of message is being overriden
THREAD0:2010/11/09 10:00:47:Correl Id: BB
THREAD0:2010/11/09 10:00:47:Message Expiry set to -1
THREAD0:2010/11/09 10:00:47:Message persistance set to 1
THREAD0:2010/11/09 10:00:47:Reply sent to MQ
THREAD0:2010/11/09 10:00:47: We have just finished sending the reply message to the MQ???????????????????????????????
getCommittedVirtualMemorySize:2010/11/09 10:00:47: = 34140160??????????????????????????
getFreePhysicalMemorySize:2010/11/09 10:00:47: = 1156521984??????????????????????????
getFreeSwapSpaceSize:2010/11/09 10:00:47: = 4165140480??????????????????????????
getProcessCpuTime:2010/11/09 10:00:47: = 500000000??????????????????????????
getTotalPhysicalMemorySize:2010/11/09 10:00:47: = 2146861056??????????????????????????
getTotalSwapSpaceSize:2010/11/09 10:00:47: = 4294967295??????????????????????????
THREAD0:2010/11/09 10:00:47:Transaction committed
THREAD0:2010/11/09 10:00:47:
requesting message is
********************
taking time?????????????????????????????????????????
*********************
THREAD0:2010/11/09 10:00:47:
requesting message is
********************
taking time?????????????????????????????????????????
*********************
THREAD0:2010/11/09 10:00:47:
requesting message is
********************
taking time?????????????????????????????????????????
*********************
THREAD0:2010/11/09 10:00:47:
requesting message is
********************
taking time?????????????????????????????????????????
*********************
THREAD0:2010/11/09 10:00:47:
requesting message is
********************
taking time?????????????????????????????????????????
*********************
THREAD0:2010/11/09 10:00:47:
requesting message is
********************
taking time?????????????????????????????????????????
*********************
THREAD0:2010/11/09 10:00:47:
requesting message is
********************
taking time?????????????????????????????????????????
*********************
|
I had added a sleep to the thread when there is no message in queue and below is the log after that sleeping for 10secs
Code: |
Reply
********************
Reply Message here
*********************
THREAD0:2010/11/09 12:26:36:Lifespan of message is being overriden
THREAD0:2010/11/09 12:26:36:Correl Id: BB
THREAD0:2010/11/09 12:26:36:Message Expiry set to -1
THREAD0:2010/11/09 12:26:36:Message persistance set to 1
THREAD0:2010/11/09 12:26:36:Reply sent to MQ
THREAD0:2010/11/09 12:26:36: We have just finished sending the reply message to the MQ???????????????????????????????
getCommittedVirtualMemorySize:2010/11/09 12:26:36: = 34144256??????????????????????????
getFreePhysicalMemorySize:2010/11/09 12:26:36: = 1010728960??????????????????????????
getFreeSwapSpaceSize:2010/11/09 12:26:36: = 3993128960??????????????????????????
getProcessCpuTime:2010/11/09 12:26:36: = 515625000??????????????????????????
getTotalPhysicalMemorySize:2010/11/09 12:26:36: = 2146861056??????????????????????????
getTotalSwapSpaceSize:2010/11/09 12:26:36: = 4294967295??????????????????????????
THREAD0:2010/11/09 12:26:36:Transaction committed
THREAD0:2010/11/09 12:26:36:
requesting message is
********************
taking time?????????????????????????????????????????
*********************
THREAD0:2010/11/09 12:26:36:Exception While reading empty Queue: com.ibm.mq.MQQueue@1ef9f1d
THREAD0:2010/11/09 12:26:46:
requesting message is
********************
taking time?????????????????????????????????????????
*********************
THREAD0:2010/11/09 12:26:46:Exception While reading empty Queue: com.ibm.mq.MQQueue@1ef9f1d
THREAD0:2010/11/09 12:26:56:
requesting message is
********************
taking time?????????????????????????????????????????
*********************
THREAD0:2010/11/09 12:26:56:Exception While reading empty Queue: com.ibm.mq.MQQueue@1ef9f1d
THREAD0:2010/11/09 12:27:06:
requesting message is
********************
taking time?????????????????????????????????????????
*********************
THREAD0:2010/11/09 12:27:06:Exception While reading empty Queue: com.ibm.mq.MQQueue@1ef9f1d
THREAD0:2010/11/09 12:27:16:
requesting message is
********************
taking time???????????????????????????
|
|
|
Back to top |
|
 |
bruce2359 |
Posted: Wed Nov 10, 2010 10:54 am Post subject: |
|
|
 Poobah
Joined: 05 Jan 2008 Posts: 9471 Location: US: west coast, almost. Otherwise, enroute.
|
Quote: |
THREAD0:2010/11/09 12:27:06:Exception While reading empty Queue: com.ibm.mq.MQQueue@1ef9f1d
|
So, was the queue really empty? Or are you relying on the 2033 as meaning queue empty? _________________ 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 |
|
 |
fjb_saper |
Posted: Wed Nov 10, 2010 1:00 pm Post subject: |
|
|
 Grand High Poobah
Joined: 18 Nov 2003 Posts: 20756 Location: LI,NY
|
Are you per chance receiving message too big for buffer as return code?  _________________ MQ & Broker admin |
|
Back to top |
|
 |
|