[hobbit] Debugging a client

[Trent Melcher]

On Thu, 2007-07-12 at 17:39 +0200, Henrik Stoerner wrote:
> 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 ?

Its a Symantec SGS firewall

Here is the output from my tcpdump.....see if you can wrap your head
around this one.

sh-3.00# tcpdump -i eth0 -n host 10.252.253.170 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
11:12:16.676177 IP 10.236.198.21.53166 > 10.252.253.170.1984: S
1042432006:1042432006(0) win 5840 <mss 1460,sackOK,timestamp 1420468346
0,nop,wscale 6>
11:12:16.676431 IP 10.252.253.170.1984 > 10.236.198.21.53166: S
2576077463:2576077463(0) ack 1042432007 win 5840 <mss
1460,nop,nop,sackOK,nop,wscale 0>
11:12:16.676508 IP 10.236.198.21.53166 > 10.252.253.170.1984: . ack 1
win 92
11:12:16.677865 IP 10.236.198.21.53166 > 10.252.253.170.1984: P 1:5(4)
ack 1 win 92
11:12:16.678204 IP 10.252.253.170.1984 > 10.236.198.21.53166: . ack 5
win 5840
11:12:16.678224 IP 10.236.198.21.53166 > 10.252.253.170.1984: F 5:5(0)
ack 1 win 92
11:12:16.716979 IP 10.252.253.170.1984 > 10.236.198.21.53166: . ack 6
win 5840
11:12:18.947433 IP 10.236.198.21.53173 > 10.252.253.170.1984: S
1052756306:1052756306(0) win 5840 <mss 1460,sackOK,timestamp 1420468914
0,nop,wscale 6>
11:12:18.947753 IP 10.252.253.170.1984 > 10.236.198.21.53173: S
3308980639:3308980639(0) ack 1052756307 win 5840 <mss
1460,nop,nop,sackOK,nop,wscale 0>
11:12:18.947781 IP 10.236.198.21.53173 > 10.252.253.170.1984: . ack 1
win 92
11:12:18.948580 IP 10.236.198.21.53173 > 10.252.253.170.1984: P
1:547(546) ack 1 win 92
11:12:18.948833 IP 10.252.253.170.1984 > 10.236.198.21.53173: . ack 547
win 6552
11:12:18.949538 IP 10.236.198.21.53173 > 10.252.253.170.1984: F
547:547(0) ack 1 win 92
11:12:18.984684 IP 10.252.253.170.1984 > 10.236.198.21.53173: . ack 548
win 6552


Here is where it sits for the 15 seconds before the timeout message 


11:12:32.852313 IP 10.236.198.21.53202 > 10.252.253.170.1984: S
1073859650:1073859650(0) win 5840 <mss 1460,sackOK,timestamp 1420472390
0,nop,wscale 6>
11:12:32.852645 IP 10.252.253.170.1984 > 10.236.198.21.53202: S
45498171:45498171(0) ack 1073859651 win 5840 <mss
1460,nop,nop,sackOK,nop,wscale 0>
11:12:32.852674 IP 10.236.198.21.53202 > 10.252.253.170.1984: . ack 1
win 92
11:12:32.853610 IP 10.236.198.21.53202 > 10.252.253.170.1984: P
1:547(546) ack 1 win 92
11:12:32.854109 IP 10.252.253.170.1984 > 10.236.198.21.53202: . ack 547
win 6552
11:12:32.854478 IP 10.236.198.21.53202 > 10.252.253.170.1984: F
547:547(0) ack 1 win 92

Thanks for the help
Trent

> 
> 
> Regards,
> Henrik
> 
> 
> To unsubscribe from the hobbit list, send an e-mail to
> hobbit-unsubscribe at hswn.dk
> 
>