Files only transfer every 30 seconds

river4

2010-11-29 03:14:07

Hello,

I am trying to connect to an ftp server but everything only seems to happen every 30 seconds (connections and file transfers). The ftp server is proftpd. I tried with coreftp and everything works fine. I have turned off firewalls and antivirus software as well. I have attached a log as well (ip address has been changed for security)

I have also turned off "Reuse Connections in Transfer Queue".

[10:19:06] SmartFTP v4.0.1140.0
[10:19:06] Resolving host name "256.67.25.196"
[10:19:06] Connecting to 256.67.25.196 Port: 21
[10:19:06] Connected to 256.67.25.196.
[10:19:36] 220 FTP Server ready.
[10:19:36] USER webadmin
[10:19:36] 331 Password required for webadmin.
[10:19:36] PASS (hidden)
[10:19:37] 230 User webadmin logged in.
[10:19:37] SYST
[10:19:37] 215 UNIX Type: L8
[10:19:37] Detected Server Type: UNIX
[10:19:37] RTT: 95.493 ms
[10:19:37] FEAT
[10:19:37] 211-Features:
[10:19:37] MDTM
[10:19:37] REST STREAM
[10:19:37] SIZE
[10:19:37] 211 End
[10:19:37] PWD
[10:19:37] 257 "/home/webadmin" is current directory.
[10:19:37] TYPE A
[10:19:37] 200 Type set to A
[10:19:37] PASV
[10:19:37] 227 Entering Passive Mode (256,67,25,196,181,95).
[10:19:37] Opening data connection to 256.67.25.196 Port: 46431
[10:19:37] LIST -aL
[10:19:37] 150 Opening ASCII mode data connection for file list
[10:19:37] 746 bytes transferred. (7.28 KB/s) (100 ms)
[10:19:37] 226 Transfer complete.
[10:19:37] MDTM .bash_history
[10:19:38] 213 20101128165451
[10:19:38] Time zone offset: 0 seconds (0.0 hours)
[10:20:08] NOOP
[10:20:09] 200 NOOP command successful
[10:20:09] CWD /home/webadmin/xxx.com
[10:20:09] 250 CWD command successful
[10:20:09] PWD
[10:20:09] 257 "/home/webadmin/xxx.com" is current directory.
[10:20:09] PASV
[10:20:09] 227 Entering Passive Mode (256,67,25,196,133,196).
[10:20:09] Opening data connection to 256.67.25.196 Port: 34244
[10:20:09] LIST -aL
[10:20:09] 150 Opening ASCII mode data connection for file list
[10:20:09] 1011 bytes transferred. (9.77 KB/s) (101 ms)
[10:20:10] 226 Transfer complete.
[10:20:11] CWD /home/webadmin/xxx.com/html
[10:20:11] 250 CWD command successful
[10:20:11] PWD
[10:20:12] 257 "/home/webadmin/xxx.com/html" is current directory.
[10:20:12] PASV
[10:20:12] 227 Entering Passive Mode (256,67,25,196,202,214).
[10:20:12] Opening data connection to 256.67.25.196 Port: 51926
[10:20:12] LIST -aL
[10:20:12] 150 Opening ASCII mode data connection for file list
[10:20:12] 1244 bytes transferred. (11.9 KB/s) (102 ms)
[10:20:12] 226 Transfer complete.
[10:20:13] CWD /home/webadmin/xxx.com/html/codeigniter
[10:20:13] 250 CWD command successful
[10:20:13] PWD
[10:20:13] 257 "/home/webadmin/xxx.com/html/codeigniter" is current directory.
[10:20:13] PASV
[10:20:13] 227 Entering Passive Mode (256,67,25,196,140,99).
[10:20:13] Opening data connection to 256.67.25.196 Port: 35939
[10:20:13] LIST -aL
[10:20:13] 150 Opening ASCII mode data connection for file list
[10:20:13] 577 bytes transferred. (5.69 KB/s) (99 ms)
[10:20:14] 226 Transfer complete.
[10:20:15] CWD /home/webadmin/xxx.com/html/codeigniter/application
[10:20:15] 250 CWD command successful
[10:20:15] PWD
[10:20:15] 257 "/home/webadmin/xxx.com/html/codeigniter/application" is current directory.
[10:20:15] PASV
[10:20:15] 227 Entering Passive Mode (256,67,25,196,180,16).
[10:20:15] Opening data connection to 256.67.25.196 Port: 46096
[10:20:15] LIST -aL
[10:20:16] 150 Opening ASCII mode data connection for file list
[10:20:16] 1146 bytes transferred. (9.48 KB/s) (118 ms)
[10:20:16] 226 Transfer complete.
[10:20:20] CWD /home/webadmin/xxx.com/html/codeigniter/application/controllers
[10:20:20] 250 CWD command successful
[10:20:20] PWD
[10:20:20] 257 "/home/webadmin/xxx.com/html/codeigniter/application/controllers" is current directory.
[10:20:20] PASV
[10:20:20] 227 Entering Passive Mode (256,67,25,196,135,148).
[10:20:20] Opening data connection to 256.67.25.196 Port: 34708
[10:20:20] LIST -aL
[10:20:20] 150 Opening ASCII mode data connection for file list
[10:20:20] 442 bytes transferred. (4.40 KB/s) (98 ms)
[10:20:20] 226 Transfer complete.
[10:20:42] CWD /home/webadmin/xxx.com/html/codeigniter/application/libraries
[10:20:42] 250 CWD command successful
[10:20:42] PWD
[10:20:42] 257 "/home/webadmin/xxx.com/html/codeigniter/application/libraries" is current directory.
[10:20:42] PASV
[10:20:42] 227 Entering Passive Mode (256,67,25,196,171,140).
[10:20:42] Opening data connection to 256.67.25.196 Port: 43916
[10:20:42] LIST -aL
[10:20:42] 150 Opening ASCII mode data connection for file list
[10:20:42] 957 bytes transferred. (9.16 KB/s) (102 ms)
[10:20:42] 226 Transfer complete.
[10:20:51] DELE Page.php
[10:20:51] 250 DELE command successful
[10:21:22] NOOP
[10:21:22] 200 NOOP command successful
[10:21:52] NOOP
[10:21:52] 200 NOOP command successful
[10:21:55] CWD /home/webadmin/xxx.com/html/codeigniter/application/config
[10:21:55] 250 CWD command successful
[10:21:55] PWD
[10:21:55] 257 "/home/webadmin/xxx.com/html/codeigniter/application/config" is current directory.
[10:21:55] PASV
[10:21:55] 227 Entering Passive Mode (256,67,25,196,227,37).
[10:21:55] Opening data connection to 256.67.25.196 Port: 58149
[10:21:55] LIST -aL
[10:21:55] 150 Opening ASCII mode data connection for file list
[10:21:55] 994 bytes transferred. (9.51 KB/s) (102 ms)
[10:21:55] 226 Transfer complete.
[10:21:58] TYPE I
[10:21:58] 200 Type set to I
[10:21:58] SIZE autoload.php
[10:21:58] 213 3321
[10:21:58] MDTM autoload.php
[10:21:58] 213 20101125210829
[10:21:59] The operation has been added to the Transfer Queue. Check the Transfer Queue for the status.
[10:22:02] CWD /home/webadmin/xxx.com/html/codeigniter/application/helpers
[10:22:02] 250 CWD command successful
[10:22:02] PWD
[10:22:02] 257 "/home/webadmin/xxx.com/html/codeigniter/application/helpers" is current directory.
[10:22:02] TYPE A
[10:22:03] 200 Type set to A
[10:22:03] PASV
[10:22:03] 227 Entering Passive Mode (256,67,25,196,213,86).
[10:22:03] Opening data connection to 256.67.25.196 Port: 54614
[10:22:03] LIST -aL
[10:22:03] 150 Opening ASCII mode data connection for file list
[10:22:03] 468 bytes transferred. (4.61 KB/s) (99 ms)
[10:22:03] 226 Transfer complete.
[10:22:05] DELE variable_helper.php
[10:22:05] 250 DELE command successful
[10:22:12] CWD /home/webadmin/xxx.com/html/codeigniter/application/config
[10:22:12] 250 CWD command successful
[10:22:12] PWD
[10:22:12] 257 "/home/webadmin/xxx.com/html/codeigniter/application/config" is current directory.
[10:22:12] TYPE I
[10:22:13] 200 Type set to I
[10:22:13] SIZE autoload.php
[10:22:13] 213 3321
[10:22:13] MDTM autoload.php
[10:22:13] 213 20101125210829
[10:22:14] The operation has been added to the Transfer Queue. Check the Transfer Queue for the status.
[10:22:23] SIZE autoload.php
[10:22:23] 213 3321
[10:22:23] MDTM autoload.php
[10:22:23] 213 20101125210829
[10:22:24] The operation has been added to the Transfer Queue. Check the Transfer Queue for the status.
[10:22:31] SIZE autoload.php
[10:22:32] 213 3303
[10:22:32] MDTM autoload.php
[10:22:32] 213 20101128182232
[10:23:02] NOOP
[10:23:02] 200 NOOP command successful
[10:23:03] SIZE autoload.php
[10:23:03] 213 3303
[10:23:03] MDTM autoload.php
[10:23:03] 213 20101128182303
[10:23:34] NOOP
[10:23:34] 200 NOOP command successful
[10:23:35] SIZE autoload.php
[10:23:35] 213 3303
[10:23:35] MDTM autoload.php
[10:23:35] 213 20101128182335
[10:24:06] NOOP
[10:24:06] 200 NOOP command successful
[10:24:36] NOOP
[10:24:36] 200 NOOP command successful
[10:25:11] CWD /home/webadmin/xxx.com/html/codeigniter/application/controllers/shop
[10:25:11] 250 CWD command successful
[10:25:11] PWD
[10:25:11] 257 "/home/webadmin/xxx.com/html/codeigniter/application/controllers/shop" is current directory.
[10:25:11] TYPE A
[10:25:11] 200 Type set to A
[10:25:11] PASV
[10:25:11] 227 Entering Passive Mode (256,67,25,196,131,254).
[10:25:11] Opening data connection to 256.67.25.196 Port: 33790
[10:25:11] LIST -aL
[10:25:12] 150 Opening ASCII mode data connection for file list
[10:25:12] 802 bytes transferred. (7.83 KB/s) (100 ms)
[10:25:12] 226 Transfer complete.
[10:25:13] TYPE I
[10:25:13] 200 Type set to I
[10:25:13] SIZE address.php
[10:25:13] 213 4926
[10:25:13] MDTM address.php
[10:25:13] 213 20101125210838
[10:25:14] The operation has been added to the Transfer Queue. Check the Transfer Queue for the status.
[10:25:44] NOOP
[10:25:44] 200 NOOP command successful
[10:25:46] SIZE address.php
[10:25:46] 213 4922
[10:25:46] MDTM address.php
[10:25:46] 213 20101128182546
[10:26:17] NOOP
[10:26:17] 200 NOOP command successful
[10:26:47] NOOP
[10:26:47] 200 NOOP command successful
[10:27:18] NOOP
[10:27:18] 200 NOOP command successful
[10:27:48] NOOP
[10:27:48] 200 NOOP command successful
[10:28:19] NOOP
[10:28:19] 200 NOOP command successful
[10:28:49] NOOP
[10:28:50] 200 NOOP command successful
[10:29:20] NOOP
[10:29:20] 200 NOOP command successful
[10:29:50] NOOP
[10:29:51] 200 NOOP command successful
[10:30:12] 421 No Transfer Timeout (300 seconds): closing control connection.
[10:30:12] Server closed connection
[10:36:01] Resolving host name "256.67.25.196"
[10:36:01] Connecting to 256.67.25.196 Port: 21
[10:36:01] Connected to 256.67.25.196.
[10:36:31] 220 FTP Server ready.
[10:36:31] USER webadmin
[10:36:31] 331 Password required for webadmin.
[10:36:31] PASS (hidden)
[10:36:31] 230 User webadmin logged in.
[10:36:31] SYST
[10:36:31] 215 UNIX Type: L8
[10:36:31] Detected Server Type: UNIX
[10:36:31] RTT: 95.714 ms
[10:36:31] FEAT
[10:36:31] 211-Features:
[10:36:31] MDTM
[10:36:31] REST STREAM
[10:36:31] SIZE
[10:36:31] 211 End
[10:36:31] PWD
[10:36:32] 257 "/home/webadmin" is current directory.
[10:36:32] CWD /home/webadmin/xxx.com/html/codeigniter/application/controllers/shop
[10:36:32] 250 CWD command successful
[10:36:32] PWD
[10:36:32] 257 "/home/webadmin/xxx.com/html/codeigniter/application/controllers/shop" is current directory.
[10:36:32] TYPE I
[10:36:32] 200 Type set to I
[10:36:32] SIZE test_ship_rules.php
[10:36:32] 213 1980
[10:36:32] MDTM test_ship_rules.php
[10:36:32] 213 20101125210842
[10:36:32] The operation has been added to the Transfer Queue. Check the Transfer Queue for the status.
[10:37:02] NOOP
[10:37:03] 200 NOOP command successful
[10:37:05] SIZE test_ship_rules.php
[10:37:05] 213 1972
[10:37:05] MDTM test_ship_rules.php
[10:37:05] 213 20101128183705
[10:37:35] NOOP
[10:37:35] 200 NOOP command successful
[10:38:06] NOOP
[10:38:06] 200 NOOP command successful
[10:38:08] SIZE index.php
[10:38:08] 213 902
[10:38:08] MDTM index.php
[10:38:08] 213 20101128183808
[10:38:21] CWD /home/webadmin/xxx.com/html/codeigniter/application/config
[10:38:21] 250 CWD command successful
[10:38:21] PWD
[10:38:22] 257 "/home/webadmin/xxx.com/html/codeigniter/application/config" is current directory.
[10:38:22] SIZE config.php
[10:38:22] 213 12173
[10:38:22] MDTM config.php
[10:38:22] 213 20101125210830
[10:38:24] The operation has been added to the Transfer Queue. Check the Transfer Queue for the status.
[10:38:28] CWD /home/webadmin/xxx.com/html/codeigniter/application/models
[10:38:28] 250 CWD command successful
[10:38:28] PWD
[10:38:28] 257 "/home/webadmin/xxx.com/html/codeigniter/application/models" is current directory.
[10:38:28] TYPE A
[10:38:28] 200 Type set to A
[10:38:28] PASV
[10:38:28] 227 Entering Passive Mode (256,67,25,196,145,34).
[10:38:28] Opening data connection to 256.67.25.196 Port: 37154
[10:38:28] LIST -aL
[10:38:28] 150 Opening ASCII mode data connection for file list
[10:38:28] 306 bytes transferred. (3.04 KB/s) (98 ms)
[10:38:28] 226 Transfer complete.
[10:38:29] CWD /home/webadmin/xxx.com/html/codeigniter/application/models/shop
[10:38:29] 250 CWD command successful
[10:38:29] PWD
[10:38:29] 257 "/home/webadmin/xxx.com/html/codeigniter/application/models/shop" is current directory.
[10:38:29] PASV
[10:38:29] 227 Entering Passive Mode (256,67,25,196,224,249).
[10:38:29] Opening data connection to 256.67.25.196 Port: 57593
[10:38:29] LIST -aL
[10:38:29] 150 Opening ASCII mode data connection for file list
[10:38:29] 1134 bytes transferred. (10.8 KB/s) (102 ms)
[10:38:30] 226 Transfer complete.
[10:38:32] TYPE I
[10:38:32] 200 Type set to I
[10:38:32] SIZE shp_mdl_products.php
[10:38:32] 213 322
[10:38:32] MDTM shp_mdl_products.php
[10:38:32] 213 20101125210910
[10:38:34] The operation has been added to the Transfer Queue. Check the Transfer Queue for the status.
[10:38:40] CWD /home/webadmin/xxx.com/html/codeigniter/application/controllers/shop
[10:38:40] 250 CWD command successful
[10:38:40] PWD
[10:38:40] 257 "/home/webadmin/xxx.com/html/codeigniter/application/controllers/shop" is current directory.
[10:38:40] SIZE product.php
[10:38:40] 213 2260
[10:38:40] MDTM product.php
[10:38:40] 213 20101128183840
[10:39:10] CWD /home/webadmin/xxx.com/html/codeigniter/application/models/shop
[10:39:11] 250 CWD command successful
[10:39:11] PWD
[10:39:11] 257 "/home/webadmin/xxx.com/html/codeigniter/application/models/shop" is current directory.
[10:39:11] NOOP
[10:39:11] 200 NOOP command successful
[10:39:41] NOOP
[10:39:41] 200 NOOP command successful
[10:39:43] CWD /home/webadmin/xxx.com/html/codeigniter/application/controllers/shop
[10:39:43] 250 CWD command successful
[10:39:43] PWD
[10:39:43] 257 "/home/webadmin/xxx.com/html/codeigniter/application/controllers/shop" is current directory.
[10:39:43] SIZE shipping.php
[10:39:43] 213 2230
[10:39:43] MDTM shipping.php
[10:39:43] 213 20101128183943
[10:40:14] CWD /home/webadmin/xxx.com/html/codeigniter/application/models/shop
[10:40:14] 250 CWD command successful
[10:40:14] PWD
[10:40:14] 257 "/home/webadmin/xxx.com/html/codeigniter/application/models/shop" is current directory.
[10:40:14] NOOP
[10:40:14] 200 NOOP command successful
[10:40:15] CWD /home/webadmin/xxx.com/html/codeigniter/application/controllers/shop
[10:40:15] 250 CWD command successful
[10:40:15] PWD
[10:40:15] 257 "/home/webadmin/xxx.com/html/codeigniter/application/controllers/shop" is current directory.
[10:40:15] SIZE shop.php
[10:40:15] 213 2194
[10:40:15] MDTM shop.php
[10:40:15] 213 20101128184015

