Timeout and segfault with trace

[Gagaro]

Hello,

I have a FTP server behind my router at home. The router and the server are configured to let FTP connections pass through. It works with Filezilla and the ftp command. But any command timeout with yafc.

I tried turning on the trace option but it segfaults :

Connecting to xxx.xxx.xxx.xxx at port 21...
Connected to xxx.xxx.xxx.xxx ([xxx.xxx.xxx.xxx]:21).
<-- [xxx.xxx.xxx.xxx] 220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------
<-- [xxx.xxx.xxx.xxx] 220-You are user number 2 of 50 allowed.
<-- [xxx.xxx.xxx.xxx] 220-Local time is now 16:11. Server port: 21.
<-- [xxx.xxx.xxx.xxx] 220-This is a private system - No anonymous login
<-- [xxx.xxx.xxx.xxx] 220-IPv6 connections are also welcome on this server.
<-- [xxx.xxx.xxx.xxx] 220 You will be disconnected after 15 minutes of inactivity.
remote address: xxx.xxx.xxx.xxx
local address: xxx.xxx.xxx.xxx
*** Using plaintext username and password ***
--> [xxx.xxx.xxx.xxx] USER partagezsh: segmentation fault  yafc xxx.xxx.xxx.xxx

My yafc version is: yafc 1.2.4 (x86_64-pc-linux-gnu)

Thanks for your help.

[Gagaro]

It doesn't segfault with the compiled version from the git, but it still doesn't work.

Some commands actually works (pwd). It seems to be the PASV request which fails.

[sebastinas]

On 2013-04-27 07:44:28, Gagaro wrote:

It doesn't segfault with the compiled version from the git, but it still doesn't work.

If you can produce a trace with the version from git, it would be great if you can share it. Maybe it helps to see what's going wrong.

[Gagaro]

Here is the trace:

yafc 1.2.4 trace file started Sat Apr 27 16:56:49 2013

