Illegal client handshake

[L] 200 Command okay
[L] MLSD
[L] 150 File status okay; about to open data connection.
[L] Connected. Negotiating TLSv1 session..
[L] error:1408F10B:SSL routines:SSL3_GET_RECORD:wrong version number
[L] Failed TLSv1 negotiation, disconnected
[L] 425 Illegal client handshake msg, 1
[L] List Error

The above is the error message I have recieved in past and present fresh installs of FlashFXP. I can duplicate this error on a regular basis by doing a site to site ssl enabled fxp from a DrFTPd site to another ftp site. I am able to connect and browse to the DrFTPd site fine, but usually after the first full directory in the queue has transferred, when FlashFXP tries to list the next directory, it ends up with the preceeding error. I have tried the same transfers on FTPRush and had no issues, which leads me to believe that FlashFXP should be able to handle this better.

I have looked at past posts regaurding similar issues and they usually get this error when connecting, not listing. Also, the ones getting the problem listing were not doing site to site and may have had a firewall/antivirus causing the problem (I have no software protection or Windows Firewall enabled). Also, any post that had the site to site ssl fxp issue similar to this I did not see any real resolution to... hence, I am bringing this to the table once again.

I was hoping that upgrading to 3.6 RC2 with updated ssl routines would help resolve this, but even the latest and greatest build of FlashFXP retains this issue.

Please advise, TIA

It would be very helpful to see a larger portion of your ftp session log.

drFTPD has been known to be buggy when using SSL/TLS, the most important thing is to make sure the ftp server is using the latest version of drFTPD.

FlashFXP v3.5.2 build 1213 [3.6 RC2]
Support Forums at http://forum.flashfxp.com
Report a Bug at http://bugtracker.inicom.net

