On Mon, 7 Nov 2011 14:37:24 +0000, Paul Regan wrote:
New install of 3.1.16, FTP appears to be configured correctly but
hence the mail group post its not working as expected ..
Using ftp.emea.ibm.com as the test destination.
Active FTP from proxy server command line works fine.
Via a browser& squidclient
The following error was encountered while trying to retrieve the URL:
ftp://ftp.emea.ibm.com/
Read Error
The system returned: [No Error]
An error condition occurred while reading data from the network.
Please retry your request.
cache.log :
2011/11/07 12:45:20| ftpDataRead: read error: (107) Transport endpoint
is not connected
Wire capture :
12:45:20.395751 IP proxyserver.domain.60769> ftp.emea.ibm.com.ftp: S
2543509559:2543509559(0) win 5840<mss 1460,sackOK,timestamp 853154020
0,nop,wscale 7>
12:45:20.414004 IP ftp.emea.ibm.com.ftp> proxyserver.domain.60769: S
429684985:429684985(0) ack 2543509560 win 65535<mss 1380,nop,wscale
5>
12:45:20.414012 IP proxyserver.domain.60769> ftp.emea.ibm.com.ftp: .
ack 1 win 46
12:45:20.444260 IP ftp.emea.ibm.com.ftp> proxyserver.domain.60769: P
1:78(77) ack 1 win 16384
<snip>
Lots of packets on control channel. Looks normal. The handshake, login, file
location etc. happen about here.
12:45:20.608768 IP ftp.emea.ibm.com.ftp> proxyserver.domain.60769: P
ack 78 win 16384
12:45:20.818002 IP ftp.emea.ibm.com.ftp-data>
proxyserver.domain.36703: S 3997244124:3997244124(0) win 65535<mss
1380,nop,wscale 5>
Server connects in with a data connection. You configured ftp_passive OFF.
So this is expected.
12:45:20.818022 IP proxyserver.domain.36703>
ftp.emea.ibm.com.ftp-data: S 2004820984:2004820984(0) ack 3997244125
win 5840<mss 1460,nop,wscale 7>
12:45:20.835744 IP ftp.emea.ibm.com.ftp-data>
proxyserver.domain.36703: . ack 1 win 11520
12:45:20.835804 IP ftp.emea.ibm.com.ftp-data>
proxyserver.domain.36703: P 1:692(691) ack 1 win 11520
12:45:20.835809 IP proxyserver.domain.36703>
ftp.emea.ibm.com.ftp-data: . ack 692 win 57
12:45:20.835812 IP ftp.emea.ibm.com.ftp-data>
proxyserver.domain.36703: FP 692:692(0) ack 1 win 11520
FIN-ACK on data channel from server after 692 bytes transferred.
12:45:20.835899 IP ftp.emea.ibm.com.ftp> proxyserver.domain.60769: P
1108:1129(21) ack 78 win 16384
12:45:20.836193 IP proxyserver.domain.60769> ftp.emea.ibm.com.ftp: F
78:78(0) ack 1129 win 63
FIN on the control channel from Squid. Data file is received and connections
can close.
12:45:20.836210 IP proxyserver.domain.36703>
ftp.emea.ibm.com.ftp-data: R 1:1(0) ack 693 win 57
12:45:20.853549 IP ftp.emea.ibm.com.ftp> proxyserver.domain.60769: P
ack 79 win 16384
12:45:20.853576 IP ftp.emea.ibm.com.ftp> proxyserver.domain.60769: P
1129:1163(34) ack 79 win 16384
Server keeps throwing data at Squid down the control channel after FIN.
12:45:20.853586 IP proxyserver.domain.60769> ftp.emea.ibm.com.ftp: R
2543509638:2543509638(0) win 0
Squid responds to the extra data with RST.
12:45:20.853603 IP ftp.emea.ibm.com.ftp> proxyserver.domain.60769: FP
1163:1163(0) ack 79 win 16384
12:45:20.853606 IP proxyserver.domain.60769> ftp.emea.ibm.com.ftp: R
2543509638:2543509638(0) win 0
More packets from the server. More RST from Squid. Only 17.41 ms have
elapsed, so its within bounds of network lag.
Overall this looks like proper TCP closing sequence. Except that the data
channel is closed first. Before any messages on the control channel arrive
to inform Squid that the transfer is completed.
Can you report this with the above details in bugzilla please so this does
not get lost. I think we could work around it by checking the expected
object size on data closure and skip the error if they match.
Amos
