Trojans, truncated files, and timeouts

We just released the first non-beta version of our product using the SmartFTP library (1.5.7.20), and we've had a few problems I was hoping you could shed some light on.
  1. We've had two customers report that when using doing FTP transfers their antivirus/antispyware software is logging trojan horse attempts:

    This morning I used it to sync to one of our web sites. Whilst getting the folder/file lists I kept getting Norton Antivirus giving me warning messages regarding worms:-



Sample message:



	Security rule:	 Default Block Shiva Burka Trojan Horse

	Date:				 11/3/2006

	Time:				11.23



	Path:				c:\ProgramFiles\BeyondCompare\BC2.exe

	Direction:		   inbound

	Local address:	all local network adapters

	Local port:		 1600
    I'm getting bombarded with Trojan horse (SubSeven 2.1/2.2, Backdoor/Subseven, TransScout, etc) attempts whenever I have the app open.
    In this release it's possible to switch between two FTP libraries, SmartFTP and Indy 9. Our previous release only used the Indy 9 library. The first customer went back to the previous release and stopped having problems, and the second customer switched the options so it used the Indy 9 library instead of SmartFTP and the attempts stopped. Switching FTP libraries does not affect any of the connection settings (proxy, passive/active, etc), so in both cases the connection should be identical.

    Can you verify that your client library isn't infected by something, and if it isn't, have you heard of other users getting false attempts? Is there any other reason they would see the above behavior?
  2. We've had two other users report intermittent problems with the last bit of their files being truncated. Both said redownloading the files got the complete version, and both said that when they switched back to the Indy 9 library they didn't have any problems. Any suggestions for things we can have them try to track this down?
  3. The last one showed up using both libraries and also when we had them try the SmartFTP client, so I'm guessing it's a connection thing, but I was wondering if there was any way you could improve the library's handling of this situation: They're downloading large files (100-140MB) and the file downloads completely, but apparently the client never recieves the data connection disconnect, because once the file is received it just sits in DownloadFile() until the read timeout kicks in. Here's a copy of the log:

    1/5/2006 7:33:49 AM  Stat> Resolving host name "142.179.196.17"

1/5/2006 7:33:49 AM  Stat> Connecting to 142.179.196.17 Port: 21

1/5/2006 7:33:49 AM  Stat> Connected to 142.179.196.17.

1/5/2006 7:33:50 AM  Recv> 220-Serv-U FTP Server v5.1 for WinSock ready...

1/5/2006 7:33:50 AM  Recv> 220-Welcome  from 216.123.239.220 to the AAG Ftp server!!

1/5/2006 7:33:50 AM  Recv> 220-Current Local time is: 07:32:53

1/5/2006 7:33:50 AM  Recv> 220-

1/5/2006 7:33:50 AM  Recv> 220-Anonymous Access is not allowed on the AAG ftp site.

1/5/2006 7:33:50 AM  Recv> 220-

1/5/2006 7:33:50 AM  Recv> 220-If you are using Internet Explorer 5.5 - 6 to Access

1/5/2006 7:33:50 AM  Recv> 220-the Ftp Site.  To login with your supplied Username

1/5/2006 7:33:50 AM  Recv> 220-and Password, RIGHT CLICK in the browser window

1/5/2006 7:33:50 AM  Recv> 220-and select LOGIN AS and then enter your supplied

1/5/2006 7:33:50 AM  Recv> 220-Username and Password provided to you by ab AAG

1/5/2006 7:33:50 AM  Recv> 220-representative.

1/5/2006 7:33:50 AM  Recv> 220-

1/5/2006 7:33:50 AM  Recv> 220-If you are using Ftp client software, please configure

1/5/2006 7:33:50 AM  Recv> 220-the connection profile in the ftp software with the

1/5/2006 7:33:50 AM  Recv> 220-supplied Username and Password provided to you by

1/5/2006 7:33:50 AM  Recv> 220-an AAG representative.

1/5/2006 7:33:50 AM  Recv> 220-

1/5/2006 7:33:50 AM  Recv> 220-If you require assistance please e-mail ####.

1/5/2006 7:33:50 AM  Recv> 220-Thanks...

1/5/2006 7:33:50 AM  Recv> 220-

1/5/2006 7:33:50 AM  Recv> 220-

