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