Intermittent 451 Error on Download

We are using DownloadFile method to retrieve a file from an FTP server running on an IBM mainframe. Every now and then the download fails with a "451 Transfer aborted: send error." message.

The mainframe folks looking at the server log says that there appears to be two sessions (attempts) to download the file when the download fails. The first one appears to have completed successfully and a second one that fails.

Any ideas on what might be causing the intermittent failures and why the server log shows two sessions?

Please post the log. Set the LogFile property to get it.

The following is a log of a successful download. NOTE: (For security reasons the server names,
IP addresses, username, folder and filenames have been replaced.)

********************************************************************************

[20090602 23:20:18] SmartFTP FTP Library v1.5.9.20
[20090602 23:20:18] Resolving host name "FTPSERVER"
[20090602 23:20:18] Connecting to 192.168.1.1 Port: 21
[20090602 23:20:18] Connected to FTPSERVER.
[20090602 23:20:19] 220-FTPD1 IBM FTP CS V1R9 at FTP.SERVER.DOM, 16:20:34 on 2009-06-02.
[20090602 23:20:19] 220 Connection will close if idle for more than 10 minutes.
[20090602 23:20:19] AUTH TLS
[20090602 23:20:19] 234 Security environment established - ready for negotiation
[20090602 23:20:19] Connected. Exchanging encryption keys...
[20090602 23:20:19] Session Cipher: 168 bit 3DES
[20090602 23:20:19] TLS encrypted session established.
[20090602 23:20:19] PBSZ 0
[20090602 23:20:19] 200 Protection buffer size accepted
[20090602 23:20:19] USER FTPUSER
[20090602 23:20:19] 331 Send password please.
[20090602 23:20:19] PASS (hidden)
[20090602 23:20:19] 230 FTPUSER is logged on. Working directory is "FTPUSER.".
[20090602 23:20:19] SYST
[20090602 23:20:19] 215 MVS is the operating system of this server. FTP Server is running on z/OS.
[20090602 23:20:19] Detected Server Type: MVS
[20090602 23:20:19] FEAT
[20090602 23:20:19] 211- Extensions supported
[20090602 23:20:19] SIZE
[20090602 23:20:19] AUTH TLS
[20090602 23:20:19] PBSZ
[20090602 23:20:19] PROT
[20090602 23:20:19] 211 End
[20090602 23:20:19] TYPE I
[20090602 23:20:19] 200 Representation type is Image
[20090602 23:20:19] REST 0
[20090602 23:20:19] 504 Restart not allowed with active security mechanism
[20090602 23:20:19] PWD
[20090602 23:20:19] 257 "'FTPUSER.'" is working directory.
[20090602 23:20:19] CWD 'XXX.YY1234'
[20090602 23:20:19] 250 "XXX.YY1234." is the working directory name prefix.
[20090602 23:20:19] PWD
[20090602 23:20:19] 257 "'XXX.YY1234.'" is working directory.
[20090602 23:20:19] TYPE A
[20090602 23:20:19] 200 Representation type is Ascii NonPrint
[20090602 23:20:19] PROT P
[20090602 23:20:19] 200 Data connection protection set to private
[20090602 23:20:19] PORT 172,19,19,24,13,88
[20090602 23:20:19] 200 Port request OK.
[20090602 23:20:19] RETR TGP1234.XCR
[20090602 23:20:19] Connected. Exchanging encryption keys...
[20090602 23:20:19] 125 Sending data set XXX.YY1234.TGP1234.XCR FIXrecfm 200
[20090602 23:20:19] Session Cipher: 168 bit 3DES
[20090602 23:20:19] TLS encrypted session established.
[20090602 23:20:57] 105270651 bytes transferred. (2.70 MB/s) (00:00:37)
[20090602 23:20:57] 250 Transfer completed successfully.
[20090602 23:20:57] QUIT
[20090602 23:20:57] 221 Quit command received. Goodbye.
[20090602 23:20:57] Client closed the connection.

********************************************************************************



The following are samples of 2 failed download attempts for the same file.

********************************************************************************

