Re: [squid-users] FTP: Error NLST Unable to build data connection: Invalid argument

From: David Touzeau <david_at_touzeau.eu>
Date: Mon, 13 Sep 2010 21:48:43 +0200

Dear

Here it is the complete debug sequence, but i don't know why NLST is
blocked
The first protocol discuss is ok but when squid want to send NLST, the
error is performed.

010/09/13 21:39:36.925| ftp.cc(1728) ftpParseControlReply:
2010/09/13 21:39:36.925| ftp.cc(1741) ftpParseControlReply: usable = 74
2010/09/13 21:39:36.925| ftp.cc(1749) ftpParseControlReply: 75 bytes to
play with
2010/09/13 21:39:36.925| ftp.cc(1758) ftpParseControlReply: s = {331
Anonymous login ok, send your complete email address as your password
}
2010/09/13 21:39:36.925| ftp>> 331 Anonymous login ok, send your
complete email address as your password
2010/09/13 21:39:36.925| ftp.cc(1938) handleControlReply: state=1, code=331
2010/09/13 21:39:36.925| ftp.cc(2075) ftpReadUser:
2010/09/13 21:39:36.925| ftp<< PASS david_at_touzeau.eu

2010/09/13 21:39:36.925| The AsyncCall
FtpStateData::ftpWriteCommandCallback constructed, this=0x845bd30
[call22716]
2010/09/13 21:39:36.925| comm_write: FD 24: sz 23: asynCall 0x845bd30*1
2010/09/13 21:39:36.925| ftp.cc(1811) scheduleReadControlReply: FD 24
2010/09/13 21:39:36.925| The AsyncCall FtpStateData::ftpReadControlReply
constructed, this=0x8458278 [call22717]
2010/09/13 21:39:36.925| comm_read, queueing read for FD 24; asynCall
0x8458278*1
2010/09/13 21:39:36.925| The AsyncCall FtpStateData::ftpTimeout
constructed, this=0x8458118 [call22718]
2010/09/13 21:39:36.925| comm.cc(1206) commSetTimeout: FD 24 timeout 900
2010/09/13 21:39:36.925| FtpStateData status out: [ job2955]
2010/09/13 21:39:36.925| leaving FtpStateData::ftpReadControlReply(FD
24, data=0x8453f70, size=75, buf=0x8712a18)
2010/09/13 21:39:36.925| commHandleWrite: FD 24: off 0, sz 23.
2010/09/13 21:39:36.925| commHandleWrite: write() returns 23
2010/09/13 21:39:36.925| commio_finish_callback: called for FD 24 (0, 0)
2010/09/13 21:39:36.925| comm.cc(165) will call
FtpStateData::ftpWriteCommandCallback(FD 24, data=0x8453f70, size=23,
buf=0x84f4ef0) [call22716]
2010/09/13 21:39:36.925| entering
FtpStateData::ftpWriteCommandCallback(FD 24, data=0x8453f70, size=23,
buf=0x84f4ef0)
2010/09/13 21:39:36.925| AsyncCall.cc(32) make: make call
FtpStateData::ftpWriteCommandCallback [call22716]
2010/09/13 21:39:36.925| FtpStateData status in: [ job2955]
2010/09/13 21:39:36.925| ftpWriteCommandCallback: wrote 23 bytes
2010/09/13 21:39:36.925| FtpStateData status out: [ job2955]
2010/09/13 21:39:36.925| leaving
FtpStateData::ftpWriteCommandCallback(FD 24, data=0x8453f70, size=23,
buf=0x84f4ef0)
2010/09/13 21:39:37.061| comm_read_try: FD 24, size 4096, retval 6, errno 0
2010/09/13 21:39:37.061| commio_finish_callback: called for FD 24 (0, 0)
2010/09/13 21:39:37.061| comm.cc(165) will call
FtpStateData::ftpReadControlReply(FD 24, data=0x8453f70, size=6,
buf=0x8712a18) [call22717]
2010/09/13 21:39:37.061| entering FtpStateData::ftpReadControlReply(FD
24, data=0x8453f70, size=6, buf=0x8712a18)
2010/09/13 21:39:37.061| AsyncCall.cc(32) make: make call
FtpStateData::ftpReadControlReply [call22717]