Looking up xxx.xxx.xxx.xxx... 
Connecting to xxx.xxx.xxx.xxx at port 21...
Connected to xxx.xxx.xxx.xxx ([xxx.xxx.xxx.xxx]:21).
<-- [xxx.xxx.xxx.xxx] 220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------
<-- [xxx.xxx.xxx.xxx] 220-You are user number 2 of 50 allowed.
<-- [xxx.xxx.xxx.xxx] 220-Local time is now 16:45. Server port: 21.
<-- [xxx.xxx.xxx.xxx] 220-This is a private system - No anonymous login
<-- [xxx.xxx.xxx.xxx] 220-IPv6 connections are also welcome on this server.
<-- [xxx.xxx.xxx.xxx] 220 You will be disconnected after 15 minutes of inactivity.
remote address: xxx.xxx.xxx.xxx
local address: xxx.xxx.xxx.xxx
*** Using plaintext username and password ***
--> [xxx.xxx.xxx.xxx] USER `]d
<-- [xxx.xxx.xxx.xxx] 331 User partage OK. Password required
--> [xxx.xxx.xxx.xxx] PASS ********
<-- [xxx.xxx.xxx.xxx] 230-User partage has group access to:  partage   
<-- [xxx.xxx.xxx.xxx] 230 OK. Current directory is /
--> [xxx.xxx.xxx.xxx] PWD
<-- [xxx.xxx.xxx.xxx] 257 "/" is your current location
--> [xxx.xxx.xxx.xxx] SYST
<-- [xxx.xxx.xxx.xxx] 215 UNIX Type: L8
yafc: 'ls'
--> [xxx.xxx.xxx.xxx] PASV
Tired of waiting for reply, timeout after 42 seconds
Closing down connection...
jumping to gvRestartJmp
Closing down connection...

More information on the server: it's a pure-ftpd launch with the following options: pure-ftpd -l puredb:/etc/pure-ftpd/pureftpd.pdb -8 UTF-8 -E -p 52000:53000 -u 1000 -d -O clf:/var/log/pure-ftpd/transfer.log -B

The following ports are forwarding: 21-22 and 51000-52000.

After looking at the server log, it seems to receive the request. I don't know why yafc doesn't have the answer. I'll make a few test and post the server logs to see the difference.

[sebastinas]

On 2013-04-27 08:02:30, Gagaro wrote:

Here is the trace:

Thank you.

More information on the server: it's a pure-ftpd launch with the following options: pure-ftpd -l puredb:/etc/pure-ftpd/pureftpd.pdb -8 UTF-8 -E -p 52000:53000 -u 1000 -d -O clf:/var/log/pure-ftpd/transfer.log -B

The following ports are forwarding: 21-22 and 51000-52000.

It probably doesn't matter, but did you mean 52000-53000 here?

After looking at the server log, it seems to receive the request. I don't know why yafc doesn't have the answer. I'll make a few test and post the server logs to see the difference.

Could you maybe run something like wireshark on both the client and server and check which packages come through, i.e. if the reply from the server makes it to the client.

[sebastinas]

Sorry for the weird formating. That happens if one tries to reply by mail.

[Gagaro]

Yes sorry I meant 52000-53000. I have some network issues with the server at the moment, but I'll check everything as soon as I will have correct these.

[Gagaro]

I did some more testing.

The timeout happens after yafc sends PASV. The server answers but yafc seems to ignore it. The server resends the response several times until yafc timeout.

Here is a tcpdump of a connection to the server with a ls command just after the authentication:

11:18:57.722003 IP SOURCE_IP.56711 > DEST_IP.21: Flags [S], seq 1762946027, win 14600, options [mss 1460,sackOK,TS val 952864245 ecr 0,nop,wscale 7], length 0
E..<..@.@.+.^...Y.v.....i.k.......9.)..........
8...........
11:18:57.755110 IP DEST_IP.21 > SOURCE_IP.56711: Flags [S.], seq 2493056351, ack 1762946028, win 5792, options [mss 1460,sackOK,TS val 1318075 ecr 952864245,nop,wscale 6], length 0
E..<..@.7...Y.v.^.........._i.k......>.........
....8.......
11:18:57.755140 IP SOURCE_IP.56711 > DEST_IP.21: Flags [.], ack 1, win 115, options [nop,nop,TS val 952864254 ecr 1318075], length 0
E..4..@.@.+.^...Y.v.....i.k....`...s)......
8.......
11:18:57.815386 IP DEST_IP.21 > SOURCE_IP.56711: Flags [P.], seq 1:321, ack 1, win 91, options [nop,nop,TS val 1318091 ecr 952864254], length 320
E..t..@.7...Y.v.^..........`i.k....[.......
....8...220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------
220-You are user number 2 of 50 allowed.
220-Local time is now 11:07. Server port: 21.
220-This is a private system - No anonymous login
220-IPv6 connections are also welcome on this server.
220 You will be disconnected after 15 minutes of inactivity.

11:18:57.815539 IP SOURCE_IP.56711 > DEST_IP.21: Flags [.], ack 321, win 123, options [nop,nop,TS val 952864269 ecr 1318091], length 0
E..4. @.@.+.^...Y.v.....i.k........{)......
8..
....
11:18:57.815614 IP SOURCE_IP.56711 > DEST_IP.21: Flags [P.], seq 1:15, ack 321, win 123, options [nop,nop,TS val 952864269 ecr 1318091], length 14
E..B.!@.@.+.^...Y.v.....i.k........{)!.....
8..
....USER user

11:18:57.851001 IP DEST_IP.21 > SOURCE_IP.56711: Flags [.], ack 15, win 91, options [nop,nop,TS val 1318098 ecr 952864269], length 0
E..4..@.7..4Y.v.^...........i.k....[.......
....8..
11:18:57.851019 IP DEST_IP.21 > SOURCE_IP.56711: Flags [P.], seq 321:361, ack 15, win 91, options [nop,nop,TS val 1318098 ecr 952864269], length 40
E..\..@.7...Y.v.^...........i.k....[.......
....8..
331 User user OK. Password required

11:18:57.906089 IP SOURCE_IP.56711 > DEST_IP.21: Flags [.], ack 361, win 123, options [nop,nop,TS val 952864292 ecr 1318098], length 0
E..4."@.@.+.^...Y.v.....i.k........{)......
8..$....
11:19:03.546767 IP SOURCE_IP.56711 > DEST_IP.21: Flags [P.], seq 15:46, ack 361, win 123, options [nop,nop,TS val 952865702 ecr 1318098], length 31
E..S.#@.@.+.^...Y.v.....i.k........{)2.....
8.......PASS password

11:19:03.582394 IP DEST_IP.21 > SOURCE_IP.56711: Flags [P.], seq 361:444, ack 46, win 91, options [nop,nop,TS val 1319532 ecr 952865702], length 83
E.....@.7...Y.v.^...........i.l....[.......
.."l8...230-User user has group access to:  user   
230 OK. Current directory is /

11:19:03.582488 IP SOURCE_IP.56711 > DEST_IP.21: Flags [.], ack 444, win 123, options [nop,nop,TS val 952865711 ecr 1319532], length 0
E..4.$@.@.+.^...Y.v.....i.l........{)......
8....."l
11:19:03.582521 IP SOURCE_IP.56711 > DEST_IP.21: Flags [P.], seq 46:51, ack 444, win 123, options [nop,nop,TS val 952865711 ecr 1319532], length 5
E..9.%@.@.+.^...Y.v.....i.l........{)......
8....."lPWD

11:19:03.613868 IP DEST_IP.21 > SOURCE_IP.56711: Flags [P.], seq 444:478, ack 51, win 91, options [nop,nop,TS val 1319540 ecr 952865711], length 34
E..V..@.7...Y.v.^...........i.l....[.t.....
.."t8...257 "/" is your current location

11:19:03.613997 IP SOURCE_IP.56711 > DEST_IP.21: Flags [P.], seq 51:57, ack 478, win 123, options [nop,nop,TS val 952865718 ecr 1319540], length 6
E..:.&@.@.+.^...Y.v.....i.l....=...{)......
8....."tSYST

11:19:03.644080 IP DEST_IP.21 > SOURCE_IP.56711: Flags [P.], seq 478:497, ack 57, win 91, options [nop,nop,TS val 1319548 ecr 952865718], length 19
E..G..@.7...Y.v.^..........=i.l$...[.L.....
.."|8...215 UNIX Type: L8

11:19:03.698100 IP SOURCE_IP.56711 > DEST_IP.21: Flags [.], ack 497, win 123, options [nop,nop,TS val 952865740 ecr 1319548], length 0
E..4.'@.@.+.^...Y.v.....i.l$...P...{)......
8....."|
11:19:05.004031 IP SOURCE_IP.56711 > DEST_IP.21: Flags [P.], seq 57:63, ack 497, win 123, options [nop,nop,TS val 952866066 ecr 1319548], length 6
E..:.(@.@.+.^...Y.v.....i.l$...P...{)......
8....."|PASV

11:19:05.033781 IP DEST_IP.21 > SOURCE_IP.56711: Flags [P.], seq 497:546, ack 63, win 91, options [nop,nop,TS val 1319895 ecr 952866066], length 49
E..e..@.7...Y.v.^..........Pi.l*...[|b.....
..#.8...227 Entering Passive Mode (xxx,xxx,xxx,xxx,204,13)

11:19:05.279371 IP DEST_IP.21 > SOURCE_IP.56711: Flags [P.], seq 497:546, ack 63, win 91, options [nop,nop,TS val 1319956 ecr 952866066], length 49
E..e..@.7...Y.v.^..........Pi.l*...[|%.....
..$.8...227 Entering Passive Mode (xxx,xxx,xxx,xxx,204,13)

11:19:05.382103 IP SOURCE_IP.56711 > DEST_IP.21: Flags [P.], seq 57:63, ack 497, win 123, options [nop,nop,TS val 952866161 ecr 1319548], length 6
E..:.)@.@.+.^...Y.v.....i.l$...P...{)......
8..q.."|PASV

11:19:05.417260 IP DEST_IP.21 > SOURCE_IP.56711: Flags [.], ack 63, win 91, options [nop,nop,TS val 1319991 ecr 952866161,nop,nop,sack 1 {57:63}], length 0
E..@..@.7..!Y.v.^...........i.l*...[+i.....
..$78..q...
i.l$i.l*
11:19:05.771224 IP DEST_IP.21 > SOURCE_IP.56711: Flags [P.], seq 497:546, ack 63, win 91, options [nop,nop,TS val 1320078 ecr 952866161], length 49
E..e..@.7...Y.v.^..........Pi.l*...[{L.....
..$.8..q227 Entering Passive Mode (xxx,xxx,xxx,xxx,204,13)

11:19:06.739925 IP DEST_IP.21 > SOURCE_IP.56711: Flags [P.], seq 497:546, ack 63, win 91, options [nop,nop,TS val 1320322 ecr 952866161], length 49
E..e..@.7...Y.v.^..........Pi.l*...[zX.....
..%.8..q227 Entering Passive Mode (xxx,xxx,xxx,xxx,204,13)

11:19:08.690373 IP DEST_IP.21 > SOURCE_IP.56711: Flags [P.], seq 497:546, ack 63, win 91, options [nop,nop,TS val 1320810 ecr 952866161], length 49
E..e..@.7...Y.v.^..........Pi.l*...[xp.....
..'j8..q227 Entering Passive Mode (xxx,xxx,xxx,xxx,204,13)

11:19:12.593414 IP DEST_IP.21 > SOURCE_IP.56711: Flags [P.], seq 497:546, ack 63, win 91, options [nop,nop,TS val 1321786 ecr 952866161], length 49
E..e..@.7...Y.v.^..........Pi.l*...[t......
..+:8..q227 Entering Passive Mode (xxx,xxx,xxx,xxx,204,13)

11:19:20.408638 IP DEST_IP.21 > SOURCE_IP.56711: Flags [P.], seq 497:546, ack 63, win 91, options [nop,nop,TS val 1323738 ecr 952866161], length 49
E..e..@.7...Y.v.^..........Pi.l*...[m......
..2.8..q227 Entering Passive Mode (xxx,xxx,xxx,xxx,204,13)

11:19:36.020725 IP DEST_IP.21 > SOURCE_IP.56711: Flags [P.], seq 497:546, ack 63, win 91, options [nop,nop,TS val 1327642 ecr 952866161], length 49
E..e..@.7...Y.v.^..........Pi.l*...[]......
..B.8..q227 Entering Passive Mode (xxx,xxx,xxx,xxx,204,13)

11:19:47.004163 IP SOURCE_IP.56711 > DEST_IP.21: Flags [F.], seq 63, ack 497, win 123, options [nop,nop,TS val 952876566 ecr 1319548], length 0
E..4.*@.@.+.^...Y.v.....i.l*...P...{)......
8....."|
11:19:47.034574 IP DEST_IP.21 > SOURCE_IP.56711: Flags [FP.], seq 546:559, ack 64, win 91, options [nop,nop,TS val 1330395 ecr 952876566], length 13
E..A..@.7...Y.v.^...........i.l+...[.......
..L.8...227 Logout.

11:19:47.034606 IP SOURCE_IP.56711 > DEST_IP.21: Flags [R], seq 1762946091, win 0, length 0
E..(..@.@...^...Y.v.....i.l+....P.......

The ftp command does not send a PASV. But Filezilla does it and handle it correctly.

[sebastinas]

Right now I'm a bit clueless. The retransmits look suspicious and I can't explain them at the moment. May I ask on which platform the client and the server are running?

[Gagaro]

Client: debian 7.0 64bits Server: debian 6.0.7 64bits

2013/4/28 Sebastian Ramacher notifications@github.com

Right now I'm a bit clueless. The retransmits look suspicious and I can't explain them at the moment. May I ask on which platform the client and the server are running?

— Reply to this email directly or view it on GitHubhttps://github.com/sebastinas/yafc/issues/30#issuecomment-17131995 .

Gagaro

[sebastinas]

Thank you.

I've pushed some changes adding more debug output to master. Could you produce a new trace file with those changes? Maybe this will help to

pinpoint the location yafc hangs.

Sebastian Ramacher

[Gagaro]

The only difference is in there:

Initializing passive connection.
--> [xxx.xxx.xxx.xxx] PASV
Tired of waiting for reply, timeout after 42 seconds
Closing down connection...
jumping to gvRestartJmp
Closing down connection...

[sebastinas]

I'm sorry for getting back to you somewhat late.

On 2013-04-28 04:58:31, Gagaro wrote:

The only difference is in there:

Initializing passive connection.
--> [xxx.xxx.xxx.xxx] PASV
Tired of waiting for reply, timeout after 42 seconds
Closing down connection...
jumping to gvRestartJmp
Closing down connection...

Okay, that didn't help. Could you create a trace with strace?

[TheJosh]

Or can you provide (using private means) the public IP address of the server?

[Gagaro]

Where can I send you the information ?

[sebastinas]

You can send it to sebastian@ramacher.at and if you want to encrypt the mail, my gpg key id is 6EA71993 [1].

[1] http://db.debian.org/fetchkey.cgi?fingerprint=F78CBA07817BB149A11D339069F2FC516EA71993

[sebastinas]

The segfault in trace is fixed by 05d22387c4688180324f99edcb94ce7463a6c9bf and the timeout was due to network issues. So I'm closing the bug now.

[Gagaro]

Sorry not to keep you updated but I still couldn't test the solution we talked about. For information, the problem would be because of a Netgear router not letting packet go through if external IP of the router and local IP of the ftp server are not the same length.