We are running into what looks like a bug with net:max-retries being
incorrectly reset to zero, which causes a looping condition.
Here is the lftp script we are using:
#!/usr/bin/ksh
IDPASSWD="ftp1 mypassword"
LOGFILE=lftp_loop.out
set -v +x
lftp 1>${LOGFILE} 2>&1 <<Ctrl-D
debug 10
set cmd:trace yes
set cmd:at-exit "kill all"
set cmd:fail-exit no
set cmd:move-background no
set cmd:save-cwd-history no
set cmd:save-rl-history no
set cmd:verbose no
set dns:fatal-timeout 10s
set ftp:passive-mode on
set net:max-retries 1
set xfer:log no
set cmd:trace yes
set cmd:default-protocol ftp
open ibm01 || exit 255
set cmd:trace no
user ${IDPASSWD}
set cmd:trace yes
cls -d || exit 254
put -a file_will_not_truncate.rpt -o
SRAYROVER/SRY260E18.S000000000 || exit 251
close
open ibm01 || exit 255
set cmd:trace no
user ${IDPASSWD}
set cmd:trace yes
put -a file_will_not_truncate.rpt -o
SRAYROVER/SRY260E18.S000000000 || exit 251
set net:max-retries 1
put -a file_will_truncate.rpt -o SRAYROVER/SRY260E18.S000000001 ||
exit 252
quit
Ctrl-D
echo lftp exist status $?
The situation is this:
When we send a file to an IBM iSeries system, and the record length in
that file exceeds the data set definition on the iSeries system, the
iSeries FTP server replies with a 426 that the record was truncated.
This is non-fatal and causes lftp to retry.
No problem - so we set the net:max-retries parameter to 1 which should
prevent looping. As the log below shows at line 90 however, the retries
value is being reset to zero, infinite retries, and thus the looping
behavior we're seeing.
This appears to be a bug. Has anybody else seen this or is able to
reproduce it?
Right now our workaround is to ensure that the data set definition on
the iSeries systems exceed the maximum record length we might send, but
this is not a guaranteed workaround. Alexander did send me a patch
which I was able to apply and recompile, however, it did not resolve the
problem. The patch was supposed to treat a 426 error as fatal and
prevent lftp from retrying, however, it still loops, but this time on a
connection retry.
I will attempt to jump into the code myself to see if I can figure out
what is happening here but if anybody else has seen this or reproduce
it, I would be very interested in hearing from you.
I have attached the patch to the end of this message. I don't think a
patch is necessary though as it appears to be a bug.
Thanks!
Curtis
Log file follows for above script:
1 notice: cannot open /home/cacre9/.netrc: No such file or
directory
2 ---- Resolving host address...
3 ---- 1 address found: 10.0.0.1
4 notice: cannot open /home/cacre9/.netrc: No such file or
directory
5 ---- dns cache hit
6 ---- Connecting to ibm01 (10.0.0.1) port 21
7 <--- 220-QTCP at IBM01.
8 <--- 220 Connection will close if idle more than 5 minutes.
9 ---> FEAT
10 <--- 211-Feature listing follows:
11 <--- AUTH TLS
12 <--- CCC
13 <--- PBSZ
14 <--- PROT
15 <--- 211 End of feature listing.
16 ---> AUTH TLS
17 <--- 431 Requested security mechanism not available at this
time.
18 ---> USER ftp1
19 <--- 331 Enter password.
20 ---> PASS mypassword
21 <--- 230 FTP1 logged on.
22 ---> PWD
23 <--- 257 "QGPL" is current library.
24 ---> CWD ..
25 <--- 501 Character (.) not allowed at beginning of name.
26 copy: get hit eof
27 copy: waiting for put confirmation
28 ./
29 copy: put confirmed store
30 copy: get is finished - all done
31 copy: get hit eof
32 copy: waiting for put confirmation
33 ---> PASV
34 <--- 227 Entering Passive Mode (10,0,0,1,203,193).
35 ---- Connecting data socket to (10.0.0.1) port 52161
36 ---- Data connection established
37 ---> ALLO 206
38 <--- 202 ALLO subcommand not required.
39 ---> STOR SRAYROVER/SRY260E18.S000000000
40 <--- 150 Sending file to member S000000000 in file SRY260E18 in
library SRAYROVER.
41 ---- Closing data socket
42 <--- 226 File transfer completed successfully.
43 copy: put confirmed store
44 copy: get is finished - all done
45 ---> QUIT
46 <--- 221 QUIT subcommand received.
47 ---- Closing control socket
48 notice: cannot open /home/cacre9/.netrc: No such file or
directory
49 ---- dns cache hit
50 ---- dns cache hit
51 ---- Connecting to ibm01 (10.0.0.1) port 21
52 copy: get hit eof
53 copy: waiting for put confirmation
54 <--- 220-QTCP at IBM01.
55 <--- 220 Connection will close if idle more than 5 minutes.
56 ---> FEAT
57 <--- 211-Feature listing follows:
58 <--- AUTH TLS
59 <--- CCC
60 <--- PBSZ
61 <--- PROT
62 <--- 211 End of feature listing.
63 ---> AUTH TLS
64 <--- 431 Requested security mechanism not available at this
time.
65 ---> USER ftp1
66 <--- 331 Enter password.
67 ---> PASS mypassword
68 <--- 230 FTP1 logged on.
69 ---> PASV
70 <--- 227 Entering Passive Mode (10,0,0,1,192,17).
71 ---- Connecting data socket to (10.0.0.1) port 49169
72 ---- Data connection established
73 ---> STOR SRAYROVER/SRY260E18.S000000000
74 <--- 150 Sending file to member S000000000 in file SRY260E18 in
library SRAYROVER.
75 ---- Closing data socket
76 <--- 226 File transfer completed successfully.
77 copy: put confirmed store
78 copy: get is finished - all done
79 copy: get hit eof
80 copy: waiting for put confirmation
81 ---> PASV
82 <--- 227 Entering Passive Mode (10,0,0,1,133,163).
83 ---- Connecting data socket to (10.0.0.1) port 34211
84 ---- Data connection established
85 ---> STOR SRAYROVER/SRY260E18.S000000001
86 <--- 150 Sending file to member S000000001 in file SRY260E18 in
library SRAYROVER.
87 ---- Closing data socket
88 <--- 426-Records written to file SRY260E18 in library SRAYROVER
have been truncated. Data in file may not be valid.
89 <--- 426 Data transfer ended.
90 try_time=1270845539, retries=0
91 ---> TYPE I
92 <--- 200 Representation type is binary IMAGE.
93 copy: get hit eof
94 copy: waiting for put confirmation
95 ---> TYPE A
96 copy: put rolled back to 0, seeking get accordingly
97 copy: get position was 217
98 copy: get hit eof
99 copy: waiting for put confirmation
100 <--- 200 Representation type is ASCII nonprint.
101 ---> PASV
102 <--- 227 Entering Passive Mode (10,0,0,1,220,107).
103 ---- Connecting data socket to (10.0.0.1) port 56427
104 ---- Data connection established
105 ---> STOR SRAYROVER/SRY260E18.S000000001
106 <--- 150 Sending file to member S000000001 in file SRY260E18 in
library SRAYROVER.
107 ---- Closing data socket
108 <--- 426-Records written to file SRY260E18 in library SRAYROVER
have been truncated. Data in file may not be valid.
109 <--- 426 Data transfer ended.
110 try_time=1270845540, retries=0
111 ---> TYPE I
112 <--- 200 Representation type is binary IMAGE.
113 copy: get hit eof
114 copy: waiting for put confirmation
115 ---> TYPE A
116 copy: put rolled back to 0, seeking get accordingly
117 copy: get position was 217
118 copy: get hit eof
119 copy: waiting for put confirmation
120 <--- 200 Representation type is ASCII nonprint.
121 ---> PASV
122 <--- 227 Entering Passive Mode (10,0,0,1,87,107).
123 ---- Connecting data socket to (10.0.0.1) port 22379
124 ---- Data connection established
125 ---> STOR SRAYROVER/SRY260E18.S000000001
126 <--- 150 Sending file to member S000000001 in file SRY260E18 in
library SRAYROVER.
127 ---- Closing data socket
128 <--- 426-Records written to file SRY260E18 in library SRAYROVER
have been truncated. Data in file may not be valid.
129 <--- 426 Data transfer ended.
130 try_time=1270845540, retries=0
131 ---> TYPE I
132 <--- 200 Representation type is binary IMAGE.
133 copy: get hit eof
134 copy: waiting for put confirmation
135 ---> TYPE A
136 copy: put rolled back to 0, seeking get accordingly
137 copy: get position was 217
138 copy: get hit eof
139 copy: waiting for put confirmation
140 <--- 200 Representation type is ASCII nonprint.
Patch:
Index: ftpclass.cc
===================================================================
RCS file: /home/lav/cvsroot/lftp/src/ftpclass.cc,v
retrieving revision 1.464
diff -u -p -r1.464 ftpclass.cc
--- ftpclass.cc 25 Mar 2010 08:08:27 -0000 1.464
+++ ftpclass.cc 7 Apr 2010 08:41:55 -0000
@@ -400,6 +400,12 @@ void Ftp::TransferCheck(int act)
if(conn->data_sock==-1 && strstr(line,"Broken pipe"))
return;
}
+ if(act==426 && mode==STORE)
+ {
+ DataClose();
+ state=EOF_STATE;
+ SetError(FATAL,all_lines);
+ }
if(is2XX(act) && conn->data_sock==-1)
eof=true;
#if USE_SSL
@@ -4086,7 +4092,7 @@ void Ftp::CheckResp(int act)
if(conn->try_feat_after_login && conn->have_feat_info)
TuneConnectionAfterFEAT();
}
- else if(act==530 || act==503)
+ else if(is5XX(act) && !cmd_unsupported(act))
conn->try_feat_after_login=true;
break;