2010/09/13 21:39:37.061| FtpStateData status in: [ job2955]
2010/09/13 21:39:37.061| ftpReadControlReply: FD 24, Read 6 bytes
2010/09/13 21:39:37.061| ftp.cc(1728) ftpParseControlReply:
2010/09/13 21:39:37.061| ftp.cc(1741) ftpParseControlReply: usable = 5
2010/09/13 21:39:37.061| ftp.cc(1749) ftpParseControlReply: 6 bytes to
play with
2010/09/13 21:39:37.061| ftp.cc(1758) ftpParseControlReply: s = {230-
}
2010/09/13 21:39:37.061| ftp>> -1
2010/09/13 21:39:37.061| ftp.cc(1811) scheduleReadControlReply: FD 24
2010/09/13 21:39:37.061| The AsyncCall FtpStateData::ftpReadControlReply
constructed, this=0x8458220 [call22719]
2010/09/13 21:39:37.061| comm_read, queueing read for FD 24; asynCall
0x8458220*1
2010/09/13 21:39:37.061| The AsyncCall FtpStateData::ftpTimeout
constructed, this=0x84f4ea0 [call22720]
2010/09/13 21:39:37.061| comm.cc(1206) commSetTimeout: FD 24 timeout 900
2010/09/13 21:39:37.061| FtpStateData status out: [ job2955]
2010/09/13 21:39:37.061| leaving FtpStateData::ftpReadControlReply(FD
24, data=0x8453f70, size=6, buf=0x8712a18)
2010/09/13 21:39:37.155| comm_read_try: FD 24, size 4090, retval 325,
errno 0
2010/09/13 21:39:37.155| commio_finish_callback: called for FD 24 (0, 0)
2010/09/13 21:39:37.155| comm.cc(165) will call
FtpStateData::ftpReadControlReply(FD 24, data=0x8453f70, size=325,
buf=0x8712a1e) [call22719]
2010/09/13 21:39:37.155| entering FtpStateData::ftpReadControlReply(FD
24, data=0x8453f70, size=325, buf=0x8712a1e)
2010/09/13 21:39:37.155| AsyncCall.cc(32) make: make call
FtpStateData::ftpReadControlReply [call22719]
2010/09/13 21:39:37.155| FtpStateData status in: [ job2955]
2010/09/13 21:39:37.155| ftpReadControlReply: FD 24, Read 325 bytes
2010/09/13 21:39:37.155| ftp.cc(1728) ftpParseControlReply:
2010/09/13 21:39:37.155| ftp.cc(1741) ftpParseControlReply: usable = 330
2010/09/13 21:39:37.155| ftp.cc(1749) ftpParseControlReply: 331 bytes to
play with
2010/09/13 21:39:37.155| ftp.cc(1758) ftpParseControlReply: s = {230-
                 *** Welcome to this anonymous ftp server! ***

      You are user 3 out of a maximum of 400 authorized anonymous logins.
      The current time here is Mon Sep 13 21:39:23 2010.
      If you experience any problems here, contact : ftpmaster_at_univ-tlse1.fr

230 Anonymous login ok, restrictions apply.
}
2010/09/13 21:39:37.155| ftp>> -1
2010/09/13 21:39:37.155| ftp.cc(1758) ftpParseControlReply: s = {
          *** Welcome to this anonymous ftp server! ***

      You are user 3 out of a maximum of 400 authorized anonymous logins.
      The current time here is Mon Sep 13 21:39:23 2010.
      If you experience any problems here, contact : ftpmaster_at_univ-tlse1.fr

230 Anonymous login ok, restrictions apply.
}
2010/09/13 21:39:37.155| ftp>> -1 *** Welcome to this
anonymous ftp server! ***
2010/09/13 21:39:37.155| ftp.cc(1758) ftpParseControlReply: s = {
      You are user 3 out of a maximum of 400 authorized anonymous logins.
      The current time here is Mon Sep 13 21:39:23 2010.
      If you experience any problems here, contact : ftpmaster_at_univ-tlse1.fr

230 Anonymous login ok, restrictions apply.
}
2010/09/13 21:39:37.155| ftp>> -1
2010/09/13 21:39:37.155| ftp.cc(1758) ftpParseControlReply: s = {
You are user 3 out of a maximum of 400 authorized anonymous logins.
      The current time here is Mon Sep 13 21:39:23 2010.
      If you experience any problems here, contact : ftpmaster_at_univ-tlse1.fr

230 Anonymous login ok, restrictions apply.
}
2010/09/13 21:39:37.155| ftp>> -1 You are user 3 out of a maximum
of 400 authorized anonymous logins.
2010/09/13 21:39:37.155| ftp.cc(1758) ftpParseControlReply: s = {
The current time here is Mon Sep 13 21:39:23 2010.
      If you experience any problems here, contact : ftpmaster_at_univ-tlse1.fr

230 Anonymous login ok, restrictions apply.
}
2010/09/13 21:39:37.156| ftp>> -1 The current time here is Mon Sep
13 21:39:23 2010.
2010/09/13 21:39:37.156| ftp.cc(1758) ftpParseControlReply: s = { If
you experience any problems here, contact : ftpmaster_at_univ-tlse1.fr

230 Anonymous login ok, restrictions apply.
}
2010/09/13 21:39:37.156| ftp>> -1 If you experience any problems
here, contact : ftpmaster_at_univ-tlse1.fr
2010/09/13 21:39:37.156| ftp.cc(1758) ftpParseControlReply: s = {

230 Anonymous login ok, restrictions apply.
}
2010/09/13 21:39:37.156| ftp>> -1
2010/09/13 21:39:37.156| ftp.cc(1758) ftpParseControlReply: s = {
230 Anonymous login ok, restrictions apply.
}
2010/09/13 21:39:37.156| ftp>> -1
2010/09/13 21:39:37.156| ftp.cc(1758) ftpParseControlReply: s = {230
Anonymous login ok, restrictions apply.
}
2010/09/13 21:39:37.156| ftp>> 230 Anonymous login ok, restrictions apply.
2010/09/13 21:39:37.156| ftp.cc(1938) handleControlReply: state=2, code=230
2010/09/13 21:39:37.156| ftp.cc(2104) ftpReadPass: code=230
2010/09/13 21:39:37.156| ftp<< TYPE A

