Home / server / Questions / 788592
Accepted
Sammitch
Asked: 2016-07-08 14:51:19 +0800 CST

Rsyslog not logging events

  • 772

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.

rsyslog.conf:

$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

rsyslog.d/*:

$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%/mail.info"
$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
mail.info               -?PerHostMailInfo
mail.warn               ?PerHostMailWarn
mail.err                ?PerHostMailErr
news.crit               ?PerHostNewsCrit
news.err                ?PerHostNewsErr
news.notice             -?PerHostNewsNotice
*.=debug;\
  auth,authpriv.none;\
  news.none;mail.none   -?PerHostDebug
*.=info;*.=notice;*.=warn;\
  auth,authpriv.none;\
  cron,daemon.none;\
  mail,news.none        -?PerHostMessages
:fromhost-ip,!isequal,"127.0.0.1" 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 127.0.0.1 --tcp --port 514 -p user.info 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("127.0.0.1")}, [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\0", 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,
linux centos syslog centos7 rsyslog

1 Answers

  1. Best Answer

    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 192.0.2.1 myproc 8710 - - %% It's time to make the do-nuts." | nc 127.0.0.1 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
    • 1