Re: [Openh323gk-developer] T.120 Forward blocked issue.

[Thomas T. <tho...@cp...>]

Hi,
Thomas Themel (tho...@cp...) wrote on 2004-03-08:
> Unfortunately, it doesn't. I set the bandwidth to '14400 bps modem' on
> both ends, it still crashes. I'm just about to create a fully traced &&
> dumped instance of this bug that I will share, so that we have a basis
> for discussion. 

Okay, everything's up:

packet dump of session - <http://www.wannabehacker.com/gnugk/gnugk-tcpdump> 
strace of gnugk - <http://www.wannabehacker.com/gnugk/gnugk-trace>
-tttt output of gnugk - <http://www.wannabehacker.com/gnugk/gnugk-log>
bandwidth-saving package - <http://www.wannabehacker.com/gnugk/gnugk-t120.tar.gz>

Hosts involved:

80.120.254.13 - the gatekeeper
192.168.0.182 - LAN client
193.171.119.217 - the WAN client (33.6 dialup)

Stuff I noticed:

- The T.120 connection shutdown is initiated by the WAN client.

- After the shutdown, the TCP connection between the LAN client
  and the GK has transferred 53185 bytes of data while the connection
  between GK and WAN client has transferred only 4422 bytes.

- The error messages that ProxyThread outputs are somewhat misleading - 
  Input/output error suggests a system call returning EIO, which never
  happens according to the strace output.

Here's a part of the strace that strongly suggests that there's an error
in the buffering of ProxyThread - 

44 is the LAN -> GK socket, 45 is the GK -> WAN socket

| 17629 recv(44, "\337.?\2223\265\376\26\0108\372\10\211%\267\245x\21\34"..., 1536, 0) = 1536
| 17629 send(45, "\337.?\2223\265\376\26\0108\372\10\211%\267\245x\21\34"..., 1536, 0) = 1536

Here, it receives a buffer full of data and sends it on - fine.

| 17629 recv(44, 0x440d2900, 32, MSG_OOB) = -1 EINVAL (Invalid argument) 
| 17629 recv(44, "\vk\327\253\235\206\347z\35l\332\334[\336\365w~\266\356"..., 1536, 0) = 1536
| 17629 send(45, "\vk\327\253\235\206\347z\35l\332\334[\336\365w~\266\356"..., 1536, 0) = 928

Here, we try again with the next packet, but the send doesn't take the full 
amount of data - the socket buffer is probably full and we will have to wait
until some more data has been transmitted to the WAN end.

| 17629 send(45, "\370\303\267\20nx\25$\320lE\254RY\327\353\214\203u\206"..., 608, 0) = -1 EAGAIN (Resource temporarily unavailable)

When we try to send() the rest of the buffer, we get EAGAIN, which tells
us that we should retry later since the socket is nonblocking and the
send would block. Note that the EAGAIN means we never sent the data that
we attempted to send.

| 17629 recv(44, 0x440d2900, 32, MSG_OOB) = -1 EINVAL (Invalid argument) 
| 17629 recv(44, "\352\236\315\303\0i\2\343\331s\367\234\0020N`S\317\3\'"..., 1536, 0) = 1536 
| 17629 send(45, "\352\236\315\303\0i\2\343\331s\367\234\0020N`S\317\3\'"..., 1536, 0) = 1536

This is the next send() afterwards - and we don't attempt to resend what
was sent before, but proceed immediately with the new data from the last
recv(). It looks exactly like what I speculated on in my first mail
to -developers regarding this issue - when the send() would block, the
packet is dropped.

ciao,
-- 
Thomas Themel    | CenterPoint Connective Software Engineering GmbH 
Hauptplatz 8/4   |    System Administrator / Software Developer 
9500 Villach     |            <http://www.cpointc.com/> 
+43 676 846623-13| work tho...@cp... play th...@th...