2010/09/13 21:39:37.156| The AsyncCall
FtpStateData::ftpWriteCommandCallback constructed, this=0x84584a8
[call22721]
2010/09/13 21:39:37.156| comm_write: FD 24: sz 8: asynCall 0x84584a8*1
2010/09/13 21:39:37.156| ftp.cc(1811) scheduleReadControlReply: FD 24
2010/09/13 21:39:37.156| The AsyncCall FtpStateData::ftpReadControlReply
constructed, this=0x8458500 [call22722]
2010/09/13 21:39:37.156| comm_read, queueing read for FD 24; asynCall
0x8458500*1
2010/09/13 21:39:37.156| The AsyncCall FtpStateData::ftpTimeout
constructed, this=0x8458558 [call22723]
2010/09/13 21:39:37.156| comm.cc(1206) commSetTimeout: FD 24 timeout 900
2010/09/13 21:39:37.156| FtpStateData status out: [ job2955]
2010/09/13 21:39:37.156| leaving FtpStateData::ftpReadControlReply(FD
24, data=0x8453f70, size=325, buf=0x8712a1e)
2010/09/13 21:39:37.156| commHandleWrite: FD 24: off 0, sz 8.
2010/09/13 21:39:37.156| commHandleWrite: write() returns 8
2010/09/13 21:39:37.156| commio_finish_callback: called for FD 24 (0, 0)
2010/09/13 21:39:37.156| comm.cc(165) will call
FtpStateData::ftpWriteCommandCallback(FD 24, data=0x8453f70, size=8,
buf=0x84583e8) [call22721]
2010/09/13 21:39:37.156| entering
FtpStateData::ftpWriteCommandCallback(FD 24, data=0x8453f70, size=8,
buf=0x84583e8)
2010/09/13 21:39:37.156| AsyncCall.cc(32) make: make call
FtpStateData::ftpWriteCommandCallback [call22721]
2010/09/13 21:39:37.156| FtpStateData status in: [ job2955]
2010/09/13 21:39:37.156| ftpWriteCommandCallback: wrote 8 bytes
2010/09/13 21:39:37.156| FtpStateData status out: [ job2955]
2010/09/13 21:39:37.156| leaving
FtpStateData::ftpWriteCommandCallback(FD 24, data=0x8453f70, size=8,
buf=0x84583e8)
2010/09/13 21:39:37.215| comm_read_try: FD 24, size 4096, retval 19, errno 0
2010/09/13 21:39:37.215| commio_finish_callback: called for FD 24 (0, 0)
2010/09/13 21:39:37.216| comm.cc(165) will call
FtpStateData::ftpReadControlReply(FD 24, data=0x8453f70, size=19,
buf=0x8712a18) [call22722]
2010/09/13 21:39:37.216| entering FtpStateData::ftpReadControlReply(FD
24, data=0x8453f70, size=19, buf=0x8712a18)
2010/09/13 21:39:37.216| AsyncCall.cc(32) make: make call
FtpStateData::ftpReadControlReply [call22722]
2010/09/13 21:39:37.216| FtpStateData status in: [ job2955]
2010/09/13 21:39:37.216| ftpReadControlReply: FD 24, Read 19 bytes
2010/09/13 21:39:37.216| ftp.cc(1728) ftpParseControlReply:
2010/09/13 21:39:37.216| ftp.cc(1741) ftpParseControlReply: usable = 18
2010/09/13 21:39:37.216| ftp.cc(1749) ftpParseControlReply: 19 bytes to
play with
2010/09/13 21:39:37.216| ftp.cc(1758) ftpParseControlReply: s = {200
Type set to A
}
2010/09/13 21:39:37.216| ftp>> 200 Type set to A
2010/09/13 21:39:37.216| ftp.cc(1938) handleControlReply: state=3, code=200
2010/09/13 21:39:37.216| ftp.cc(2173) ftpReadType:
2010/09/13 21:39:37.216| ftp.cc(2579) ftpSendPassive:
2010/09/13 21:39:37.216| ftp.cc(3006) ftpSendEPRT:
2010/09/13 21:39:37.216| comm_openex: Attempt open socket for: 192.168.1.19
2010/09/13 21:39:37.216| comm_openex: Opened socket FD 25 : family=2,
type=1, protocol=6
2010/09/13 21:39:37.216| comm_open: FD 25 is a new socket
2010/09/13 21:39:37.216| fd_open() FD 25 ftp://ftp.univ-tlse1.fr/
2010/09/13 21:39:37.216| commBind: bind socket FD 25 to 192.168.1.19
2010/09/13 21:39:37.216| ftp.cc(2904) ftpOpenListenSocket: Unconnected
data socket created on FD 25
2010/09/13 21:39:37.216| The AsyncCall FtpStateData::dataClosed
constructed, this=0x8458118 [call22724]
2010/09/13 21:39:37.216| comm_add_close_handler: FD 25,
AsyncCall=0x8458118*2
2010/09/13 21:39:37.216| comm_local_port: FD 25: port 36793(family=2)
2010/09/13 21:39:37.216| ftp<< EPRT |1|192.168.1.19|36793|

