ssh connections stalling

ssh connections stalling

[Carl Michal]

I'm having some troubles with what should be a very simple firewall to 
simply protect a local machine.  When the firewall is enabled, ssh and scp 
connections will sometimes hang indefinitely.  I've tried configuring the 
firewall (which blocks all incoming requests to ports 0:1023 except ssh 
and icmp) with several different tools: firehol, ufw and lutelwall.  If 
the firewall is turned off, the problem disappears.  With lutelwall there 
is an option to create a non-stateful firewall - if that is done, the 
problem also disappears.

My syslog does show dropped packets that appear to be the cause of the 
problem.  From tcpdumps at both ends of the connection it looks like the 
problem happens if large packets are sent out from behind the firewall and 
then arrive in pieces at the other end with a piece missing.  ack 
packets coming back in are dropped, and the connection never recovers.

Any help in diagnosing this would be much appreciated.

Carl

Re: ssh connections stalling

[Karl Hiramoto]

On Thursday 22 October 2009 20:45:47 Carl Michal wrote:
> I'm having some troubles with what should be a very simple firewall to
> simply protect a local machine.  When the firewall is enabled, ssh and scp
> connections will sometimes hang indefinitely.  I've tried configuring the
> firewall (which blocks all incoming requests to ports 0:1023 except ssh
> and icmp) with several different tools: firehol, ufw and lutelwall.  If
> the firewall is turned off, the problem disappears.  With lutelwall there
> is an option to create a non-stateful firewall - if that is done, the
> problem also disappears.
> 
> My syslog does show dropped packets that appear to be the cause of the
> problem.  From tcpdumps at both ends of the connection it looks like the
> problem happens if large packets are sent out from behind the firewall and
> then arrive in pieces at the other end with a piece missing.  ack
> packets coming back in are dropped, and the connection never recovers.
> 
> Any help in diagnosing this would be much appreciated.
> 

Send your configuration,  as root or using sudo do:

iptables -L -vn
iptables -L -vn -t mangle
iptables -L -vn -t nat

--
Karl Hiramoto

Re: ssh connections stalling

[Carl Michal]

>
> Send your configuration,  as root or using sudo do:
>
> iptables -L -vn
> iptables -L -vn -t mangle
> iptables -L -vn -t nat
>
> --
> Karl Hiramoto
>

as configured by firehol:

iptables -L -vn 
Chain INPUT (policy DROP 0 packets, 0 bytes)
  pkts bytes target     prot opt in     out     source               destination
     0     0 ACCEPT     all  --  lo     *       0.0.0.0/0            0.0.0.0/0
    42  5534 in_world   all  --  *      *       0.0.0.0/0            0.0.0.0/0
     0     0 ACCEPT     all  --  *      *       0.0.0.0/0            0.0.0.0/0           state RELATED
     0     0 LOG        all  --  *      *       0.0.0.0/0            0.0.0.0/0           limit: avg 1/sec burst 5 LOG flags 0 level 4 prefix  `'IN-unknown:''
     0     0 DROP       all  --  *      *       0.0.0.0/0            0.0.0.0/0

Chain FORWARD (policy DROP 0 packets, 0 bytes)
  pkts bytes target     prot opt in     out     source 
destination
     0     0 ACCEPT     all  --  *      *       0.0.0.0/0            0.0.0.0/0           state RELATED
     0     0 LOG        all  --  *      *       0.0.0.0/0            0.0.0.0/0           limit: avg 1/sec burst 5 LOG flags 0 level 4 prefix  `'PASS-unknown:''
     0     0 DROP       all  --  *      *       0.0.0.0/0            0.0.0.0/0

Chain OUTPUT (policy DROP 0 packets, 0 bytes)
  pkts bytes target     prot opt in     out     source               destination
     0     0 ACCEPT     all  --  *      lo      0.0.0.0/0            0.0.0.0/0
     4   350 out_world  all  --  *      *       0.0.0.0/0            0.0.0.0/0
     0     0 ACCEPT     all  --  *      *       0.0.0.0/0            0.0.0.0/0           state RELATED
     0     0 LOG        all  --  *      *       0.0.0.0/0            0.0.0.0/0           limit: avg 1/sec burst 5 LOG flags 0 level 4 prefix `'OUT-unknown:''
     0     0 DROP       all  --  *      *       0.0.0.0/0            0.0.0.0/0

Chain in_world (1 references)
  pkts bytes target     prot opt in     out     source               destination
    42  5534 in_world_all_c1  all  --  *      *       0.0.0.0/0            0.0.0.0/0
    40  5168 in_world_irc_c2  all  --  *      *       0.0.0.0/0            0.0.0.0/0
    40  5168 in_world_ftp_c3  all  --  *      *       0.0.0.0/0            0.0.0.0/0
    40  5168 in_world_ssh_s4  all  --  *      *       0.0.0.0/0            0.0.0.0/0
    40  5168 in_world_icmp_s5  all  --  *      *       0.0.0.0/0            0.0.0.0/0
     0     0 ACCEPT     all  --  *      *       0.0.0.0/0            0.0.0.0/0           state RELATED
    36  4773 LOG        all  --  *      *       0.0.0.0/0            0.0.0.0/0           limit: avg 1/sec burst 5 LOG flags 0 level 4 prefix `''IN-world':''
    40  5168 DROP       all  --  *      *       0.0.0.0/0            0.0.0.0/0

Chain in_world_all_c1 (1 references)
  pkts bytes target     prot opt in     out     source               destination
     2   366 ACCEPT     all  --  *      *       0.0.0.0/0            0.0.0.0/0           state ESTABLISHED

Chain in_world_ftp_c3 (1 references)
  pkts bytes target     prot opt in     out     source               destination
     0     0 ACCEPT     tcp  --  *      *       0.0.0.0/0            0.0.0.0/0           tcp spt:21 dpts:32768:61000 state ESTABLISHED
     0     0 ACCEPT     tcp  --  *      *       0.0.0.0/0            0.0.0.0/0           tcp spt:20 dpts:32768:61000 state RELATED,ESTABLISHED
     0     0 ACCEPT     tcp  --  *      *       0.0.0.0/0            0.0.0.0/0           tcp spts:1024:65535 dpts:32768:61000 state ESTABLISHED

Chain in_world_icmp_s5 (1 references)
  pkts bytes target     prot opt in     out     source               destination
     0     0 ACCEPT     icmp --  *      *       0.0.0.0/0            0.0.0.0/0           state NEW,ESTABLISHED

Chain in_world_irc_c2 (1 references)
  pkts bytes target     prot opt in     out     source               destination
     0     0 ACCEPT     tcp  --  *      *       0.0.0.0/0 
0.0.0.0/0           tcp spt:6667 dpts:32768:61000 state ESTABLISHED

Chain in_world_ssh_s4 (1 references)
  pkts bytes target     prot opt in     out     source               destination
     0     0 ACCEPT     tcp  --  *      *       0.0.0.0/0            0.0.0.0/0           tcp spts:1024:65535 dpt:22 state NEW,ESTABLISHED