WinSock 2.0 -- OpenSSL 0.9.8e 23 Feb 2007
Ident Server: Unable to listen on port 113
[L] Connecting to XXX -> DNS=XXX IP=XXX.XXX.XXX.100 PORT=999
[L] Connected to XXX
[L] AUTH TLS
[L] 234 AUTH command ok; starting SSL connection.
[L] Connected. Negotiating TLSv1 session..
[L] TLSv1 negotiation successful...
[L] TLSv1 encrypted session using cipher AES256-SHA (256 bits)
[L] PBSZ 0
[L] 200 PBSZ=0
[L] USER myusername
[L] 331 Password required for myusername.
[L] PASS (hidden)
[L] 230-User myusername logged in.
[L] 230 Free Space on Disk: 31.311 GBytes
[L] SYST
[L] 215 UNIX Type: L8
[L] FEAT
[L] 211-Extensions supported:
[L] AUTH TLS
[L] CCC
[L] CLNT
[L] CPSV
[L] EPRT
[L] EPSV
[L] MDTM
[L] MFCT
[L] MFMT
[L] MLST type*;size*;create;modify*;
[L] MODE Z
[L] PASV
[L] PBSZ
[L] PROT
[L] REST STREAM
[L] SIZE
[L] SSCN
[L] UTF8
[L] XCRC "filename" SP EP
[L] XMD5 "filename" SP EP
[L] XSHA1 "filename" SP EP
[L] 211 End.
[L] CLNT FlashFXP 3.5.2.1213
[L] 200 Noted.
[L] OPTS UTF8 ON
[L] 200 UTF8 OPTS ON
[L] PWD
[L] 257 "/" is current directory.
[L] TYPE A
[L] 200 Type set to A.
[L] MODE Z
[L] 200 Mode Z ok.
[L] PROT P
[L] 200 PROT command successful.
[L] PASV
[L] 227 Entering Passive Mode (XXX,XXX,XXX,100,234,120)
[L] Opening data connection IP: XXX.XXX.XXX.100 PORT: 60024
[L] MLSD
[L] Connected. Negotiating TLSv1 session..
[L] 150 Data connection accepted from XXX,XXX,XXX.147:63563; transfer starting.
[L] TLSv1 negotiation successful...
[L] TLSv1 encrypted session using cipher AES256-SHA (256 bits)
[L] 226-Compression : 31.91% (2.092 KBytes/6.555 KBytes).
[L] 226 Transfer ok.
[L] List Complete: 6 KB in 5.67 seconds (1.1 KB/s)
Ident Server: Unable to listen on port 113
[R] Connecting to ZZZ -> IP=XXX.XXX.XXX.223 PORT=1413
[R] Connected to ZZZ
[R] 220 DrFTPD+ 2.0 (+STABLE+) $Revision: 1761 $ http://drftpd.org
[R] AUTH TLS
[R] 234 AUTH TLS successful
[R] Connected. Negotiating TLSv1 session..
[R] TLSv1 negotiation successful...
[R] TLSv1 encrypted session using cipher EDH-DSS-DES-CBC3-SHA (168 bits)
[R] PBSZ 0
[R] 200 Command okay
[R] USER myusername
[R] 331 Password required for myusername.
[R] PASS (hidden)
[R] 230 myusername logged in successfully.
[R] SYST
[R] 215 UNIX system type.
[R] FEAT
[R] 211-Extensions supported:
[R] PRET
[R] AUTH SSL
[R] PBSZ
[R] CPSV
[R] SSCN
[R] CLNT
[R] NOOP
[R] MLST type*,x.crc32*,size*,modify*,unix.owner*,unix.grou p*,x.slaves*,x.xfertime*
[R] 211 End
[R] CLNT FlashFXP 3.5.2.1213
[R] 200 Command okay
[R] CWD /
[R] 250 Directory changed to /
[R] PWD
[R] 257 "/" is current directory
[R] TYPE A
[R] 200 Command okay
[R] PROT P
[R] 200 Command okay
[R] Listening on PORT: 60101, Waiting for connection.
[R] PORT XXX,XXX,XXX,147,234,197
[R] 200 Command okay
[R] MLSD
[R] 150 File status okay; about to open data connection.
[R] Connected. Negotiating TLSv1 session..
[R] TLSv1 negotiation successful...
[R] TLSv1 encrypted session using cipher EDH-DSS-DES-CBC3-SHA (168 bits)
[R] 226 Closing data connection
[R] List Complete: 969 bytes in 4.91 seconds (0.2 KB/s)
[R] CWD PRIVATE
[R] 250 Directory changed to /PRIVATE
[R] PWD
[R] 257 "/PRIVATE" is current directory
[R] Listening on PORT: 60102, Waiting for connection.
[R] PORT XXX,XXX,XXX,147,234,198
[R] 200 Command okay
[R] MLSD
[R] 150 File status okay; about to open data connection.
[R] Connected. Negotiating TLSv1 session..
[R] TLSv1 negotiation successful...
[R] TLSv1 encrypted session using cipher EDH-DSS-DES-CBC3-SHA (168 bits)
[R] 226 Closing data connection
[R] List Complete: 2 KB in 2.42 seconds (1.2 KB/s)
[R] CWD temp
[R] 250 Directory changed to /PRIVATE/temp
[R] PWD
[R] 257 "/PRIVATE/temp" is current directory
[R] Listening on PORT: 60103, Waiting for connection.
[R] PORT XXX,XXX,XXX,147,234,199
[R] 200 Command okay
[R] MLSD
[R] 150 File status okay; about to open data connection.
[R] Connected. Negotiating TLSv1 session..
[R] TLSv1 negotiation successful...
[R] TLSv1 encrypted session using cipher EDH-DSS-DES-CBC3-SHA (168 bits)
[R] 226 Closing data connection
[R] List Complete: 172 bytes in 3.89 seconds (0.0 KB/s)
[R] CWD /PRIVATE/temp/folder1
[R] 250 Directory changed to /PRIVATE/temp/folder1
[R] PWD
[R] 257 "/PRIVATE/temp/folder1" is current directory
[R] Listening on PORT: 60104, Waiting for connection.
[R] PORT XXX,XXX,XXX,147,234,200
[R] 200 Command okay
[R] MLSD
[R] 150 File status okay; about to open data connection.
[R] Connected. Negotiating TLSv1 session..
[R] TLSv1 negotiation successful...
[R] TLSv1 encrypted session using cipher EDH-DSS-DES-CBC3-SHA (168 bits)
[R] 226 Closing data connection
[R] List Complete: 305 bytes in 4.11 seconds (0.1 KB/s)
[L] MKD /folder1
[L] 257 "/folder1": directory created.
[L] CWD /folder1
[L] 250-CWD command successful. "/folder1" is current directory.
[L] 250 Free Space in current directory: 31 GB
[L] PWD
[L] 257 "/folder1" is current directory.
[L] PASV
[L] 227 Entering Passive Mode (XXX,XXX,XXX,100,234,98)
[L] Opening data connection IP: XXX.XXX.XXX.100 PORT: 60002
[L] MLSD
[L] Connected. Negotiating TLSv1 session..
[L] 150 Data connection accepted from XXX,XXX,XXX.147:63585; transfer starting.
[L] TLSv1 negotiation successful...
[L] TLSv1 encrypted session using cipher AES256-SHA (256 bits)
[L] 226-Compression : 55.17% (64 Bytes/116 Bytes).
[L] 226 Transfer ok.
[L] List Complete: 110 bytes in 3.44 seconds (0.0 KB/s)
[R] CWD /PRIVATE/temp/folder1/sub1
[R] 250 Directory changed to /PRIVATE/temp/folder1/sub1
[R] PWD
[R] 257 "/PRIVATE/temp/folder1/sub1" is current directory
[R] Listening on PORT: 60105, Waiting for connection.
[R] PORT XXX,XXX,XXX,147,234,201
[R] 200 Command okay
[R] MLSD