2010/09/13 21:39:37.216| The AsyncCall
FtpStateData::ftpWriteCommandCallback constructed, this=0x84584a8
[call22725]
2010/09/13 21:39:37.216| comm_write: FD 24: sz 29: asynCall 0x84584a8*1
2010/09/13 21:39:37.216| ftp.cc(1811) scheduleReadControlReply: FD 24
2010/09/13 21:39:37.216| The AsyncCall FtpStateData::ftpReadControlReply
constructed, this=0x84f4ea0 [call22726]
2010/09/13 21:39:37.216| comm_read, queueing read for FD 24; asynCall
0x84f4ea0*1
2010/09/13 21:39:37.216| comm.cc(1206) commSetTimeout: FD 25 timeout -1
2010/09/13 21:39:37.216| The AsyncCall FtpStateData::ftpTimeout
constructed, this=0x8458220 [call22727]
2010/09/13 21:39:37.216| comm.cc(1206) commSetTimeout: FD 24 timeout 900
2010/09/13 21:39:37.216| FtpStateData status out: [ job2955]
2010/09/13 21:39:37.216| leaving FtpStateData::ftpReadControlReply(FD
24, data=0x8453f70, size=19, buf=0x8712a18)
2010/09/13 21:39:37.216| commHandleWrite: FD 24: off 0, sz 29.
2010/09/13 21:39:37.216| commHandleWrite: write() returns 29
2010/09/13 21:39:37.216| commio_finish_callback: called for FD 24 (0, 0)
2010/09/13 21:39:37.216| comm.cc(165) will call
FtpStateData::ftpWriteCommandCallback(FD 24, data=0x8453f70, size=29,
buf=0x84583a8) [call22725]
2010/09/13 21:39:37.216| entering
FtpStateData::ftpWriteCommandCallback(FD 24, data=0x8453f70, size=29,
buf=0x84583a8)
2010/09/13 21:39:37.216| AsyncCall.cc(32) make: make call
FtpStateData::ftpWriteCommandCallback [call22725]
2010/09/13 21:39:37.216| FtpStateData status in: [ job2955]
2010/09/13 21:39:37.216| ftpWriteCommandCallback: wrote 29 bytes
2010/09/13 21:39:37.216| FtpStateData status out: [ job2955]
2010/09/13 21:39:37.216| leaving
FtpStateData::ftpWriteCommandCallback(FD 24, data=0x8453f70, size=29,
buf=0x84583a8)
2010/09/13 21:39:37.276| comm_read_try: FD 24, size 4096, retval 29, errno 0
2010/09/13 21:39:37.276| commio_finish_callback: called for FD 24 (0, 0)
2010/09/13 21:39:37.276| comm.cc(165) will call
FtpStateData::ftpReadControlReply(FD 24, data=0x8453f70, size=29,
buf=0x8712a18) [call22726]
2010/09/13 21:39:37.276| entering FtpStateData::ftpReadControlReply(FD
24, data=0x8453f70, size=29, buf=0x8712a18)
2010/09/13 21:39:37.276| AsyncCall.cc(32) make: make call
FtpStateData::ftpReadControlReply [call22726]
2010/09/13 21:39:37.276| FtpStateData status in: [ job2955]
2010/09/13 21:39:37.276| ftpReadControlReply: FD 24, Read 29 bytes
2010/09/13 21:39:37.276| ftp.cc(1728) ftpParseControlReply:
2010/09/13 21:39:37.276| ftp.cc(1741) ftpParseControlReply: usable = 28
2010/09/13 21:39:37.276| ftp.cc(1749) ftpParseControlReply: 29 bytes to
play with
2010/09/13 21:39:37.276| ftp.cc(1758) ftpParseControlReply: s = {200
EPRT command successful
}
2010/09/13 21:39:37.276| ftp>> 200 EPRT command successful
2010/09/13 21:39:37.276| ftp.cc(1938) handleControlReply: state=6, code=200
2010/09/13 21:39:37.276| ftp.cc(3040) ftpReadEPRT:
2010/09/13 21:39:37.276| ftp.cc(3135) ftpRestOrList:
2010/09/13 21:39:37.276| ftp.cc(3304) ftpSendList:
2010/09/13 21:39:37.276| ftp<< LIST

