[omniORB] TCP configuration?

Thu Sep 8 17:59:18 BST 2011

Hi Martin,

Sorry for taking ages to reply. Those traces show that the server is
quite correct in delaying the ACK because it's still waiting for more
data. The real question is why the client is waiting for the ACK before
sending the next chunk of data. It should keep sending regardless.

Is it the first call on the connection?  If so, does the same delay
happen on subsequent calls?

What happens if you set the maxSocketSend configuration parameter to
8192 on the client?  That will prevent it sending the 249620 bytes in
one single send() call.

How about if you set giopStream::directSendCutOff to a number larger
than your buffer?  You'll need to #include
<omniORB4/internal/giopStream.h> to access it.

Cheers,

Duncan.

On Mon, 2011-08-08 at 15:36 -0700, Martin Kocian wrote:
> Hi Duncan,
> 
> > What does omniORB think is happening at this time?  Can you get a trace
> > from both client and server with these options:
> 
> Here is the output with the additional options turned on. Tcpdump is 
> running on the receiving Linux box so the time stamps between tcpdump and
> the omniorb output on that machine are consistent.
> 
> Sender (rce12):
> 
> omniORB: (3) 1988-01-01 00:00:14.910000: Invoke 'update' on remote: root/is/replica<0>
> omniORB: (3) 1988-01-01 00:00:14.910000: sendChunk: to giop:tcp:172.21.6.45:44449 212 bytes
> omniORB: (3) 1988-01-01 00:00:14.910000: sendCopyChunk: to giop:tcp:172.21.6.45:44449 249620 bytes
> omniORB: (3) 1988-01-01 00:00:14.960000: sendChunk: to giop:tcp:172.21.6.45:44449 100 bytes
> omniORB: (3) 1988-01-01 00:00:14.960000: inputMessage: from giop:tcp:172.21.6.45:44449 24 bytes
> 
> Receiver (rdcds105):
> 
> omniORB: (4) 2011-08-08 15:20:34.809634: AsyncInvoker: thread id = 4 has started. Total threads = 3
> omniORB: (4) 2011-08-08 15:20:34.809682: giopWorker task execute.
> omniORB: (4) 2011-08-08 15:20:34.809718: inputMessage: from giop:tcp:[::ffff:172.21.6.24]:1027 212 bytes
> omniORB: (4) 2011-08-08 15:20:34.850187: inputMessage: (body) from giop:tcp:[::ffff:172.21.6.24]:1027 1448 bytes
> omniORB: (4) 2011-08-08 15:20:34.850232: inputMessage: (body) from giop:tcp:[::ffff:172.21.6.24]:1027 1448 bytes
> omniORB: (4) 2011-08-08 15:20:34.850420: inputMessage: (body) from giop:tcp:[::ffff:172.21.6.24]:1027 2896 bytes
> omniORB: (4) 2011-08-08 15:20:34.850457: inputMessage: (body) from giop:tcp:[::ffff:172.21.6.24]:1027 1448 bytes
> omniORB: (4) 2011-08-08 15:20:34.850515: inputMessage: (body) from giop:tcp:[::ffff:172.21.6.24]:1027 740 bytes
> omniORB: (4) 2011-08-08 15:20:34.850560: Dispatching remote call 'update' to: root/is/replica<0> (active)
> omniORB: (4) 2011-08-08 15:20:34.850645: inputCopyChunk: from giop:tcp:[::ffff:172.21.6.24]:1027 241640 bytes
> omniORB: (4) 2011-08-08 15:20:34.864043: inputMessage: from giop:tcp:[::ffff:172.21.6.24]:1027 100 bytes
> omniORB: (4) 2011-08-08 15:20:34.865406: sendChunk: to giop:tcp:[::ffff:172.21.6.24]:1027 24 bytes
> 
> 
> tcpdump:
> 
> 15:20:34.809553 IP rce12.lab1.reg.1027 > rdcds105.lab1.reg.44449: P 399:611(212) ack 73 win 17376 <nop,nop,timestamp 27 3545665898>
> 15:20:34.849970 IP rdcds105.lab1.reg.44449 > rce12.lab1.reg.1027: . ack 611 win 62 <nop,nop,timestamp 3545676958 27>
> 15:20:34.850137 IP rce12.lab1.reg.1027 > rdcds105.lab1.reg.44449: . 611:2059(1448) ack 73 win 17376 <nop,nop,timestamp 27 3545676958>
> 15:20:34.850164 IP rdcds105.lab1.reg.44449 > rce12.lab1.reg.1027: . ack 2059 win 85 <nop,nop,timestamp 3545676958 27>
> 15:20:34.850191 IP rce12.lab1.reg.1027 > rdcds105.lab1.reg.44449: . 2059:3507(1448) ack 73 win 17376 <nop,nop,timestamp 27 3545676958>
> 15:20:34.850198 IP rdcds105.lab1.reg.44449 > rce12.lab1.reg.1027: . ack 3507 win 108 <nop,nop,timestamp 3545676959 27>
> 
> ...
> 
> 15:20:34.864015 IP rce12.lab1.reg.1027 > rdcds105.lab1.reg.44449: P 250231:250327(96) ack 73 win 17376 <nop,nop,timestamp 27 3545676972>
> 15:20:34.864021 IP rce12.lab1.reg.1027 > rdcds105.lab1.reg.44449: P 250327:250331(4) ack 73 win 17376 <nop,nop,timestamp 27 3545676972>
> 15:20:34.864027 IP rdcds105.lab1.reg.44449 > rce12.lab1.reg.1027: . ack 250327 win 505 <nop,nop,timestamp 3545676972 27>
> 15:20:34.864032 IP rdcds105.lab1.reg.44449 > rce12.lab1.reg.1027: . ack 250331 win 505 <nop,nop,timestamp 3545676972 27>
> 15:20:34.865436 IP rdcds105.lab1.reg.44449 > rce12.lab1.reg.1027: P 73:97(24) ack 250331 win 505 <nop,nop,timestamp 3545676974 27>
> 15:20:34.867110 IP rce12.lab1.reg.1027 > rdcds105.lab1.reg.44449: P 250331:251079(748) ack 97 win 17376 <nop,nop,timestamp 27 3545676974>
> 
> 
> Thanks a lot,
> 
> Martin
> 
> 
> On Fri, 5 Aug 2011, Duncan Grisby wrote:
> 
> > On Wed, 2011-07-20 at 10:20 -0700, Martin Kocian wrote:
> >
> >> I am experiencing delays in the TCP communication in omniorb 4.1.4 where
> >> 212 bytes get sent to a Linux box (kernel 2.6.18-92.el5) immediately
> >> followed by about 200 kB. The problem is that the Linux box does not send
> >> the ack for the 212 bytes until 40 ms later(see time in the second line):
> >
> > What does omniORB think is happening at this time?  Can you get a trace
> > from both client and server with these options:
> >
> > -ORBtraceLevel 25 -ORBtraceInvocations 1 -ORBtraceTime 1
> > -ORBtraceThreadId 1
> >
> > And get another tcpdump. Then we can correlate them all.
> >
> > Cheers,
> >
> > Duncan.
> >
> > -- 
> > -- Duncan Grisby         --
> >  -- duncan at grisby.org     --
> >   -- http://www.grisby.org --
> >
> >
> 
> | Martin Kocian                                       |
> | kocian at slac.stanford.edu                            |
> | Stanford Linear Accelerator Center                  |
> | M.S. 95, P.O. Box 20450                             |
> | Stanford, CA 94309                                  |
> | Tel. (650)926-2887  Fax (650)926-2923               |
> 

-- 
 -- Duncan Grisby         --
  -- duncan at grisby.org     --
   -- http://www.grisby.org --