Author Topic: Issue with SFTP filezilla  (Read 14750 times)

Offline Jocko

  • Regular User
  • **
  • Posts: 40
    • View Profile
    • Alternative firmware for Lacie NWSP, ISP and Philips SPD8020
Issue with SFTP filezilla
« on: February 12, 2012, 03:51:09 pm »
Hi,

I have a problem with the sftp client filezilla.
Connection and file transfers work but unable to close the channels. They are destroyed only with the timeout ...

filezilla version 3.5.3

FTP version  : 1.3.4 with mod_sftp 0.9.8
Openssl : OpenSSL/0.9.7m

My SFTP Server Configuration
Code: [Select]
# enabling mod_sftp
<IfModule mod_sftp.c>
<virtualhost 192.168.1.100>
SFTPEngine on
SFTPLog /tmp/var/log/proftpd/proftpd.log

# Configure the server to listen on the normal SSH2 port,
Port 8022

# Configure both the RSA and DSA host keys, using the same host key
# files that dropbear uses.
SFTPHostKey /xxxx/xxxxxxxx_openssh
#SFTPHostKey /etc/ssh_host_dsa_key

#use UTF8 for all SFTP protocol versions and all clients.
SFTPClientMatch .* sftpUTF8ProtocolVersion 3

#Fix channel size for CoreFTP can not support normal channel 4GB
SFTPClientMatch "PuTTY_Local.*" channelWindowSize 2GB

#Only support SFTP protocol version 1 through 3 for WinSCP and CuteFTP
SFTPClientMatch WinSCP|ClientSftp sftpProtocolVersion 1-3

#Fix channel size for CoreFTP can not support normal channel 4GB
SFTPClientMatch CoreFTP channelWindowSize 1GB

#Fix channel size for Axway SFTP clients can not support normal channel 4GB
SFTPClientMatch .*Axway channelWindowSize 1GB

# JSch - Java Secure Channel (SSH-2.0-JSCH-0.1.39)
SFTPClientMatch "JSCH.*" channelWindowSize 1GB

#Fix for FireFTP SFTP clients
SFTPOptions PessimisticKexinit

#Allow the same number of authentication attempts as Dropbear.
MaxLoginAttempts 5

#Path of a file which will be sent to the client prior to authentication
SFTPDisplayBanner /etc/sftp_msg

<Limit LOGIN>
Order deny,allow
Allow xxxxxx
</Limit>
</virtualhost>
</IfModule>
the output of systemLog
Quote
Feb 12 16:16:16 Kappa.local proftpd[9189] 127.0.0.1: ProFTPD 1.3.4a (maint) (built Thu Feb 9 2012 21:19:20 GMT+1) standalone mode STARTUP
Feb 12 16:16:41 mod_sftp/0.9.8[9222]: using '/rw_fs/etc/dropbear/dropbear_rsa_host_key_openssh' as RSA hostkey
Feb 12 16:16:41 Kappa.local proftpd[9222] 192.168.1.100 (192.168.1.41[192.168.1.41]): SSH2 session opened.
Feb 12 16:16:41 mod_sftp/0.9.8[9222]: received client version 'SSH-2.0-PuTTY_Local:_Jan__8_2012_14:40:35'
Feb 12 16:16:41 mod_sftp/0.9.8[9222]: handling connection from SSH2 client 'PuTTY_Local:_Jan__8_2012_14:40:35'
Feb 12 16:16:41 mod_sftp/0.9.8[9222]:  + Session key exchange: diffie-hellman-group-exchange-sha1
Feb 12 16:16:41 mod_sftp/0.9.8[9222]:  + Session server hostkey: ssh-rsa
Feb 12 16:16:41 mod_sftp/0.9.8[9222]:  + Session client-to-server encryption: aes256-ctr
Feb 12 16:16:41 mod_sftp/0.9.8[9222]:  + Session server-to-client encryption: aes256-ctr
Feb 12 16:16:41 mod_sftp/0.9.8[9222]:  + Session client-to-server MAC: hmac-sha1
Feb 12 16:16:41 mod_sftp/0.9.8[9222]:  + Session server-to-client MAC: hmac-sha1
Feb 12 16:16:41 mod_sftp/0.9.8[9222]:  + Session client-to-server compression: none
Feb 12 16:16:41 mod_sftp/0.9.8[9222]:  + Session server-to-client compression: none
Feb 12 16:16:43 mod_sftp/0.9.8[9222]: sending acceptable userauth methods: password
Feb 12 16:16:43 Kappa.local proftpd[9222] 192.168.1.100 (192.168.1.41[192.168.1.41]): Preparing to chroot to directory '/share/1000'
Feb 12 16:16:43 Kappa.local proftpd[9222] 192.168.1.100 (192.168.1.41[192.168.1.41]): USER xxxx: Login successful
Feb 12 16:16:43 mod_sftp/0.9.8[9222]: sending userauth success
Feb 12 16:16:43 mod_sftp/0.9.8[9222]: user 'xxxx' authenticated via 'password' method
Feb 12 16:16:43 Kappa.local proftpd[9222] 192.168.1.100 (192.168.1.41[192.168.1.41]): USER xxxx: Login successful.
Feb 12 16:16:43 mod_sftp/0.9.8[9222]: client sent SSH_MSG_IGNORE message (9 bytes)
Feb 12 16:16:43 mod_sftp/0.9.8[9222]: unsupported 'simple@putty.projects.tartarus.org' channel requested, ignoring
Feb 12 16:16:43 mod_sftp/0.9.8[9222]: 'subsystem' channel request for 'sftp' subsystem
Feb 12 16:16:43 mod_sftp/0.9.8[9222]: using SFTP protocol version 3 for this session (channel ID 0)
Feb 12 16:26:43 Kappa.local proftpd[9222] 192.168.1.100 (192.168.1.41[192.168.1.41]): Client session idle timeout, disconnected
Feb 12 16:26:43 Kappa.local proftpd[9222] 192.168.1.100 (192.168.1.41[192.168.1.41]): SSH2 session closed.

