Rsyslog not logging events

Posted on

Rsyslog not logging events – Managing your servers can streamline the performance of your team by allowing them to complete complex tasks faster. Plus, it can enable them to detect problems early on before they get out of hand and compromise your business. As a result, the risk of experiencing operational setbacks is drastically lower.

But the only way to make the most of your server management is to perform it correctly. And to help you do so, this article will share nine tips on improving your server management and fix some problem about linux, centos, centos7, syslog, rsyslog.

I’m trying to stand up a syslog server to receive events from a piece of network equipment, but I can’t seem to get it to actually log the events to disk. I can confirm that the connection is being made successfully, and that rsyslogd is getting the event, I just can’t figure out why it’s not doing anything with it. The only thing that gets logged is the startup of rsyslogd itself.

Config and debug outputs below, this was originally generated from the rsyslog chef cookbook, but I added a couple tweaks to fix the super deprecated syntax that it was complaining about.


$MaxMessageSize 2k
$PreserveFQDN off
$ModLoad imuxsock
$ModLoad imklog
$ModLoad imtcp
$InputTCPServerRun 514
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat
$RepeatedMsgReduction on
$WorkDirectory /var/spool/rsyslog
$FileOwner root
$FileGroup root
$FileCreateMode 0640
$DirCreateMode 0755
$Umask 0022
$IncludeConfig /etc/rsyslog.d/*.conf


$DirGroup root
$DirCreateMode 0755
$FileGroup root
$template PerHostAuth,"/var/log/rsyslog/%HOSTNAME%/auth.log"
$template PerHostCron,"/var/log/rsyslog/%HOSTNAME%/cron.log"
$template PerHostSyslog,"/var/log/rsyslog/%HOSTNAME%/syslog"
$template PerHostDaemon,"/var/log/rsyslog/%HOSTNAME%/daemon.log"
$template PerHostKern,"/var/log/rsyslog/%HOSTNAME%/kern.log"
$template PerHostLpr,"/var/log/rsyslog/%HOSTNAME%/lpr.log"
$template PerHostUser,"/var/log/rsyslog/%HOSTNAME%/user.log"
$template PerHostMail,"/var/log/rsyslog/%HOSTNAME%/mail.log"
$template PerHostMailInfo,"/var/log/rsyslog/%HOSTNAME%/"
$template PerHostMailWarn,"/var/log/rsyslog/%HOSTNAME%/mail.warn"
$template PerHostMailErr,"/var/log/rsyslog/%HOSTNAME%/mail.err"
$template PerHostNewsCrit,"/var/log/rsyslog/%HOSTNAME%/news.crit"
$template PerHostNewsErr,"/var/log/rsyslog/%HOSTNAME%/news.err"
$template PerHostNewsNotice,"/var/log/rsyslog/%HOSTNAME%/news.notice"
$template PerHostDebug,"/var/log/rsyslog/%HOSTNAME%/debug"
$template PerHostMessages,"/var/log/rsyslog/%HOSTNAME%/messages"
auth,authpriv.*         ?PerHostAuth
*.*;auth,authpriv.none  -?PerHostSyslog
cron.*                  ?PerHostCron
daemon.*                -?PerHostDaemon
kern.*                  -?PerHostKern
lpr.*                   -?PerHostLpr
mail.*                  -?PerHostMail
user.*                  -?PerHostUser               -?PerHostMailInfo
mail.warn               ?PerHostMailWarn
mail.err                ?PerHostMailErr
news.crit               ?PerHostNewsCrit
news.err                ?PerHostNewsErr
news.notice             -?PerHostNewsNotice
  news.none;mail.none   -?PerHostDebug
  mail,news.none        -?PerHostMessages
:fromhost-ip,!isequal,"" stop
*.info;mail.none;authpriv.none;cron.none    /var/log/messages
authpriv.*    /var/log/secure
mail.*    -/var/log/maillog
cron.*    /var/log/cron
*.emerg    :omusrmsg:*
uucp,news.crit    /var/log/spooler
local7.*    /var/log/boot.log
$SystemLogSocketName /run/systemd/journal/syslog

Test event:

logger --server --tcp --port 514 -p test

strace -f of rsyslogd receiving the event, but doing nothing:

[pid 32310] accept(5, {sa_family=AF_INET, sin_port=htons(59755), sin_addr=inet_addr("")}, [16]) = 11
[pid 32310] rt_sigprocmask(SIG_BLOCK, [HUP], ~[KILL STOP TTIN RTMIN RT_1], 8) = 0
[pid 32310] open("/etc/hosts", O_RDONLY|O_CLOEXEC) = 12
[pid 32310] fstat(12, {st_mode=S_IFREG|0644, st_size=451, ...}) = 0
[pid 32310] mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb290d18000
[pid 32310] read(12, "#n# This file is managed by Chef"..., 4096) = 451
[pid 32310] close(12)                   = 0
[pid 32310] munmap(0x7fb290d18000, 4096) = 0
[pid 32310] rt_sigprocmask(SIG_SETMASK, ~[KILL STOP TTIN RTMIN RT_1], NULL, 8) = 0
[pid 32310] fcntl(11, F_GETFL)          = 0x2 (flags O_RDWR)
[pid 32310] fcntl(11, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 32310] epoll_ctl(10, EPOLL_CTL_ADD, 11, {EPOLLIN, {u32=2147497424, u64=140404628403664}}) = 0
[pid 32310] epoll_wait(10, {{EPOLLIN, {u32=2147497424, u64=140404628403664}}}, 128, -1) = 1
[pid 32310] recvfrom(11, "<14>Jul  7 22:41:54 stack: test", 131072, MSG_DONTWAIT, NULL, NULL) = 32
[pid 32310] gettimeofday({1467931314, 137777}, NULL) = 0
[pid 32310] epoll_wait(10, {{EPOLLIN, {u32=2147497424, u64=140404628403664}}}, 128, -1) = 1
[pid 32310] recvfrom(11, "", 131072, MSG_DONTWAIT, NULL, NULL) = 0
[pid 32310] epoll_ctl(10, EPOLL_CTL_DEL, 11, {EPOLLIN, {u32=2147497424, u64=140404628403664}}) = 0
[pid 32310] close(11)                   = 0
[pid 32310] epoll_wait(10,

Solution :

You know what the problem is? logger.

However logger tries to format the message it sends over the network is broken.

I cannot comprehend how such a simple utility can be broken.

I’ve wasted an entire day trying to debug a perfectly valid config.

Here’s a test that isn’t broken and won’t waste your life:

echo "<165>1 2003-08-24T05:14:15.000003-07:00 myproc 8710 - - %% It's time to make the do-nuts." | nc 514

edit: Now that it’s a day later and I’m no longer visibly upset I’ve gone back and compared the message sent by logger and the one above that I pulled from the RFC. The message generated by logger is:

<14>Jul  8 16:39:08 user: test

Which is just hilariously wrong. The proper, equivalent message would be:

<14>1 2016-07-08T16:39:08.000000-07:00 syslog-01 myproc - - - user: test

Leave a Reply

Your email address will not be published. Required fields are marked *