Bug 1311561 - Message is not logged to syslog when syslog_enable=yes in vsftpd.conf
Message is not logged to syslog when syslog_enable=yes in vsftpd.conf
Status: CLOSED ERRATA
Product: Fedora
Classification: Fedora
Component: vsftpd (Show other bugs)
rawhide
All Linux
low Severity low
: ---
: ---
Assigned To: Martin Sehnoutka
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2016-02-24 08:12 EST by Tomáš Hozza
Modified: 2016-07-12 19:53 EDT (History)
4 users (show)

See Also:
Fixed In Version: vsftpd-3.0.3-2.fc23
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: 1175071
Environment:
Last Closed: 2016-07-12 19:53:54 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
Fix (358 bytes, patch)
2016-02-24 08:12 EST, Tomáš Hozza
no flags Details | Diff

  None (edit)
Description Tomáš Hozza 2016-02-24 08:12:36 EST
Created attachment 1130224 [details]
Fix

This issue is present also in Fedora (I tested at least F23).

+++ This bug was initially created as a clone of Bug #1175071 +++

Description of problem:

From the man page,
---
"When syslog is enabled, any log output which would have gone to /var/log/vsftpd.log goes to the system log instead."
---
But,

"User is not in the allow user list." message is logged to /var/log/vsftpd.log when syslog_enable=no

"User is not in the allow user list." message is NOT logged to syslog when syslog_enable=yes

Version-Release number of selected component (if applicable):
vsftpd-2.2.2-13.el6_6.1.x86_64

How reproducible:

Steps to Reproduce:

Enviornment,
Red Hat Enterprise Linux Server release 6.6 (Santiago)
vsftpd-2.2.2-13.el6_6.1.x86_64

1: Enable syslog and add userlist settings to vsftpd.conf configuration file :
cat >>/etc/vsftpd/vsftpd.conf <<EOF

userlist_log=yes
userlist_deny=NO
syslog_enable=yes
EOF

2: Disable wu-ftpd style transfer log :
sed -i 's/^xferlog_std_format=YES/xferlog_std_format=NO/' /etc/vsftpd/vsftpd.conf

3: Add ftp facility to /etc/rsyslog.conf configuration file :
sed -i '/local7/a\\nftp.*    \/var\/log\/vsftpd.log' /etc/rsyslog.conf

4: service rsyslog restart ; service vsftpd restart

5: Verify that user "toto" is not in /etc/vsftpd/user_list

grep -c toto /etc/vsftpd/user_list
0

6: Check test login:
ftp localhost
Trying ::1...
Connected to localhost (127.0.0.1).
220 (vsFTPd 2.2.2)
Name (localhost:root): toto
530 Permission denied.
Login failed.
ftp> bye

7: verify that nothing has been logged in /var/log/vsftpd.log

grep -c toto /var/log/vsftpd.log

0


8:  Revert syslog_enable to default value (NO) :

sed -i 's/^syslog_enable/#&/' /etc/vsftpd/vsftpd.conf
service vsftpd restart

ftp localhost
Trying 127.0.0.1...
Connected to localhost (127.0.0.1).
220 (vsFTPd 2.2.2)
Name (localhost:root): toto
530 Permission denied.
Login failed.
ftp> bye

verify that "User is not in the allow user list." message is logged 

cat /var/log/vsftpd.log

[toto] FAIL LOGIN: Client "127.0.0.1", "User is not in the allow user list."

Conclusion :
When syslog is enabled, a message which would have gone to /var/log/vsftpd.log doesn’t go to the system log instead

Note:Also setting xferlog_std_format to YES, "User is not in the allow user list." message is not logged to /var/log/xferlog.

--- Additional comment from Tomas Hozza on 2016-02-24 12:36:25 CET ---

The issue is with syslog in general, so no log messages are print from the child process which handles the client.

When new client connects, new child process is forked to handle it. The child process opens necessary files (like user_list, ...) initializes logging (in case of other means than syslog it opens the files), then it drops privileges and calls setrlimit(RLIMIT_NOFILE, {rlim_cur=0, rlim_max=0}) = 0. This means that the process will not be able to open any new file descriptors.

When syslog is used, during the logging initialization in child process, the openlog() is called. However the LOG_NDELAY is not set as option, which means that the /dev/log socket will be opened with first call to syslog() to log some message. openlog() is called before the setrlimit() call, but the first syslog() call is done after the setrlimit() call.

In the source, the syslog() function is called correctly, however inside the function the opening of new socket fails due to previously set LIMIT_NOFILE.

This can be investigated by using the ltrace and strace tools. The snippet from strace when following the child process:

...
[pid  2668] chroot(".")                 = 0
[pid  2668] setrlimit(RLIMIT_NOFILE, {rlim_cur=0, rlim_max=0}) = 0
[pid  2668] setgid(99)                  = 0
[pid  2668] setuid(99)                  = 0
[pid  2668] setrlimit(RLIMIT_NPROC, {rlim_cur=0, rlim_max=0}) = 0
[pid  2668] rt_sigaction(SIGALRM, {0x7f8a421d8490, ~[RTMIN RT_1], SA_RESTORER, 0x7f8a40f93660}, NULL, 8) = 0
[pid  2668] alarm(300)                  = 0
[pid  2668] gettimeofday({1456313069, 206740}, NULL) = 0
[pid  2668] socket(PF_LOCAL, SOCK_DGRAM|SOCK_CLOEXEC, 0) = -1 EMFILE (Too many open files)
[pid  2668] write(0, "220 (vsFTPd 2.2.2)\r\n", 20) = 20
...

You can see that the creation of the socket used for logging fails with EMFILE.

The solution is to call openlog() with option LOG_NDELAY. This will assure, that the socket is opened before the call to setrlimit() and the logging then works just fine.
Comment 1 Fedora Admin XMLRPC Client 2016-03-03 08:30:56 EST
This package has changed ownership in the Fedora Package Database.  Reassigning to the new owner of this component.
Comment 2 Martin Sehnoutka 2016-04-14 04:42:41 EDT
Fixed in:
vsftpd-3.0.3-2.fc23

Patch:
http://pkgs.fedoraproject.org/cgit/rpms/vsftpd.git/diff/vsftpd-2.2.2-syslog.patch?h=f23
Comment 3 Fedora Update System 2016-04-14 04:45:03 EDT
vsftpd-3.0.3-2.fc23 has been submitted as an update to Fedora 23. https://bodhi.fedoraproject.org/updates/FEDORA-2016-61c40f55a7
Comment 4 Fedora Update System 2016-04-16 15:26:27 EDT
vsftpd-3.0.3-2.fc23 has been pushed to the Fedora 23 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2016-61c40f55a7
Comment 5 Fedora Update System 2016-07-12 19:53:43 EDT
vsftpd-3.0.3-2.fc23 has been pushed to the Fedora 23 stable repository. If problems still persist, please make note of it in this bug report.

Note You need to log in before you can comment on or make changes to this bug.