and the trace log (attached file)
Note: no writing in the record when the client requests to close the channel.


Thanks for advance

Offline castaglia

  • Administrator
  • Support Hero
  • *****
  • Posts: 5415
    • View Profile
    • http://www.castaglia.org/
Re: Issue with SFTP filezilla
« Reply #1 on: February 12, 2012, 05:23:27 pm »
If the client doesn't request a CHANNEL_CLOSE, then it's not a server bug -- it's a client issue.  And there is no explicit requirement that clients politely send CHANNEL_CLOSE requests in the SSH RFCs.  So I'm wondering why you think it's an issue...?

Offline Jocko

  • Regular User
  • **
  • Posts: 40
    • View Profile
    • Alternative firmware for Lacie NWSP, ISP and Philips SPD8020
Re: Issue with SFTP filezilla
« Reply #2 on: February 12, 2012, 05:54:21 pm »
I will be surprised that filezilla does not send a request to close channel and it seems do it :
Code: [Select]
Status: Directory listing successful
Trace: CFileZillaEnginePrivate::ResetOperation(0)
Status: Disconnected from server
Trace: CControlSocket::DoClose(64)
Trace: CSftpControlSocket::ResetOperation(66)
Trace: CControlSocket::ResetOperation(66)
Trace: CFileZillaEnginePrivate::ResetOperation(66)
Trace: CControlSocket::DoClose(64)
Trace: CControlSocket::DoClose(64)
Trace: CFileZillaEnginePrivate::ResetOperation(0)

Offline castaglia

  • Administrator
  • Support Hero
  • *****
  • Posts: 5415
    • View Profile
    • http://www.castaglia.org/
Re: Issue with SFTP filezilla
« Reply #3 on: February 13, 2012, 03:05:22 pm »
A client's logging of its function calls is not indicative of anything it sends on the wire; I still see no evidence that your client sends a CHANNEL_CLOSE.

Offline Jocko

  • Regular User
  • **
  • Posts: 40
    • View Profile
    • Alternative firmware for Lacie NWSP, ISP and Philips SPD8020
Re: Issue with SFTP filezilla
« Reply #4 on: February 13, 2012, 07:03:45 pm »
I send a post about it in the http://forum.filezilla-project.org  ;)

Offline Jocko

  • Regular User
  • **
  • Posts: 40
    • View Profile
    • Alternative firmware for Lacie NWSP, ISP and Philips SPD8020
