| |
|
RSS Feed - WebSphere MQ Support
|
RSS Feed - Message Broker Support
|
  |
|
| Latency of technical acknowledgement during |
« View previous topic :: View next topic » |
| Author |
Message
|
| xiangh |
 Posted: Thu Aug 26, 2010 2:57 am Post subject: Latency of technical acknowledgement during |
 |
|
Newbie
Joined: 24 Aug 2010
Posts: 2
|
Hi,
We are currently facing an almost blocking latency issue during calls to MQQueue.put() (we are using 6.0) and could benefit from some advices.
Basically, situation is the following :- Any MQQueue.put() call takes about 10ms (our expectations are in the ~1ms range)
- Low level tracing shows that almost all this time is spent inside MQSESSIONClient.lowLevelComms() during the call to receive() immediately following the actual send() [from what Isee, this is some kind of technical ack)
- If we use multiple queues (mutithreading the input), as a workaround, latency is still 10ms (for each queue, though at some point it seems one of the queue went wild, but I do not have those logs).
- we ruled out a consumer issue by testing with a dummy application (just in case, as MQ is supposed to isolate our application from such potential issues)
Our basic hypothesis are the followings :- It could be a server setting, however no explicit throttling setting apparently exists.
- It could be a network issue (we're currently requesting ITs on both sides to perform trame capture so that we can check the figures on each side, delta between sent message and technical ack in particular)
- could be a TCP_NODELAY related issue, however I do not know how to check/ensure that TCP_NODELAY is set for the MQ connection (and ITs might be reluctant to set it at global level).
Any other lead (or comments regarding those) is welcome.
Regards,
Xiangh
PS: for information, the corresponding trace (well, some non significant function calls have been removed to focus on the critical part... especially since it was originally from a level 5 trace log)
| Code: |
00:02:11 [1282665731006] Thread: XXX, Object: com.ibm.mq.MQQueue@e2df60d ==> put() entry
00:02:11 [1282665731006] Thread: XXX, Object: com.ibm.mq.MQMessage@6eb8d517 ==> toByteArray() entry
00:02:11 [1282665731006] Thread: XXX, Object: com.ibm.mq.MQMessage@6eb8d517 <== toByteArray() exit
00:02:11 [1282665731006] Thread: XXX ==> MQSESSIONClient::MQPUT() entry
00:02:11 [1282665731006] Thread: XXX, Object: com.ibm.mq.MQSESSIONClient@3b0bb517 ==> supportsV2Structures() entry
00:02:11 [1282665731006] Thread: XXX, Object: com.ibm.mq.MQSESSIONClient@3b0bb517 <== supportsV2Structures() exit
00:02:11 [1282665731006] Thread: XXX, Object: com.ibm.mq.MQMessage@6eb8d517 ==> writeTo() entry
00:02:11 [1282665731006] Thread: XXX, Object: com.ibm.mq.MQMessage@6eb8d517 <== writeTo() exit
00:02:11 [1282665731006] Thread: XXX, Object: com.ibm.mq.MQPutMessageOptions@28ae11cb ==> writeTo() entry
00:02:11 [1282665731006] Thread: XXX, Object: com.ibm.mq.MQPutMessageOptions@28ae11cb <== writeTo() exit
00:02:11 [1282665731006] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 ==> buildAPIHeader() entry
00:02:11 [1282665731006] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 <== buildAPIHeader() exit
00:02:11 [1282665731006] Thread: XXX, Object: com.ibm.mq.MQSESSIONClient@3b0bb517 ==> lowLevelComms() entry
00:02:11 [1282665731007] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 ==> send() entry
00:02:11 [1282665731007] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 ==> writeTSH() entry
00:02:11 [1282665731007] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 <== writeTSH() exit
00:02:11 [1282665731008] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 <== send() exit
00:02:11 [1282665731008] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 ==> receive() entry
00:02:11 [1282665731008] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 ==> receiveBytesFaster() entry
00:02:11 [1282665731008] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 ==> timedReadInt() entry
00:02:11 [1282665731027] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 <== timedReadInt() exit
00:02:11 [1282665731027] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 ==> timedReadInt() entry
00:02:11 [1282665731027] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 <== timedReadInt() exit
00:02:11 [1282665731027] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 ==> timedReadFully() entry
00:02:11 [1282665731027] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 <== timedReadFully() exit
00:02:11 [1282665731028] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 <== receiveBytesFaster() exit
00:02:11 [1282665731028] Thread: XXX, Object: com.ibm.mq.MQv6InternalCommunications@3f418e04 <== receive() exit
00:02:11 [1282665731028] Thread: XXX, Object: com.ibm.mq.MQSESSIONClient@3b0bb517 <== lowLevelComms() exit
00:02:11 [1282665731028] Thread: XXX, Object: com.ibm.mq.MQMessage@6eb8d517 ==> readFrom() entry
00:02:11 [1282665731028] Thread: XXX, Object: com.ibm.mq.MQMessage@6eb8d517 <== readFrom() exit
00:02:11 [1282665731028] Thread: XXX, Object: com.ibm.mq.MQPutMessageOptions@28ae11cb ==> readFrom() entry
00:02:11 [1282665731028] Thread: XXX, Object: com.ibm.mq.MQPutMessageOptions@28ae11cb <== readFrom() exit
00:02:11 [1282665731028] Thread: XXX Class: MQSESSIONClient CC,RC = 0,0
00:02:11 [1282665731028] Thread:XXX <== MQSESSIONClient::MQPUT() exit
00:02:11 [1282665731028] Thread: XXXX, Object: com.ibm.mq.MQQueue@e2df60d <== put() exit
|
|
|
| Back to top |
|
 |
| mvic |
| Posted: Thu Aug 26, 2010 5:54 am Post subject: Re: Latency of technical acknowledgement during |
|
|
Jedi
Joined: 09 Mar 2004
Posts: 2080
|
| xiangh wrote: |
| we are using 6.0 |
What 6.0.a.b version, exactly?
And please answer:
- are the messages all persistent?
- are the messages all put inside a transaction / "syncpoint" ?
- if not, please describe persistence and syncpoint usage by the app |
|
| Back to top |
|
|
| mvic |
| Posted: Thu Aug 26, 2010 5:57 am Post subject: Re: Latency of technical acknowledgement during |
|
|
Jedi
Joined: 09 Mar 2004
Posts: 2080
|
| xiangh wrote: |
| Low level tracing shows that almost all this time is spent inside MQSESSIONClient.lowLevelComms() during the call to receive() immediately following the actual send() [from what Isee, this is some kind of technical ack |
I don't know what a technical ack is, but the elapsed time you see is the time taken by the server to enact the application's request. |
|
| Back to top |
|
|
| xiangh |
| Posted: Thu Aug 26, 2010 9:18 am Post subject: |
|
|
Newbie
Joined: 24 Aug 2010
Posts: 2
|
Hello,
| Quote: |
| What 6.0.a.b version, exactly? |
*** BuildInfo *** WebSphere MQ classes for Java (6.0.2.2)
*** BuildInfo *** j600-202-070711 (Production)
| Quote: |
| are the messages all persistent? |
According to the application configuration, yes
| Quote: |
| are the messages all put inside a transaction / "syncpoint" ? |
As far as I can see (and according to initial developer), not
| Quote: |
| if not, please describe persistence and syncpoint usage by the app |
None, the application has its own transaction system, which is not coordinated with MQ.... good thing you asked indeed...
| Quote: |
| I don't know what a technical ack is, but the elapsed time you see is the time taken by the server to enact the application's request. |
Technical ack : a message sent by the server to acknowledge he enacted our message. (for me the latency is the network_time_sent+enact_time+nework_time_ack... ptentially + maybe some naggle algorithm related delay, as our messages are rather small)
Thanks,
Xiangh |
|
| Back to top |
|
|
| fjb_saper |
| Posted: Thu Aug 26, 2010 9:25 am Post subject: |
|
|
Grand High Poobah
Joined: 18 Nov 2003
Posts: 20756
Location: LI,NY
|
10 ms sound a little bit much to me.
But then the experience I've had is a little bit different from what you are doing.
Let's say on an open queue going with a binding connection (memory pipe), with the message size you're talking about (< 4k) I'd have thought you should be able to achieve something like 4 ms... that would leave 6 ms to network latency in your case... (but then that's just me...)
A good point to start for you would be opening a PMR and working with IBM to achieve your goals. You might need to get the low latency edition of the software... 
_________________
MQ & Broker admin |
|
| Back to top |
|
|
| mvic |
| Posted: Thu Aug 26, 2010 11:08 am Post subject: |
|
|
Jedi
Joined: 09 Mar 2004
Posts: 2080
|
| xiangh wrote: |
| Quote: |
| are the messages all persistent? |
According to the application configuration, yes
| Quote: |
| are the messages all put inside a transaction / "syncpoint" ? |
As far as I can see (and according to initial developer), not |
Put persistent messages INSIDE a transaction/syncpoint, then commit. MQ will not perform well if you put persistent messages outside syncpoints. |
|
| Back to top |
|
|
| gbaddeley |
| Posted: Thu Aug 26, 2010 5:24 pm Post subject: |
|
|
Jedi Knight
Joined: 25 Mar 2003
Posts: 2538
Location: Melbourne, Australia
|
| Quote: |
| * Low level tracing shows that almost all this time is spent inside MQSESSIONClient.lowLevelComms() during the call to receive() immediately following the actual send() [from what Isee, this is some kind of technical ack) |
MQ Client uses a synchronous protocol, ie. send the MQI request to the qmgr server, wait for MQI completion from the qmgr server. So there are two network and comms stack latencies for the TCP packets, plus the socket API calls and message processing in the qmgr.
You need to identify where the most time is being spent.
_________________
Glenn |
|
| Back to top |
|
|
| mqjeff |
| Posted: Thu Aug 26, 2010 6:21 pm Post subject: |
|
|
Grand Master
Joined: 25 Jun 2008
Posts: 17447
|
| gbaddeley wrote: |
| Quote: |
| * Low level tracing shows that almost all this time is spent inside MQSESSIONClient.lowLevelComms() during the call to receive() immediately following the actual send() [from what Isee, this is some kind of technical ack) |
MQ Client uses a synchronous protocol, ie. send the MQI request to the qmgr server, wait for MQI completion from the qmgr server. So there are two network and comms stack latencies for the TCP packets, plus the socket API calls and message processing in the qmgr.
You need to identify where the most time is being spent. |
Yes.
AND.
You need to send persistent messages in a syncpoint, SO THAT the MQ API calls complete in the best possible time, REGARDLESS of whether you are using a client connection or the much faster bindings connection. |
|
| Back to top |
|
|
|
|
|
| |
|
Page 1 of 1 |
|
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum
|
|
|
|