[R] 150 File status okay; about to open data connection.
[R] Connected. Negotiating TLSv1 session..
[R] TLSv1 negotiation successful...
[R] TLSv1 encrypted session using cipher EDH-DSS-DES-CBC3-SHA (168 bits)
[R] 226 Closing data connection
[R] List Complete: 138 bytes in 4.08 seconds (0.0 KB/s)
[L] MKD /folder1/sub1
[L] 257 "/folder1/sub1": directory created.
[L] CWD /folder1/sub1
[L] 250-CWD command successful. "/folder1/sub1" is current directory.
[L] 250 Free Space in current directory: 31 GB
[L] PWD
[L] 257 "/folder1/sub1" is current directory.
[L] PASV
[L] 227 Entering Passive Mode (XXX,XXX,XXX,100,234,116)
[L] Opening data connection IP: XXX.XXX.XXX.100 PORT: 60020
[L] MLSD
[L] Connected. Negotiating TLSv1 session..
[L] 150 Data connection accepted from XXX,XXX,XXX.147:63587; transfer starting.
[L] TLSv1 negotiation successful...
[L] TLSv1 encrypted session using cipher AES256-SHA (256 bits)
[L] 226-Compression : 54.68% (70 Bytes/128 Bytes).
[L] 226 Transfer ok.
[L] List Complete: 122 bytes in 2.88 seconds (0.0 KB/s)
[L] MODE S
[L] 200 Mode S ok.
[R] PRET RETR sub1.txt
[R] 200 OK, will use SLAVE2 for upcoming transfer
[R] SSCN ON
[R] 220 SSCN:CLIENT METHOD
[R] PASV
[R] 227 Entering Passive Mode (XXX,XXX,XXX,231,201,196).
[L] PORT XXX,XXX,XXX,231,201,196
[L] 200 Port command successful.
[L] STOR sub1.txt
[L] 150 Opening data connection for sub1.txt
[R] RETR sub1.txt
[R] 150 File status okay; about to open data connection from SLAVE2.
[R] 226- Checksum from transfer: 7952780b
[R] 226 Transfer complete, 7.9KB in 0.0010 seconds (7.9MB/s)
[L] 226 File received ok.
Transferred: sub1.txt 7 KB in 0.39 seconds (19.8 KB/s)
[R] CWD /PRIVATE/temp/folder1/sub2
[R] 250 Directory changed to /PRIVATE/temp/folder1/sub2
[R] PWD
[R] 257 "/PRIVATE/temp/folder1/sub2" is current directory
[R] Listening on PORT: 60106, Waiting for connection.
[R] PORT XXX,XXX,XXX,147,234,202
[R] 200 Command okay
[R] MLSD
[R] 150 File status okay; about to open data connection.
[R] Connected. Negotiating TLSv1 session..
[R] error:1408F10B:SSL routines:SSL3_GET_RECORD:wrong version number
[R] Failed TLSv1 negotiation, disconnected
[R] 425 Connection reset
[R] List Error
[R] PWD
[R] 257 "/PRIVATE/temp/folder1/sub2" is current directory
[R] Listening on PORT: 60107, Waiting for connection.
[R] PORT XXX,XXX,XXX,147,234,203
[R] 200 Command okay
[R] MLSD
[R] 150 File status okay; about to open data connection.
[R] Connected. Negotiating TLSv1 session..
[R] error:1408F10B:SSL routines:SSL3_GET_RECORD:wrong version number
[R] Failed TLSv1 negotiation, disconnected
[R] 425 Connection reset
[R] List Error
[L] CWD /folder1
[L] 250-CWD command successful. "/folder1" is current directory.
[L] 250 Free Space in current directory: 31 GB
[L] PWD
[L] 257 "/folder1" is current directory.
[L] MODE Z
[L] 200 Mode Z ok.
[L] PASV
[L] 227 Entering Passive Mode (XXX,XXX,XXX,100,234,103)
[L] Opening data connection IP: XXX.XXX.XXX.100 PORT: 60007
[L] MLSD
[L] Connected. Negotiating TLSv1 session..
[L] 150 Data connection accepted from XXX,XXX,XXX.147:63591; transfer starting.
[L] TLSv1 negotiation successful...
[L] TLSv1 encrypted session using cipher AES256-SHA (256 bits)
[L] 226-Compression : 51.94% (80 Bytes/154 Bytes).
[L] 226 Transfer ok.
[L] List Complete: 146 bytes in 4.05 seconds (0.0 KB/s)
[R] CWD /PRIVATE/temp/folder1
[R] 250 Directory changed to /PRIVATE/temp/folder1
[R] PWD
[R] 257 "/PRIVATE/temp/folder1" is current directory
[L] MODE S
[L] 200 Mode S ok.
[R] PRET RETR root.txt
[R] 200 OK, will use SLAVE1 for upcoming transfer
[R] PASV
[R] 227 Entering Passive Mode (XXX,XXX,XXX,223,128,23).
[L] PORT XXX,XXX,XXX,223,128,23
[L] 200 Port command successful.
[L] STOR root.txt
[L] 150 Opening data connection for root.txt
[R] RETR root.txt
[R] 150 File status okay; about to open data connection from SLAVE1.
[L] 226 File received ok.
[R] 226- Checksum from transfer: 7952780b
[R] 226 Transfer complete, 7.9KB in 0.0010 seconds (7.9MB/s)
Transferred: root.txt 7 KB in 0.39 seconds (19.8 KB/s)
[L] CWD /
[L] 250-CWD command successful. "/" is current directory.
[L] 250 Free Space in current directory: 31 GB
[L] PWD
[L] 257 "/" is current directory.
[L] MODE Z
[L] 200 Mode Z ok.
[L] PASV
[L] 227 Entering Passive Mode (XXX,XXX,XXX,100,234,103)
[L] Opening data connection IP: XXX.XXX.XXX.100 PORT: 60007
[L] MLSD
[L] Connected. Negotiating TLSv1 session..
[L] 150 Data connection accepted from XXX,XXX,XXX.147:63592; transfer starting.
[L] TLSv1 negotiation successful...
[L] TLSv1 encrypted session using cipher AES256-SHA (256 bits)
[L] 226-Compression : 31.94% (2.106 KBytes/6.595 KBytes).
[L] 226 Transfer ok.
[L] List Complete: 6 KB in 0.91 seconds (7.1 KB/s)
[R] CWD /PRIVATE/temp
[R] 250 Directory changed to /PRIVATE/temp
[R] PWD
[R] 257 "/PRIVATE/temp" is current directory
Transfer queue completed
Transferred 2 files totaling 15 KB in 38.86 seconds (19.8 KB/s)

