Search code examples
clinuxloggingglibcrsyslog

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?


Solution

  • 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 ...