Once mounted, the filesystem is extremely slow, taking as much as 20 min. to refresh. I look at the proftpd tls logs and i see that curlftpfs & my server seem to be continuously handshaking. I look at the proftpd logs and see that as soon as i successfully authenticate and login, curlftpfs is disconnected.
Here are the logs:
root@veridian:/var/log/proftpd# cat tls.log
Jan 23 22:44:05 mod_tls/2.1.1[26710]: SSL/TLS-P requested, starting TLS handshake
Jan 23 22:44:06 mod_tls/2.1.1[26710]: TLSv1/SSLv3 connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
Jan 23 22:44:08 mod_tls/2.1.1[26710]: Protection set to Private
Jan 23 22:44:09 mod_tls/2.1.1[26710]: starting TLS negotiation on data connection
Jan 23 22:44:09 mod_tls/2.1.1[26710]: TLSv1/SSLv3 data connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
Jan 23 22:44:09 mod_tls/2.1.1[26710]: starting TLS negotiation on data connection
Jan 23 22:44:10 mod_tls/2.1.1[26710]: starting TLS negotiation on data connection
Jan 23 22:44:20 mod_tls/2.1.1[26718]: SSL/TLS-P requested, starting TLS handshake
Jan 23 22:44:20 mod_tls/2.1.1[26718]: TLSv1/SSLv3 connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
Jan 23 22:44:24 mod_tls/2.1.1[26718]: Protection set to Private
Jan 23 22:44:24 mod_tls/2.1.1[26718]: starting TLS negotiation on data connection
Jan 23 22:44:24 mod_tls/2.1.1[26718]: TLSv1/SSLv3 data connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
Jan 23 22:44:34 mod_tls/2.1.1[26725]: SSL/TLS-P requested, starting TLS handshake
Jan 23 22:44:34 mod_tls/2.1.1[26725]: TLSv1/SSLv3 connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
Jan 23 22:44:37 mod_tls/2.1.1[26725]: Protection set to Private
Jan 23 22:44:37 mod_tls/2.1.1[26725]: starting TLS negotiation on data connection
Jan 23 22:44:37 mod_tls/2.1.1[26725]: TLSv1/SSLv3 data connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
Jan 23 22:44:47 mod_tls/2.1.1[26732]: SSL/TLS-P requested, starting TLS handshake
Jan 23 22:44:47 mod_tls/2.1.1[26732]: TLSv1/SSLv3 connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
Jan 23 22:44:50 mod_tls/2.1.1[26732]: Protection set to Private
...and so on
root@veridian:/var/log/proftpd# cat proftpd.log
Jan 23 22:44:05 veridian proftpd[26710] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session opened.
Jan 23 22:44:06 veridian proftpd[26710] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 31 usecs
Jan 23 22:44:08 veridian proftpd[26710] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): PAM(orbisvicis): Authentication failure.
Jan 23 22:44:08 veridian proftpd[26710] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): USER orbisvicis: Login successful.
Jan 23 22:44:08 veridian proftpd[26710] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): Preparing to chroot to directory '/home/ftp/users/orbisvicis'
Jan 23 22:44:10 veridian proftpd[26710] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session closed.
Jan 23 22:44:20 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session opened.
Jan 23 22:44:20 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 32 usecs
Jan 23 22:44:22 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): PAM(orbisvicis): Authentication failure.
Jan 23 22:44:22 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): USER orbisvicis: Login successful.
Jan 23 22:44:22 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): Preparing to chroot to directory '/home/ftp/users/orbisvicis'
Jan 23 22:44:22 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 1225379 usecs
Jan 23 22:44:24 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): notice: user orbisvicis: aborting transfer: Link to file server lost.
Jan 23 22:44:24 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session closed.
Jan 23 22:44:34 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session opened.
Jan 23 22:44:34 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 44 usecs
Jan 23 22:44:36 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): PAM(orbisvicis): Authentication failure.
Jan 23 22:44:36 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): USER orbisvicis: Login successful.
Jan 23 22:44:36 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): Preparing to chroot to directory '/home/ftp/users/orbisvicis'
Jan 23 22:44:36 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 489127 usecs
Jan 23 22:44:37 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): notice: user orbisvicis: aborting transfer: Link to file server lost.
Jan 23 22:44:37 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session closed.
Jan 23 22:44:47 veridian proftpd[26732] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session opened.
Jan 23 22:44:48 veridian proftpd[26732] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 51 usecs
Jan 23 22:44:49 veridian proftpd[26732] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): PAM(orbisvicis): Authentication failure.
Jan 23 22:44:49 veridian proftpd[26732] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): USER orbisvicis: Login successful.
Jan 23 22:44:49 veridian proftpd[26732] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): Preparing to chroot to directory '/home/ftp/users/orbisvicis'
..and so on
################################################################
However, my typical ftp client filezilla has no problems:
################################################################
root@veridian:/var/log/proftpd# cat tls.log
Jan 23 22:40:51 mod_tls/2.1.1[26614]: TLS/TLS-C requested, starting TLS handshake
Jan 23 22:40:52 mod_tls/2.1.1[26614]: TLSv1/SSLv3 connection accepted, using cipher AES128-SHA (128 bits)
Jan 23 22:41:00 mod_tls/2.1.1[26614]: Protection set to Private
Jan 23 22:41:00 mod_tls/2.1.1[26614]: starting TLS negotiation on data connection
Jan 23 22:41:00 mod_tls/2.1.1[26614]: TLSv1/SSLv3 data connection accepted, using cipher AES128-SHA (128 bits)
Jan 23 22:41:00 mod_tls/2.1.1[26614]: starting TLS negotiation on data connection
Jan 23 22:41:24 mod_tls/2.1.1[26614]: starting TLS negotiation on data connection
Jan 23 22:41:28 mod_tls/2.1.1[26614]: starting TLS negotiation on data connection
.... so on till i disconnect
root@veridian:/var/log/proftpd# cat proftpd.log
Jan 23 22:40:51 veridian proftpd[26614] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session opened.
Jan 23 22:40:57 veridian proftpd[26614] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 164 usecs
Jan 23 22:40:58 veridian proftpd[26614] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): PAM(orbisvicis): Authentication failure.
Jan 23 22:40:58 veridian proftpd[26614] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): USER orbisvicis: Login successful.
Jan 23 22:40:58 veridian proftpd[26614] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): Preparing to chroot to directory '/home/ftp/users/orbisvicis'
Jan 23 22:40:58 veridian proftpd[26614] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 1165812 usecs
Jan 23 22:43:09 veridian proftpd[26614] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session closed.
.. this is b/c i disconnected normally
#################################################################
curlftpfs connects normally, and does not throw any errors, even when -v -o ftpfs_debug -d
So basically, is there any way i can fix the issue and make the connection permanent?
In proftpd I use mod_delay, MasqueradeAddress (so that ftp clients wont freak out), sql virtual users, mod_tls with TLSProtocol SSLv23 and TLSVerifyClient off
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I connect to my proftpd server like this:
curlftpfs ftp://username:password@place.domain.net:5200 -o ssl,no_verify_peer,no_verify_hostname ~/FTP
curlftpfs -V
curlftpfs 0.9.1 libcurl/7.16.4 fuse/2.5
Ubuntu 7.10
Once mounted, the filesystem is extremely slow, taking as much as 20 min. to refresh. I look at the proftpd tls logs and i see that curlftpfs & my server seem to be continuously handshaking. I look at the proftpd logs and see that as soon as i successfully authenticate and login, curlftpfs is disconnected.
Here are the logs:
root@veridian:/var/log/proftpd# cat tls.log
Jan 23 22:44:05 mod_tls/2.1.1[26710]: SSL/TLS-P requested, starting TLS handshake
Jan 23 22:44:06 mod_tls/2.1.1[26710]: TLSv1/SSLv3 connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
Jan 23 22:44:08 mod_tls/2.1.1[26710]: Protection set to Private
Jan 23 22:44:09 mod_tls/2.1.1[26710]: starting TLS negotiation on data connection
Jan 23 22:44:09 mod_tls/2.1.1[26710]: TLSv1/SSLv3 data connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
Jan 23 22:44:09 mod_tls/2.1.1[26710]: starting TLS negotiation on data connection
Jan 23 22:44:10 mod_tls/2.1.1[26710]: starting TLS negotiation on data connection
Jan 23 22:44:20 mod_tls/2.1.1[26718]: SSL/TLS-P requested, starting TLS handshake
Jan 23 22:44:20 mod_tls/2.1.1[26718]: TLSv1/SSLv3 connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
Jan 23 22:44:24 mod_tls/2.1.1[26718]: Protection set to Private
Jan 23 22:44:24 mod_tls/2.1.1[26718]: starting TLS negotiation on data connection
Jan 23 22:44:24 mod_tls/2.1.1[26718]: TLSv1/SSLv3 data connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
Jan 23 22:44:34 mod_tls/2.1.1[26725]: SSL/TLS-P requested, starting TLS handshake
Jan 23 22:44:34 mod_tls/2.1.1[26725]: TLSv1/SSLv3 connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
Jan 23 22:44:37 mod_tls/2.1.1[26725]: Protection set to Private
Jan 23 22:44:37 mod_tls/2.1.1[26725]: starting TLS negotiation on data connection
Jan 23 22:44:37 mod_tls/2.1.1[26725]: TLSv1/SSLv3 data connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
Jan 23 22:44:47 mod_tls/2.1.1[26732]: SSL/TLS-P requested, starting TLS handshake
Jan 23 22:44:47 mod_tls/2.1.1[26732]: TLSv1/SSLv3 connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
Jan 23 22:44:50 mod_tls/2.1.1[26732]: Protection set to Private
...and so on
root@veridian:/var/log/proftpd# cat proftpd.log
Jan 23 22:44:05 veridian proftpd[26710] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session opened.
Jan 23 22:44:06 veridian proftpd[26710] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 31 usecs
Jan 23 22:44:08 veridian proftpd[26710] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): PAM(orbisvicis): Authentication failure.
Jan 23 22:44:08 veridian proftpd[26710] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): USER orbisvicis: Login successful.
Jan 23 22:44:08 veridian proftpd[26710] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): Preparing to chroot to directory '/home/ftp/users/orbisvicis'
Jan 23 22:44:10 veridian proftpd[26710] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session closed.
Jan 23 22:44:20 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session opened.
Jan 23 22:44:20 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 32 usecs
Jan 23 22:44:22 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): PAM(orbisvicis): Authentication failure.
Jan 23 22:44:22 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): USER orbisvicis: Login successful.
Jan 23 22:44:22 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): Preparing to chroot to directory '/home/ftp/users/orbisvicis'
Jan 23 22:44:22 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 1225379 usecs
Jan 23 22:44:24 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): notice: user orbisvicis: aborting transfer: Link to file server lost.
Jan 23 22:44:24 veridian proftpd[26718] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session closed.
Jan 23 22:44:34 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session opened.
Jan 23 22:44:34 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 44 usecs
Jan 23 22:44:36 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): PAM(orbisvicis): Authentication failure.
Jan 23 22:44:36 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): USER orbisvicis: Login successful.
Jan 23 22:44:36 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): Preparing to chroot to directory '/home/ftp/users/orbisvicis'
Jan 23 22:44:36 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 489127 usecs
Jan 23 22:44:37 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): notice: user orbisvicis: aborting transfer: Link to file server lost.
Jan 23 22:44:37 veridian proftpd[26725] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session closed.
Jan 23 22:44:47 veridian proftpd[26732] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session opened.
Jan 23 22:44:48 veridian proftpd[26732] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 51 usecs
Jan 23 22:44:49 veridian proftpd[26732] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): PAM(orbisvicis): Authentication failure.
Jan 23 22:44:49 veridian proftpd[26732] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): USER orbisvicis: Login successful.
Jan 23 22:44:49 veridian proftpd[26732] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): Preparing to chroot to directory '/home/ftp/users/orbisvicis'
..and so on
################################################################
However, my typical ftp client filezilla has no problems:
################################################################
root@veridian:/var/log/proftpd# cat tls.log
Jan 23 22:40:51 mod_tls/2.1.1[26614]: TLS/TLS-C requested, starting TLS handshake
Jan 23 22:40:52 mod_tls/2.1.1[26614]: TLSv1/SSLv3 connection accepted, using cipher AES128-SHA (128 bits)
Jan 23 22:41:00 mod_tls/2.1.1[26614]: Protection set to Private
Jan 23 22:41:00 mod_tls/2.1.1[26614]: starting TLS negotiation on data connection
Jan 23 22:41:00 mod_tls/2.1.1[26614]: TLSv1/SSLv3 data connection accepted, using cipher AES128-SHA (128 bits)
Jan 23 22:41:00 mod_tls/2.1.1[26614]: starting TLS negotiation on data connection
Jan 23 22:41:24 mod_tls/2.1.1[26614]: starting TLS negotiation on data connection
Jan 23 22:41:28 mod_tls/2.1.1[26614]: starting TLS negotiation on data connection
.... so on till i disconnect
root@veridian:/var/log/proftpd# cat proftpd.log
Jan 23 22:40:51 veridian proftpd[26614] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session opened.
Jan 23 22:40:57 veridian proftpd[26614] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 164 usecs
Jan 23 22:40:58 veridian proftpd[26614] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): PAM(orbisvicis): Authentication failure.
Jan 23 22:40:58 veridian proftpd[26614] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): USER orbisvicis: Login successful.
Jan 23 22:40:58 veridian proftpd[26614] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): Preparing to chroot to directory '/home/ftp/users/orbisvicis'
Jan 23 22:40:58 veridian proftpd[26614] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): mod_delay/0.5: delaying for 1165812 usecs
Jan 23 22:43:09 veridian proftpd[26614] veridian.home (::ffff:128.180.238.228[::ffff:128.180.238.228]): FTP session closed.
.. this is b/c i disconnected normally
#################################################################
curlftpfs connects normally, and does not throw any errors, even when -v -o ftpfs_debug -d
So basically, is there any way i can fix the issue and make the connection permanent?
In proftpd I use mod_delay, MasqueradeAddress (so that ftp clients wont freak out), sql virtual users, mod_tls with TLSProtocol SSLv23 and TLSVerifyClient off
im moving this