[20090602 23:19:14] SmartFTP FTP Library v1.5.9.20
[20090602 23:19:14] Resolving host name "FTPSERVER"
[20090602 23:19:14] Connecting to 192.168.1.1 Port: 21
[20090602 23:19:14] Connected to FTPSERVER.
[20090602 23:19:14] 220-FTPD1 IBM FTP CS V1R9 at FTP.SERVER.DOM, 16:19:29 on 2009-06-02.
[20090602 23:19:14] 220 Connection will close if idle for more than 10 minutes.
[20090602 23:19:14] AUTH TLS
[20090602 23:19:15] 234 Security environment established - ready for negotiation
[20090602 23:19:15] Connected. Exchanging encryption keys...
[20090602 23:19:15] Session Cipher: 168 bit 3DES
[20090602 23:19:15] TLS encrypted session established.
[20090602 23:19:15] PBSZ 0
[20090602 23:19:15] 200 Protection buffer size accepted
[20090602 23:19:15] USER FTPUSER
[20090602 23:19:15] 331 Send password please.
[20090602 23:19:15] PASS (hidden)
[20090602 23:19:15] 230 FTPUSER is logged on. Working directory is "FTPUSER.".
[20090602 23:19:15] SYST
[20090602 23:19:15] 215 MVS is the operating system of this server. FTP Server is running on z/OS.
[20090602 23:19:15] Detected Server Type: MVS
[20090602 23:19:15] FEAT
[20090602 23:19:15] 211- Extensions supported
[20090602 23:19:15] SIZE
[20090602 23:19:15] AUTH TLS
[20090602 23:19:15] PBSZ
[20090602 23:19:15] PROT
[20090602 23:19:15] 211 End
[20090602 23:19:15] TYPE I
[20090602 23:19:15] 200 Representation type is Image
[20090602 23:19:15] REST 0
[20090602 23:19:15] 504 Restart not allowed with active security mechanism
[20090602 23:19:15] PWD
[20090602 23:19:15] 257 "'FTPUSER.'" is working directory.
[20090602 23:19:15] CWD 'XXX.YY1234'
[20090602 23:19:15] 250 "XXX.YY1234." is the working directory name prefix.
[20090602 23:19:15] PWD
[20090602 23:19:15] 257 "'XXX.YY1234.'" is working directory.
[20090602 23:19:15] TYPE A
[20090602 23:19:15] 200 Representation type is Ascii NonPrint
[20090602 23:19:15] PROT P
[20090602 23:19:15] 200 Data connection protection set to private
[20090602 23:19:15] PORT 172,19,19,24,13,67
[20090602 23:19:15] 200 Port request OK.
[20090602 23:19:15] RETR TGP1234.XCR
[20090602 23:19:15] Connected. Exchanging encryption keys...
[20090602 23:19:15] 125 Sending data set XXX.YY1234.TGP1234.XCR FIXrecfm 200
[20090602 23:19:15] Session Cipher: 168 bit 3DES
[20090602 23:19:15] TLS encrypted session established.
[20090602 23:19:51] Transfer Timeout (30s). Closing data connection.
[20090602 23:19:51] 29460842 bytes transferred. (796 KB/s) (00:00:36)
[20090602 23:19:51] 451 Transfer aborted: send error.
[20090602 23:19:51] QUIT
[20090602 23:19:51] 221 Quit command received. Goodbye.
[20090602 23:19:51] Client closed the connection.



