Couple of months ago I really had a strange situation ,the ftp client suddenly was not be able to login to the ftp server (vsftpd) and not to mention to put and get data. All this while it works.
Since the setup was in the customer premise, I need to find out what went wrong, first they told me that they replace the old firewall to a brand new, aha.. could that be the culprit?
Details of my environment:
1) There were a FTP server (vsftpd) running on RHEL 6.5.
- selinux enabled
- SSL enabled and that makes the communication and file transfer in an encrypted form hence the connection being used is ftpes
- passive port enabled, the control port is port 21 tcp and range of 30000-30100 tcp for data port.
Clik Here for more explanation on active vs passive ftp.
2) 2 FTP clients namely IBM data power (an appliance) and Filezilla ftp client on Windows
The connection illustration below shows three Agencies, I name it Agency-A, Agency-B and Agency-X being the ftp clients. They all are at different sites on different network and different firewalls.
Lets focus on Agency-x to Agency-A connection, since the issue was between them.
Below are the steps I used to find the root cause:
1) Testing made behind firewall in Agency-A between the client and server works fine.
2) Now, from Agency-x to Agency-A, there were three set of test I used:
A) use default setting with ssl enabled (ftpes) - failed
B) disabled ssl (configured in vsftpd) - success
C) telnet to port 21 and randomly port 30000-30100 - success, means firewall not blocking the tcp ports.
Could that be the setting in vsftpd, I don't think so since it worked previously, however let get more information from the log.
On the vsftpd.conf, I enabled the debug_ssl option, for a complete of the configuration, lets look the following:
anonymous_enable=NO
local_enable=YES
write_enable=YES
local_umask=022
dirmessage_enable=YES
xferlog_enable=NO
connect_from_port_20=YES
xferlog_file=/var/log/xferlog
xferlog_std_format=YES
ftpd_banner=Welcome to server FTP service.
chroot_local_user=YES
listen=YES
pam_service_name=vsftpd
userlist_enable=YES
tcp_wrappers=YES
ssl_enable=YES
allow_anon_ssl=NO
force_local_data_ssl=YES
force_local_logins_ssl=YES
ssl_tlsv1=YES
ssl_sslv2=NO
ssl_sslv3=NO
ssl_ciphers=HIGH
require_ssl_reuse=NO
ssl_request_cert=no
rsa_cert_file=/etc/vsftpd/server.crt
rsa_private_key_file=/etc/vsftpd/server.key
pasv_enable=YES
pasv_min_port=30000
pasv_max_port=30100
dual_log_enable=YES
log_ftp_protocol=YES
vsftpd_log_file=/var/log/vsftpd.log
xferlog_enable=YES
xferlog_std_format=NO
xferlog_file=/var/log/xferlog
debug_ssl=yes
Now, lets look at the vsftpd.log entries
05:54:52 2015 [pid 20383] CONNECT: Client "10.x.x.x"
Thu Jan 22 05:54:52 2015 [pid 20383] FTP response: Client "10.x.x.x", "220 Welcome to server FTP service."
Thu Jan 22 05:54:52 2015 [pid 20383] FTP command: Client "10.x.x.x", "AUTH TLS"
Thu Jan 22 05:54:52 2015 [pid 20383] FTP response: Client "10.x.x.x", "234 Proceed with negotiation."
Thu Jan 22 05:54:52 2015 [pid 20383] DEBUG: Client "10.x.x.x", "SSL_accept failed: error:00000000:lib(0):func(0):reason(0)"
"DEBUG: Client "10.x.x.x", "SSL_accept failed: error:00000000:lib(0):func(0):reason(0)"
Above line indicate something wrong with the SSL, literally it says "Hey FTP Server, I am the client, since you require ssl connection then I need your certificate to continue hand shaking, but I am not getting it"
Well then who is interrupting or denying the handshake ??
It took me few days to google information, what could be root cause, the hunting for clues brought me to this search:
"http://www.experts-exchange.com/Software/Internet_Email/File_Sharing/Q_22690366.html"
As I have subscription with Redhat, I opened a case and that tooks sometime for Redhat support engineer to trace, from the trace it notice that the client terminate the connection, but why?
strace output:
~~~
16966 write(0, "234 Proceed with negotiation.\r\n", 31) = 31 <0.000034>
16966 read(0, 0x7f6fb88c5d30, 11) = -1 ECONNRESET (Connection reset by peer) <0.003219> <<---
16966 brk(0x7f6fb88fa000) = 0x7f6fb88fa000 <0.000031>
16966 fcntl(4, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}) = 0 <0.000072>
16966 write(4, "Fri Jan 23 17:01:34 2015 [pid 16"..., 127) = 127 <0.000067>
16966 fcntl(4, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0 <0.000018>
16966 fcntl(0, F_GETFL) = 0x2 (flags O_RDWR) <0.000023>
16966 fcntl(0, F_SETFL, O_RDWR|O_NONBLOCK) = 0 <0.000017>
16966 write(0, "500 OOPS: ", 10) = -1 EPIPE (Broken pipe) <0.000022>
16966 --- SIGPIPE (Broken pipe) @ 0 (0) ---
16966 rt_sigreturn(0xd) = -1 EPIPE (Broken pipe) <0.000016>
16966 write(0, "error:00000000:lib(0):func(0):re"..., 39) = -1 EPIPE (Broken pipe) <0.000017>
16966 --- SIGPIPE (Broken pipe) @ 0 (0) ---
~~~
As soon as vsftpd server proceeds with SSL connection, client terminates the connection. Here we can see connection reset by peer.
Now, the last thing to check is the firewall itself. To make the long story short, I met the firewall guy and ask him to check if there indicators in the firewall log, but it was not there, no nothing about firewall blocking designated ports.
Again, this is not about port connectivity issue, I emphasized on checking if there rules made to deny encrypted content to pass through the firewall since protocol being used is ftpes.
Walla... finally he notice that the default setting that comes with the appliance is Intrusion Prevention System (IPS) is ENABLED and DROPPED encrypted file transfer protocol.
It took just couple of minutes for the firewall guy to configure to allow the protocol, root cause found and problem resolved !!