INITIAL DATA ON SOURCE:
/PRIVATE/temp/folder1/root.txt
/PRIVATE/temp/folder1/sub2/
/PRIVATE/temp/folder1/sub2/sub2.txt
/PRIVATE/temp/folder1/sub1/
/PRIVATE/temp/folder1/sub1/sub1.txt

FINAL DATA ON DESTINATION:
/folder1/root.txt
/folder1/sub1/
/folder1/sub1/sub1.txt

The latest version of FlashFXP and drftpd seem to be used in the above example.

As you can see, after listing the first directory for the FXP, FlashFXP has a problem listing subsequent directories.

Before the FXP I can browse all folders on source OK. Once the FXP takes place with SSL and I get the preceeding errors and the FXP finishes, I need to reconnect to the site or I get those SSL errors when trying to list any folders.

This seems to be a very similar issue the one i reported here...
http://www.inicom.net/forum/bugtrack...acker_bugid=42

The only difference i see is that this is occuring during listing rather than file transfers, i did confirm that the bug i reported seemed to be fixed, however i do notice that the OP here is using MLSD to list which is something i never tested the fix with myself at the time.

To OP, does this still occur if you use LIST or STAT -l rather than MLSD?

To bigstar, depending on the OP's response, is it possible that when fixing the prior bug something was overlooked in regards to MLSD specifically?