mb

2010-11-29 09:48:13

Post the log from the transfer: Double click the file in the transfer queue.

river4

2010-11-29 11:39:30

Hello,

here are 2 logs from 2 file transfers:

[03:33:31] Operation Begin
[03:33:31] Resolving host name "115.23.25.196"
[03:33:31] Connecting to 115.23.25.196 Port: 21
[03:33:31] Connected to 115.23.25.196.
[03:34:01] 220 FTP Server ready.
[03:34:01] USER webadmin
[03:34:01] 331 Password required for webadmin.
[03:34:01] PASS (hidden)
[03:34:01] 230 User webadmin logged in.
[03:34:01] SYST
[03:34:01] 215 UNIX Type: L8
[03:34:01] Detected Server Type: UNIX
[03:34:01] RTT: 95.728 ms
[03:34:01] FEAT
[03:34:02] 211-Features:
[03:34:02] MDTM
[03:34:02] REST STREAM
[03:34:02] SIZE
[03:34:02] 211 End
[03:34:02] PWD
[03:34:02] 257 "/home/webadmin" is current directory.
[03:34:02] CWD /home/webadmin/xxx.com/html/codeigniter/application/config
[03:34:02] 250 CWD command successful
[03:34:02] PWD
[03:34:02] 257 "/home/webadmin/xxx.com/html/codeigniter/application/config" is current directory.
[03:34:02] TYPE I
[03:34:02] 200 Type set to I
[03:34:02] PASV
[03:34:02] 227 Entering Passive Mode (115,23,25,196,194,96).
[03:34:02] Opening data connection to 115.23.25.196 Port: 49760
[03:34:02] STOR config.php
[03:34:02] 150 Opening BINARY mode data connection for config.php
[03:34:02] 12231 bytes transferred. (97.1 KB/s) (123 ms)
[03:34:03] 226 Transfer complete.
[03:34:03] MDTM 20101128183242 config.php
[03:34:03] 550 20101128183242 config.php: No such file or directory
[03:34:03] SITE UTIME config.php 20101128183242 20101128183242 20101128183242 UTC
[03:34:03] 500 'SITE UTIME' not understood
[03:34:03] SITE UTIME 20101128183242 config.php
[03:34:03] 500 'SITE UTIME' not understood
[03:34:03] SIZE config.php
[03:34:03] 213 12231
[03:34:03] Source File Size=12231, Destination File Size=12231
[03:34:03] Operation End