1/5/2006 7:33:50 AM  Recv> 220

1/5/2006 7:33:50 AM  Sent> USER *********

1/5/2006 7:33:50 AM  Recv> 331 User name okay, need password.

1/5/2006 7:33:50 AM  Sent> PASS *********

1/5/2006 7:33:50 AM  Recv> 230 User logged in, proceed.

1/5/2006 7:33:50 AM  Sent> SYST

1/5/2006 7:33:50 AM  Recv> 215 UNIX Type: L8

1/5/2006 7:33:50 AM  Sent> FEAT

1/5/2006 7:33:50 AM  Recv> 211-Extension supported

1/5/2006 7:33:50 AM  Recv>  CLNT

1/5/2006 7:33:51 AM  Recv>  MDTM

1/5/2006 7:33:51 AM  Recv>  MDTM YYYYMMDDHHMMSS[+-TZ];filename

1/5/2006 7:33:51 AM  Recv>  SIZE

1/5/2006 7:33:51 AM  Recv>  SITE PSWD;EXEC;SET;INDEX;ZONE;CHMOD;MSG

1/5/2006 7:33:51 AM  Recv>  REST STREAM

1/5/2006 7:33:51 AM  Recv>  XCRC filename;start;end

1/5/2006 7:33:51 AM  Recv>  MODE Z

1/5/2006 7:33:51 AM  Recv> 211 End

1/5/2006 7:33:51 AM  Stat> Detected Server Software: Serv-U 5.x/6.x

1/5/2006 7:33:51 AM  Sent> PWD

1/5/2006 7:33:51 AM  Recv> 257 "/d:/Network Shares/web-data/FTP/USERS/USERNAME" is current directory.

1/5/2006 7:34:08 AM  Sent> CWD //nt-server/gis/Production/warehouses

1/5/2006 7:34:08 AM  Recv> 250 Directory changed to //nt-server/gis/Production/warehouses

1/5/2006 7:34:08 AM  Sent> PWD 

1/5/2006 7:34:08 AM  Recv> 257 "//nt-server/gis/Production/warehouses" is current directory.

1/5/2006 7:34:08 AM  Sent> PASV

1/5/2006 7:34:08 AM  Recv> 227 Entering Passive Mode (142,179,196,17,40,1)

1/5/2006 7:34:08 AM  Stat> Opening data connection to 142.179.196.17 Port: 10241

1/5/2006 7:34:08 AM  Sent> LIST -T

1/5/2006 7:34:09 AM  Stat> 1066 bytes transferred. (4.16 KB/s) (250 ms)

1/5/2006 7:34:09 AM  Recv> 150 Opening ASCII mode data connection for /bin/ls.

1/5/2006 7:34:09 AM  Recv> 226 Transfer complete.

...

1/5/2006 7:34:12 AM  Sent> CWD //nt-server/gis/Production/warehouses

1/5/2006 7:34:12 AM  Recv> 250 Directory changed to //nt-server/gis/Production/warehouses

1/5/2006 7:34:12 AM  Sent> PWD

1/5/2006 7:34:13 AM  Recv> 257 "//nt-server/gis/Production/warehouses" is current directory.

1/5/2006 7:34:13 AM  Sent> PASV

1/5/2006 7:34:13 AM  Recv> 227 Entering Passive Mode (142,179,196,17,40,8)

1/5/2006 7:34:13 AM  Stat> Opening data connection to 142.179.196.17 Port: 10248

1/5/2006 7:34:13 AM  Sent> RETR GV_disp_utm83.mdb

1/5/2006 7:34:13 AM  Recv> 150 Opening BINARY mode data connection for GV_disp_utm83.mdb (111513600 Bytes).

1/5/2006 8:07:37 AM  Stat> 111513600 bytes transferred. (54.3 KB/s) (00:33:24)

1/5/2006 8:22:37 AM  Stat> Timeout (900s).

1/5/2006 8:22:37 AM  LocalHelp: 3

1/5/2006 8:22:37 AM  Stat> Client closed the connection.
Thank you for any help you can give.

Craig Peterson
Scooter Software

>1
False alarm. If incoming connections should be avoided use Passive Mode instead of Port Mode. Disable worm protection in AV software.

