Ask a Question

Random Timeout on FTP connection when uploading files

+1 vote
by (220 points)

We got one customer environment on which we have temporarly problems when we try to upload files on an other ftp-server. From our internal environment there is no problem with this server and from within the customers environment with filezilla you can also transfer files without problems. So i got no idea what to do here.

i attach some debuglogfiles where you can see the problem happening.

Applies to: Rebex FTP/SSL
by (220 points)
Log with successful transfer:

...
2021-02-24 13:09:13.785 VERBOSE Ftp(2)[1] Info: Received data over control connection:
 0000 |32-30-30-20-4D-4C-53-54 20-4F-50-54-53-20-6D-6F| 200 MLST OPTS mo
 0010 |64-69-66-79-3B-70-65-72 6D-3B-73-69-7A-65-3B-74| dify;perm;size;t
 0020 |79-70-65-3B-55-4E-49-58 2E-67-72-6F-75-70-3B-55| ype;UNIX.group;U
 0030 |4E-49-58-2E-6D-6F-64-65 3B-55-4E-49-58-2E-6F-77| NIX.mode;UNIX.ow
 0040 |6E-65-72-3B-0D-0A                              | ner;..
2021-02-24 13:09:13.786 INFO Ftp(2)[1] Response: 200 MLST OPTS modify;perm;size;type;UNIX.group;UNIX.mode;UNIX.owner;
2021-02-24 13:09:13.786 INFO Ftp(2)[1] Batch: Calling Upload(string = '\\S0file\ORG\Projekte_GVim\PIM\ftp_export\SoKoExportkpl.csv', string = '.', TraversalMode = 'Recursive', TransferMethod = 'Copy', ActionOnExistingFiles = 'OverwriteOlder').
2021-02-24 13:09:13.786 DEBUG Ftp(2)[1] Batch: Executing multi-file operation: Uploading, source = '\\S0file\ORG\Projekte_GVim\PIM\ftp_export\SoKoExportkpl.csv', target = '.', TransferMethod.Copy, MoveMode.All, LinkProcessingMode.FollowLinks, ActionOnExistingFiles.OverwriteOlder.
2021-02-24 13:09:13.786 DEBUG Ftp(2)[1] Batch: Normalizing source path ('\\S0file\ORG\Projekte_GVim\PIM\ftp_export\SoKoExportkpl.csv').
2021-02-24 13:09:13.787 DEBUG Ftp(2)[1] Batch: Checking source path ('\\S0file\ORG\Projekte_GVim\PIM\ftp_export\SoKoExportkpl.csv').
2021-02-24 13:09:13.787 DEBUG Ftp(2)[1] Batch: Normalizing target path ('.').
2021-02-24 13:09:13.788 VERBOSE Ftp(2)[1] TLS: Sent TLS packet:
 0000 |17-03-03-00-05-50-57-44 0D-0A                  | .....PWD..
2021-02-24 13:09:13.788 VERBOSE Ftp(2)[1] Info: Sent data over control connection:
 0000 |50-57-44-0D-0A                                 | PWD..
2021-02-24 13:09:13.788 INFO Ftp(2)[1] Command: PWD
2021-02-24 13:09:13.802 VERBOSE Ftp(2)[1] TLS: Received TLS packet:
 0000 |17-03-03-00-22-32-35-37 20-22-2F-22-20-69-73-20| ...."257 "/" is
 0010 |74-68-65-20-63-75-72-72 65-6E-74-20-64-69-72-65| the current dire
 0020 |63-74-6F-72-79-0D-0A                           | ctory..
2021-02-24 13:09:13.803 VERBOSE Ftp(2)[1] Info: Received data over control connection:
 0000 |32-35-37-20-22-2F-22-20 69-73-20-74-68-65-20-63| 257 "/" is the c
 0010 |75-72-72-65-6E-74-20-64 69-72-65-63-74-6F-72-79| urrent directory
 0020 |0D-0A                                          | ..