[20090602 22:53:27] SmartFTP FTP Library v1.5.9.20
[20090602 22:53:27] Resolving host name "FTPSERVER"
[20090602 22:53:27] Connecting to 192.168.1.1 Port: 21
[20090602 22:53:27] Connected to FTPSERVER.
[20090602 22:53:28] 220-FTPD1 IBM FTP CS V1R9 at FTP.SERVER.DOM, 15:53:43 on 2009-06-02.
[20090602 22:53:28] 220 Connection will close if idle for more than 10 minutes.
[20090602 22:53:28] AUTH TLS
[20090602 22:53:28] 234 Security environment established - ready for negotiation
[20090602 22:53:28] Connected. Exchanging encryption keys...
[20090602 22:53:28] Session Cipher: 168 bit 3DES
[20090602 22:53:28] TLS encrypted session established.
[20090602 22:53:28] PBSZ 0
[20090602 22:53:28] 200 Protection buffer size accepted
[20090602 22:53:28] USER FTPUSER
[20090602 22:53:28] 331 Send password please.
[20090602 22:53:28] PASS (hidden)
[20090602 22:53:28] 230 FTPUSER is logged on. Working directory is "FTPUSER.".
[20090602 22:53:28] SYST
[20090602 22:53:28] 215 MVS is the operating system of this server. FTP Server is running on z/OS.
[20090602 22:53:28] Detected Server Type: MVS
[20090602 22:53:28] FEAT
[20090602 22:53:28] 211- Extensions supported
[20090602 22:53:28] SIZE
[20090602 22:53:28] AUTH TLS
[20090602 22:53:28] PBSZ
[20090602 22:53:28] PROT
[20090602 22:53:28] 211 End
[20090602 22:53:28] TYPE I
[20090602 22:53:28] 200 Representation type is Image
[20090602 22:53:28] REST 0
[20090602 22:53:28] 504 Restart not allowed with active security mechanism
[20090602 22:53:28] PWD
[20090602 22:53:28] 257 "'FTPUSER.'" is working directory.
[20090602 22:53:29] CWD 'XXX.YY1234'
[20090602 22:53:29] 250 "XXX.YY1234." is the working directory name prefix.
[20090602 22:53:29] PWD
[20090602 22:53:29] 257 "'XXX.YY1234.'" is working directory.
[20090602 22:53:29] TYPE A
[20090602 22:53:29] 200 Representation type is Ascii NonPrint
[20090602 22:53:29] PROT P
[20090602 22:53:29] 200 Data connection protection set to private
[20090602 22:53:29] PORT 172,19,19,24,8,70
[20090602 22:53:29] 200 Port request OK.
[20090602 22:53:29] RETR TGP1234.XCR
[20090602 22:53:29] Connected. Exchanging encryption keys...
[20090602 22:53:29] 125 Sending data set XXX.YY1234.TGP1234.XCR FIXrecfm 200
[20090602 22:53:29] Session Cipher: 168 bit 3DES
[20090602 22:53:29] TLS encrypted session established.
[20090602 22:54:39] Transfer Timeout (30s). Closing data connection.
[20090602 22:54:39] 76431187 bytes transferred. (1.03 MB/s) (00:01:10)
[20090602 22:54:39] 451 Transfer aborted: send error.
[20090602 22:54:40] QUIT
[20090602 22:54:40] 221 Quit command received. Goodbye.
[20090602 22:54:40] Client closed the connection.

The server stop sending data for more than 30 seconds and therefore you get the timeout. Maybe you can find the reason in the server logs.

Regards,
Mat

I tried turning encryption off and it appears I can download the same file successfully consistently. When I turn on encryption I get the intermittent 451 error for the same file. Any ideas?

Did you run a test with another FTP client?

Please also test it with the latest version of the FTP Library: https://www.smartftp.com/download
The one you are using is almost 2 years old.

Regards,
Mat

Would our license for the older version work with the latest version?

Unfortunately no. The maintenance renewal also includes technical support.

Regards,
Mat

I installed the latest version of the SmartFTP FTP Library, but the problem still persists. We still get intermittent download errors for the same file, with encryption (FTP SSL/TLS Explicit protocol) turned on See sample session logs below. If I turn OFF encryption (plain FTP), I can download the file consistently with no errors.

I also installed WS FTP Pro and configured it to use FTP SSL/TLS Explicit, and I am able to download the same file consistently with no errors.

Are there any other configuration parameters that I should be using specifically when connecting to an FTP server on a mainframe using FTP SSL/TLS Explicit? Any ideas will be greatly appreciated.

Thanks.


The following is a log of a successful download.

********************************************************************************