2010/09/13 21:39:37.276| The AsyncCall
FtpStateData::ftpWriteCommandCallback constructed, this=0x845bd50
[call22728]
2010/09/13 21:39:37.276| comm_write: FD 24: sz 6: asynCall 0x845bd50*1
2010/09/13 21:39:37.276| ftp.cc(1811) scheduleReadControlReply: FD 24
2010/09/13 21:39:37.276| The AsyncCall FtpStateData::ftpReadControlReply
constructed, this=0x84584a8 [call22729]
2010/09/13 21:39:37.276| comm_read, queueing read for FD 24; asynCall
0x84584a8*1
2010/09/13 21:39:37.276| comm.cc(1206) commSetTimeout: FD 25 timeout -1
2010/09/13 21:39:37.276| The AsyncCall FtpStateData::ftpTimeout
constructed, this=0x8458500 [call22730]
2010/09/13 21:39:37.276| comm.cc(1206) commSetTimeout: FD 24 timeout 900
2010/09/13 21:39:37.276| FtpStateData status out: [ job2955]
2010/09/13 21:39:37.276| leaving FtpStateData::ftpReadControlReply(FD
24, data=0x8453f70, size=29, buf=0x8712a18)
2010/09/13 21:39:37.276| commHandleWrite: FD 24: off 0, sz 6.
2010/09/13 21:39:37.276| commHandleWrite: write() returns 6
2010/09/13 21:39:37.276| commio_finish_callback: called for FD 24 (0, 0)
2010/09/13 21:39:37.276| comm.cc(165) will call
FtpStateData::ftpWriteCommandCallback(FD 24, data=0x8453f70, size=6,
buf=0x874eb08) [call22728]
2010/09/13 21:39:37.276| entering
FtpStateData::ftpWriteCommandCallback(FD 24, data=0x8453f70, size=6,
buf=0x874eb08)
2010/09/13 21:39:37.276| AsyncCall.cc(32) make: make call
FtpStateData::ftpWriteCommandCallback [call22728]
2010/09/13 21:39:37.276| FtpStateData status in: [ job2955]
2010/09/13 21:39:37.276| ftpWriteCommandCallback: wrote 6 bytes
2010/09/13 21:39:37.276| FtpStateData status out: [ job2955]
2010/09/13 21:39:37.276| leaving
FtpStateData::ftpWriteCommandCallback(FD 24, data=0x8453f70, size=6,
buf=0x874eb08)
2010/09/13 21:39:37.334| comm_read_try: FD 24, size 4096, retval 55, errno 0
2010/09/13 21:39:37.334| commio_finish_callback: called for FD 24 (0, 0)
2010/09/13 21:39:37.334| comm.cc(165) will call
FtpStateData::ftpReadControlReply(FD 24, data=0x8453f70, size=55,
buf=0x8712a18) [call22729]
2010/09/13 21:39:37.334| entering FtpStateData::ftpReadControlReply(FD
24, data=0x8453f70, size=55, buf=0x8712a18)
2010/09/13 21:39:37.334| AsyncCall.cc(32) make: make call
FtpStateData::ftpReadControlReply [call22729]
2010/09/13 21:39:37.334| FtpStateData status in: [ job2955]
2010/09/13 21:39:37.334| ftpReadControlReply: FD 24, Read 55 bytes
2010/09/13 21:39:37.334| ftp.cc(1728) ftpParseControlReply:
2010/09/13 21:39:37.334| ftp.cc(1741) ftpParseControlReply: usable = 54
2010/09/13 21:39:37.334| ftp.cc(1749) ftpParseControlReply: 55 bytes to
play with
2010/09/13 21:39:37.334| ftp.cc(1758) ftpParseControlReply: s = {425
Unable to build data connection: Invalid argument
}
2010/09/13 21:39:37.334| ftp>> 425 Unable to build data connection:
Invalid argument
2010/09/13 21:39:37.334| ftp.cc(1938) handleControlReply: state=13, code=425
2010/09/13 21:39:37.334| ftp.cc(3343) ftpReadList:
2010/09/13 21:39:37.334| ftp.cc(3324) ftpSendNlst:
2010/09/13 21:39:37.334| ftp<< NLST