2021-02-24 13:09:13.803 INFO Ftp(2)[1] Response: 257 "/" is the current directory
2021-02-24 13:09:13.803 DEBUG Ftp(2)[1] Batch: Checking target path ('/').
2021-02-24 13:09:13.803 DEBUG Ftp(2)[1] Batch: Multi-file operation started.
2021-02-24 13:09:13.804 DEBUG Ftp(2)[1] Batch: Transferring hierarchy started.
2021-02-24 13:09:13.804 DEBUG Ftp(2)[1] Batch: Processing file to transfer ('\\S0file\ORG\Projekte_GVim\PIM\ftp_export\SoKoExportkpl.csv').
2021-02-24 13:09:13.804 DEBUG Ftp(2)[1] Batch: Checking existence of target item ('/SoKoExportkpl.csv').
2021-02-24 13:09:13.804 VERBOSE Ftp(2)[1] TLS: Sent TLS packet:
 0000 |17-03-03-00-18-4D-4C-53 54-20-53-6F-4B-6F-45-78| .....MLST SoKoEx
 0010 |70-6F-72-74-6B-70-6C-2E 63-73-76-0D-0A         | portkpl.csv..
2021-02-24 13:09:13.805 VERBOSE Ftp(2)[1] Info: Sent data over control connection:
 0000 |4D-4C-53-54-20-53-6F-4B 6F-45-78-70-6F-72-74-6B| MLST SoKoExportk
 0010 |70-6C-2E-63-73-76-0D-0A                        | pl.csv..
2021-02-24 13:09:13.805 INFO Ftp(2)[1] Command: MLST SoKoExportkpl.csv
2021-02-24 13:09:13.819 VERBOSE Ftp(2)[1] TLS: Received TLS packet:
 0000 |17-03-03-00-29-32-35-30 2D-53-74-61-72-74-20-6F| ....)250-Start o
 0010 |66-20-6C-69-73-74-20-66 6F-72-20-53-6F-4B-6F-45| f list for SoKoE
 0020 |78-70-6F-72-74-6B-70-6C 2E-63-73-76-0D-0A      | xportkpl.csv..
2021-02-24 13:09:13.820 VERBOSE Ftp(2)[1] Info: Received data over control connection:
 0000 |32-35-30-2D-53-74-61-72 74-20-6F-66-20-6C-69-73| 250-Start of lis
 0010 |74-20-66-6F-72-20-53-6F 4B-6F-45-78-70-6F-72-74| t for SoKoExport
 0020 |6B-70-6C-2E-63-73-76-0D 0A                     | kpl.csv..
2021-02-24 13:09:13.820 INFO Ftp(2)[1] Response: 250-Start of list for SoKoExportkpl.csv
2021-02-24 13:09:13.820 VERBOSE Ftp(2)[1] TLS: Received TLS packet:
 0000 |17-03-03-00-7E-20-6D-6F 64-69-66-79-3D-32-30-32| ....~ modify=202
 0010 |31-30-32-32-34-31-32-30 36-34-32-3B-70-65-72-6D| 10224120642;perm
 0020 |3D-61-64-66-72-77-3B-73 69-7A-65-3D-31-35-35-34| =adfrw;size=1554
 0030 |34-37-33-35-3B-74-79-70 65-3D-66-69-6C-65-3B-55| 4735;type=file;U
 0040 |4E-49-58-2E-67-72-6F-75 70-3D-32-30-30-34-3B-55| NIX.group=2004;U
 0050 |4E-49-58-2E-6D-6F-64-65 3D-30-36-34-34-3B-55-4E| NIX.mode=0644;UN
 0060 |49-58-2E-6F-77-6E-65-72 3D-31-30-30-32-3B-20-2F| IX.owner=1002; /
 0070 |53-6F-4B-6F-45-78-70-6F 72-74-6B-70-6C-2E-63-73| SoKoExportkpl.cs
 0080 |76-0D-0A                                       | v..