[03:35:14] Operation Begin
[03:35:14] Resolving host name "115.23.25.196"
[03:35:14] Connecting to 115.23.25.196 Port: 21
[03:35:14] Connected to 115.23.25.196.
[03:35:45] 220 FTP Server ready.
[03:35:45] USER webadmin
[03:35:45] 331 Password required for webadmin.
[03:35:45] PASS (hidden)
[03:35:45] 230 User webadmin logged in.
[03:35:45] SYST
[03:35:45] 215 UNIX Type: L8
[03:35:45] Detected Server Type: UNIX
[03:35:45] RTT: 95.672 ms
[03:35:45] FEAT
[03:35:45] 211-Features:
[03:35:45] MDTM
[03:35:45] REST STREAM
[03:35:45] SIZE
[03:35:45] 211 End
[03:35:45] PWD
[03:35:45] 257 "/home/webadmin" is current directory.
[03:35:45] CWD /home/webadmin/xxx.com/html/codeigniter/application/config
[03:35:45] 250 CWD command successful
[03:35:45] PWD
[03:35:45] 257 "/home/webadmin/xxx.com/html/codeigniter/application/config" is current directory.
[03:35:45] TYPE I
[03:35:45] 200 Type set to I
[03:35:45] PASV
[03:35:45] 227 Entering Passive Mode (115,23,25,196,128,189).
[03:35:45] Opening data connection to 115.23.25.196 Port: 32957
[03:35:45] STOR database.php
[03:35:46] 150 Opening BINARY mode data connection for database.php
[03:35:46] 4764 bytes transferred. (42.2 KB/s) (110 ms)
[03:35:46] 226 Transfer complete.
[03:35:46] MDTM 20101128191544 database.php
[03:35:46] 550 20101128191544 database.php: No such file or directory
[03:35:46] SITE UTIME database.php 20101128191544 20101128191544 20101128191544 UTC
[03:35:46] 500 'SITE UTIME' not understood
[03:35:46] SITE UTIME 20101128191544 database.php
[03:35:46] 500 'SITE UTIME' not understood
[03:35:46] SIZE database.php
[03:35:46] 213 4764
[03:35:46] Source File Size=4764, Destination File Size=4764
[03:35:46] Operation End

mb

2010-11-29 15:46:36

The server takes 30 seconds to establish a connection. Most likely because the server is trying resolve your IP address with a 30s timeout. The server should not try to reverse lookup your IP address or at least use a lower timeout. This is something that can be changed in the proftpd.confg. The following two config directives need to be added:
UseReverseDNS off
IdentLookups off

river4

2010-11-29 18:21:58

thank you, that worked great!

river4

2010-11-29 18:55:54

actually, the host replied with the following, which is what they had changed to fix it. I'll post here in case it helps anyone else.

ProFTP is managed by xinetd on your VPS so I edited the file /etc/xinetd.d/xproftpd and removed USERID from it. If you look into that file, you will see the original content commented.

# LOG_ON_SUCCESS += DURATION_USERID
# LOG_ON_FAILURE += USER_ID