[20090608 00:33:18] SmartFTP FTP Library v1.5.17.47
[20090608 00:33:18] Resolving host name "FTPSERVER"
[20090608 00:33:18] Connecting to 192.168.1.1 Port: 21
[20090608 00:33:18] Connected to FTPSERVER.
[20090608 00:33:18] 220-FTPD1 IBM FTP CS V1R9 at FTP.SERVER.DOM, 17:33:31 on 2009-06-07.
[20090608 00:33:18] 220 Connection will close if idle for more than 10 minutes.
[20090608 00:33:18] AUTH TLS
[20090608 00:33:18] 234 Security environment established - ready for negotiation
[20090608 00:33:19] Connected. Exchanging encryption keys...
[20090608 00:33:19] Session Cipher: 168 bit 3DES
[20090608 00:33:19] TLS encrypted session established.
[20090608 00:33:19] Command channel protection set to Private.
[20090608 00:33:19] PBSZ 0
[20090608 00:33:19] 200 Protection buffer size accepted
[20090608 00:33:19] USER FTPUSER
[20090608 00:33:19] 331 Send password please.
[20090608 00:33:19] PASS (hidden)
[20090608 00:33:19] 230 FTPUSER is logged on. Working directory is "FTPUSER.".
[20090608 00:33:19] SYST
[20090608 00:33:19] 215 MVS is the operating system of this server. FTP Server is running on z/OS.
[20090608 00:33:19] Detected Server Type: MVS
[20090608 00:33:19] RTT: 2.613 ms
[20090608 00:33:19] FEAT
[20090608 00:33:19] 211- Extensions supported
[20090608 00:33:19] SIZE
[20090608 00:33:19] AUTH TLS
[20090608 00:33:19] PBSZ
[20090608 00:33:19] PROT
[20090608 00:33:19] 211 End
[20090608 00:33:19] TYPE I
[20090608 00:33:19] 200 Representation type is Image
[20090608 00:33:19] REST 0
[20090608 00:33:19] 504 Restart not allowed with active security mechanism
[20090608 00:33:19] PWD
[20090608 00:33:19] 257 "'FTPUSER.'" is working directory.
[20090608 00:33:19] CWD 'XXX.YY1234'
[20090608 00:33:19] 250 "XXX.YY1234." is the working directory name prefix.
[20090608 00:33:19] PWD
[20090608 00:33:19] 257 "'XXX.YY1234.'" is working directory.
[20090608 00:33:19] TYPE A
[20090608 00:33:19] 200 Representation type is Ascii NonPrint
[20090608 00:33:19] PROT P
[20090608 00:33:19] 200 Data connection protection set to private
[20090608 00:33:19] PORT 172,19,19,24,6,38
[20090608 00:33:19] 200 Port request OK.
[20090608 00:33:19] RETR TGP1234.XCR
[20090608 00:33:19] Connected. Exchanging encryption keys...
[20090608 00:33:19] 125 Sending data set XXX.YY1234.TGP1234.XCR FIXrecfm 200
[20090608 00:33:19] Session Cipher: 168 bit 3DES
[20090608 00:33:19] TLS encrypted session established.
[20090608 00:33:19] Socket receive buffer set to 32768 bytes.
[20090608 00:33:19] Socket receive buffer set to 65536 bytes.
[20090608 00:33:21] Socket receive buffer set to 131072 bytes.
[20090608 00:34:01] 105270651 bytes transferred. (2.40 MB/s) (00:00:41)
[20090608 00:34:01] 250 Transfer completed successfully.
[20090608 00:34:01] QUIT
[20090608 00:34:01] 221 Quit command received. Goodbye.
[20090608 00:34:01] Client closed the connection.



********************************************************************************



The following is a log of a failed download.

********************************************************************************