Re: Issue with SFTP filezilla
« Reply #5 on: February 14, 2012, 09:03:09 am »
Hi Castaglia,

I think I found the cause of not channels closing

If I disable the firewall on the client side, the channels are closed when filezilla makes a request channel_close! ;D
Filezilla needs special rules because it uses a related program "fzsftp.exe".

More detail this evening, because I have to do some further tests and it seems there are some error messages in the SFTP server Log.

Offline Jocko

  • Regular User
  • **
  • Posts: 40
    • View Profile
    • Alternative firmware for Lacie NWSP, ISP and Philips SPD8020
Re: Issue with SFTP filezilla
« Reply #6 on: February 14, 2012, 06:02:41 pm »
I made some additional tests, and I can confirm my problem was a firewall issue  ::)

Here my sftp server log upto receiving a request channel_close
Code: [Select]
Feb 14 17:11:20 mod_sftp/0.9.8[11744]: using '/rw_fs/etc/dropbear/dropbear_rsa_host_key_openssh' as RSA hostkey
Feb 14 17:11:20 mySftpserver.local proftpd[11744] 192.168.1.100 (192.168.1.41[192.168.1.41]): SSH2 session opened.
Feb 14 17:11:20 mod_sftp/0.9.8[11744]: received client version 'SSH-2.0-PuTTY_Local:_Jan__8_2012_14:40:35'
Feb 14 17:11:20 mod_sftp/0.9.8[11744]: handling connection from SSH2 client 'PuTTY_Local:_Jan__8_2012_14:40:35'
Feb 14 17:11:20 mod_sftp/0.9.8[11744]:  + Session key exchange: diffie-hellman-group-exchange-sha1
Feb 14 17:11:20 mod_sftp/0.9.8[11744]:  + Session server hostkey: ssh-rsa
Feb 14 17:11:20 mod_sftp/0.9.8[11744]:  + Session client-to-server encryption: aes256-ctr
Feb 14 17:11:20 mod_sftp/0.9.8[11744]:  + Session server-to-client encryption: aes256-ctr
Feb 14 17:11:20 mod_sftp/0.9.8[11744]:  + Session client-to-server MAC: hmac-sha1
Feb 14 17:11:20 mod_sftp/0.9.8[11744]:  + Session server-to-client MAC: hmac-sha1
Feb 14 17:11:20 mod_sftp/0.9.8[11744]:  + Session client-to-server compression: none
Feb 14 17:11:20 mod_sftp/0.9.8[11744]:  + Session server-to-client compression: none
Feb 14 17:11:30 mod_sftp/0.9.8[11744]: sending acceptable userauth methods: password
Feb 14 17:11:30 mySftpserver.local proftpd[11744] 192.168.1.100 (192.168.1.41[192.168.1.41]): Preparing to chroot to directory '/share/1000'
Feb 14 17:11:30 mySftpserver.local proftpd[11744] 192.168.1.100 (192.168.1.41[192.168.1.41]): USER mylogin: Login successful
Feb 14 17:11:30 mod_sftp/0.9.8[11744]: sending userauth success
Feb 14 17:11:30 mod_sftp/0.9.8[11744]: user 'mylogin' authenticated via 'password' method
Feb 14 17:11:30 mySftpserver.local proftpd[11744] 192.168.1.100 (192.168.1.41[192.168.1.41]): USER mylogin: Login successful.
Feb 14 17:11:30 mod_sftp/0.9.8[11744]: client sent SSH_MSG_IGNORE message (160 bytes)
Feb 14 17:11:30 mod_sftp/0.9.8[11744]: unsupported 'simple@putty.projects.tartarus.org' channel requested, ignoring
Feb 14 17:11:30 mod_sftp/0.9.8[11744]: 'subsystem' channel request for 'sftp' subsystem
Feb 14 17:11:30 mod_sftp/0.9.8[11744]: using SFTP protocol version 3 for this session (channel ID 0)
Feb 14 17:11:42 mod_sftp/0.9.8[11781]: using '/rw_fs/etc/dropbear/dropbear_rsa_host_key_openssh' as RSA hostkey
Feb 14 17:11:42 mySftpserver.local proftpd[11781] 192.168.1.100 (192.168.1.41[192.168.1.41]): SSH2 session opened.
Feb 14 17:11:42 mod_sftp/0.9.8[11781]: received client version 'SSH-2.0-PuTTY_Local:_Jan__8_2012_14:40:35'
Feb 14 17:11:42 mod_sftp/0.9.8[11781]: handling connection from SSH2 client 'PuTTY_Local:_Jan__8_2012_14:40:35'
Feb 14 17:11:42 mod_sftp/0.9.8[11781]:  + Session key exchange: diffie-hellman-group-exchange-sha1
Feb 14 17:11:42 mod_sftp/0.9.8[11781]:  + Session server hostkey: ssh-rsa
Feb 14 17:11:42 mod_sftp/0.9.8[11781]:  + Session client-to-server encryption: aes256-ctr
Feb 14 17:11:42 mod_sftp/0.9.8[11781]:  + Session server-to-client encryption: aes256-ctr
Feb 14 17:11:42 mod_sftp/0.9.8[11781]:  + Session client-to-server MAC: hmac-sha1
Feb 14 17:11:42 mod_sftp/0.9.8[11781]:  + Session server-to-client MAC: hmac-sha1
Feb 14 17:11:42 mod_sftp/0.9.8[11781]:  + Session client-to-server compression: none
Feb 14 17:11:42 mod_sftp/0.9.8[11781]:  + Session server-to-client compression: none
Feb 14 17:11:43 mod_sftp/0.9.8[11781]: sending acceptable userauth methods: password
Feb 14 17:11:43 mySftpserver.local proftpd[11781] 192.168.1.100 (192.168.1.41[192.168.1.41]): Preparing to chroot to directory '/share/1000'
Feb 14 17:11:43 mySftpserver.local proftpd[11781] 192.168.1.100 (192.168.1.41[192.168.1.41]): USER mylogin: Login successful
Feb 14 17:11:43 mod_sftp/0.9.8[11781]: sending userauth success
Feb 14 17:11:43 mod_sftp/0.9.8[11781]: user 'mylogin' authenticated via 'password' method
Feb 14 17:11:43 mySftpserver.local proftpd[11781] 192.168.1.100 (192.168.1.41[192.168.1.41]): USER mylogin: Login successful.
Feb 14 17:11:43 mod_sftp/0.9.8[11781]: client sent SSH_MSG_IGNORE message (58 bytes)
Feb 14 17:11:43 mod_sftp/0.9.8[11781]: unsupported 'simple@putty.projects.tartarus.org' channel requested, ignoring
Feb 14 17:11:43 mod_sftp/0.9.8[11781]: 'subsystem' channel request for 'sftp' subsystem
Feb 14 17:11:43 mod_sftp/0.9.8[11781]: using SFTP protocol version 3 for this session (channel ID 0)
Feb 14 17:12:18 mod_sftp/0.9.8[11781]: requested read offset (44433408 bytes) greater than size of '/Perso/Mes DVD/DVD.mdb' (44417024 bytes)
Feb 14 17:12:18 mod_sftp/0.9.8[11781]: requested read offset (44466176 bytes) greater than size of '/Perso/Mes DVD/DVD.mdb' (44417024 bytes)
...several identical lines...
Feb 14 17:12:18 mod_sftp/0.9.8[11781]: requested read offset (45449216 bytes) greater than size of '/Perso/Mes DVD/DVD.mdb' (44417024 bytes)
Feb 14 17:13:31 mod_sftp/0.9.8[11744]: error reading from client (fd 0): Connection reset by peer
Feb 14 17:13:31 mod_sftp/0.9.8[11744]: disconnecting client (Connection reset by peer)
Feb 14 17:13:31 mySftpserver.local proftpd[11744] 192.168.1.100 (192.168.1.41[192.168.1.41]): SSH2 session closed.
Feb 14 17:13:51 mod_sftp/0.9.8[11781]: error reading from client (fd 0): Connection reset by peer
Feb 14 17:13:51 mod_sftp/0.9.8[11781]: disconnecting client (Connection reset by peer)
Feb 14 17:13:51 mySftpserver.local proftpd[11781] 192.168.1.100 (192.168.1.41[192.168.1.41]): SSH2 session closed.

