[hobbit] Debugging a client

[Henrik Stoerner]

On Thu, Jul 12, 2007 at 10:10:31AM -0500, Trent Melcher wrote:
> On Thu, 2007-07-12 at 16:42 +0200, Henrik Stoerner wrote:
> >    cd ~hobbit/client
> >    HOBBITCLIENTHOME=`pwd` ./bin/bbcmd --env=etc/hobbitclient.cfg
> >    $BB $BBDISP --debug "ping"
> 
> Here is my output.....looks like I cant ping the hobbit server.
> 
> sh-3.00# $BB $BBDISP --debug "ping"
> 2007-07-12 10:05:57 Transport setup is:
> 2007-07-12 10:05:57 bbdportnumber = 1984
> 2007-07-12 10:05:57 bbdispproxyhost = NONE
> 2007-07-12 10:05:57 bbdispproxyport = 0
> 2007-07-12 10:05:57 Recipient listed as '5601-hobbit.sitel.net'
> 2007-07-12 10:05:57 Standard BB protocol on port 1984
> 2007-07-12 10:05:57 Will connect to address 5601-hobbit.sitel.net port 1984
> 2007-07-12 10:05:57 Connect status is 0
> 2007-07-12 10:05:57 Sent 4 bytes
> 2007-07-12 10:06:12 Whoops ! bb failed to send message - timeout
> 
> DNS and IP of the hobbit server are correct from the client....the
> firewall blocks ping from our DMZ to internal.

The "ping" here is actually a request for the Hobbit server process, it
isn't a normal ICMP ping. So if the firewall allows your Hobbit traffic
through, it will also permit the Hobbit "ping" through (Hobbit responds
with the word "PONG").

It's interesting that the connection succeeds ("Connect status is 0"),
and it does send the "PING" command ("Sent 4 bytes"). But then it
doesn't get the response back, and it gives up after 15 seconds flagging
the result as a timeout.

This *could* look like a firewall that drops the connection prematurely.

When the Hobbit client talks to the server, it opens the connection,
sends the data ("PING", or the client message), and then signals that
it has no more data to send by sending a TCP "FIN" packet to the server.
The FIN packet means that the Hobbit client cannot send any more data to
the server, but the server CAN send data back to the client (indeed,
that's what the client is waiting for). Once the server has sent back
the response, then the server will also send a FIN to the client
(indicating that the response has been sent completely) - and at that
point the connection is finished.

Some firewalls, however, see the first FIN packet and thinks "OK, this
connection is done" and then the response from the Hobbit server is 
blocked by the firewall.

If you have a program on the Hobbit client to do network sniffing (e.g.
tcpdump or ethereal / wireshark), then you can try doing a trace of the
network traffic while doing the "$BB $BBDISP ping". Normally, it should
look like this (172.16.10.100 is the client, 172.16.10.2 is the server):

$ tcpdump -i eth0 -n host 172.16.10.2 and tcp port 1984
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), capture size 96 bytes
17:22:21.583804 IP 172.16.10.100.32995 > 172.16.10.2.1984: S 232776140:232776140(0) win 5840 <mss 1460,sackOK,timestamp 2590316800,nop,wscale 5>
17:22:21.583986 IP 172.16.10.2.1984 > 172.16.10.100.32995: S 84545403:84545403(0) ack 232776141 win 5792 <mss 1460,sackOK,timestamp
258332627 259031680,nop,wscale 7>
17:22:21.584012 IP 172.16.10.100.32995 > 172.16.10.2.1984: . ack 1 win 183 <nop,nop,timestamp 259031680 258332627>
17:22:21.584174 IP 172.16.10.100.32995 > 172.16.10.2.1984: P 1:5(4) ack 1 win 183 <nop,nop,timestamp 259031680 258332627>
17:22:21.584187 IP 172.16.10.100.32995 > 172.16.10.2.1984: F 5:5(0) ack 1 win 183 <nop,nop,timestamp 259031680 258332627>
17:22:21.584370 IP 172.16.10.2.1984 > 172.16.10.100.32995: . ack 5 win 46 <nop,nop,timestamp 258332627 259031680>
17:22:21.584561 IP 172.16.10.2.1984 > 172.16.10.100.32995: P 1:15(14) ack 6 win 46 <nop,nop,timestamp 258332627 259031680>
17:22:21.584576 IP 172.16.10.100.32995 > 172.16.10.2.1984: . ack 15 win 183 <nop,nop,timestamp 259031681 258332627>
17:22:21.584615 IP 172.16.10.2.1984 > 172.16.10.100.32995: F 15:15(0) ack 6 win 46 <nop,nop,timestamp 258332627 259031680>
17:22:21.584623 IP 172.16.10.100.32995 > 172.16.10.2.1984: . ack 16 win 183 <nop,nop,timestamp 259031681 258332627>

You don't have to understand all of this, just that each line begins
with a timestamp, the IP-adress and port-number of the sender and the 
recipient for each packet, and then (after the colon) any TCP "flags" 
present in the packet - the flags are interesting.

The first 3 lines (two with the "S"="SYN" flag, and one ack) is the connection 
setup, also called the TCP "three-way handshake".

The next line with the "P" flag is when the client sends the "ping"
command. Right after that, the client sends a packet with the "F"="FIN"
flag set.

The server then sends the response (one packet with "P" flag), and then
close the connection (packet with "F" flag). The final ack packet
terminates the connection.

My guess is that if you do this on your client, you will only see the
data sent by the client, until it sends the "FIN" packet - the remaining
lines will be missing. If you do the same trace on the Hobbit server, 
you will see the data from the client, and the server sending back the
response - and then it will re-transmit the response over and over
because it doesn't get any ack back from the client.


Unfortunately, if this is the problem then I don't see a quick fix. You
can talk to your firewall admin's - maybe they have some setting in the
firewall they can tweak (the firewall is actually mis-behaving it it
acts like this - what Hobbit does is quite normal TCP behaviour). If
they cannot provide a solution, then drop me a mail and I'll see if I
can think of some work-around for it.

What kind of firewall are you using ?


Regards,
Henrik