Re: [squid-users] 3.1.16 FTP problems ..

 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
Received on Mon Nov 07 2011 - 22:37:08 MST