How to log to /var/log/mail.log using rsyslogd?

I am currently playing around with logging under Linux. I have made the following very simple test application (in plain C):

#include <syslog.h>

int main(int argc, char **argv)
{
  openlog("mytest", (LOG_PID | LOG_NDELAY), LOG_MAIL);

  syslog(LOG_MAKEPRI(LOG_MAIL, LOG_ERR), "Test");

  return(0);
}

This “application” compiles, and when I execute it, it generates an entry in /var/log/syslog, but no entry in /var/log/mail.log and no entry in /var/log/mail.err.

Could somebody please explain why?

I am using rsyslogd on the test machine; this is the configuration from /etc/rsyslog.conf (please note that /etc/rsyslog.d is just empty, and that I have stripped out all comments and lines which clearly don’t have anything to do with the problem):

:msg,startswith, " fetching user_deny" ~
:msg,startswith, " seen_db: user " ~
auth,authpriv.*                 /var/log/auth.log
*.*;auth,authpriv.none          -/var/log/syslog
daemon.*                        -/var/log/daemon.log
kern.*                          -/var/log/kern.log
lpr.*                           -/var/log/lpr.log
mail.*                          -/var/log/mail.log
user.*                          -/var/log/user.log

mail.info                       -/var/log/mail.info
mail.warn                       -/var/log/mail.warn
mail.err                        /var/log/mail.err

*.=debug;
        auth,authpriv.none;
        news.none;mail.none     -/var/log/debug
*.=info;*.=notice;*.=warn;
        auth,authpriv.none;
        cron,daemon.none;
        mail,news.none          -/var/log/messages

*.emerg                         :omusrmsg:*

daemon.*;mail.*;
        news.err;
        *.=debug;*.=info;
        *.=notice;*.=warn       |/dev/xconsole

As far as I have understood from reading man rsyslog.conf, that configuration should make rsyslogd write messages for LOG_MAIL with priority LOG_ERR to /var/log/mail.err. I am somewhat mistrustful regarding the lines where the file path has a - prepended, though. I don’t know what this means because I could not find any hint in the manual.

So what is going wrong?

Answer

I hate answering my own question, but I think I have found a bug either in the documentation or in the source of glibc, and I’d like to have it documented for future visitors of this question.

From https://www.gnu.org/software/libc/manual/html_node/syslog_003b-vsyslog.html#syslog_003b-vsyslog (as per the time of this writing):

syslog submits the message with the facility and priority indicated by facility_priority. The macro LOG_MAKEPRI generates a facility/priority from a facility and a priority, as in the following example:

LOG_MAKEPRI(LOG_USER, LOG_WARNING)

Now look at some code from syslog.h as it resides on my test machine (Debian wheezy, up-to-date, no custom patches, non-relevant parts stripped out):

/*
 * priorities/facilities are encoded into a single 32-bit quantity, where the
 * bottom 3 bits are the priority (0-7) and the top 28 bits are the facility
 * (0-big number).  Both the priorities and the facilities map roughly
 * one-to-one to strings in the syslogd(8) source code.  This mapping is
 * included in this file.
 *
 * priorities (these are ordered)
 */
#define LOG_EMERG   0   /* system is unusable */
#define LOG_ALERT   1   /* action must be taken immediately */
#define LOG_CRIT    2   /* critical conditions */
#define LOG_ERR     3   /* error conditions */
#define LOG_WARNING 4   /* warning conditions */
#define LOG_NOTICE  5   /* normal but significant condition */
#define LOG_INFO    6   /* informational */
#define LOG_DEBUG   7   /* debug-level messages */

#define LOG_MAKEPRI(fac, pri)   (((fac) << 3) | (pri))

/* facility codes */
#define LOG_KERN    (0<<3)  /* kernel messages */
#define LOG_USER    (1<<3)  /* random user-level messages */
#define LOG_MAIL    (2<<3)  /* mail system */
#define LOG_DAEMON  (3<<3)  /* system daemons */
#define LOG_AUTH    (4<<3)  /* security/authorization messages */
#define LOG_SYSLOG  (5<<3)  /* messages generated internally by syslogd */
#define LOG_LPR     (6<<3)  /* line printer subsystem */
#define LOG_NEWS    (7<<3)  /* network news subsystem */
#define LOG_UUCP    (8<<3)  /* UUCP subsystem */
#define LOG_CRON    (9<<3)  /* clock daemon */
#define LOG_AUTHPRIV    (10<<3) /* security/authorization messages (private) */
#define LOG_FTP     (11<<3) /* ftp daemon */

    /* other codes through 15 reserved for system use */
#define LOG_LOCAL0  (16<<3) /* reserved for local use */
#define LOG_LOCAL1  (17<<3) /* reserved for local use */
#define LOG_LOCAL2  (18<<3) /* reserved for local use */
#define LOG_LOCAL3  (19<<3) /* reserved for local use */
#define LOG_LOCAL4  (20<<3) /* reserved for local use */
#define LOG_LOCAL5  (21<<3) /* reserved for local use */
#define LOG_LOCAL6  (22<<3) /* reserved for local use */
#define LOG_LOCAL7  (23<<3) /* reserved for local use */

We are obviously having multiple problems here.

• The comment at the top: If I have 3 bottom bits, then I have 29 top bits (and not 28). But this is a minor problem.

• The facility codes are already defined as shifted-to-left by three bits. Using the macro LOG_MAKEPRI (as recommended by the manual page linked above) obviously shifts them to the left by three bits a second time, which clearly is wrong.

SOLUTION

The solution is simple: Don’t use that macro; instead, just OR the facility code and the priority code. I have tried that, and it worked. Error messages from my test programs are now logged as expected, according to the configuration of rsyslogd in /etc/rsyslog.conf.

I am quite surprised about that very obvious bug in syslog.h …