And a last question what mean's the lines type : "requested read offset (xxx bytes) greater than size of 'download file' (yyy)"

Thanks

Offline castaglia

  • Administrator
  • Support Hero
  • *****
  • Posts: 5415
    • View Profile
    • http://www.castaglia.org/
Re: Issue with SFTP filezilla
« Reply #7 on: February 14, 2012, 06:13:17 pm »
For the benefit of other mod_sftp users: what is the firewall in question which was causing the problem, and how did you have to configure that firewall to make the SFTP connection work better?

As for this error:

  "requested read offset (xxx bytes) greater than size of 'download file' (yyy)"

it means that your client requested that mod_sftp start reading data from the file at an offset into the file which is larger than the file is; in other words, to start reading data from past the end of the file.  This is obviously not correct.

What's interesting, however, is that that particular check in mod_sftp *is disabled in the proftpd source code that is distributed from proftpd.org*.  So it appears you might be running a modified proftpd version; not sure why.  But when mod_sftp sees such an invalid READ request, it returns an error response code to the client; it doesn't close the SFTP connection.

Offline Jocko

  • Regular User
  • **
  • Posts: 40
    • View Profile
    • Alternative firmware for Lacie NWSP, ISP and Philips SPD8020
Re: Issue with SFTP filezilla
« Reply #8 on: February 14, 2012, 06:29:03 pm »
My firewall is Comodo (last version 5.9.xxxxx)