[20090608 00:34:16] SmartFTP FTP Library v1.5.17.47
[20090608 00:34:16] Resolving host name "FTPSERVER"
[20090608 00:34:16] Connecting to 192.168.1.1 Port: 21
[20090608 00:34:16] Connected to FTPSERVER.
[20090608 00:34:16] 220-FTPD1 IBM FTP CS V1R9 at FTP.SERVER.DOM, 17:34:28 on 2009-06-07.
[20090608 00:34:16] 220 Connection will close if idle for more than 10 minutes.
[20090608 00:34:16] AUTH TLS
[20090608 00:34:16] 234 Security environment established - ready for negotiation
[20090608 00:34:16] Connected. Exchanging encryption keys...
[20090608 00:34:16] Session Cipher: 168 bit 3DES
[20090608 00:34:16] TLS encrypted session established.
[20090608 00:34:16] Command channel protection set to Private.
[20090608 00:34:16] PBSZ 0
[20090608 00:34:16] 200 Protection buffer size accepted
[20090608 00:34:16] USER FTPUSER
[20090608 00:34:16] 331 Send password please.
[20090608 00:34:16] PASS (hidden)
[20090608 00:34:16] 230 FTPUSER is logged on. Working directory is "FTPUSER.".
[20090608 00:34:16] SYST
[20090608 00:34:16] 215 MVS is the operating system of this server. FTP Server is running on z/OS.
[20090608 00:34:16] Detected Server Type: MVS
[20090608 00:34:16] RTT: 2.703 ms
[20090608 00:34:16] FEAT
[20090608 00:34:16] 211- Extensions supported
[20090608 00:34:16] SIZE
[20090608 00:34:16] AUTH TLS
[20090608 00:34:16] PBSZ
[20090608 00:34:16] PROT
[20090608 00:34:16] 211 End
[20090608 00:34:16] TYPE I
[20090608 00:34:16] 200 Representation type is Image
[20090608 00:34:16] REST 0
[20090608 00:34:16] 504 Restart not allowed with active security mechanism
[20090608 00:34:16] PWD
[20090608 00:34:16] 257 "'FTPUSER.'" is working directory.
[20090608 00:34:16] CWD 'XXX.YY1234'
[20090608 00:34:16] 250 "XXX.YY1234." is the working directory name prefix.
[20090608 00:34:16] PWD
[20090608 00:34:16] 257 "'XXX.YY1234.'" is working directory.
[20090608 00:34:16] TYPE A
[20090608 00:34:16] 200 Representation type is Ascii NonPrint
[20090608 00:34:16] PROT P
[20090608 00:34:16] 200 Data connection protection set to private
[20090608 00:34:16] PORT 172,19,19,24,6,44
[20090608 00:34:16] 200 Port request OK.
[20090608 00:34:16] RETR TGP1234.XCR
[20090608 00:34:16] Connected. Exchanging encryption keys...
[20090608 00:34:16] 125 Sending data set XXX.YY1234.TGP1234.XCR FIXrecfm 200
[20090608 00:34:16] Session Cipher: 168 bit 3DES
[20090608 00:34:16] TLS encrypted session established.
[20090608 00:34:16] Socket receive buffer set to 32768 bytes.
[20090608 00:34:16] Socket receive buffer set to 65536 bytes.
[20090608 00:34:58] Transfer Timeout (30s). Closing data connection.
[20090608 00:34:58] 27312207 bytes transferred. (637 KB/s) (00:00:41)
[20090608 00:34:58] 451 Transfer aborted: send error.
[20090608 00:34:58] QUIT
[20090608 00:34:58] 221 Quit command received. Goodbye.
[20090608 00:34:58] Client closed the connection.

Did you check the server logs? Because the server throws an error:
[20090608 00:34:58] 451 Transfer aborted: send error.

The mainframe folks ran a packet trace on the mainframe to see what is going on, and sent the trace to IBM support. Here is what they have to say:


*******************************************************************************
Hi,

The packet trace confirms my original suspicions.

Exerpt from packet trace:

A I a 1122978958 1547400449 23192 0 0.000251
A I a 1122978958 1547403185 20456 0 0.000311
A I a 1122978958 1547405921 17720 0 0.000177
A I a 1122978958 1547408657 14984 0 0.000264
A I a 1122978958 1547411329 12312 0 0.000429
A I a 1122978958 1547414065 9576 0 0.000117
A I a 1122978958 1547416457 7184 0 0.000252
A I a 1122978958 1547419537 4104 0 0.000195
A I a 1122978958 1547422273 1368 0 0.000256
A I a 1122978958 1547423641 0 0 0.154429
AP O p 1547423641 1122978958 32768 1 0.537495
A I z 1122978958 1547423641 0 0 0.000749
AP O r 1547423641 1122978958 32768 1 1.107836
A I z 1122978958 1547423641 0 0 0.000879
AP O r 1547423641 1122978958 32768 1 2.047645
A I z 1122978958 1547423641 0 0 0.000746
AP O r 1547423641 1122978958 32768 1 4.152154
A I z 1122978958 1547423641 0 0 0.000700
AP O r 1547423641 1122978958 32768 1 8.014510
A I z 1122978958 1547423641 0 0 0.000643
A R I z 1122978958 1547423641 0 0 13.350844

The 3rd column of numbers is the window size which we can see going to 0 for the remote side. It looks as if the remote partner can't keep up with the transfer. The remote side eventually resets the connection.