Chain out_world (1 references)
  pkts bytes target     prot opt in     out     source               destination
     4   350 out_world_all_c1  all  --  *      *       0.0.0.0/0            0.0.0.0/0
     0     0 out_world_irc_c2  all  --  *      *       0.0.0.0/0            0.0.0.0/0
     0     0 out_world_ftp_c3  all  --  *      *       0.0.0.0/0            0.0.0.0/0
     0     0 out_world_ssh_s4  all  --  *      *       0.0.0.0/0            0.0.0.0/0
     0     0 out_world_icmp_s5  all  --  *      *       0.0.0.0/0            0.0.0.0/0
     0     0 ACCEPT     all  --  *      *       0.0.0.0/0            0.0.0.0/0           state RELATED
     0     0 LOG        all  --  *      *       0.0.0.0/0            0.0.0.0/0           limit: avg 1/sec burst 5 LOG flags 0 level 4 prefix `''OUT-world':''
     0     0 DROP       all  --  *      *       0.0.0.0/0            0.0.0.0/0

Chain out_world_all_c1 (1 references)
  pkts bytes target     prot opt in     out     source               destination
     4   350 ACCEPT     all  --  *      *       0.0.0.0/0            0.0.0.0/0           state NEW,ESTABLISHED

Chain out_world_ftp_c3 (1 references)
  pkts bytes target     prot opt in     out     source               destination
     0     0 ACCEPT     tcp  --  *      *       0.0.0.0/0            0.0.0.0/0           tcp spts:32768:61000 dpt:21 state NEW,ESTABLISHED
     0     0 ACCEPT     tcp  --  *      *       0.0.0.0/0            0.0.0.0/0           tcp spts:32768:61000 dpt:20 state ESTABLISHED
     0     0 ACCEPT     tcp  --  *      *       0.0.0.0/0            0.0.0.0/0           tcp spts:32768:61000 dpts:1024:65535 state RELATED,ESTABLISHED

Chain out_world_icmp_s5 (1 references)
  pkts bytes target     prot opt in     out     source               destination
     0     0 ACCEPT     icmp --  *      *       0.0.0.0/0            0.0.0.0/0           state ESTABLISHED

Chain out_world_irc_c2 (1 references)
  pkts bytes target     prot opt in     out     source               destination
     0     0 ACCEPT     tcp  --  *      *       0.0.0.0/0            0.0.0.0/0           tcp spts:32768:61000 dpt:6667 state NEW,ESTABLISHED

Chain out_world_ssh_s4 (1 references)
  pkts bytes target     prot opt in     out     source               destination
     0     0 ACCEPT     tcp  --  *      *       0.0.0.0/0            0.0.0.0/0           tcp spt:22 dpts:1024:65535 state ESTABLISHED


iptables -L -vn -t mangle

Chain PREROUTING (policy ACCEPT 0 packets, 0 bytes)
  pkts bytes target     prot opt in     out     source               destination

Chain INPUT (policy ACCEPT 0 packets, 0 bytes)
  pkts bytes target     prot opt in     out     source               destination

Chain FORWARD (policy ACCEPT 0 packets, 0 bytes)
  pkts bytes target     prot opt in     out     source               destination

Chain OUTPUT (policy ACCEPT 0 packets, 0 bytes)
  pkts bytes target     prot opt in     out     source               destination

Chain POSTROUTING (policy ACCEPT 0 packets, 0 bytes)
  pkts bytes target     prot opt in     out     source               destination

iptables -L -vn -t nat:

Chain PREROUTING (policy ACCEPT 789 packets, 138K bytes)
  pkts bytes target     prot opt in     out     source               destination

Chain POSTROUTING (policy ACCEPT 1 packets, 62 bytes)
  pkts bytes target     prot opt in     out     source               destination

Chain OUTPUT (policy ACCEPT 1 packets, 62 bytes)
  pkts bytes target     prot opt in     out     source               destination

Re: ssh connections stalling

[Carl Michal]

Here's a simpler configuration (by hand, based on
http://www.brandonhutchinson.com/iptables_fw.html ) that shows the same 
problem:

iptables -L -vn
Chain INPUT (policy DROP 1 packets, 78 bytes)
  pkts bytes target     prot opt in     out     source               destination
     0     0 ACCEPT     all  --  lo     *       0.0.0.0/0            0.0.0.0/0
   140  112K ACCEPT     all  --  *      *       0.0.0.0/0            0.0.0.0/0           state RELATED,ESTABLISHED
     0     0 ACCEPT     tcp  --  *      *       0.0.0.0/0            0.0.0.0/0           tcp dpt:22 state NEW
    89 10029 DROP       all  --  *      *       0.0.0.0/0            0.0.0.0/0

Chain FORWARD (policy DROP 0 packets, 0 bytes)
  pkts bytes target     prot opt in     out     source               destination

Chain OUTPUT (policy DROP 0 packets, 0 bytes)
  pkts bytes target     prot opt in     out     source               destination
     0     0 ACCEPT     all  --  *      lo      0.0.0.0/0            0.0.0.0/0
   143 20996 ACCEPT     all  --  *      *       0.0.0.0/0            0.0.0.0/0           state NEW,RELATED,ESTABLISHED

Chain LOGDROP (0 references)
  pkts bytes target     prot opt in     out     source               destination

> Send your configuration,  as root or using sudo do:
>
> iptables -L -vn
> iptables -L -vn -t mangle
> iptables -L -vn -t nat
>
> --
> Karl Hiramoto
> --

RE: ssh connections stalling

[Rob Sterenborg]

> > Send your configuration,  as root or using sudo do:
> >
> > iptables -L -vn
> > iptables -L -vn -t mangle
> > iptables -L -vn -t nat
> >
> > --
> > Karl Hiramoto
> >
> 
> as configured by firehol:
> 
> iptables -L -vn

[...]

I've not looked extensively through the entire listing but I didn't see
anything relating to it: I've seen delays when sshd is not able to
lookup the hostname/IP. Are you allowing DNS lookups in your ruleset? Or
maybe the hosts file can help.


Rob

Re: ssh connections stalling

[Mart Frauenlob]

netfilter-owner@vger.kernel.org wrote:
> I'm having some troubles with what should be a very simple firewall to 
> simply protect a local machine.  When the firewall is enabled, ssh and 
> scp connections will sometimes hang indefinitely.  I've tried 
> configuring the firewall (which blocks all incoming requests to ports 
> 0:1023 except ssh and icmp) with several different tools: firehol, ufw 
> and lutelwall.  If the firewall is turned off, the problem 
> disappears.  With lutelwall there is an option to create a 
> non-stateful firewall - if that is done, the problem also disappears.
>
> My syslog does show dropped packets that appear to be the cause of the 
> problem.  From tcpdumps at both ends of the connection it looks like 
> the problem happens if large packets are sent out from behind the 
> firewall and then arrive in pieces at the other end with a piece 
> missing.  ack packets coming back in are dropped, and the connection 
> never recovers.
>
> Any help in diagnosing this would be much appreciated.
>
> Carl

Hello,

The rules you showed us, would all allow a local ssh server, so the 
ruleset is not the problem.
What confuses me, you talk about packets from behind the firewall, but 
your rulesets don't show any FORWARD rules that would even allow ssh.
If you would have, I'd say the problem may be fixable using the TCPMSS 
target:

TCPMSS
       [...]
       This target is used to overcome criminally braindead ISPs or 
servers which block "ICMP Fragmentation Needed" or "ICMPv6  Packet  Too  
Big"  packets.   The
       symptoms of this problem are that everything works fine from your 
Linux firewall/router, but machines behind it can never exchange large 
packets:
        1) Web browsers connect, then hang with no data received.
        2) Small mail works fine, but large emails hang.
        3) ssh works fine, but scp hangs after initial handshaking.
       [...]

If you need rules for a non routing (forwarding) machine, why do you 
talk about 'behind the firewall'?
Otherwise it's something else, than the ruleset.
Log outputs? tcpdumps? Distro? Kernel? iptables version?

Regards

Mart

Re: ssh connections stalling

[Karl Hiramoto]

Could you send your syslog rules that match your LOG   rules from firehol, 
That might explain what is being dropped.

Does your connection stall when your doing something or just when idle?
If your idle you could try and modify your sshd config TCPKeepAlive option.  
It could be the kernel timed out the state of your connection. 

Another thing you could try is making your SSH ports more permissive with 
something like: 
iptables -I INPUT -p tcp --dport 22 -j ACCEPT

To accept ssh destined TCP traffic regardless of state. 

--
Karl

Re: ssh connections stalling

[Carl Michal]

Rob:

DNS queries are definitely allowed.  My problem is somewhat 
intermittent - sometimes an scp transfer will complete, sometimes it 
won't.  When an scp transfer of a file stalls, it often stalls at the
same point in a file.

Karl + Matt:

Stalls are when there's something going on - usually heavy traffic.
If a file transfer is going to stall, its usually near the beginning - in 
the first few 100 kB or so.

This is just a local firewall, this machine isn't doing any routing.

iptables -I INPUT -p tcp --dport 22 -j ACCEPT
doesn't seem to help.

I tried the --clamp-mss-to-pmtu option, but it didn't help

kernel: 2.6.31-gentoo
distro: gentoo
iptables:  1.4.3.2

tcpdump of a stall:
tcpdump host 128.189.212.241
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), capture size 68 bytes
10:11:53.666783 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: S 1204070872:1204070872(0) win 5840 <mss 1380,[|tcp]>
10:11:53.666819 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: S 3213527017:3213527017(0) ack 1204070873 win 5792 <mss 1460,[|tcp]>
10:11:53.668396 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 1 win 92 <nop,nop,timestamp[|tcp]>
10:11:53.671570 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: P 1:22(21) ack 1 win 46 <nop,nop,timestamp[|tcp]>
10:11:53.673083 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 22 win 92 <nop,nop,timestamp[|tcp]>
10:11:53.673232 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: P 1:40(39) ack 22 win 92 <nop,nop,timestamp[|tcp]>
10:11:53.673261 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . ack 40 win 46 <nop,nop,timestamp[|tcp]>
10:11:53.673597 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: P 22:806(784) ack 40 win 46 <nop,nop,timestamp[|tcp]>
10:11:53.675120 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: P 40:832(792) ack 22 win 92 <nop,nop,timestamp[|tcp]>
10:11:53.713122 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . ack 832 win 58 <nop,nop,timestamp[|tcp]>
10:11:53.714633 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: P 832:856(24) ack 806 win 116 <nop,nop,timestamp[|tcp]>
10:11:53.714647 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . ack 856 win 58 <nop,nop,timestamp[|tcp]>
10:11:53.715894 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: P 806:958(152) ack 856 win 58 <nop,nop,timestamp[|tcp]>

...snip...

10:11:56.199883 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: P 7512:7656(144) ack 2846 win 214 <nop,nop,timestamp[|tcp]>
10:11:56.238437 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . ack 7656 win 286 <nop,nop,timestamp[|tcp]>
10:11:56.250616 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: P 2846:2990(144) ack 7656 win 286 <nop,nop,timestamp[|tcp]>
10:11:56.252161 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 2990 win 239 <nop,nop,timestamp[|tcp]>
10:11:56.404346 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: P 7656:7784(128) ack 2990 win 239 <nop,nop,timestamp[|tcp]>
10:11:56.404364 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . ack 7784 win 307 <nop,nop,timestamp[|tcp]>
10:11:56.833815 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 2990:8462(5472) ack 7784 win 307 <nop,nop,timestamp[|tcp]>
10:11:56.895442 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 4358 win 281 <nop,nop,timestamp[|tcp]>
10:11:56.895553 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 5726 win 324 <nop,nop,timestamp[|tcp]>
10:11:56.895564 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 8462:12566(4104) ack 7784 win 307 <nop,nop,timestamp[|tcp]>
10:11:56.895713 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 7094 win 367 <nop,nop,timestamp[|tcp]>
10:11:56.895721 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: P 12566:15302(2736) ack 7784 win 307 <nop,nop,timestamp[|tcp]>
10:11:56.896837 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 8462 win 410 <nop,nop,timestamp[|tcp]>
10:11:56.897729 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 9830 win 452 <nop,nop,timestamp[|tcp]>
10:11:56.897739 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 15302:16670(1368) ack 7784 win 307 <nop,nop,timestamp[|tcp]>
10:11:56.897743 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: P 16670:16942(272) ack 7784 win 307 <nop,nop,timestamp[|tcp]>
10:11:56.898198 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 11198 win 495 <nop,nop,timestamp[|tcp]>
10:11:56.898847 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 12566 win 538 <nop,nop,timestamp[|tcp]>
10:11:56.899049 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 13934 win 581 <nop,nop,timestamp[|tcp]>
10:11:56.899841 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 15302 win 623 <nop,nop,timestamp[|tcp]>
10:11:56.899954 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 15302 win 623 <nop,nop,timestamp[|tcp]>
10:11:56.901001 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 16942 win 666 <nop,nop,timestamp[|tcp]>
10:11:58.448358 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . 7784:9152(1368) ack 16942 win 666 <nop,nop,timestamp[|tcp]>
10:11:58.448384 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . ack 9152 win 330 <nop,nop,timestamp[|tcp]>
10:11:58.448387 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: P 9152:9640(488) ack 16942 win 666 <nop,nop,timestamp[|tcp]>
10:11:58.448393 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . ack 9640 win 351 <nop,nop,timestamp[|tcp]>
10:11:58.448857 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: P 16942:18286(1344) ack 9640 win 351 <nop,nop,timestamp[|tcp]>
10:11:58.450854 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 18286 win 709 <nop,nop,timestamp[|tcp]>
10:11:58.460890 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . 9640:11008(1368) ack 18286 win 709 <nop,nop,timestamp[|tcp]>
10:11:58.461441 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . 11008:12376(1368) ack 18286 win 709 <nop,nop,timestamp[|tcp]>
10:11:58.461446 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . ack 12376 win 396 <nop,nop,timestamp[|tcp]>
10:11:58.462017 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . 12376:13744(1368) ack 18286 win 709 <nop,nop,timestamp[|tcp]>
10:11:58.462615 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . 13744:15112(1368) ack 18286 win 709 <nop,nop,timestamp[|tcp]>
10:11:58.462620 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . ack 15112 win 442 <nop,nop,timestamp[|tcp]>
10:11:58.463163 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . 15112:16480(1368) ack 18286 win 709 <nop,nop,timestamp[|tcp]>
10:11:58.463453 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: P 17848:17880(32) ack 18286 win 709 <nop,nop,timestamp[|tcp]>
10:11:58.463460 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . ack 16480 win 464 <nop,nop,timestamp[|tcp]>
10:11:58.463596 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . 16480:17848(1368) ack 18286 win 709 <nop,nop,timestamp[|tcp]>
10:11:58.463603 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . ack 17880 win 487 <nop,nop,timestamp[|tcp]>
10:11:58.477649 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . 17880:19248(1368) ack 18286 win 709 <nop,nop,timestamp[|tcp]>
10:11:58.477661 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . ack 19248 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.478203 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . 19248:20616(1368) ack 18286 win 709 <nop,nop,timestamp[|tcp]>
10:11:58.478209 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . ack 20616 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.478815 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . 20616:21984(1368) ack 18286 win 709 <nop,nop,timestamp[|tcp]>
10:11:58.478821 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . ack 21984 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.479324 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: P 21984:23304(1320) ack 18286 win 709 <nop,nop,timestamp[|tcp]>
10:11:58.479331 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.481550 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 18286:23758(5472) ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.484329 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 21022 win 794 <nop,nop,timestamp[|tcp]>
10:11:58.484355 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 23758:27862(4104) ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.485499 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 23758 win 880 <nop,nop,timestamp[|tcp]>
10:11:58.485512 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 27862:31966(4104) ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.486930 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 26494 win 965 <nop,nop,timestamp[|tcp]>
10:11:58.486939 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 31966:36070(4104) ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.487827 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 29230 win 997 <nop,nop,timestamp[|tcp]>
10:11:58.487836 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 36070:40174(4104) ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.489157 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 31966 win 997 <nop,nop,timestamp[|tcp]>
10:11:58.489164 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 40174:44278(4104) ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.490014 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 34702 win 997 <nop,nop,timestamp[|tcp]>
10:11:58.490055 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 44278:48382(4104) ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.491194 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 37438 win 997 <nop,nop,timestamp[|tcp]>
10:11:58.493170 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 40174 win 997 <nop,nop,timestamp[|tcp]>
10:11:58.493177 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 48382:56590(8208) ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.494761 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 42910 win 997 <nop,nop,timestamp[|tcp]>
10:11:58.495770 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 45646 win 997 <nop,nop,timestamp[|tcp]>
10:11:58.495780 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 56590:64798(8208) ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.496809 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 48382 win 997 <nop,nop,timestamp[|tcp]>
10:11:58.496833 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 64798:68902(4104) ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.500763 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 51118 win 997 <nop,nop,timestamp[|tcp]>
10:11:58.501333 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 53854 win 997 <nop,nop,timestamp[|tcp]>
10:11:58.501342 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 68902:77110(8208) ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.502484 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:11:58.502596 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:11:58.503590 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:11:58.504589 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:11:58.505144 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:11:58.505720 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:11:58.506995 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:11:58.507438 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:11:58.507576 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:11:58.508945 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:11:58.509081 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:11:58.509708 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:11:58.510058 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:11:58.709142 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 53854:55222(1368) ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:11:58.711223 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:11:59.125124 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 53854:55222(1368) ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:11:59.147882 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:11:59.957121 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 53854:55222(1368) ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:11:59.967197 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
10:12:01.621134 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: . 53854:55222(1368) ack 23304 win 501 <nop,nop,timestamp[|tcp]>
10:12:01.708439 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: . ack 55222 win 976 <nop,nop,timestamp[|tcp]>
^C
841 packets captured
841 packets received by filter
0 packets dropped by kernel

syslog shows:
Oct 23 10:11:56 spider ''IN-world':'IN=eth0 OUT= MAC=00:1c:c0:72:48:e9:00:11:bb:09:36:80:08:00 SRC=128.189.212.241 DST=142.103.235.177 LEN=64 TOS=0x10 PREC=0x00 TTL=63 ID=43426 DF PROTO=TCP SPT=49536 DPT=22 WINDOW=623 RES=0x00 ACK URGP=0
Oct 23 10:11:58 spider ''IN-world':'IN=eth0 OUT= MAC=00:1c:c0:72:48:e9:00:11:bb:09:36:80:08:00 SRC=128.189.212.241 DST=142.103.235.177 LEN=64 TOS=0x10 PREC=0x00 TTL=63 ID=43455 DF PROTO=TCP SPT=49536 DPT=22 WINDOW=976 RES=0x00 ACK URGP=0
Oct 23 10:11:58 spider ''IN-world':'IN=eth0 OUT= MAC=00:1c:c0:72:48:e9:00:11:bb:09:36:80:08:00 SRC=128.189.212.241 DST=142.103.235.177 LEN=64 TOS=0x10 PREC=0x00 TTL=63 ID=43456 DF PROTO=TCP SPT=49536 DPT=22 WINDOW=976 RES=0x00 ACK URGP=0
Oct 23 10:11:58 spider ''IN-world':'IN=eth0 OUT= MAC=00:1c:c0:72:48:e9:00:11:bb:09:36:80:08:00 SRC=128.189.212.241 DST=142.103.235.177 LEN=64 TOS=0x10 PREC=0x00 TTL=63 ID=43457 DF PROTO=TCP SPT=49536 DPT=22 WINDOW=976 RES=0x00 ACK URGP=0
Oct 23 10:11:58 spider ''IN-world':'IN=eth0 OUT= MAC=00:1c:c0:72:48:e9:00:11:bb:09:36:80:08:00 SRC=128.189.212.241 DST=142.103.235.177 LEN=64 TOS=0x10 PREC=0x00 TTL=63 ID=43458 DF PROTO=TCP SPT=49536 DPT=22 WINDOW=976 RES=0x00 ACK URGP=0
Oct 23 10:11:58 spider ''IN-world':'IN=eth0 OUT= MAC=00:1c:c0:72:48:e9:00:11:bb:09:36:80:08:00 SRC=128.189.212.241 DST=142.103.235.177 LEN=80 TOS=0x10 PREC=0x00 TTL=63 ID=43468 DF PROTO=TCP SPT=49536 DPT=22 WINDOW=976 RES=0x00 ACK URGP=0
Oct 23 10:12:01 spider ''IN-world':'IN=eth0 OUT= MAC=00:1c:c0:72:48:e9:00:11:bb:09:36:80:08:00 SRC=128.189.212.241 DST=142.103.235.177 LEN=80 TOS=0x10 PREC=0x00 TTL=63 ID=43471 DF PROTO=TCP SPT=49536 DPT=22 WINDOW=976 RES=0x00 ACK URGP=0


It looks to me like the ack 55222 packets at 10:11:58.5xxx are being 
dropped, but why?

Carl

Re: ssh connections stalling

[Jozsef Kadlecsik]

On Fri, 23 Oct 2009, Carl Michal wrote:

> 
> DNS queries are definitely allowed.  My problem is somewhat intermittent -
> sometimes an scp transfer will complete, sometimes it won't.  When an scp
> transfer of a file stalls, it often stalls at the
> same point in a file.
> 
> Karl + Matt:
> 
> Stalls are when there's something going on - usually heavy traffic.
> If a file transfer is going to stall, its usually near the beginning - in the
> first few 100 kB or so.
> 
> This is just a local firewall, this machine isn't doing any routing.
> 
> iptables -I INPUT -p tcp --dport 22 -j ACCEPT
> doesn't seem to help.
> 
> I tried the --clamp-mss-to-pmtu option, but it didn't help
[...]
> 10:11:53.666783 IP 128.189.212.241.49536 > spider.phas.ubc.ca.ssh: S
> 1204070872:1204070872(0) win 5840 <mss 1380,[|tcp]>
> 10:11:53.666819 IP spider.phas.ubc.ca.ssh > 128.189.212.241.49536: S
> 3213527017:3213527017(0) ack 1204070873 win 5792 <mss 1460,[|tcp]>

Different MTU sizes? It does look like an MTU problem. What kind of 
Internet connection do you have? What is your network topology?

Try to set MSS to 1380 with the TCPMSS target in the OUTPUT chain.

Best regards,
Jozsef
-
E-mail  : kadlec@blackhole.kfki.hu, kadlec@mail.kfki.hu
PGP key : http://www.kfki.hu/~kadlec/pgp_public_key.txt
Address : KFKI Research Institute for Particle and Nuclear Physics
          H-1525 Budapest 114, POB. 49, Hungary

Re: ssh connections stalling

[Carl Michal]

Hi,

> Different MTU sizes? It does look like an MTU problem. What kind of
> Internet connection do you have? What is your network topology?
>
> Try to set MSS to 1380 with the TCPMSS target in the OUTPUT chain.
>
> Best regards,
> Jozsef
> -

so if I add:

iptables -t mangle -A OUTPUT  -p tcp --tcp-flags SYN,RST SYN -j TCPMSS --set-mss 1380

it doesn't help,

now the tcpdump starts:
11:36:16.742371 IP 128.189.212.241.39178 > spider.phas.ubc.ca.ssh: S  1086962333:1086962333(0) win 5840 <mss 1380,[|tcp]>
11:36:16.742409 IP spider.phas.ubc.ca.ssh > 128.189.212.241.39178: S 995440061:995440061(0) ack 1086962334 win 5792 <mss 1380,[|tcp]>

but it still stalls the same way.

I'm connected to a gigabit switch in a university department.  I'm afraid 
I don't know more about the topology than that.

My understanding of some of this is pretty weak, but I'm surprised the 
packets coming out of spider are so big: 8208 bytes in some cases.  I seem 
to run into problems when the packets get so big.  They are still 
that big even after forcing mss to 1380.

Carl

Re: ssh connections stalling

[Carl Michal]

ok,

so if I replace firehol's rules to allow INVALID packets like this:

iptables -R in_world_ssh_s4 1 -p tcp --dport 22 -m state --state NEW,INVALID,ESTABLISHED -j ACCEPT
iptables -R out_world_ssh_s4 1 -p tcp --sport 22 -m state --state INVALID,ESTABLISHED -j ACCEPT

Then my stalls go away.

It needs both though.  If just the input allows invalid, then the output 
packets start being dropped.

Is there some way to figure out why my packets are being marked invalid?

Carl

Re: ssh connections stalling

[Jozsef Kadlecsik]

On Fri, 23 Oct 2009, Carl Michal wrote:

> so if I replace firehol's rules to allow INVALID packets like this:
> 
> iptables -R in_world_ssh_s4 1 -p tcp --dport 22 -m state --state
> NEW,INVALID,ESTABLISHED -j ACCEPT
> iptables -R out_world_ssh_s4 1 -p tcp --sport 22 -m state --state
> INVALID,ESTABLISHED -j ACCEPT
> 
> Then my stalls go away.
> 
> It needs both though.  If just the input allows invalid, then the output
> packets start being dropped.
> 
> Is there some way to figure out why my packets are being marked invalid?

Log the INVALID packets. Also, it'd be good if you could capture them by 
tcpdump (please use the -Sv options at least).

Best regards,
Jozsef
-
E-mail  : kadlec@blackhole.kfki.hu, kadlec@mail.kfki.hu
PGP key : http://www.kfki.hu/~kadlec/pgp_public_key.txt
Address : KFKI Research Institute for Particle and Nuclear Physics
          H-1525 Budapest 114, POB. 49, Hungary

Re: ssh connections stalling

[Carl Michal]

> Log the INVALID packets. Also, it'd be good if you could capture them by
> tcpdump (please use the -Sv options at least).
>

just discovered that if ip_conntrack_tcp_be_liberal is set to 1, my 
problem also goes away.

Here's the whole connection (with be_liberal=0):

in syslog (with tcp sequence numbers logged):

Oct 23 15:00:30 spider IN=eth0 OUT= MAC=00:1c:c0:72:48:e9:00:11:bb:09:36:80:08:00 SRC=128.189.212.241 DST=142.103.235.177 LEN=64 TOS=0x10 PREC=0x00 TTL=63 ID=35028 DF PROTO=TCP SPT=46294 DPT=22 SEQ=3104782063 ACK=4116444452 WINDOW=538 RES=0x00 ACK URGP=0
Oct 23 15:00:32 spider IN=eth0 OUT= MAC=00:1c:c0:72:48:e9:00:11:bb:09:36:80:08:00 SRC=128.189.212.241 DST=142.103.235.177 LEN=64 TOS=0x10 PREC=0x00 TTL=63 ID=35039 DF PROTO=TCP SPT=46294 DPT=22 SEQ=3104784591 ACK=4116460924 WINDOW=997 RES=0x00 ACK URGP=0
Oct 23 15:00:32 spider IN=eth0 OUT= MAC=00:1c:c0:72:48:e9:00:11:bb:09:36:80:08:00 SRC=128.189.212.241 DST=142.103.235.177 LEN=64 TOS=0x10 PREC=0x00 TTL=63 ID=35040 DF PROTO=TCP SPT=46294 DPT=22 SEQ=3104784591 ACK=4116462292 WINDOW=976 RES=0x00 ACK URGP=0
Oct 23 15:00:32 spider IN=eth0 OUT= MAC=00:1c:c0:72:48:e9:00:11:bb:09:36:80:08:00 SRC=128.189.212.241 DST=142.103.235.177 LEN=64 TOS=0x10 PREC=0x00 TTL=63 ID=35057 DF PROTO=TCP SPT=46294 DPT=22 SEQ=3104784719 ACK=4116486980 WINDOW=1002 RES=0x00 ACK URGP=0
Oct 23 15:00:32 spider IN=eth0 OUT= MAC=00:1c:c0:72:48:e9:00:11:bb:09:36:80:08:00 SRC=128.189.212.241 DST=142.103.235.177 LEN=64 TOS=0x10 PREC=0x00 TTL=63 ID=35058 DF PROTO=TCP SPT=46294 DPT=22 SEQ=3104784719 ACK=4116486980 WINDOW=1002 RES=0x00 ACK URGP=0
Oct 23 15:00:32 spider IN=eth0 OUT= MAC=00:1c:c0:72:48:e9:00:11:bb:09:36:80:08:00 SRC=128.189.212.241 DST=142.103.235.177 LEN=64 TOS=0x10 PREC=0x00 TTL=63 ID=35059 DF PROTO=TCP SPT=46294 DPT=22 SEQ=3104784719 ACK=4116486980 WINDOW=1002 RES=0x00 ACK URGP=0
Oct 23 15:00:32 spider IN=eth0 OUT= MAC=00:1c:c0:72:48:e9:00:11:bb:09:36:80:08:00 SRC=128.189.212.241 DST=142.103.235.177 LEN=64 TOS=0x10 PREC=0x00 TTL=63 ID=35060 DF PROTO=TCP SPT=46294 DPT=22 SEQ=3104784719 ACK=4116486980 WINDOW=1002 RES=0x00 ACK URGP=0  and with tcpdump -Sv I see:

and tcpdump -Sv shows
tcpdump: listening on eth0, link-type EN10MB (Ethernet), capture size 68 bytes
15:00:26.839973 IP (tos 0x0, ttl 63, id 34989, offset 0, flags [DF], proto TCP (6), length 60) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: S 3104774279:3104774279(0) win 5840 <mss 1380,[|tcp]>
15:00:26.840009 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto TCP (6), length 60) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: S 4116431886:4116431886(0) ack 3104774280 win 5792 <mss 1460,[|tcp]>15:00:26.841672 IP (tos 0x0, ttl 63, id 34990, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116431887 win 92 <nop,nop,timestamp[|tcp]>
15:00:26.844884 IP (tos 0x0, ttl 64, id 60271, offset 0, flags [DF], proto TCP (6), length 73) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116431887:4116431908(21) ack 3104774280 win 46 <nop,nop,timestamp[|tcp]>
15:00:26.846414 IP (tos 0x0, ttl 63, id 34991, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116431908 win 92 <nop,nop,timestamp[|tcp]>
15:00:26.846684 IP (tos 0x0, ttl 63, id 34992, offset 0, flags [DF], proto TCP (6), length 91) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104774280:3104774319(39) ack 4116431908 win 92 <nop,nop,timestamp[|tcp]>
15:00:26.846713 IP (tos 0x0, ttl 64, id 60272, offset 0, flags [DF], proto TCP (6), length 52) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . ack 3104774319 win 46 <nop,nop,timestamp[|tcp]>
15:00:26.847090 IP (tos 0x0, ttl 64, id 60273, offset 0, flags [DF], proto TCP (6), length 836) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116431908:4116432692(784) ack 3104774319 win 46 <nop,nop,timestamp[|tcp]>
15:00:26.848785 IP (tos 0x0, ttl 63, id 34993, offset 0, flags [DF], proto TCP (6), length 844) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104774319:3104775111(792) ack 4116431908 win 92 <nop,nop,timestamp[|tcp]>
15:00:26.885134 IP (tos 0x0, ttl 64, id 60274, offset 0, flags [DF], proto TCP (6), length 52) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . ack 3104775111 win 58 <nop,nop,timestamp[|tcp]>
15:00:26.886894 IP (tos 0x0, ttl 63, id 34994, offset 0, flags [DF], proto TCP (6), length 76) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104775111:3104775135(24) ack 4116432692 win 116 <nop,nop,timestamp[|tcp]>
15:00:26.886919 IP (tos 0x0, ttl 64, id 60275, offset 0, flags [DF], proto TCP (6), length 52) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . ack 3104775135 win 58 <nop,nop,timestamp[|tcp]>
15:00:26.888195 IP (tos 0x0, ttl 64, id 60276, offset 0, flags [DF], proto TCP (6), length 204) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116432692:4116432844(152) ack 3104775135 win 58 <nop,nop,timestamp[|tcp]>
15:00:26.900535 IP (tos 0x0, ttl 63, id 34995, offset 0, flags [DF], proto TCP (6), length 196) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104775135:3104775279(144) ack 4116432844 win 141 <nop,nop,timestamp[|tcp]>
15:00:26.905993 IP (tos 0x0, ttl 64, id 60277, offset 0, flags [DF], proto TCP (6), length 772) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116432844:4116433564(720) ack 3104775279 win 70 <nop,nop,timestamp[|tcp]>
15:00:26.923093 IP (tos 0x0, ttl 63, id 34996, offset 0, flags [DF], proto TCP (6), length 68) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104775279:3104775295(16) ack 4116433564 win 165 <nop,nop,timestamp[|tcp]>
15:00:26.961125 IP (tos 0x0, ttl 64, id 60278, offset 0, flags [DF], proto TCP (6), length 52) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . ack 3104775295 win 70 <nop,nop,timestamp[|tcp]>
15:00:26.962709 IP (tos 0x0, ttl 63, id 34997, offset 0, flags [DF], proto TCP (6), length 100) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104775295:3104775343(48) ack 4116433564 win 165 <nop,nop,timestamp[|tcp]>
15:00:26.962743 IP (tos 0x0, ttl 64, id 60279, offset 0, flags [DF], proto TCP (6), length 52) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . ack 3104775343 win 70 <nop,nop,timestamp[|tcp]>
15:00:26.962794 IP (tos 0x0, ttl 64, id 60280, offset 0, flags [DF], proto TCP (6), length 100) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116433564:4116433612(48) ack 3104775343 win 70 <nop,nop,timestamp[|tcp]>
15:00:26.970068 IP (tos 0x0, ttl 63, id 34998, offset 0, flags [DF], proto TCP (6), length 116) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104775343:3104775407(64) ack 4116433612 win 165 <nop,nop,timestamp[|tcp]>
15:00:26.971797 IP (tos 0x0, ttl 64, id 60281, offset 0, flags [DF], proto TCP (6), length 116) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116433612:4116433676(64) ack 3104775407 win 70 <nop,nop,timestamp[|tcp]>
15:00:26.973716 IP (tos 0x0, ttl 63, id 34999, offset 0, flags [DF], proto TCP (6), length 148) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104775407:3104775503(96) ack 4116433676 win 165 <nop,nop,timestamp[|tcp]>
15:00:26.974232 IP (tos 0x0, ttl 64, id 60282, offset 0, flags [DF], proto TCP (6), length 116) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116433676:4116433740(64) ack 3104775503 win 70 <nop,nop,timestamp[|tcp]>
15:00:27.013591 IP (tos 0x0, ttl 63, id 35000, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116433740 win 165 <nop,nop,timestamp[|tcp]>
15:00:29.198673 IP (tos 0x0, ttl 63, id 35001, offset 0, flags [DF], proto TCP (6), length 132) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104775503:3104775583(80) ack 4116433740 win 165 <nop,nop,timestamp[|tcp]>
15:00:29.199568 IP (tos 0x0, ttl 64, id 60283, offset 0, flags [DF], proto TCP (6), length 100) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116433740:4116433788(48) ack 3104775583 win 70 <nop,nop,timestamp[|tcp]>
15:00:29.201076 IP (tos 0x0, ttl 63, id 35002, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116433788 win 165 <nop,nop,timestamp[|tcp]>
15:00:29.201303 IP (tos 0x0, ttl 63, id 35003, offset 0, flags [DF], proto TCP (6), length 132) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104775583:3104775663(80) ack 4116433788 win 165 <nop,nop,timestamp[|tcp]>
15:00:29.201406 IP (tos 0x0, ttl 64, id 60284, offset 0, flags [DF], proto TCP (6), length 84) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116433788:4116433820(32) ack 3104775663 win 70 <nop,nop,timestamp[|tcp]>
15:00:29.203421 IP (tos 0x0, ttl 63, id 35004, offset 0, flags [DF], proto TCP (6), length 180) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104775663:3104775791(128) ack 4116433820 win 165 <nop,nop,timestamp[|tcp]>
15:00:29.210426 IP (tos 0x0, ttl 64, id 60285, offset 0, flags [DF], proto TCP (6), length 100) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116433820:4116433868(48) ack 3104775791 win 83 <nop,nop,timestamp[|tcp]>
15:00:29.218506 IP (tos 0x0, ttl 63, id 35005, offset 0, flags [DF], proto TCP (6), length 164) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104775791:3104775903(112) ack 4116433868 win 165 <nop,nop,timestamp[|tcp]>
15:00:29.218631 IP (tos 0x10, ttl 63, id 35006, offset 0, flags [DF], proto TCP (6), length 180) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104775903:3104776031(128) ack 4116433868 win 165 <nop,nop,timestamp[|tcp]>
15:00:29.220304 IP (tos 0x0, ttl 64, id 60286, offset 0, flags [DF], proto TCP (6), length 52) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . ack 3104776031 win 95 <nop,nop,timestamp[|tcp]>
15:00:29.222969 IP (tos 0x10, ttl 64, id 60287, offset 0, flags [DF], proto TCP (6), length 132) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116433868:4116433948(80) ack 3104776031 win 95 <nop,nop,timestamp[|tcp]>
15:00:29.247528 IP (tos 0x10, ttl 64, id 60288, offset 0, flags [DF], proto TCP (6), length 116) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116433948:4116434012(64) ack 3104776031 win 95 <nop,nop,timestamp[|tcp]>
15:00:29.249106 IP (tos 0x10, ttl 63, id 35007, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116434012 win 165 <nop,nop,timestamp[|tcp]>
15:00:29.249937 IP (tos 0x10, ttl 63, id 35008, offset 0, flags [DF], proto TCP (6), length 196) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104776031:3104776175(144) ack 4116434012 win 165 <nop,nop,timestamp[|tcp]>
15:00:29.250044 IP (tos 0x10, ttl 64, id 60289, offset 0, flags [DF], proto TCP (6), length 180) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116434012:4116434140(128) ack 3104776175 win 108 <nop,nop,timestamp[|tcp]>
15:00:29.252007 IP (tos 0x10, ttl 63, id 35009, offset 0, flags [DF], proto TCP (6), length 196) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104776175:3104776319(144) ack 4116434140 win 190 <nop,nop,timestamp[|tcp]>
15:00:29.252097 IP (tos 0x10, ttl 64, id 60290, offset 0, flags [DF], proto TCP (6), length 196) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116434140:4116434284(144) ack 3104776319 win 120 <nop,nop,timestamp[|tcp]>
15:00:29.254095 IP (tos 0x10, ttl 63, id 35010, offset 0, flags [DF], proto TCP (6), length 196) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104776319:3104776463(144) ack 4116434284 win 214 <nop,nop,timestamp[|tcp]>
15:00:29.254177 IP (tos 0x10, ttl 64, id 60291, offset 0, flags [DF], proto TCP (6), length 164) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116434284:4116434396(112) ack 3104776463 win 132 <nop,nop,timestamp[|tcp]>
15:00:29.257360 IP (tos 0x10, ttl 63, id 35011, offset 0, flags [DF], proto TCP (6), length 1420) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . 3104776463:3104777831(1368) ack 4116434396 win 214 <nop,nop,timestamp[|tcp]>
15:00:29.258009 IP (tos 0x10, ttl 63, id 35012, offset 0, flags [DF], proto TCP (6), length 1420) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . 3104777831:3104779199(1368) ack 4116434396 win 214 <nop,nop,timestamp[|tcp]>
15:00:29.258015 IP (tos 0x10, ttl 64, id 60292, offset 0, flags [DF], proto TCP (6), length 52) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . ack 3104779199 win 178 <nop,nop,timestamp[|tcp]>
15:00:29.258587 IP (tos 0x10, ttl 63, id 35013, offset 0, flags [DF], proto TCP (6), length 1420) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . 3104779199:3104780567(1368) ack 4116434396 win 214 <nop,nop,timestamp[|tcp]>
15:00:29.258910 IP (tos 0x10, ttl 63, id 35014, offset 0, flags [DF], proto TCP (6), length 988) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104780567:3104781503(936) ack 4116434396 win 214 <nop,nop,timestamp[|tcp]>
15:00:29.258918 IP (tos 0x10, ttl 64, id 60293, offset 0, flags [DF], proto TCP (6), length 52) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . ack 3104781503 win 222 <nop,nop,timestamp[|tcp]>
15:00:29.259154 IP (tos 0x10, ttl 64, id 60294, offset 0, flags [DF], proto TCP (6), length 164) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116434396:4116434508(112) ack 3104781503 win 222 <nop,nop,timestamp[|tcp]>
15:00:29.260794 IP (tos 0x10, ttl 63, id 35015, offset 0, flags [DF], proto TCP (6), length 196) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104781503:3104781647(144) ack 4116434508 win 214 <nop,nop,timestamp[|tcp]>
15:00:29.260915 IP (tos 0x10, ttl 64, id 60295, offset 0, flags [DF], proto TCP (6), length 164) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116434508:4116434620(112) ack 3104781647 win 243 <nop,nop,timestamp[|tcp]>
15:00:29.277432 IP (tos 0x10, ttl 63, id 35016, offset 0, flags [DF], proto TCP (6), length 196) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104781647:3104781791(144) ack 4116434620 win 214 <nop,nop,timestamp[|tcp]>
15:00:29.277508 IP (tos 0x10, ttl 64, id 60296, offset 0, flags [DF], proto TCP (6), length 164) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116434620:4116434732(112) ack 3104781791 win 264 <nop,nop,timestamp[|tcp]>
15:00:29.316995 IP (tos 0x10, ttl 63, id 35017, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116434732 win 214 <nop,nop,timestamp[|tcp]>
15:00:29.654660 IP (tos 0x10, ttl 63, id 35018, offset 0, flags [DF], proto TCP (6), length 196) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104781791:3104781935(144) ack 4116434732 win 214 <nop,nop,timestamp[|tcp]>
15:00:29.693153 IP (tos 0x10, ttl 64, id 60297, offset 0, flags [DF], proto TCP (6), length 52) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . ack 3104781935 win 286 <nop,nop,timestamp[|tcp]>
15:00:29.702027 IP (tos 0x10, ttl 64, id 60298, offset 0, flags [DF], proto TCP (6), length 196) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116434732:4116434876(144) ack 3104781935 win 286 <nop,nop,timestamp[|tcp]>
15:00:29.703795 IP (tos 0x10, ttl 63, id 35019, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116434876 win 239 <nop,nop,timestamp[|tcp]>
15:00:29.902835 IP (tos 0x10, ttl 63, id 35020, offset 0, flags [DF], proto TCP (6), length 180) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104781935:3104782063(128) ack 4116434876 win 239 <nop,nop,timestamp[|tcp]>
15:00:29.902863 IP (tos 0x10, ttl 64, id 60299, offset 0, flags [DF], proto TCP (6), length 52) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . ack 3104782063 win 307 <nop,nop,timestamp[|tcp]>
15:00:30.314104 IP (tos 0x10, ttl 64, id 60300, offset 0, flags [DF], proto TCP (6), length 5524) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116434876:4116440348(5472) ack 3104782063 win 307 <nop,nop,timestamp[|tcp]>
15:00:30.321993 IP (tos 0x10, ttl 63, id 35021, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116436244 win 281 <nop,nop,timestamp[|tcp]>
15:00:30.322087 IP (tos 0x10, ttl 63, id 35022, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116437612 win 324 <nop,nop,timestamp[|tcp]>
15:00:30.322098 IP (tos 0x10, ttl 64, id 60304, offset 0, flags [DF], proto TCP (6), length 4156) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116440348:4116444452(4104) ack 3104782063 win 307 <nop,nop,timestamp[|tcp]>
15:00:30.323246 IP (tos 0x10, ttl 63, id 35023, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116438980 win 367 <nop,nop,timestamp[|tcp]>
15:00:30.323255 IP (tos 0x10, ttl 64, id 60307, offset 0, flags [DF], proto TCP (6), length 1420) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116444452:4116445820(1368) ack 3104782063 win 307 <nop,nop,timestamp[|tcp]>
15:00:30.323259 IP (tos 0x10, ttl 64, id 60308, offset 0, flags [DF], proto TCP (6), length 196) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116445820:4116445964(144) ack 3104782063 win 307 <nop,nop,timestamp[|tcp]>
15:00:30.323368 IP (tos 0x10, ttl 63, id 35024, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116440348 win 410 <nop,nop,timestamp[|tcp]>
15:00:30.324447 IP (tos 0x10, ttl 63, id 35025, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116441716 win 452 <nop,nop,timestamp[|tcp]>
15:00:30.324562 IP (tos 0x10, ttl 63, id 35026, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116443084 win 495 <nop,nop,timestamp[|tcp]>
15:00:30.325419 IP (tos 0x10, ttl 63, id 35027, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116444452 win 538 <nop,nop,timestamp[|tcp]>
15:00:30.325530 IP (tos 0x10, ttl 63, id 35028, offset 0, flags [DF], proto TCP (6), length 64) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116444452 win 538 <nop,nop,timestamp[|tcp]>
15:00:30.326696 IP (tos 0x10, ttl 63, id 35029, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116445964 win 581 <nop,nop,timestamp[|tcp]>
15:00:32.292880 IP (tos 0x10, ttl 63, id 35031, offset 0, flags [DF], proto TCP (6), length 236) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104783431:3104783615(184) ack 4116445964 win 581 <nop,nop,timestamp[|tcp]>
15:00:32.292905 IP (tos 0x10, ttl 64, id 60309, offset 0, flags [DF], proto TCP (6), length 64) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . ack 3104782063 win 307 <nop,nop,timestamp[|tcp]>
15:00:32.292955 IP (tos 0x10, ttl 63, id 35030, offset 0, flags [DF], proto TCP (6), length 1420) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . 3104782063:3104783431(1368) ack 4116445964 win 581 <nop,nop,timestamp[|tcp]>
15:00:32.292965 IP (tos 0x10, ttl 64, id 60310, offset 0, flags [DF], proto TCP (6), length 52) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . ack 3104783615 win 330 <nop,nop,timestamp[|tcp]>
15:00:32.293430 IP (tos 0x10, ttl 64, id 60311, offset 0, flags [DF], proto TCP (6), length 1332) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116445964:4116447244(1280) ack 3104783615 win 330 <nop,nop,timestamp[|tcp]>
15:00:32.295312 IP (tos 0x10, ttl 63, id 35032, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116447244 win 623 <nop,nop,timestamp[|tcp]>
15:00:32.313336 IP (tos 0x10, ttl 63, id 35033, offset 0, flags [DF], proto TCP (6), length 1028) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104783615:3104784591(976) ack 4116447244 win 623 <nop,nop,timestamp[|tcp]>
15:00:32.314772 IP (tos 0x10, ttl 64, id 60312, offset 0, flags [DF], proto TCP (6), length 5524) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116447244:4116452716(5472) ack 3104784591 win 351 <nop,nop,timestamp[|tcp]>
15:00:32.317556 IP (tos 0x10, ttl 63, id 35034, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116449980 win 709 <nop,nop,timestamp[|tcp]>
15:00:32.317572 IP (tos 0x10, ttl 64, id 60316, offset 0, flags [DF], proto TCP (6), length 4156) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116452716:4116456820(4104) ack 3104784591 win 351 <nop,nop,timestamp[|tcp]>
15:00:32.318845 IP (tos 0x10, ttl 63, id 35035, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116452716 win 794 <nop,nop,timestamp[|tcp]>
15:00:32.318854 IP (tos 0x10, ttl 64, id 60319, offset 0, flags [DF], proto TCP (6), length 4156) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116456820:4116460924(4104) ack 3104784591 win 351 <nop,nop,timestamp[|tcp]>
15:00:32.320194 IP (tos 0x10, ttl 63, id 35036, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116455452 win 880 <nop,nop,timestamp[|tcp]>
15:00:32.320215 IP (tos 0x10, ttl 64, id 60322, offset 0, flags [DF], proto TCP (6), length 2788) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116460924:4116463660(2736) ack 3104784591 win 351 <nop,nop,timestamp[|tcp]>
15:00:32.320220 IP (tos 0x10, ttl 64, id 60324, offset 0, flags [DF], proto TCP (6), length 116) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: P 4116463660:4116463724(64) ack 3104784591 win 351 <nop,nop,timestamp[|tcp]>
15:00:32.321353 IP (tos 0x10, ttl 63, id 35037, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116458188 win 965 <nop,nop,timestamp[|tcp]>
15:00:32.321363 IP (tos 0x10, ttl 64, id 60325, offset 0, flags [DF], proto TCP (6), length 4156) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116463724:4116467828(4104) ack 3104784591 win 351 <nop,nop,timestamp[|tcp]>
15:00:32.322482 IP (tos 0x10, ttl 63, id 35038, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116460924 win 997 <nop,nop,timestamp[|tcp]>
15:00:32.322488 IP (tos 0x10, ttl 64, id 60328, offset 0, flags [DF], proto TCP (6), length 4156) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116467828:4116471932(4104) ack 3104784591 win 351 <nop,nop,timestamp[|tcp]>
15:00:32.322598 IP (tos 0x10, ttl 63, id 35039, offset 0, flags [DF], proto TCP (6), length 64) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116460924 win 997 <nop,nop,timestamp[|tcp]>
15:00:32.323070 IP (tos 0x10, ttl 63, id 35040, offset 0, flags [DF], proto TCP (6), length 64) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116462292 win 976 <nop,nop,timestamp[|tcp]>
15:00:32.323785 IP (tos 0x10, ttl 63, id 35041, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116463724 win 970 <nop,nop,timestamp[|tcp]>
15:00:32.323794 IP (tos 0x10, ttl 64, id 60331, offset 0, flags [DF], proto TCP (6), length 5524) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116471932:4116477404(5472) ack 3104784591 win 351 <nop,nop,timestamp[|tcp]>
15:00:32.324041 IP (tos 0x10, ttl 63, id 35042, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116465092 win 997 <nop,nop,timestamp[|tcp]>
15:00:32.324064 IP (tos 0x10, ttl 64, id 60335, offset 0, flags [DF], proto TCP (6), length 2788) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116477404:4116480140(2736) ack 3104784591 win 351 <nop,nop,timestamp[|tcp]>
15:00:32.324568 IP (tos 0x10, ttl 63, id 35043, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116466460 win 997 <nop,nop,timestamp[|tcp]>
15:00:32.325436 IP (tos 0x10, ttl 63, id 35044, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116467828 win 997 <nop,nop,timestamp[|tcp]>
15:00:32.325716 IP (tos 0x10, ttl 63, id 35045, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116469196 win 997 <nop,nop,timestamp[|tcp]>
15:00:32.325724 IP (tos 0x10, ttl 64, id 60337, offset 0, flags [DF], proto TCP (6), length 8260) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116480140:4116488348(8208) ack 3104784591 win 351 <nop,nop,timestamp[|tcp]>
15:00:32.326280 IP (tos 0x10, ttl 63, id 35046, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116470564 win 997 <nop,nop,timestamp[|tcp]>
15:00:32.327006 IP (tos 0x10, ttl 63, id 35047, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116471932 win 997 <nop,nop,timestamp[|tcp]>
15:00:32.327095 IP (tos 0x10, ttl 63, id 35048, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116473300 win 997 <nop,nop,timestamp[|tcp]>
15:00:32.327103 IP (tos 0x10, ttl 64, id 60343, offset 0, flags [DF], proto TCP (6), length 8260) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116488348:4116496556(8208) ack 3104784591 win 351 <nop,nop,timestamp[|tcp]>
15:00:32.328115 IP (tos 0x10, ttl 63, id 35049, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116474668 win 997 <nop,nop,timestamp[|tcp]>
15:00:32.328139 IP (tos 0x10, ttl 64, id 60349, offset 0, flags [DF], proto TCP (6), length 1420) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116496556:4116497924(1368) ack 3104784591 win 351 <nop,nop,timestamp[|tcp]>
15:00:32.328802 IP (tos 0x10, ttl 63, id 35050, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116476036 win 997 <nop,nop,timestamp[|tcp]>
15:00:32.329167 IP (tos 0x10, ttl 63, id 35051, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116477404 win 997 <nop,nop,timestamp[|tcp]>
15:00:32.329888 IP (tos 0x10, ttl 63, id 35052, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116478772 win 997 <nop,nop,timestamp[|tcp]>
15:00:32.329992 IP (tos 0x10, ttl 63, id 35053, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116480140 win 997 <nop,nop,timestamp[|tcp]>
15:00:32.331117 IP (tos 0x10, ttl 63, id 35054, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116481508 win 997 <nop,nop,timestamp[|tcp]>
15:00:32.332802 IP (tos 0x10, ttl 63, id 35055, offset 0, flags [DF], proto TCP (6), length 52) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116485612 win 1002 <nop,nop,timestamp[|tcp]>
15:00:32.332811 IP (tos 0x10, ttl 64, id 60350, offset 0, flags [DF], proto TCP (6), length 10996) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116497924:4116508868(10944) ack 3104784591 win 351 <nop,nop,timestamp[|tcp]>
15:00:32.333954 IP (tos 0x10, ttl 63, id 35056, offset 0, flags [DF], proto TCP (6), length 180) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: P 3104784591:3104784719(128) ack 4116486980 win 1002 <nop,nop,timestamp[|tcp]>
15:00:32.334700 IP (tos 0x10, ttl 63, id 35057, offset 0, flags [DF], proto TCP (6), length 64) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116486980 win 1002 <nop,nop,timestamp[|tcp]>
15:00:32.335161 IP (tos 0x10, ttl 63, id 35058, offset 0, flags [DF], proto TCP (6), length 64) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116486980 win 1002 <nop,nop,timestamp[|tcp]>
15:00:32.335703 IP (tos 0x10, ttl 63, id 35059, offset 0, flags [DF], proto TCP (6), length 64) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116486980 win 1002 <nop,nop,timestamp[|tcp]>
15:00:32.336173 IP (tos 0x10, ttl 63, id 35060, offset 0, flags [DF], proto TCP (6), length 64) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116486980 win 1002 <nop,nop,timestamp[|tcp]>
15:00:32.336725 IP (tos 0x10, ttl 63, id 35061, offset 0, flags [DF], proto TCP (6), length 64) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116486980 win 1002 <nop,nop,timestamp[|tcp]>
15:00:32.337534 IP (tos 0x10, ttl 63, id 35062, offset 0, flags [DF], proto TCP (6), length 72) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116486980 win 1002 <nop,nop,timestamp[|tcp]>
15:00:32.338086 IP (tos 0x10, ttl 63, id 35063, offset 0, flags [DF], proto TCP (6), length 72) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116486980 win 1002 <nop,nop,timestamp[|tcp]>
15:00:32.338656 IP (tos 0x10, ttl 63, id 35064, offset 0, flags [DF], proto TCP (6), length 72) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116486980 win 1002 <nop,nop,timestamp[|tcp]>
15:00:32.338671 IP (tos 0x10, ttl 63, id 35065, offset 0, flags [DF], proto TCP (6), length 72) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116486980 win 1002 <nop,nop,timestamp[|tcp]>
15:00:32.340936 IP (tos 0x10, ttl 63, id 35066, offset 0, flags [DF], proto TCP (6), length 72) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116486980 win 1002 <nop,nop,timestamp[|tcp]>
15:00:32.340959 IP (tos 0x10, ttl 63, id 35067, offset 0, flags [DF], proto TCP (6), length 72) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116486980 win 1002 <nop,nop,timestamp[|tcp]>
15:00:32.373132 IP (tos 0x10, ttl 64, id 60358, offset 0, flags [DF], proto TCP (6), length 52) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . ack 3104784719 win 372 <nop,nop,timestamp[|tcp]>
15:00:32.541132 IP (tos 0x10, ttl 64, id 60359, offset 0, flags [DF], proto TCP (6), length 1420) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116486980:4116488348(1368) ack 3104784719 win 372 <nop,nop,timestamp[|tcp]>
15:00:32.543517 IP (tos 0x10, ttl 63, id 35068, offset 0, flags [DF], proto TCP (6), length 64) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116495188 win 874 <nop,nop,timestamp[|tcp]>
15:00:32.957127 IP (tos 0x10, ttl 64, id 60360, offset 0, flags [DF], proto TCP (6), length 1420) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116486980:4116488348(1368) ack 3104784719 win 372 <nop,nop,timestamp[|tcp]>
15:00:32.984538 IP (tos 0x10, ttl 63, id 35069, offset 0, flags [DF], proto TCP (6), length 72) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116495188 win 874 <nop,nop,timestamp[|tcp]>
15:00:33.789131 IP (tos 0x10, ttl 64, id 60361, offset 0, flags [DF], proto TCP (6), length 1420) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116486980:4116488348(1368) ack 3104784719 win 372 <nop,nop,timestamp[|tcp]>
15:00:33.803902 IP (tos 0x10, ttl 63, id 35070, offset 0, flags [DF], proto TCP (6), length 72) 128.189.212.241.46294 > spider.phas.ubc.ca.ssh: . ack 4116495188 win 874 <nop,nop,timestamp[|tcp]> 
15:00:35.453134 IP (tos 0x10, ttl 64, id 60362, offset 0, flags [DF], proto TCP (6), length 1420) spider.phas.ubc.ca.ssh > 128.189.212.241.46294: . 4116486980:4116488348(1368) ack 3104784719 win 372 <nop,nop,timestamp[|tcp]>

Carl

RE: ssh connections stalling

[Steven Kath]

> > Log the INVALID packets. Also, it'd be good if you could capture them
by
> > tcpdump (please use the -Sv options at least).
> >
> 
> just discovered that if ip_conntrack_tcp_be_liberal is set to 1, my
> problem also goes away.

If you set /proc/sys/net/netfilter/nf_conntrack_log_invalid to 1 and check
dmesg after some invalid packets are dropped, you might get some more
output about how the packets are judged invalid.  

Re: ssh connections stalling

[Carl Michal]

Eegads,

so logging the invalid packets (strangely setting 
ip_conntrack_log_invalid to 1 didn't actually produce the logs, I 
had to bypass the check for LOG_INVALID in nf_conntrack_proto_tcp.c 
and recompile...) gives:

Oct 23 23:35:00 spider nf_ct_tcp: ACK is over the upper bound (ACKed data not seen yet) IN= OUT= SRC=142.103.236.11 DST=142.103.235.177 LEN=52 TOS=0x00 PREC=0x00 TTL=64 ID=10722 DF PROTO=TCP SPT=44574 DPT=22 SEQ=3218503158 ACK=2892721343 WINDOW=24840 RES=0x00 ACK URGP=0 OPT (0101050ACCFD9D1FCCFDA283)
Oct 23 23:35:00 spider nf_ct_tcp: ACK is over the upper bound (ACKed data not seen yet) IN= OUT= SRC=142.103.236.11 DST=142.103.235.177 LEN=52 TOS=0x00 PREC=0x00 TTL=64 ID=10723 DF PROTO=TCP SPT=44574 DPT=22 SEQ=3218503158 ACK=2892721343 WINDOW=24840 RES=0x00 ACK URGP=0 OPT (0101050ACCFD9D1FCCFDA7E7)

but how can that be?  in the dumps posted earlier, the data had gone 
through?  Hadn't it?

Carl

Re: ssh connections stalling

[Payam Chychi]

On Fri, Oct 23, 2009 at 11:44 PM, Carl Michal <michal@physics.ubc.ca> wrote:
> Eegads,
>
> so logging the invalid packets (strangely setting ip_conntrack_log_invalid
> to 1 didn't actually produce the logs, I had to bypass the check for
> LOG_INVALID in nf_conntrack_proto_tcp.c and recompile...) gives:
>
> Oct 23 23:35:00 spider nf_ct_tcp: ACK is over the upper bound (ACKed data
> not seen yet) IN= OUT= SRC=142.103.236.11 DST=142.103.235.177 LEN=52
> TOS=0x00 PREC=0x00 TTL=64 ID=10722 DF PROTO=TCP SPT=44574 DPT=22
> SEQ=3218503158 ACK=2892721343 WINDOW=24840 RES=0x00 ACK URGP=0 OPT
> (0101050ACCFD9D1FCCFDA283)
> Oct 23 23:35:00 spider nf_ct_tcp: ACK is over the upper bound (ACKed data
> not seen yet) IN= OUT= SRC=142.103.236.11 DST=142.103.235.177 LEN=52
> TOS=0x00 PREC=0x00 TTL=64 ID=10723 DF PROTO=TCP SPT=44574 DPT=22
> SEQ=3218503158 ACK=2892721343 WINDOW=24840 RES=0x00 ACK URGP=0 OPT
> (0101050ACCFD9D1FCCFDA7E7)
>
> but how can that be?  in the dumps posted earlier, the data had gone
> through?  Hadn't it?
>
> Carl
>
>
> --
> To unsubscribe from this list: send the line "unsubscribe netfilter" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>

To be honest im not sure, i didnt have much time to review your entire
dump though i did see mass ack/push in the logs. I can spend some time
this weekend but it really sounds like your packets are going to the
wrong place/device or being dropped somewhere and thats why tcp is not
being very reliable.

have you tried looking at the network layer? look at your layer3 and
see if there are any packet loss on either end during the time where
ssh is breaking.
btw, UBC? nice ... I went to BCIT ;)
-- 
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

Re: ssh connections stalling

[Jozsef Kadlecsik]

On Fri, 23 Oct 2009, Carl Michal wrote:

> so logging the invalid packets (strangely setting 
> ip_conntrack_log_invalid to 1 didn't actually produce the logs, I had to 
> bypass the check for LOG_INVALID in nf_conntrack_proto_tcp.c and 
> recompile...) gives:
> 
> Oct 23 23:35:00 spider nf_ct_tcp: ACK is over the upper bound (ACKed data not
> seen yet) IN= OUT= SRC=142.103.236.11 DST=142.103.235.177 LEN=52 TOS=0x00
> PREC=0x00 TTL=64 ID=10722 DF PROTO=TCP SPT=44574 DPT=22 SEQ=3218503158
> ACK=2892721343 WINDOW=24840 RES=0x00 ACK URGP=0 OPT (0101050ACCFD9D1FCCFDA283)

The TCP options are:

No-Operation
No-Operation
SACK option(10): 3439172895:3439174275(1380) 

So it looks like SACK issue - you can verify it by disabling SACK support 
(/proc/sys/net/ipv4/tcp_sack, preferably at both sides) and running your 
original rule sets. Does the ssh connection still hang?

Best regards,
Jozsef
-
E-mail  : kadlec@blackhole.kfki.hu, kadlec@mail.kfki.hu
PGP key : http://www.kfki.hu/~kadlec/pgp_public_key.txt
Address : KFKI Research Institute for Particle and Nuclear Physics
          H-1525 Budapest 114, POB. 49, Hungary

Re: ssh connections stalling

[Carl Michal]

> So it looks like SACK issue - you can verify it by disabling SACK support
> (/proc/sys/net/ipv4/tcp_sack, preferably at both sides) and running your
> original rule sets. Does the ssh connection still hang?
>

Good call.  No hangs if SACK is disabled.

Carl

Re: ssh connections stalling

[Carl Michal]

> The TCP options are:
>
> No-Operation
> No-Operation
> SACK option(10): 3439172895:3439174275(1380)
>
> So it looks like SACK issue - you can verify it by disabling SACK support
> (/proc/sys/net/ipv4/tcp_sack, preferably at both sides) and running your
> original rule sets. Does the ssh connection still hang?
>

doing a better tcpdump shows packets like this:
21:00:14.553927 IP (tos 0x0, ttl 64, id 60074, offset 0, flags [DF], proto TCP (6), length 68) warp.phas.ubc.ca.45084 > spider.phas.ubc.ca.ssh: ., cksum 0x6227 (correct), 401537117:401537117(0) ack 2834113458 win 24840 <nop,nop,sack 3 {147619638:147629298}{147615498:147618258}{147607218:147612738}>

where the SACK numbers appear (to me) to be completely bogus.

It appears that I see a hang right at the first packet using SACK.

This is a very short path, just a single hop, tracepath shows:
  1:  142.103.235.177   0.039ms pmtu 1500
  1:  142.103.236.11    1.053ms reached
  1:  142.103.236.11    0.980ms reached
      Resume: pmtu 1500 hops 1 back 255

I can't capture the other end of that connection, but connecting to
another machine (several hops farther away) where I can capture both sides 
shows that somewhere along the way, the sequence numbers and ack values 
are being translated, but the sack numbers aren't.  This sounds like what 
is discussed here:

http://lkml.indiana.edu/hypermail/linux/kernel/0707.3/2402.html

and I'm 99% sure there is a Pix firewall in the building...

Thanks for the help!

Carl