2010/09/13 21:39:37.334| The AsyncCall
FtpStateData::ftpWriteCommandCallback constructed, this=0x8458220
[call22731]
2010/09/13 21:39:37.334| comm_write: FD 24: sz 6: asynCall 0x8458220*1
2010/09/13 21:39:37.334| ftp.cc(1811) scheduleReadControlReply: FD 24
2010/09/13 21:39:37.334| The AsyncCall FtpStateData::ftpReadControlReply
constructed, this=0x84f4ea0 [call22732]
2010/09/13 21:39:37.334| comm_read, queueing read for FD 24; asynCall
0x84f4ea0*1
2010/09/13 21:39:37.334| comm.cc(1206) commSetTimeout: FD 25 timeout -1
2010/09/13 21:39:37.334| The AsyncCall FtpStateData::ftpTimeout
constructed, this=0x845bd30 [call22733]
2010/09/13 21:39:37.334| comm.cc(1206) commSetTimeout: FD 24 timeout 900
2010/09/13 21:39:37.334| FtpStateData status out: [ job2955]
2010/09/13 21:39:37.334| leaving FtpStateData::ftpReadControlReply(FD
24, data=0x8453f70, size=55, buf=0x8712a18)
2010/09/13 21:39:37.334| commHandleWrite: FD 24: off 0, sz 6.
2010/09/13 21:39:37.334| commHandleWrite: write() returns 6
2010/09/13 21:39:37.335| commio_finish_callback: called for FD 24 (0, 0)
2010/09/13 21:39:37.335| comm.cc(165) will call
FtpStateData::ftpWriteCommandCallback(FD 24, data=0x8453f70, size=6,
buf=0x8747080) [call22731]
2010/09/13 21:39:37.335| entering
FtpStateData::ftpWriteCommandCallback(FD 24, data=0x8453f70, size=6,
buf=0x8747080)
2010/09/13 21:39:37.335| AsyncCall.cc(32) make: make call
FtpStateData::ftpWriteCommandCallback [call22731]
2010/09/13 21:39:37.335| FtpStateData status in: [ job2955]
2010/09/13 21:39:37.335| ftpWriteCommandCallback: wrote 6 bytes
2010/09/13 21:39:37.335| FtpStateData status out: [ job2955]
2010/09/13 21:39:37.335| leaving
FtpStateData::ftpWriteCommandCallback(FD 24, data=0x8453f70, size=6,
buf=0x8747080)
2010/09/13 21:39:37.393| comm_read_try: FD 24, size 4096, retval 55, errno 0
2010/09/13 21:39:37.393| commio_finish_callback: called for FD 24 (0, 0)
2010/09/13 21:39:37.393| comm.cc(165) will call
FtpStateData::ftpReadControlReply(FD 24, data=0x8453f70, size=55,
buf=0x8712a18) [call22732]
2010/09/13 21:39:37.393| entering FtpStateData::ftpReadControlReply(FD
24, data=0x8453f70, size=55, buf=0x8712a18)
2010/09/13 21:39:37.393| AsyncCall.cc(32) make: make call
FtpStateData::ftpReadControlReply [call22732]
2010/09/13 21:39:37.393| FtpStateData status in: [ job2955]
2010/09/13 21:39:37.393| ftpReadControlReply: FD 24, Read 55 bytes
2010/09/13 21:39:37.393| ftp.cc(1728) ftpParseControlReply:
2010/09/13 21:39:37.393| ftp.cc(1741) ftpParseControlReply: usable = 54
2010/09/13 21:39:37.393| ftp.cc(1749) ftpParseControlReply: 55 bytes to
play with
2010/09/13 21:39:37.393| ftp.cc(1758) ftpParseControlReply: s = {425
Unable to build data connection: Invalid argument

2010/09/13 21:39:37.393| ftp.cc(1728) ftpParseControlReply:
2010/09/13 21:39:37.393| ftp.cc(1741) ftpParseControlReply: usable = 54
2010/09/13 21:39:37.393| ftp.cc(1749) ftpParseControlReply: 55 bytes to
play with
2010/09/13 21:39:37.393| ftp.cc(1758) ftpParseControlReply: s = {425
Unable to build data connection: Invalid argument
}
2010/09/13 21:39:37.393| ftp>> 425 Unable to build data connection:
Invalid argument
2010/09/13 21:39:37.393| ftp.cc(1938) handleControlReply: state=14, code=425
2010/09/13 21:39:37.393| ftp.cc(3343) ftpReadList:
2010/09/13 21:39:37.393| ftp.cc(3600) ftpFail: flags(IS_DIR,), mdtm=-1,
size=-1slashhack=F
2010/09/13 21:39:37.393| ftp.cc(3629) failed: entry-null=1, entry=0x845bee0
2010/09/13 21:39:37.393| init-ing hdr: 0x84584ec owner: 3
2010/09/13 21:39:37.393| 0x845b6a4: joined for id 3: 0xbfffde50
2010/09/13 21:39:37.393| errorpage.cc(955) BuildContent: Testing Header:
'en,fr-FR;q=0.9,fr;q=0.8'
2010/09/13 21:39:37.394| errorpage.cc(1004) BuildContent: Found language
'en', testing for available template in: '/usr/share/squid3/errors/en'
2010/09/13 21:39:37.394| file_open: FD 26
2010/09/13 21:39:37.394| fd_open() FD 26
/usr/share/squid3/errors/en/ERR_FTP_FAILURE
2010/09/13 21:39:37.394| file_close: FD 26 really closing

2010/09/13 21:39:37.394| fd_close FD 26
/usr/share/squid3/errors/en/ERR_FTP_FAILURE
2010/09/13 21:39:37.394| errorConvert: %%l --> '/*

2010/09/13 21:39:37.394| errorConvert: %%; --> '%;'
2010/09/13 21:39:37.394| errorConvert: %%U --> 'ftp://ftp.univ-tlse1.fr/'
2010/09/13 21:39:37.394| errorConvert: %%U --> 'ftp://ftp.univ-tlse1.fr/'
2010/09/13 21:39:37.394| errorConvert: %%f --> 'NLST
'
2010/09/13 21:39:37.394| errorConvert: %%F --> 'Unable to build data
connection: Invalid argument'
2010/09/13 21:39:37.394| errorConvert: %%g --> ''
2010/09/13 21:39:37.394| errorConvert: %%w --> 'webmaster'
2010/09/13 21:39:37.394| packing hdr: (0x845b6a4)
2010/09/13 21:39:37.394| errorConvert: %%W -->
'?subject=CacheErrorInfo%20-%20ERR_FTP_FAILURE&body=CacheHost%3A%20proxyweb%0D%0AErrPage%3A%20ERR_FTP_FAILURE%0D%0AErr%3A%20%5Bnone%5D%0D%0ATimeStamp%3A%20Mon,%2013%20Sep%202010%2019%3A39%3A37%20GMT%0D%0A%0D%0AClientIP%3A%20192.168.1.240%0D%0AServerIP%3A%20193.49.48.249%0D%0A%0D%0AHTTP%20Request%3A%0D%0AGET%20%2F%20HTTP%2F1.0%0AUser-Agent%3A%20Opera%2F9.80%20(X11%3B%20Linux%20i686%3B%20U%3B%20en)%20Presto%2F2.2.15%20Version%2F10.10%0D%0AHost%3A%20ftp.univ-tlse1.fr%3A21%0D%0AAccept%3A%20text%2Fhtml,%20application%2Fxml%3Bq%3D0.9,%20application%2Fxhtml+xml,%20image%2Fpng,%20image%2Fjpeg,%20image%2Fgif,%20image%2Fx-xbitmap,%20*%2F*%3Bq%3D0.1%0D%0AAccept-Language%3A%20en,fr-FR%3Bq%3D0.9,fr%3Bq%3D0.8%0D%0AAccept-Charset%3A%20iso-8859-1,%20utf-8,%20utf-16,%20*%3Bq%3D0.1%0D%0AAccept-Encoding%3A%20deflate,%20gzip,%20x-gzip,%20identity,%20*%3Bq%3D0%0D%0AProxy-Connection%3A%20Keep-Alive%0D%0A%0D%0AFTP%20Request%3A%20NLST%0D%0A%0D%0AFTP%20Reply%3A%20Unable%20to%20build%20data%20connecti
on%3A%20Invalid%20argument%0D%0AFTP%20Msg%3A%20%0D%0A%0D%0A'
2010/09/13 21:39:37.394| errorConvert: %%w --> 'webmaster'
2010/09/13 21:39:37.394| errorConvert: %%T --> 'Mon, 13 Sep 2010
19:39:37 GMT'
2010/09/13 21:39:37.394| errorConvert: %%h --> 'proxyweb'
2010/09/13 21:39:37.394| errorConvert: %%s --> 'squid/3.1.7'
2010/09/13 21:39:37.394| errorConvert: %%c --> 'ERR_FTP_FAILURE'
2010/09/13 21:39:37.394| StoreEntry::replaceHttpReply:
ftp://ftp.univ-tlse1.fr/

On 13/09/2010 01:27, Amos Jeffries wrote:
> On Sun, 12 Sep 2010 20:59:08 +0200, David Touzeau<david_at_touzeau.eu>
> wrote:
>> Dear all
>>
>> I'm using squid 3.1.7, when i'm browsing on ftp server like
>>
>> ftp://ftp.univ-tlse1.fr/
>> ftp://ftp.redhat.com
>>
>> Browser give error :
>> ******************************************************************
>> An FTP protocol error occurred while trying to retrieve the URL:
>> ftp://ftp.univ-tlse1.fr/
>>
>> Squid sent the following FTP command:
>> NLST
>>
>> The server responded with:
>> Unable to build data connection: Invalid argument
>>
>> ******************************************************************
>>
>
> A few minutes on google indicates that you have a firewall blocking
> incoming FTP data connections. The server is unable to send you the
> directory listing when requested.
>
> Amos
>
Received on Mon Sep 13 2010 - 19:48:53 MDT

This archive was generated by hypermail 2.2.0 : Tue Sep 14 2010 - 12:00:02 MDT