| Author |
Message
|
| smdavies99 |
 Posted: Tue Nov 20, 2012 12:29 am Post subject: TCPServerInput Node 12 second delay |
 |
|
Jedi Council
Joined: 10 Feb 2003
Posts: 6076
Location: Somewhere over the Rainbow this side of Never-never land.
|
Here's an hopefully thought provoking question for you.
I have TWO VM's. both windows Server 2008 R2 with Btoker 7.0.0.4 running on both.
I'm developing a message flow that uses TCP/IP to communicate with a server.
So I've written a simulator on the second VM that listens on the TCP Ports and when it gets a message, It writes the contents to a table and sends an ack back. all so far so good.
However when the ACK returns to the first VM and the flow that I'm developing, the TCP Server Input node introduces a 12 second delay in processing the message.
There is a sample of the usertrace output for the Server Input Node.
| Code: |
2012-11-20 10:03:00.214716 5888 UserTrace BIP4142I: Evaluating cniElementSet'Type'. Changing value from '0' to '16777216'.
Element ''Type'' has been changed to '16777216'.
No user action required.
2012-11-20 10:03:00.214728 5888 UserTrace BIP4142I: Evaluating cniElementSet'Name'. Changing value from '''' to ''ClientDetails''.
Element ''Name'' has been changed to ''ClientDetails''.
No user action required.
2012-11-20 10:03:12.220770 5888 UserTrace BIP3907I: Message received and propagated to 'out' terminal of input node 'MYSERVER_MF.SF_MYSERVER_TCPInput.TCPIPServerInput'.
2012-11-20 10:03:12.221065 5888 UserTrace BIP6063I: A parser of type ''Properties'' was created on behalf of node 'MYSERVER_MF.SF_MYSERVER_TCPInput.TCPIPServerInput'
to handle the input stream, beginning at offset '0'.
2012-11-20 10:03:12.221219 5888 UserTrace BIP6069W: The broker is not capable of handling a message of data type ''BLOB''.
The message broker received a message that requires the handling of data of type ''BLOB'',
but the broker does not have the capability to handle data of this type.
Check both the message being sent to the message broker and the configuration data for the node.
References to the unsupported data type must be removed if the message is to be processed by the broker.
2012-11-20 10:03:12.221343 5888 UserTrace BIP6064I: A parser of type ''BLOB'' was created on behalf of node 'MYSERVER_MF.SF_MYSERVER_TCPInput.TCPIPServerInput'
to handle the input stream, beginning at offset '0'. The parser type was selected based on value ''NONE'' from the previous parser.
[I've wrapped the long lines a bit]
|
This node is configured to read a 5 character element. In this it has the length of the remaining message which is read by a TCPServerReceive node. all pretty SOP here. The connection is not configured to Close after receiving data.
The timestamps go
| Code: |
2012-11-20 10:03:00.214728
2012-11-20 10:03:12.220770 |
Whilst the delay is not critical to the system operation I'm wondering why this might be happening?
Has anyone any ideas?
I'll be trying the code out with the real system later today. I will be looking at the response times with interest
_________________
WMQ User since 1999
MQSI/WBI/WMB/'Thingy' User since 2002
Linux user since 1995
Every time you reinvent the wheel the more square it gets (anon). If in doubt think and investigate before you ask silly questions. |
|
| Back to top |
|
 |
| fjb_saper |
| Posted: Tue Nov 20, 2012 3:36 am Post subject: |
|
|
Grand High Poobah
Joined: 18 Nov 2003
Posts: 20756
Location: LI,NY
|
Question: how are the communications initiated.
Can you please check the initiation of a TCP/IP communication, from A to B and B to A with timing?
I have seen (network setup problem) a case where comms from A to B were OK but B to A had a significant delay establishing the comms. 
_________________
MQ & Broker admin |
|
| Back to top |
|
|
| McueMart |
| Posted: Tue Nov 20, 2012 4:38 am Post subject: |
|
|
Chevalier
Joined: 29 Nov 2011
Posts: 490
Location: UK...somewhere
|
Also can you clarify a bit regarding your flow topology?
Additionally, which is the Server and Client side of the TCP connection? You mention you are using a TCPIPServerOutput node so im assuming the server side is actually your message flow and the 'Server' is a TCP client? |
|
| Back to top |
|
|
| smdavies99 |
| Posted: Tue Nov 20, 2012 4:55 am Post subject: |
|
|
Jedi Council
Joined: 10 Feb 2003
Posts: 6076
Location: Somewhere over the Rainbow this side of Never-never land.
|
Messages are sent from the Client to this flow hence the use of the 'Server' nodes.
The test flows use TCPIPClient nodes to send that data and from trace logs I can see that the data has been sent in microseconds. A wireshark trace also reveals that the data has been transmitted without issue.
There is something in the final processing of the ServerINput node that is causing the delay.
VM1
Client Flow uses TCPIPClientOutput to send message to Server
VM2
Receiving Flow uses TCPIPServerInput Node to read 1st 5 bytes from input stream.
This is where the delay happens
OUtput from this node goes to a Compute Node where the length bytes are extracted from the 5 byte blob that has been read.
Then a TCPIPServerReceive node reads and parses the rest of the message. Again, no delay is present in the processing.
Just to complicate matters, I've deployed the flow(from VM2) into the proper test environment where the Client is the real system not a simulation. There is no delay in the message processing. That is why I'm not going to raise a PMR at this stage.
_________________
WMQ User since 1999
MQSI/WBI/WMB/'Thingy' User since 2002
Linux user since 1995
Every time you reinvent the wheel the more square it gets (anon). If in doubt think and investigate before you ask silly questions. |
|
| Back to top |
|
|
| McueMart |
| Posted: Tue Nov 20, 2012 5:14 am Post subject: |
|
|
Chevalier
Joined: 29 Nov 2011
Posts: 490
Location: UK...somewhere
|
| In your test env is it 100% repeatable and always 12 seconds? I have no idea if a service trace will give you more granular details of whats going on but it might be worth a bash. |
|
| Back to top |
|
|
| Esa |
| Posted: Tue Nov 20, 2012 5:17 am Post subject: |
|
|
Grand Master
Joined: 22 May 2008
Posts: 1387
Location: Finland
|
Have you run mqsireportproperties with -o ComIbmSocketConnectionManager for your client side execution group?
This reminds me of the problem I had last Spring with SOAPRequestNodes and SSL. That was resolved by changing the client side EG tcpNoDelay setting. Even if the ip trace seemed to point out that the problem was on the server side.
But I'm not sure if tcpNoDelay applies to execution groups running on a Windows system. Anyway, your ComIbmSocketConnectionManager properties list would be interesting to see. |
|
| Back to top |
|
|
| Esa |
| Posted: Tue Nov 20, 2012 5:21 am Post subject: |
|
|
Grand Master
Joined: 22 May 2008
Posts: 1387
Location: Finland
|
| By the way, are you by any chance running your Windows VM's on top of a UNIX box? |
|
| Back to top |
|
|
| McueMart |
| Posted: Tue Nov 20, 2012 5:24 am Post subject: |
|
|
Chevalier
Joined: 29 Nov 2011
Posts: 490
Location: UK...somewhere
|
| tcpNoDelay was also a thought I had but smdavies pointed out that wireshark shows the data has all been transmitted successfully from the client (before the 12 second delay commences...). So this seems unlikely. |
|
| Back to top |
|
|
| Esa |
| Posted: Tue Nov 20, 2012 5:39 am Post subject: |
|
|
Grand Master
Joined: 22 May 2008
Posts: 1387
Location: Finland
|
My experience was that tcpNoDelay operates on a lower level than iptrace or wireshark and for this reason the information showed by the trace may be incorrect.
And by this I mean the AIX operating system level tcpNodelay, not the EG setting. If there is a difference. I'm not sure. |
|
| Back to top |
|
|
| McueMart |
| Posted: Tue Nov 20, 2012 7:14 am Post subject: |
|
|
Chevalier
Joined: 29 Nov 2011
Posts: 490
Location: UK...somewhere
|
| Quote: |
| My experience was that tcpNoDelay operates on a lower level than iptrace or wireshark and for this reason the information showed by the trace may be incorrect. |
Not if you are running wireshark on the receiving end of the socket  |
|
| Back to top |
|
|
| smdavies99 |
| Posted: Tue Nov 20, 2012 7:52 pm Post subject: |
|
|
Jedi Council
Joined: 10 Feb 2003
Posts: 6076
Location: Somewhere over the Rainbow this side of Never-never land.
|
Thanks for all the suggestions
To answer soe of the questions
The Windows Server 2008 R2 VM's are running ontop of Windows 7 Ultimate
The wireshark trace was run on the receiving end of the connection.
It seems that the TCP Node has received the data. If it hadn't then why would it output so much data to the usertrace before pausing for 12 seconds. That is what I find strange.
As there is nothing obviously wrong AND I'm not seeing this delay on the UAT Systems I'll just have to live with it for now.
_________________
WMQ User since 1999
MQSI/WBI/WMB/'Thingy' User since 2002
Linux user since 1995
Every time you reinvent the wheel the more square it gets (anon). If in doubt think and investigate before you ask silly questions. |
|
| Back to top |
|
|
| fjb_saper |
| Posted: Tue Nov 20, 2012 8:33 pm Post subject: |
|
|
Grand High Poobah
Joined: 18 Nov 2003
Posts: 20756
Location: LI,NY
|
if the 12 seconds delay is due to some windows OS process, like paging etc... it will be quite difficult to track down...
_________________
MQ & Broker admin |
|
| Back to top |
|
|
| smdavies99 |
| Posted: Wed Nov 21, 2012 2:00 am Post subject: |
|
|
Jedi Council
Joined: 10 Feb 2003
Posts: 6076
Location: Somewhere over the Rainbow this side of Never-never land.
|
| fjb_saper wrote: |
| if the 12 seconds delay is due to some windows OS process, like paging etc... it will be quite difficult to track down... |
A good point but there is no paging going on. Besides the VM's are running on an SSD.
If we start seeing it elsewhere then I'll raise a PMR until then....
fingers crossed.
_________________
WMQ User since 1999
MQSI/WBI/WMB/'Thingy' User since 2002
Linux user since 1995
Every time you reinvent the wheel the more square it gets (anon). If in doubt think and investigate before you ask silly questions. |
|
| Back to top |
|
|
| Esa |
| Posted: Wed Nov 21, 2012 2:22 am Post subject: |
|
|
Grand Master
Joined: 22 May 2008
Posts: 1387
Location: Finland
|
| smdavies99 wrote: |
Just to complicate matters, I've deployed the flow(from VM2) into the proper test environment where the Client is the real system not a simulation. There is no delay in the message processing. That is why I'm not going to raise a PMR at this stage. |
Let me guess, the real client is not running on Message Broker?
Did you compare the server-side wireshark traces for the simulation and the real system clients?
Could somebody refresh my memory and tell if tcpNoDelay has any effect on an EG running on top of Windows? |
|
| Back to top |
|
|
| smdavies99 |
| Posted: Wed Nov 21, 2012 6:51 am Post subject: |
|
|
Jedi Council
Joined: 10 Feb 2003
Posts: 6076
Location: Somewhere over the Rainbow this side of Never-never land.
|
| Esa wrote: |
Let me guess, the real client is not running on Message Broker?
Did you compare the server-side wireshark traces for the simulation and the real system clients?
Could somebody refresh my memory and tell if tcpNoDelay has any effect on an EG running on top of Windows? |
1) you are correct that the client is not running Broker.
2) No able to install Wireshark on the UAT System
3) Don't know.
_________________
WMQ User since 1999
MQSI/WBI/WMB/'Thingy' User since 2002
Linux user since 1995
Every time you reinvent the wheel the more square it gets (anon). If in doubt think and investigate before you ask silly questions. |
|
| Back to top |
|
|
|
|
