| Author |
Message
|
| mqjeff |
 Posted: Wed Jan 04, 2012 1:11 pm Post subject: |
 |
|
Grand Master
Joined: 25 Jun 2008
Posts: 17447
|
| Vitor wrote: |
You need to pin down where this extra time is coming from. |
My bet is that it's being used up during MQCMIT |
|
| Back to top |
|
 |
| bruce2359 |
| Posted: Wed Jan 04, 2012 4:13 pm Post subject: |
|
|
Poobah
Joined: 05 Jan 2008
Posts: 9475
Location: US: west coast, almost. Otherwise, enroute.
|
Is there only one MQCMIT in the trace (after the last MQPUT)? Or is there one MQCMIT after each MQPUT?
If the former, you might ponder why include all resulting messages (5000, in your case) in a single UofW? It may have made sense in the development cycle when the workload was to be 20 or 30 messages total.
If the latter, the total time for an MQPUT must include both the MQPUT and MQCMIT.
_________________
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 |
|
|
| PeterPotkay |
| Posted: Wed Jan 04, 2012 4:53 pm Post subject: |
|
|
Poobah
Joined: 15 May 2001
Posts: 7723
|
| kotagiriaashish wrote: |
we did a ping from the client to the server it took 400+ ms .... will that help? |
If a simple ping takes 400 ms, your network performance between the MQ Client and the MQ Server is pathetic. You should be thrilled with the performance you are getting from MQ if simple pings take that long.
Your trace shows MQPUTs and MQPUT1s - huh? MQPUT1s are going to take more time to execute than MQPUTs. Why are MQPUT1s mixed in with MQPUTs?
_________________
Peter Potkay
Keep Calm and MQ On |
|
| Back to top |
|
|
| bruce2359 |
| Posted: Wed Jan 04, 2012 5:10 pm Post subject: |
|
|
Poobah
Joined: 05 Jan 2008
Posts: 9475
Location: US: west coast, almost. Otherwise, enroute.
|
Try this: ping localhost What is the result?
Ping www.google.com. What is the result?
Ping some nearby servers in your network. Are the results consistent with 400ms you experience with the WMQ server?
_________________
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 Jan 04, 2012 9:48 pm Post subject: |
|
|
Grand High Poobah
Joined: 18 Nov 2003
Posts: 20763
Location: LI,NY
|
| bruce2359 wrote: |
Try this: ping localhost What is the result?
Ping www.google.com. What is the result?
Ping some nearby servers in your network. Are the results consistent with 400ms you experience with the WMQ server? |
You might also want to do a traceroute (or tracert in windows) from your client to the mq server. This may yield some interesting results when ping is blocked....
I just did a tracert to a server in Europe (newspaper) and did not have a single hop over 110 ms... (of course the tracert got blocked at the firewall before hitting the dest server, but I got pretty close to it in only 15 hops...)
| Code: |
>tracert www.dna.fr
Tracing route to prd-www-dna-fr.cm-cic.com [145.226.50.24]
over a maximum of 30 hops:
1 1 ms <1 ms 1 ms 192.168.0.1
2 * * * Request timed out.
3 8 ms 9 ms 8 ms 67.59.232.1
4 10 ms 9 ms 9 ms opti33-9.contact admin.cv.net [167.206.33.9]
5 10 ms 10 ms 11 ms rtr1-tg0-1-0-2.wan.hcvlny.cv.net [64.15.4.13]
6 10 ms 13 ms 10 ms 64.15.1.66
7 11 ms 11 ms 11 ms xe-4-3-0.edge3.NewYork2.Level3.net [4.59.128.81]
8 12 ms 12 ms 11 ms ae-1-51.edge2.NewYork2.Level3.net [4.69.138.195]
9 9 ms 10 ms 10 ms Verizon-level3-2x10g.NewYork.Level3.net [4.68.62.42]
10 9 ms 9 ms 14 ms 0.ae1.XL3.NYC1.ALTER.NET [152.63.18.221]
11 11 ms 10 ms 11 ms 0.xe-3-2-0.IL1.NYC9.ALTER.NET [152.63.26.81]
12 11 ms 12 ms 12 ms 0.ge-1-2-0.IL1.NYC12.ALTER.NET [152.63.26.86]
13 90 ms 90 ms 90 ms ge-1-1-0.XT2.SDE2.ALTER.NET [146.188.4.74]
14 91 ms 90 ms 91 ms xe-11-0-0.GW7.SDE2.ALTER.NET [212.157.179.14]
15 103 ms 103 ms 107 ms ufr201726.fr.customer.alter.net [212.208.255.82]
16 * * * Request timed out. |
Have fun 
_________________
MQ & Broker admin |
|
| Back to top |
|
|
| kotagiriaashish |
| Posted: Thu Jan 05, 2012 12:32 am Post subject: |
|
|
Disciple
Joined: 06 Aug 2011
Posts: 165
|
| bruce2359 wrote: |
Try this: ping localhost What is the result?
Ping www.google.com. What is the result?
Ping some nearby servers in your network. Are the results consistent with 400ms you experience with the WMQ server? |
Ya.. i tried pinging
| Code: |
google.com 71ms
google.ca 120ms
google.ru 71ms
|
And todays ping to the MQ server Resulted in 240ms [This ping was done in off business hours] |
|
| Back to top |
|
|
| kotagiriaashish |
| Posted: Thu Jan 05, 2012 12:36 am Post subject: |
|
|
Disciple
Joined: 06 Aug 2011
Posts: 165
|
| PeterPotkay wrote: |
| kotagiriaashish wrote: |
we did a ping from the client to the server it took 400+ ms .... will that help? |
If a simple ping takes 400 ms, your network performance between the MQ Client and the MQ Server is pathetic. You should be thrilled with the performance you are getting from MQ if simple pings take that long.
Your trace shows MQPUTs and MQPUT1s - huh? MQPUT1s are going to take more time to execute than MQPUTs. Why are MQPUT1s mixed in with MQPUTs? |
That's what i have to prove, The network team says any value near to 400 is a healthy ping I know that's dumb But i cant prove it...
All of them are MQPUT, only the last one is MQPUT1... |
|
| Back to top |
|
|
| kotagiriaashish |
| Posted: Thu Jan 05, 2012 12:39 am Post subject: |
|
|
Disciple
Joined: 06 Aug 2011
Posts: 165
|
| The client is in Vietnam and the Server is in China |
|
| Back to top |
|
|
| exerk |
| Posted: Thu Jan 05, 2012 1:22 am Post subject: |
|
|
Jedi Council
Joined: 02 Nov 2006
Posts: 6339
|
| kotagiriaashish wrote: |
| The client is in Vietnam and the Server is in China |
Ah! It's obviously having problems traversing the Great Firewall of China 
_________________
It's puzzling, I don't think I've ever seen anything quite like this before...and it's hard to soar like an eagle when you're surrounded by turkeys. |
|
| Back to top |
|
|
| JasonE |
| Posted: Thu Jan 05, 2012 1:42 am Post subject: |
|
|
Grand Master
Joined: 03 Nov 2003
Posts: 1220
Location: Hursley
|
| If this is test data, can you make the trace available somewhere? |
|
| Back to top |
|
|
| kotagiriaashish |
| Posted: Thu Jan 05, 2012 5:09 am Post subject: |
|
|
Disciple
Joined: 06 Aug 2011
Posts: 165
|
|
| Back to top |
|
|
| JasonE |
| Posted: Thu Jan 05, 2012 7:01 am Post subject: |
|
|
Grand Master
Joined: 03 Nov 2003
Posts: 1220
Location: Hursley
|
Thanks for the trace. In it you cover 17 mins and 10 seconds, which include a connect, open, 3497 puts of persistent messages outside of syncpoint, a put1, close and disc.
The puts take a _minimum_ of 00.270404, and a max of 02.651927 to complete, although only 105 of them are over 00.300000 in length (so 3392 @ 0.3 secs == 1017.6 secs == nearly 17 mins). The longer ones may be indicative of the server being busy, although 2.65 seconds is a long time!
The delay appears to be either be server side OR network i/o - I'd need to see a (ideally concurrent client and) server side trace to see how long the processing is from receive -> send. Given each put is a put / response, ie 2 flows, is it really the case that its taking 0.13-0.15(ish) seconds (130-150ms) for each flow/response?
If those figures are really unexpected, then you'd need to do the same server side, ie get a trace (full, ie -t detail -t all) and look at the put times vs send->receive wait time to see where the delay is.
The other comment is that MQ is optimized for persistent messages being inside a syncpoint, and you are putting lots of them outside of a syncpoint. From memory, I think each persistent put outside of syncpoint will end up waiting on disk i/o to flush, which on some systems could be a number of ms on its own. Note I could be wrong here - this is from memory! |
|
| Back to top |
|
|
| kotagiriaashish |
| Posted: Thu Jan 05, 2012 7:07 am Post subject: |
|
|
Disciple
Joined: 06 Aug 2011
Posts: 165
|
| JasonE wrote: |
Thanks for the trace. In it you cover 17 mins and 10 seconds, which include a connect, open, 3497 puts of persistent messages outside of syncpoint, a put1, close and disc.
The puts take a _minimum_ of 00.270404, and a max of 02.651927 to complete, although only 105 of them are over 00.300000 in length (so 3392 @ 0.3 secs == 1017.6 secs == nearly 17 mins). The longer ones may be indicative of the server being busy, although 2.65 seconds is a long time!
The delay appears to be either be server side OR network i/o - I'd need to see a (ideally concurrent client and) server side trace to see how long the processing is from receive -> send. Given each put is a put / response, ie 2 flows, is it really the case that its taking 0.13-0.15(ish) seconds (130-150ms) for each flow/response?
If those figures are really unexpected, then you'd need to do the same server side, ie get a trace (full, ie -t detail -t all) and look at the put times vs send->receive wait time to see where the delay is.
The other comment is that MQ is optimized for persistent messages being inside a syncpoint, and you are putting lots of them outside of a syncpoint. From memory, I think each persistent put outside of syncpoint will end up waiting on disk i/o to flush, which on some systems could be a number of ms on its own. Note I could be wrong here - this is from memory! |
WOW!! Thats great info.... Ill check with the server side traces... |
|
| Back to top |
|
|
| bruce2359 |
| Posted: Thu Jan 05, 2012 7:33 am Post subject: |
|
|
Poobah
Joined: 05 Jan 2008
Posts: 9475
Location: US: west coast, almost. Otherwise, enroute.
|
How many MQCMITs in the trace? One for each MQPUT(1)?
How many MQCONNects? MQDISConnects?
_________________
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 |
|
|
| JasonE |
| Posted: Thu Jan 05, 2012 7:55 am Post subject: |
|
|
Grand Master
Joined: 03 Nov 2003
Posts: 1220
Location: Hursley
|
| Quote: |
which include a connect, open, 3497 puts of persistent messages outside of syncpoint, a put1, close and disc.
|
None... One conn, one disc |
|
| Back to top |
|
|
|
|