Unfortunately, I have not yet succeeded in obtaining a correct rule.
In Comodo firewall, I set 2 TCP "In/Out" rules for the applications "fzsftp" and "filezilla" which autorize all connexions from everywhere to everywhere  and with every ports (source/destination).

But these very permissive rules are not sufficient, I must always disable the firewall. >:(

About the read error, I didn't make myself the compilation. I will ask information to the person.

Offline Jocko

  • Regular User
  • **
  • Posts: 40
    • View Profile
    • Alternative firmware for Lacie NWSP, ISP and Philips SPD8020
Re: Issue with SFTP filezilla
« Reply #9 on: February 15, 2012, 10:14:20 pm »
About the version proftpd used, the source files were downloaded from proftpd website and the configure line used as specified. No  files  were modified in the source code.

As far as I can see the check is not disabled in file "fxp.c"

For a same file downloaded, the number of this read error lines changes following the sftp client used :
0 with fireftp,
4 with winscp
32 lines with filezilla

Offline castaglia

  • Administrator
  • Support Hero
  • *****
  • Posts: 5415
    • View Profile
    • http://www.castaglia.org/
Re: Issue with SFTP filezilla
« Reply #10 on: February 16, 2012, 12:25:20 am »
Ah, I was looking at some other (similar) check in the mod_sftp code. Sorry.

Still, the error is correct -- the client is sending a request to starting reading a file at point past the end of the file.  Not sure why a client would do that.  The offset in question is determined by the client, not by the server -- so to stop seeing those error messages, you'll have to talk to the client developers.

Offline Jocko

  • Regular User
  • **
  • Posts: 40
    • View Profile
    • Alternative firmware for Lacie NWSP, ISP and Philips SPD8020
Re: Issue with SFTP filezilla
« Reply #11 on: February 16, 2012, 09:47:30 am »
Thanks Castaglia for your answer:

I put a post in the forum.filezilla-project.org forum (my post)

Offline Jocko

  • Regular User
  • **
  • Posts: 40
    • View Profile
    • Alternative firmware for Lacie NWSP, ISP and Philips SPD8020
Re: Issue with SFTP filezilla
« Reply #12 on: February 20, 2012, 12:47:31 pm »
The ping-pong play continues ...  :'(

Now FileZilla developers asks me to contact PUTTY developers because I have the same log when I use the client psftp.

Offline castaglia

  • Administrator
  • Support Hero
  • *****
  • Posts: 5415
    • View Profile
    • http://www.castaglia.org/
Re: Issue with SFTP filezilla
« Reply #13 on: February 20, 2012, 05:35:25 pm »
I'm not surprised.  Last I'd checked the FileZilla source code, I saw that it used the PuTTY client for SSH2/SFTP/SCP support.

 

sighted planning