>2
We need the logs to see whats exactly going on. Connection drops are normal and your application needs to handle them correctly by reconnecting and auto resuming the broken transfers. Use SIZE to get the size of the remote file. Then restart the transfer from this position.

>3
Nothing really you can do about it beside decreasing the timeout. 900 seconds seems to be rather high. 30 seconds should be enough. Then reconnect and make sure the file has been transferred correctly. Use SIZE and XCRC if supported by the server.

Regards,
-Mat
SmartFTP

Thanks for the help. I've emailed both users about the truncated files and I'll post logs as soon as I get them.

Another minor problem: IsServerFeature(ftpServerFeatureMDTM) returns false when connected to the Cerberus FTP server (http://www.cerberusftp.com/), even though it returns MDTM as the first item in the FEAT response.

>MDTM in FEAT
A lot of servers return a non RFC compliant FEAT reply. e.g. proftpd 1.2. If you can send me the log from the FTP server I can tell you if the library has a workaround implemented. For proftpd it does.

Regards,
-Mat

Here's the log from one of the users who encountered a truncated file. The file that got truncated is artl-lok.p, which is transferred once in the middle incorrectly, and once at the end correctly. I've snipped out irrelevant bits, which is just a bunch of directory listings and downloads of other files. There's only the one connection involved for the duration of the log.

17-03-2006 8:54:57  Stat> Resolving host name "r40"

17-03-2006 8:54:57  Stat> Connecting to 172.16.100.1 Port: 21

17-03-2006 8:54:57  Stat> Connected to r40.

17-03-2006 8:54:57  Recv> 220 r40 FTP server (Version 4.1 Sun Jun 13 21:46:07 CDT 2004) ready.

17-03-2006 8:54:57  Sent> USER ********

17-03-2006 8:54:57  Recv> 331 Password required for root.

17-03-2006 8:54:57  Sent> PASS ********

17-03-2006 8:54:57  Recv> 230-Last unsuccessful login: do 16 mrt 14:08:22 2006 on /dev/pts/364 from pc9228

17-03-2006 8:54:57  Recv> 230-Last login: vr 17 mrt 08:54:26 2006 on ftp from pc0030

17-03-2006 8:54:57  Recv> 230 User ******** logged in.

17-03-2006 8:54:57  Sent> SYST

17-03-2006 8:54:57  Recv> 215 UNIX Type: L8 Version: BSD-44

17-03-2006 8:54:57  Sent> FEAT

17-03-2006 8:54:57  Recv> 500 'FEAT': command not understood.

17-03-2006 8:54:57  Sent> TYPE I

17-03-2006 8:54:57  Recv> 200 Type set to I.

17-03-2006 8:54:57  Sent> REST 0

17-03-2006 8:54:57  Recv> 350 Restarting at 0 Send STORE or RETRIEVE to initiate transfer.

17-03-2006 8:54:57  Sent> PWD

17-03-2006 8:54:57  Recv> 257 "/" is current directory.

17-03-2006 8:54:57  Sent> CWD appl/a

17-03-2006 8:54:57  Recv> 250 CWD command successful.

17-03-2006 8:54:57  Sent> PWD

17-03-2006 8:54:57  Recv> 257 "/appl/a" is current directory.

17-03-2006 8:54:57  Sent> PASV

17-03-2006 8:54:57  Recv> 227 Entering Passive Mode (172,16,100,1,141,67)

17-03-2006 8:54:57  Stat> Opening data connection to 172.16.100.1 Port: 36163

17-03-2006 8:54:57  Sent> LIST

17-03-2006 8:54:57  Recv> 150 Opening data connection for /bin/ls.

17-03-2006 8:54:57  Stat> 96851 bytes transferred. (1,16 MB/s) (79 ms)

17-03-2006 8:54:57  Recv> 226 Transfer complete.

17-03-2006 8:54:57  Sent> PASV

17-03-2006 8:54:57  Recv> 227 Entering Passive Mode (172,16,100,1,141,68)

17-03-2006 8:54:57  Stat> Opening data connection to 172.16.100.1 Port: 36164

17-03-2006 8:54:57  Sent> LIST

17-03-2006 8:54:57  Recv> 150 Opening data connection for /bin/ls.

17-03-2006 8:54:57  Stat> 96851 bytes transferred. (0,98 MB/s) (94 ms)

17-03-2006 8:54:57  Recv> 226 Transfer complete.

17-03-2006 8:54:58  Sent> TYPE A

17-03-2006 8:54:58  Recv> 200 Type set to A; form set to N.

17-03-2006 8:54:58  Sent> PASV

17-03-2006 8:54:58  Recv> 227 Entering Passive Mode (172,16,100,1,141,69)

17-03-2006 8:54:58  Stat> Opening data connection to 172.16.100.1 Port: 36165

17-03-2006 8:54:58  Sent> RETR aantalbo.p

17-03-2006 8:54:58  Recv> 150 Opening data connection for aantalbo.p (1352 bytes).

17-03-2006 8:54:58  Recv> 226 Transfer complete.

17-03-2006 8:54:58  Stat> 1385 bytes transferred. (N/A/s) (0 ms)

...

17-03-2006 8:55:00  Sent> TYPE A

17-03-2006 8:55:00  Recv> 200 Type set to A; form set to N.

17-03-2006 8:55:00  Sent> PASV

17-03-2006 8:55:00  Recv> 227 Entering Passive Mode (172,16,100,1,141,189)

17-03-2006 8:55:00  Stat> Opening data connection to 172.16.100.1 Port: 36285

17-03-2006 8:55:00  Sent> RETR artlijst.p

17-03-2006 8:55:00  Recv> 150 Opening data connection for artlijst.p (47057 bytes).

17-03-2006 8:55:00  Recv> 226 Transfer complete.

17-03-2006 8:55:00  Stat> 48270 bytes transferred. (2,87 MB/s) (16 ms)

17-03-2006 8:55:00  Sent> TYPE I

17-03-2006 8:55:00  Recv> 200 Type set to I.

17-03-2006 8:55:00  Sent> PASV

17-03-2006 8:55:00  Recv> 227 Entering Passive Mode (172,16,100,1,141,190)

17-03-2006 8:55:00  Stat> Opening data connection to 172.16.100.1 Port: 36286

17-03-2006 8:55:00  Sent> RETR artlijst.v

17-03-2006 8:55:00  Recv> 150 Opening data connection for artlijst.v (2095 bytes).

17-03-2006 8:55:00  Stat> 2095 bytes transferred. (N/A/s) (0 ms)

17-03-2006 8:55:00  Recv> 226 Transfer complete.

17-03-2006 8:55:00  Sent> TYPE A

17-03-2006 8:55:00  Recv> 200 Type set to A; form set to N.

17-03-2006 8:55:00  Sent> PASV

17-03-2006 8:55:00  Recv> 227 Entering Passive Mode (172,16,100,1,141,191)

17-03-2006 8:55:00  Stat> Opening data connection to 172.16.100.1 Port: 36287

17-03-2006 8:55:00  Sent> RETR artl-lok.p

17-03-2006 8:55:00  Recv> 150 Opening data connection for artl-lok.p (4370 bytes).

17-03-2006 8:55:00  Recv> 226 Transfer complete.

17-03-2006 8:55:00  Stat> 4096 bytes transferred. (N/A/s) (0 ms)

17-03-2006 8:55:00  Sent> PASV

17-03-2006 8:55:00  Recv> 227 Entering Passive Mode (172,16,100,1,141,192)

17-03-2006 8:55:00  Stat> Opening data connection to 172.16.100.1 Port: 36288

17-03-2006 8:55:00  Sent> RETR artl-wit.p

17-03-2006 8:55:00  Recv> 150 Opening data connection for artl-wit.p (2052 bytes).

17-03-2006 8:55:00  Stat> 2106 bytes transferred. (N/A/s) (0 ms)

17-03-2006 8:55:00  Recv> 226 Transfer complete.

...

17-03-2006 8:55:42  Sent> TYPE A

17-03-2006 8:55:42  Recv> 200 Type set to A; form set to N.

17-03-2006 8:55:42  Sent> PASV

17-03-2006 8:55:42  Recv> 227 Entering Passive Mode (172,16,100,1,145,93)

17-03-2006 8:55:42  Stat> Opening data connection to 172.16.100.1 Port: 37213

17-03-2006 8:55:42  Sent> RETR zet-marge.p

17-03-2006 8:55:42  Recv> 150 Opening data connection for zet-marge.p (1208 bytes).

17-03-2006 8:55:42  Stat> 1261 bytes transferred. (N/A/s) (0 ms)

17-03-2006 8:55:42  Recv> 226 Transfer complete.

17-03-2006 8:55:42  Sent> PASV

17-03-2006 8:55:42  Recv> 227 Entering Passive Mode (172,16,100,1,145,95)

17-03-2006 8:55:42  Stat> Opening data connection to 172.16.100.1 Port: 37215

17-03-2006 8:55:42  Sent> RETR zoekkostenpl.p

17-03-2006 8:55:42  Recv> 150 Opening data connection for zoekkostenpl.p (2082 bytes).

17-03-2006 8:55:42  Stat> 2166 bytes transferred. (8,46 kB/s) (250 ms)

17-03-2006 8:55:42  Recv> 226 Transfer complete.

17-03-2006 8:57:12  Sent> PASV

17-03-2006 8:57:12  Recv> 227 Entering Passive Mode (172,16,100,1,146,164)

17-03-2006 8:57:12  Stat> Opening data connection to 172.16.100.1 Port: 37540

17-03-2006 8:57:12  Sent> RETR artl-lok.p

17-03-2006 8:57:12  Recv> 150 Opening data connection for artl-lok.p (4370 bytes).

17-03-2006 8:57:12  Recv> 226 Transfer complete.

17-03-2006 8:57:12  Stat> 4488 bytes transferred. (292 kB/s) (15 ms)

Here's the log from the Cerberus FTP server that's having trouble with the FEAT support:
3/17/2006 11:18:16 AM  Stat> Resolving host name "192.168.184.128"

3/17/2006 11:18:16 AM  Stat> Connecting to 192.168.184.128 Port: 21

3/17/2006 11:18:16 AM  Stat> Connected to 192.168.184.128.

3/17/2006 11:18:17 AM  Recv> 220-Welcome to Cerberus FTP Server

3/17/2006 11:18:17 AM  Recv> 220 Created by Grant Averett

3/17/2006 11:18:17 AM  Sent> USER anonymous

3/17/2006 11:18:17 AM  Recv> 331 User anonymous, password please

3/17/2006 11:18:17 AM  Sent> PASS *******

3/17/2006 11:18:17 AM  Recv> 230 Password Ok, User logged in

3/17/2006 11:18:17 AM  Sent> SYST

3/17/2006 11:18:17 AM  Recv> 215 UNIX Type: L8

3/17/2006 11:18:17 AM  Sent> FEAT

3/17/2006 11:18:17 AM  Recv> 211- Additional features supported include:

3/17/2006 11:18:17 AM  Recv> 211- MDTM

3/17/2006 11:18:17 AM  Recv> 211- SIZE

3/17/2006 11:18:17 AM  Recv> 211- REST STREAM

3/17/2006 11:18:17 AM  Recv> 211- UTF8

3/17/2006 11:18:17 AM  Recv> 211- LANG EN*

3/17/2006 11:18:17 AM  Recv> 211- SITE CHMOD

3/17/2006 11:18:17 AM  Recv> 211- SITE PSWD

3/17/2006 11:18:17 AM  Recv> 211

3/17/2006 11:18:17 AM  Sent> TYPE I

3/17/2006 11:18:17 AM  Recv> 200 Type Binary

3/17/2006 11:18:17 AM  Sent> REST 0

3/17/2006 11:18:17 AM  Recv> 350 Restarting at byte offset 0. Send STOR or RETR to initiate transfer

Thanks,
Craig

>truncated transfers
Thanks. The reason a data connection gets closed before all data is transferred can have several reasons. The log doesn't give any clues why. Impossible to debug unless it's reproducible.

>FEAT
The latest version has a workaround for the non RFC compliant FEAT server reply.
https://www.smartftp.com/ftplib/download

Regards,
-Mat

The truncated files problem is intermittent, but reproduceable, and we've just had a third user report it. What information/access do you need to solve the problem?

Edit: We just got a fourth user reporting this. The one from the log above was connecting to an AIX system; the new one was connecting to a Win2K system running the Unix services packages.

Please test it again with the latest version of the FTP library.

As mentioned before you have to verify your transfers otherwise you will always end up with problems.

Regards,
SmartFTP

The new release appears to have fixed the problem. Thanks.