Unable to do any testing myself at the moment due to a crash that will require a format to clean up properly, bug report just seemed very familiar so decided to share my thoughts.


Side note: DrFTPD stable is still pretty much the same as it has been for quite some time, the 2.0 branch gets mainly bug fixes only. I have been following and playing with the new 2.1 recode branch, but i can not recall if their have been any changes/improvements in the use of SSL/TLS transfers. However since the main dev team have been working heavily on the 2.1 branch their certainly hasnt been any changes to the 2.0 branch in that regards.

DayCuts: It's a good thing you mentioned the other listing methods, I had not tried those.

MLSD gives the error posted originally

LIST -la (PORT MODE) gives the error:
[R] LIST -al
[R] 150 File status okay; about to open data connection.
[R] Connected. Negotiating TLSv1 session..
[R] error:1408F10B:SSL routines:SSL3_GET_RECORD:wrong version number
[R] Failed TLSv1 negotiation, disconnected
[R] 425 Connection reset

LIST -la (PASV MODE): WORKS!
STAT -l: WORKS!

I also noticed that in FTPRush, I was using MLSD for directory listing. So it still works properly in FTPRush and not in FlashFXP.

It's good there is some workaround. I'm not sure if STAT -l will show all hidden files. Using PASV mode to LIST will also use PASV mode for transfers, which I get less than half the speed direct downloading vs PORT. I suppose I could make one site for FXP and one site for downloading.

None the less it still seems like a bug

Indeed, but nice job noticing the difference in port/pasv, both that and the tests with different lists methods should prove helpful in locating the source of any bugs and fixing them (or so logic would suggest which is why i asked about the other list methods).

I've been looking into this problem both from FlashFXP and from drFTPd and there appears to be ongoing SSL issues with drFTPd and some ftp clients, I'm afraid that FlashFXP is one of the problem clients. I've tried to setup drFTPd locally and after spending many many hours trying to get it to work properly I've failed to get it working. I've pretty much given up all hope of getting drFTPd to work for me locally. I've had a couple people provide me with drFTPd test sites in the past however they were only to test SSL during the connection attempt as I didn't have an actual login/password.

I don't know if there is anything I can do on my end to make things work better, OpenSSL is pretty straightforward, either its going to work or bomb and I think it might be bombing even though my code is correct due to the compatibility problems with drFTPd. If the issue is specifically limited to OpenSSL there wont be much I can do from my end, however if its within my code I'll be more than happy to try and work out a solution, but first I need some test ftp servers to test with.

bigstar, were you trying to get drftpd working on windows or on linux? i dont have any personal experience building it on windows but i can get it working fairly quickly on a linux box (or vm) and would be happy to assist. Could also give it a go on windows, being familiar with the configs and some of the code base could be helpful.

In my experience it takes longer to get jre, jdk and ant compiled (or installed in the case of windows) than it does to build and config drftpd itself.

Or if your getting any specific errors feel free to pm.

I was trying to get it working on a windows machine.