2021-02-24 13:09:13.820 VERBOSE Ftp(2)[1] Info: Received data over control connection:
 0000 |20-6D-6F-64-69-66-79-3D 32-30-32-31-30-32-32-34|  modify=20210224
 0010 |31-32-30-36-34-32-3B-70 65-72-6D-3D-61-64-66-72| 120642;perm=adfr
 0020 |77-3B-73-69-7A-65-3D-31 35-35-34-34-37-33-35-3B| w;size=15544735;
 0030 |74-79-70-65-3D-66-69-6C 65-3B-55-4E-49-58-2E-67| type=file;UNIX.g
 0040 |72-6F-75-70-3D-32-30-30 34-3B-55-4E-49-58-2E-6D| roup=2004;UNIX.m
 0050 |6F-64-65-3D-30-36-34-34 3B-55-4E-49-58-2E-6F-77| ode=0644;UNIX.ow
 0060 |6E-65-72-3D-31-30-30-32 3B-20-2F-53-6F-4B-6F-45| ner=1002; /SoKoE
 0070 |78-70-6F-72-74-6B-70-6C 2E-63-73-76-0D-0A      | xportkpl.csv..
2021-02-24 13:09:13.821 INFO Ftp(2)[1] Response:  modify=20210224120642;perm=adfrw;size=15544735;type=file;UNIX.group=2004;UNIX.mode=0644;UNIX.owner=1002; /SoKoExportkpl.csv
2021-02-24 13:09:13.821 VERBOSE Ftp(2)[1] TLS: Received TLS packet:
 0000 |17-03-03-00-11-32-35-30 20-45-6E-64-20-6F-66-20| .....250 End of
 0010 |6C-69-73-74-0D-0A                              | list..
2021-02-24 13:09:13.821 VERBOSE Ftp(2)[1] Info: Received data over control connection:
 0000 |32-35-30-20-45-6E-64-20 6F-66-20-6C-69-73-74-0D| 250 End of list.
 0010 |0A                                             | .
2021-02-24 13:09:13.821 INFO Ftp(2)[1] Response: 250 End of list
2021-02-24 13:09:13.822 DEBUG Ftp(2)[1] Batch: Multi-file operation done.
2021-02-24 13:09:13.822 VERBOSE Ftp(2)[1] TLS: Sent TLS packet:
 0000 |17-03-03-00-06-51-55-49 54-0D-0A               | .....QUIT..
2021-02-24 13:09:13.822 VERBOSE Ftp(2)[1] Info: Sent data over control connection:
 0000 |51-55-49-54-0D-0A                              | QUIT..
2021-02-24 13:09:13.823 INFO Ftp(2)[1] Command: QUIT
2021-02-24 13:09:13.837 VERBOSE Ftp(2)[1] TLS: Received TLS packet:
 0000 |17-03-03-00-0E-32-32-31 20-47-6F-6F-64-62-79-65| .....221 Goodbye
 0010 |2E-0D-0A                                       | ...
2021-02-24 13:09:13.837 VERBOSE Ftp(2)[1] Info: Received data over control connection:
 0000 |32-32-31-20-47-6F-6F-64 62-79-65-2E-0D-0A      | 221 Goodbye...
2021-02-24 13:09:13.838 INFO Ftp(2)[1] Response: 221 Goodbye.
2021-02-24 13:09:13.838 DEBUG Ftp(2)[1] TLS: Closing TLS socket.
2021-02-24 13:09:13.838 INFO Ftp(2)[1] TLS: Alert Alert:Alert was sent.
2021-02-24 13:09:13.839 VERBOSE Ftp(2)[1] TLS: Sent TLS packet:
 0000 |15-03-03-00-02-01-00                           | .......
by (147k points)
It looks like the log files are missing. However, this might be a common issue where a router or firewall drops the FTP control connection that stays inactive during the transfer. To address that, try enabling the keep--alive option:

ftp.Settings.KeepAliveDuringTransfer = true;
ftp.Settings.KeepAliveDuringTransferInterval = 600; // send NOOP every 600 seconds

Also, it might be useful to check the FileZilla log to see whether it's attempting any reconnects and resuming the transfer. FileZilla is resuming transfers after failures by default.

1 Answer

0 votes
by (147k points)

We never received the log showing a failed transfer.

However, as I wrote in the comment, this might be a common issue where a router or firewall drops the FTP control connection that stays inactive during the transfer. To address that, try enabling the keep--alive option:

ftp.Settings.KeepAliveDuringTransfer = true;
ftp.Settings.KeepAliveDuringTransferInterval = 600; // send NOOP every 600 seconds

Please give this a try and let us know whether it helps. If it doesn't, please post the log.

...