I see multiple times in the trace that the remote side gets hung up and a period of retransmits and floods of ACKs from the remote side come in.

I would investigate with the remote parter as to why they aren't being able to keep up with the transfer.

Let me know if you have any questions or would like me to clarify anything further.

Thanks

*******************************************************************************


We see this intermittent problem only when the encryption is ON. It seems that since the client (component) has to decrypt the received packets is not able to keep up with the file transfers.

Is there a property that we need to set in order for the component to keep up with the transfers.

Thanks

Can you test it with the SmartFTP client?
Then to disable the dynamic tcp window size. Go to the Performance dialog in the favorite properties and disable the Auto Tuning for Receive.

Regards,
Mat

I tested using the latest SmartFTP client and I seem to ba able to download the file consistently. This is on both having AutoTuneReceiveBuffer setting checked or unchecked.

I tried to Set AutoReceiveBufferSize to disabled in my program, but that did not seem to help.

I did try to Set DataTransferSpeedLimit to 1024*1024 and this seem to work better. It's not 100% consistent but the download success rate is much better.

My next question is what is the SmartFTP client doing differently. I am using a programming platform where you don't write lines of codes so I can't post my source code. But here is the sequence of COM object calls I use to invoke the library:

1. Load FTPConnectionMTA object
2. Load Global object

3. Call LoadLicenseKeyData method
4. Set Host property
5. Set Username
6. Set Password
7. Set HidePassword (true)
8. Set Protocol (2)
9. Set Passive (false)
10. Set Logfile (conditional based on program swtich for debugging)

11. Call Connect

12. Call InitializeTransfer
13. Set DataTransferSpeedLimit (1MB/s)
14. Call DownloadFile

15. Get LastReply (IF DownloadFile returned error)

16. Call Disconnect

I just added 12 and 13 in my development environment. Are there other settings the SmartFTP client setting differently from what I have, Any recommendations will definitely be appreciated as this problem has been getting much attention.

Thanks

Oopps. I missed some of the steps. Here it is again:


1. Load FTPConnectionMTA object
2. Load Global object

3. Call LoadLicenseKeyData method
4. Set Host property
5. Set Username
6. Set Password
7. Set HidePassword (true)
8. Set Protocol (2)
9. Set Passive (false)
10. Set Logfile (conditional based on program swtich for debugging)

11. Call Connect

12. Call ChangeDirectory
13. Set DataTransferType (based on file extension)
14. Set DataProtection (2)

12. Call InitializeTransfer
13. Set DataTransferSpeedLimit (1MB/s)
14. Call DownloadFile

15. Get LastReply (IF DownloadFile returned error)

16. Call Disconnect

SmartFTP doesn't do anything different. It uses the same component. Did the DataTransfer SpeedLimit help or did you have this before because I strongly discourage you from setting a limit.

The call to InitializeTransfer is not necessary.

Regards,
Mat

I just added the DataTransferSpeedLimit for testing and it seem to help a bit. I also just added the InitializeTransfer since I saw it in the SmartFTP client log.

The main problem is when we turn on the encryption is when we get the intermittent download failures. I thought that slowing down the transmission will help since it seems that the component is choking up at higher speeds. Any thoughts on this?

Also, I noticed that there is a Cache setting on the client that says Use Default. What does this correspond to in the component and do you think this would help?

Thanks.

Hello ..

I'm not sure what you are doing in your application so I cannot comment whether your application is causing the slow down. What language are you using?
If you are using VB6 or VBScript etc try to set TransferProgressEventInterval property to 10000.

The cache setting is irrelevant.

Regards,
Mat

We are using a tool caled Magic eDeveloper. We are not really doing anything special in the application.

I just tried that setting TransferProgressEventInterval and it didn't seem to make a difference.

What are the different properties that might affect data transfers, that we could tweak? If you could provide some info on how these properties affect the transfers, like the Auto Tune Receive Buffers you suggested changing in the client.

If we need to buy a license for the latest version of the library, we will, if it will help us solve this problem we are having with encrytion turned on, because this is a BIG requirement for the application and something we can't do without.

Please contact our sales department (sales@smartftp.com) for the maintenance renewal. Your current maintenance plan (technical support) has expired.

Thank you
Regards,
Mat