Frame Relay & tail -f hanging
Hello,
(Sent to debian-isp mailing list and CCed to Sangoma, the frame relay
card suppliers and wanpipe authors, in case they have any ideas.)
I have to computers connected via Frame Relay, one in Melbourne with
192.168.100.129 IP address, and one at Auckland with 192.168.100.130
IP address.
Both systems use wanpipe for frame relay, the Melbourne site
is wanpipe 2.3.0-1 Linux 2.4.21, the Auckland is 2.2.5-1 with Linux 2.4.20.
If I ssh from the melbourne site directly to the auckland site and type
in "tail -f /var/log/messages" the ssh connection hangs, and Ctrl+C, Ctrl+Q,
and nothing else works. The only option I have is to kill the ssh connection
with "\n~.\n". If I leave the connection, eventually it times out.
The computer where the ssh session originates on doesn't seem to be
a problem. I haven't tried connecting in the other direction either,
because it is more convenient connecting in this direction.
Standard shorewall firewalls are used on both ends, but I really doubt
this would be an issue. Firewalls can't filter packets based on the
encrypted data transferred via a ssh connection...
This only happens if I go over the frame relay connection, and only
occurs with the frame relay end point. If I ssh via frame relay to any
other system, I do not get any problems.
Example:
--- cut ---
melbourne1:~# ssh 192.168.100.130
root@192.168.100.130's password:
Last login: Fri Aug 1 17:58:08 2003 from melbourne2.melb.local on pts/1
Linux auckland2 2.4.20-686 #1 Sat May 3 12:21:27 EST 2003 i686 unknown
Most of the programs included with the Debian GNU/Linux system are
freely redistributable; the exact distribution terms for each program
are described in the individual files in /usr/share/doc/*/copyright
Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
Last login: Fri Aug 1 17:58:08 2003 from melbourne2.melb.local
auckland2:~# tail -f /var/log/messages
Aug 1 17:03:29 auckland2 kernel: Shorewall:loc2all:REJECT:IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:09:6b:84:57:d6:08:00 SRC=192.168.2.106 DST=192.168.2.255 LEN=118 TOS=0x00 PREC=0x00 TTL=1 ID=8976 PROTO=UDP SPT=1661 DPT=42508 LEN=98
Aug 1 17:03:29 auckland2 kernel: Shorewall:loc2all:REJECT:IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:09:6b:b4:09:62:08:00 SRC=192.168.2.105 DST=192.168.2.255 LEN=246 TOS=0x00 PREC=0x00 TTL=1 ID=24398 PROTO=UDP SPT=4327 DPT=42508 LEN=226
Aug 1 17:03:29 auckland2 kernel: Shorewall:loc2all:REJECT:IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:09:6b:84:57:d6:08:00 SRC=192.168.2.106 DST=192.168.2.255 LEN=246 TOS=0x00 PREC=0x00 TTL=1 ID=8977 PROTO=UDP SPT=1661 DPT=42508 LEN=226
Aug 1 17:03:29 auckland2 kernel: Shorewall:loc2all:REJECT:IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:09:6b:b4:09:62:08:00 SRC=192.168.2.105 DST=192.168.2.255 LEN=220 TOS=0x00 PREC=0x00 TTL=1 ID=24399 PROTO=UDP SPT=4327 DPT=42508 LEN=200
Aug 1 17:03:29 auckland2 kernel: Shorewall:loc2all:REJECT:IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:09:6b:84:57:d6:08:00 SRC=192.168.2.106 DST=192.168.2.255 LEN=220 TOS=0x00 PREC=0x00 TTL=1 ID=8978 PROTO=UDP SPT=1661 DPT=42508 LEN=200
Aug 1 17:03:29 auckland2 kernel: Shorewall:loc2all:REJECT:IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:09:6b:b4:08:95:08:00 SRC=192.168.2.109 DST=192.168.2.255 LEN=118 TOS=0x00 PREC=0x00 TTL=1 ID=42220 PROTO=UDP SPT=1869 DPT=42508 LEN=98
Aug 1 17:03:29 auckland2 kernel: Shorewall:loc2all:REJECT:IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:09:6b:b4:08:95:08:00 SRC=192.168.2.109 DST=192.168.2.255 LEN=246 TOS=0x00 PREC=0x00 TTL=1 ID=42221 PROTO=UDP SPT=1869 DPT=42508 LEN=226
Aug 1 17:03:29 auckland2 kernel: Shorewall:loc2all:REJECT:IN=eth0 OUT= MAC=ff:ff:ff:ff:ff:ff:00:09:6b:b4:08:95:08:00 SRC=192.168.2.109 DST=192.168.2.255 LEN=220 TOS=0x00 PREC=0x00 TTL=1 ID=42222 PROTO=UDP SPT=1869 DPT=42508 LEN=200
Aug 1 17:20:17 auckland2 -- MARK --
Aug 1 17:40:17 auckland2 -- MARK --
auckland2:~#
auckland2:~# tail -f /var/log/messages
[hangs]
--- cut ---
At time of crash, on other sessions (not using frame relay) (only relevent
entry shown):
--- cut ---
melbourne1:~# netstat --tcp -n | grep 22
tcp 0 0 192.168.100.129:1050 192.168.100.130:22 ESTABLISHED
... (after several minutes) ...
melbourne1:~# tcpdump -i wp2mfr16
[...push some keys on ssh window...]
18:24:42.121895 192.168.100.129.1050 > 192.168.100.130.ssh: P 96:144(48) ack 1 win 15184 <nop,nop,timestamp 17478291 391559765,nop,nop,sack sack 1 {1449:2001} > (DF) [tos 0x10]
18:24:42.219225 192.168.100.130.ssh > 192.168.100.129.1050: . ack 144 win 9648 <nop,nop,timestamp 391639921 17478291> (DF) [tos 0x10]
18:24:42.425822 192.168.100.129.1050 > 192.168.100.130.ssh: P 144:192(48) ack 1 win 15184 <nop,nop,timestamp 17478321 391559765,nop,nop,sack sack 1 {1449:2001} > (DF) [tos 0x10]
18:24:42.519032 192.168.100.130.ssh > 192.168.100.129.1050: . ack 192 win 9648 <nop,nop,timestamp 391639951 17478321> (DF) [tos 0x10]
18:24:42.561729 192.168.100.129.1050 > 192.168.100.130.ssh: P 192:240(48) ack 1 win 15184 <nop,nop,timestamp 17478335 391559765,nop,nop,sack sack 1 {1449:2001} > (DF) [tos 0x10]
18:24:42.659667 192.168.100.130.ssh > 192.168.100.129.1050: . ack 240 win 9648 <nop,nop,timestamp 391639965 17478335> (DF) [tos 0x10]
18:24:42.745802 192.168.100.129.1050 > 192.168.100.130.ssh: P 240:288(48) ack 1 win 15184 <nop,nop,timestamp 17478353 391559765,nop,nop,sack sack 1 {1449:2001} > (DF) [tos 0x10]
18:24:42.839342 192.168.100.130.ssh > 192.168.100.129.1050: . ack 288 win 9648 <nop,nop,timestamp 391639983 17478353> (DF) [tos 0x10]
[...nothing seems terribly abnormal here...]
--- cut ---
--- cut ---
auckland2:~# netstat --tcp -n | grep 22
tcp 0 2048 192.168.100.130:22 192.168.100.129:1050 ESTABLISHED
... (after several minutes) ...
auckland2:~# netstat --tcp -n | grep 22
tcp 0 2128 192.168.100.130:22 192.168.100.129:1050 ESTABLISHED
... (after several minutes) ...
auckland2:~# netstat --tcp -n | grep 22
tcp 0 7904 192.168.100.130:22 192.168.100.129:1050 ESTABLISHED
... (after several minutes) ...
auckland2:~# netstat --tcp -n | grep 22
tcp 0 7904 192.168.100.130:22 192.168.100.129:1050 ESTABLISHED
... (after tcpdump, above. nothing has changed????? if data was sent, why
hasn't the queue changed????) ...
auckland2:~# netstat --tcp -n | grep 22
tcp 0 7904 192.168.100.130:22 192.168.100.129:1050 ESTABLISHED
--- cut ---
This was incredibly weird, because the first time it worked, I have not
seen tail work the first time before. The reason it worked here could easily
be because the last line in the log file was a "MARK" line, and when
I tried again latter another "REJECT line had appeared[2].
If I were to redirect the output of tail to a file, then no hang
occurs. If I don't go via frame relay, then no hang occurs.
It seems to vary slightly depending on the data in the file, but have
yet to find a consistant pattern.
I cannot even come up with a theory as to what is going on, if the problem
was frame relay, I can't see how frame relay could be responding differently
to the encrypted data ssh is sending.
Any ideas? Any thoeries? Is the frame relay haunted?
I am not CCed to debian-isp, so please CC responses to me, thanks[1]. I plan
to fix this ASAP.
Note:
[1] Mail-Followups-To header should be set correctly.
[2] I didn't say that this would be any sort of sense...
--
Brian May <bam@snoopy.apana.org.au>
Reply to: