Rsyslog not logging

Dig · 09-17-2014, 11:38 AM

Hello friends

Am facing problem with rsyslog. server should receive logs from all of my network and store it in /var/log/routers/$ip.log

#rpm -qa | grep rsyslog
rsyslog-mysql-5.8.10-6.el6.x86_64
rsyslog-5.8.10-6.el6.x86_64

#cat /etc/rsyslog.conf

$template filename, "/var/log/routers/%fromhost-ip%-%fromhost%.log"
$template format, "\nHost:%fromhost%; Time:%timereported%; Message:%msg%\n"
*.* ?filename; format
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat
$ModLoad imklog
$ModLoad imuxsock
$ModLoad imudp.so # provides UDP syslog reception
$UDPServerRun 514 # start a UDP syslog server at standard port 514
*.info;mail.none;authpriv.none;cron.none /var/log/messages
authpriv.* /var/log/secure
mail.* -/var/log/maillog
cron.* /var/log/cron
*.emerg *
uucp,news.crit /var/log/spooler
local7.* /var/log/boot.log

#ls -ld /var/log/routers/
drwxrw-rw-. 2 router root 12288 Sep 15 14:49 /var/log/routers/

the problem that many routers logging not logged although i performed tcpdump and i can see the log messages normally also the local logging not logged for the server itself.

i flushed the iptables and set selinux to be permissive and still facing this issue. thanks

netnix99 · 09-17-2014, 02:09 PM

This might sound crazy, but you said that you flushed IP TABLES, but did you write a rule to allow traffic in on port 514?

Code:

iptables -A INPUT -s x.x.x.x -d x.x.x.x -p udp -m udp --dport 514 -j ACCEPT

Also, have you tried disabling the firewall, temporarily, just to see if it is still blocking the traffic? If you disable the firewall, and logging starts to occur, you might need to revisit the rule that you created. Then re-enable the firewall.

I run rsyslog on OpenBSD, but the config looks about the same except for the templates.

I think you might need to add EXECUTE privilege on the group on the routers folder, and I would remove "write" from "other".

drwxrwxr--. 2 router root 12288 Sep 15 14:49 /var/log/routers/

Habitual · 09-17-2014, 02:46 PM

does the /etc/rsyslog.conf on these routers have a

Code:

*.* @syslog_server_ip:514

in it?

Dig · 09-17-2014, 03:39 PM

Quote:

Originally Posted by netnix99

This might sound crazy, but you said that you flushed IP TABLES, but did you write a rule to allow traffic in on port 514?

Code:

iptables -A INPUT -s x.x.x.x -d x.x.x.x -p udp -m udp --dport 514 -j ACCEPT

Also, have you tried disabling the firewall, temporarily, just to see if it is still blocking the traffic? If you disable the firewall, and logging starts to occur, you might need to revisit the rule that you created. Then re-enable the firewall.

I run rsyslog on OpenBSD, but the config looks about the same except for the templates.

I think you might need to add EXECUTE privilege on the group on the routers folder, and I would remove "write" from "other".

drwxrwxr--. 2 router root 12288 Sep 15 14:49 /var/log/routers/

Thanks netnix, actually the iptables was already flushed and not working but your reply guide me to ACCEPT the traffic over port 514 to make sure that am receiving it probably. the problem is that the rsyslog not logging all the information based on the template for example the info messages not written to the router file

Dig · 09-17-2014, 03:40 PM

Quote:

Originally Posted by Habitual

does the /etc/rsyslog.conf on these routers have a

Code:

*.* @syslog_server_ip:514

in it?

It shows that from the tcpdump that log sent from the router to the rsyslog server but it didn't written to any file, router file or even the messages file.

unSpawn · 09-17-2014, 04:38 PM

Quote:

Originally Posted by Dig

Code:

$ModLoad imudp.so  # provides UDP syslog reception

No idea if it's allowed but the bold red part doesn't seem right.
*If that's not it please execute

Code:

. /etc/sysconfig/rsyslog; /bin/env RSYSLOG_DEBUG="NoLogTimeStamp" /sbin/rsyslogd $SYSLOGD_OPTIONS -d -n -N10 2>&1 | tee /tmp/rsyslogd.tee

and attach (as plaint text) or post the contents of "/tmp/rsyslogd.tee".

Quote:

Originally Posted by Dig

Code:

#ls -ld /var/log/routers/
drwxrw-rw-. 2 router root 12288 Sep 15 14:49 /var/log/routers/

Probably doesn't affect logging (as Rsyslogd starts and runs as root anyway) but removing "write" from "other" w/o execute bit set makes no sense as does having some other user own the directory. (And since you don't specify $FileOwner or $FileGroup those would default to root anyway.) I would allow only root user and group to own the directory and files. (If you have problems with that solve it later and in a different way: one problem at a time.)

Dig · 09-18-2014, 07:38 AM

Hi unSpawn, nice to see you again

Regarding directory permissions i will take look later as you said, the first related to .so it will not impact. below the output for rsyslogd.tee

Code:

7f9ef2872700: rsyslogd 5.8.10 startup, compatibility mode 5, module path '', cwd:/root
7f9ef2872700: caller requested object 'net', not found (iRet -3003)
7f9ef2872700: Requested to load module 'lmnet'
7f9ef2872700: loading module '/lib64/rsyslog/lmnet.so'
7f9ef2872700: module of type 2 being loaded.
7f9ef2872700: entry point 'isCompatibleWithFeature' not present in module
7f9ef2872700: source file conf.c requested reference for module 'lmnet', reference count now 1
7f9ef2872700: rsyslog runtime initialized, version 5.8.10, current users 1
7f9ef2872700: source file syslogd.c requested reference for module 'lmnet', reference count now 2
7f9ef2872700: GenerateLocalHostName uses 'Dig'
7f9ef2872700: omfile: using transactional output interface.
7f9ef2872700: module of type 1 being loaded.
7f9ef2872700: module of type 1 being loaded.
7f9ef2872700: entry point 'beginTransaction' not present in module
7f9ef2872700: entry point 'endTransaction' not present in module
7f9ef2872700: source file omfwd.c requested reference for module 'lmnet', reference count now 3
7f9ef2872700: module of type 1 being loaded.
7f9ef2872700: entry point 'doHUP' not present in module
7f9ef2872700: entry point 'beginTransaction' not present in module
7f9ef2872700: entry point 'endTransaction' not present in module
7f9ef2872700: module of type 1 being loaded.
7f9ef2872700: entry point 'doHUP' not present in module
7f9ef2872700: entry point 'beginTransaction' not present in module
7f9ef2872700: entry point 'endTransaction' not present in module
7f9ef2872700: module of type 1 being loaded.
7f9ef2872700: entry point 'doHUP' not present in module
7f9ef2872700: entry point 'beginTransaction' not present in module
7f9ef2872700: entry point 'endTransaction' not present in module
7f9ef2872700: module of type 1 being loaded.
7f9ef2872700: entry point 'doHUP' not present in module
7f9ef2872700: entry point 'beginTransaction' not present in module
7f9ef2872700: entry point 'endTransaction' not present in module
7f9ef2872700: rfc5424 parser init called
7f9ef2872700: GetParserName addr 0x7f9ef28998e0
7f9ef2872700: module of type 3 being loaded.
7f9ef2872700: Parser 'rsyslog.rfc5424' added to list of available parsers.
7f9ef2872700: rfc3164 parser init called
7f9ef2872700: module of type 3 being loaded.
7f9ef2872700: Parser 'rsyslog.rfc3164' added to list of available parsers.
7f9ef2872700: Parser 'rsyslog.rfc5424' added to default parser set.
7f9ef2872700: Parser 'rsyslog.rfc3164' added to default parser set.
7f9ef2872700: rsyslog standard file format strgen init called, compiled with version 5.8.10
7f9ef2872700: module of type 4 being loaded.
7f9ef2872700: entry point 'isCompatibleWithFeature' not present in module
7f9ef2872700: Strgen 'RSYSLOG_FileFormat' added to list of available strgens.
7f9ef2872700: traditional file format strgen init called, compiled with version 5.8.10
7f9ef2872700: module of type 4 being loaded.
7f9ef2872700: entry point 'isCompatibleWithFeature' not present in module
7f9ef2872700: Strgen 'RSYSLOG_TraditionalFileFormat' added to list of available strgens.
7f9ef2872700: rsyslog standard (network) forward format strgen init called, compiled with version 5.8.10
7f9ef2872700: module of type 4 being loaded.
7f9ef2872700: entry point 'isCompatibleWithFeature' not present in module
7f9ef2872700: Strgen 'RSYSLOG_ForwardFormat' added to list of available strgens.
7f9ef2872700: rsyslog traditional (network) forward format strgen init called, compiled with version 5.8.10
7f9ef2872700: module of type 4 being loaded.
7f9ef2872700: entry point 'isCompatibleWithFeature' not present in module
7f9ef2872700: Strgen 'RSYSLOG_TraditionalForwardFormat' added to list of available strgens.
7f9ef2872700: deque option n, optarg ''
7f9ef2872700: deque option N, optarg '10'
rsyslogd: version 5.8.10, config validation run (level 10), master config /etc/rsyslog.conf
7f9ef2872700: template bound to strgen 'RSYSLOG_FileFormat'
7f9ef2872700: template bound to strgen 'RSYSLOG_TraditionalFileFormat'
7f9ef2872700: template bound to strgen 'RSYSLOG_ForwardFormat'
7f9ef2872700: template bound to strgen 'RSYSLOG_TraditionalForwardFormat'
7f9ef2872700: rsyslog 5.8.10 - called init()
7f9ef2872700: cfline: '$template filename, "/var/log/routers/%fromhost-ip%-%fromhost%.log"'
7f9ef2872700: cfline: '$template format,  "\nHost:%fromhost%; Time:%timereported%; Message:%msg%\n"'
7f9ef2872700: cfline: '*.* ?filename; format'
7f9ef2872700:  - traditional PRI filter
7f9ef2872700: symbolic name: * ==> 255
7f9ef2872700: tried selector action for builtin-file: 0
7f9ef2872700: Module builtin-file processed this config line.
7f9ef2872700: template: 'format' assigned
7f9ef2872700: template: 'filename' assigned
7f9ef2872700: action 1 queue: save on shutdown 1, max disk space allowed 0
7f9ef2872700: action 1 queue: type 3, enq-only 0, disk assisted 0, maxFileSz 1048576, lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16 starting
7f9ef2872700: Action 0x7f9ef31520d0: queue 0x7f9ef31521e0 created
7f9ef2872700: cfline: '$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat'
7f9ef2872700: selector line successfully processed
7f9ef2872700: doGetWord: get newval 'RSYSLOG_TraditionalFileFormat' (len 29), hdlr (nil)
7f9ef2872700: cfline: '$ModLoad imklog'
7f9ef2872700: Requested to load module 'imklog'
7f9ef2872700: loading module '/lib64/rsyslog/imklog.so'
7f9ef2872700: module of type 0 being loaded.
7f9ef2872700: entry point 'isCompatibleWithFeature' not present in module
7f9ef2872700: cfline: '$ModLoad imuxsock'
7f9ef2872700: Requested to load module 'imuxsock'
7f9ef2872700: loading module '/lib64/rsyslog/imuxsock.so'
7f9ef2872700: imuxsock version 5.8.10 initializing
7f9ef2872700: module of type 0 being loaded.
7f9ef2872700: cfline: '$ModLoad imudp.so  # provides UDP syslog reception'
7f9ef2872700: Requested to load module 'imudp.so'
7f9ef2872700: loading module '/lib64/rsyslog/imudp.so'
7f9ef2872700: source file imudp.c requested reference for module 'lmnet', reference count now 4
7f9ef2872700: module of type 0 being loaded.
7f9ef2872700: cfline: '$UDPServerRun 514 # start a UDP syslog server at standard port 514'
7f9ef2872700: doGetWord: get newval '514' (len 3), hdlr 0x7f9ef10065e0
7f9ef2872700: Trying to open syslog UDP ports at *:514.
7f9ef2872700: cfline: '*.info;mail.none;authpriv.none;cron.none                /var/log/messages'
7f9ef2872700:  - traditional PRI filter
7f9ef2872700: symbolic name: info ==> 6
7f9ef2872700: symbolic name: none ==> 16
7f9ef2872700: symbolic name: mail ==> 16
7f9ef2872700: symbolic name: none ==> 16
7f9ef2872700: symbolic name: authpriv ==> 80
7f9ef2872700: symbolic name: none ==> 16
7f9ef2872700: symbolic name: cron ==> 72
7f9ef2872700: file stream messages params: flush interval 0, async write 0
7f9ef2872700: tried selector action for builtin-file: 0
7f9ef2872700: Module builtin-file processed this config line.
7f9ef2872700: template: 'RSYSLOG_TraditionalFileFormat' assigned
7f9ef2872700: action 2 queue: save on shutdown 1, max disk space allowed 0
7f9ef2872700: action 2 queue: type 3, enq-only 0, disk assisted 0, maxFileSz 1048576, lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16 starting
7f9ef2872700: Action 0x7f9ef3156150: queue 0x7f9ef3156240 created
7f9ef2872700: cfline: 'authpriv.*                                              /var/log/secure'
7f9ef2872700: selector line successfully processed
7f9ef2872700:  - traditional PRI filter
7f9ef2872700: symbolic name: * ==> 255
7f9ef2872700: symbolic name: authpriv ==> 80
7f9ef2872700: file stream secure params: flush interval 0, async write 0
7f9ef2872700: tried selector action for builtin-file: 0
7f9ef2872700: Module builtin-file processed this config line.
7f9ef2872700: template: 'RSYSLOG_TraditionalFileFormat' assigned
7f9ef2872700: action 3 queue: save on shutdown 1, max disk space allowed 0
7f9ef2872700: action 3 queue: type 3, enq-only 0, disk assisted 0, maxFileSz 1048576, lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16 starting
7f9ef2872700: Action 0x7f9ef3156d40: queue 0x7f9ef3156e30 created
7f9ef2872700: cfline: 'mail.*                                                  -/var/log/maillog'
7f9ef2872700: selector line successfully processed
7f9ef2872700:  - traditional PRI filter
7f9ef2872700: symbolic name: * ==> 255
7f9ef2872700: symbolic name: mail ==> 16
7f9ef2872700: file stream maillog params: flush interval 0, async write 0
7f9ef2872700: tried selector action for builtin-file: 0
7f9ef2872700: Module builtin-file processed this config line.
7f9ef2872700: template: 'RSYSLOG_TraditionalFileFormat' assigned
7f9ef2872700: action 4 queue: save on shutdown 1, max disk space allowed 0
7f9ef2872700: action 4 queue: type 3, enq-only 0, disk assisted 0, maxFileSz 1048576, lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16 starting
7f9ef2872700: Action 0x7f9ef31579a0: queue 0x7f9ef3157a90 created
7f9ef2872700: cfline: 'cron.*                                                  /var/log/cron'
7f9ef2872700: selector line successfully processed
7f9ef2872700:  - traditional PRI filter
7f9ef2872700: symbolic name: * ==> 255
7f9ef2872700: symbolic name: cron ==> 72
7f9ef2872700: file stream cron params: flush interval 0, async write 0
7f9ef2872700: tried selector action for builtin-file: 0
7f9ef2872700: Module builtin-file processed this config line.
7f9ef2872700: template: 'RSYSLOG_TraditionalFileFormat' assigned
7f9ef2872700: action 5 queue: save on shutdown 1, max disk space allowed 0
7f9ef2872700: action 5 queue: type 3, enq-only 0, disk assisted 0, maxFileSz 1048576, lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16 starting
7f9ef2872700: Action 0x7f9ef3158600: queue 0x7f9ef31586f0 created
7f9ef2872700: cfline: '*.emerg                                                 *'
7f9ef2872700: selector line successfully processed
7f9ef2872700:  - traditional PRI filter
7f9ef2872700: symbolic name: emerg ==> 0
7f9ef2872700: tried selector action for builtin-file: -2001
7f9ef2872700: tried selector action for builtin-pipe: -2001
7f9ef2872700: tried selector action for builtin-fwd: -2001
7f9ef2872700: tried selector action for builtin-shell: -2001
7f9ef2872700: tried selector action for builtin-discard: -2001
7f9ef2872700: write-alltried selector action for builtin-usrmsg: 0
7f9ef2872700: Module builtin-usrmsg processed this config line.
7f9ef2872700: template: ' WallFmt' assigned
7f9ef2872700: action 6 queue: save on shutdown 1, max disk space allowed 0
7f9ef2872700: action 6 queue: type 3, enq-only 0, disk assisted 0, maxFileSz 1048576, lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16 starting
7f9ef2872700: Action 0x7f9ef3158ba0: queue 0x7f9ef3158cb0 created
7f9ef2872700: cfline: 'uucp,news.crit                                          /var/log/spooler'
7f9ef2872700: selector line successfully processed
7f9ef2872700:  - traditional PRI filter
7f9ef2872700: symbolic name: crit ==> 2
7f9ef2872700: symbolic name: uucp ==> 64
7f9ef2872700: symbolic name: news ==> 56
7f9ef2872700: file stream spooler params: flush interval 0, async write 0
7f9ef2872700: tried selector action for builtin-file: 0
7f9ef2872700: Module builtin-file processed this config line.
7f9ef2872700: template: 'RSYSLOG_TraditionalFileFormat' assigned
7f9ef2872700: action 7 queue: save on shutdown 1, max disk space allowed 0
7f9ef2872700: action 7 queue: type 3, enq-only 0, disk assisted 0, maxFileSz 1048576, lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16 starting
7f9ef2872700: Action 0x7f9ef3159860: queue 0x7f9ef3159950 created
7f9ef2872700: cfline: 'local7.*                                                /var/log/boot.log'
7f9ef2872700: selector line successfully processed
7f9ef2872700:  - traditional PRI filter
7f9ef2872700: symbolic name: * ==> 255
7f9ef2872700: symbolic name: local7 ==> 184
7f9ef2872700: file stream boot.log params: flush interval 0, async write 0
7f9ef2872700: tried selector action for builtin-file: 0
7f9ef2872700: Module builtin-file processed this config line.
7f9ef2872700: template: 'RSYSLOG_TraditionalFileFormat' assigned
7f9ef2872700: action 8 queue: save on shutdown 1, max disk space allowed 0
7f9ef2872700: action 8 queue: type 3, enq-only 0, disk assisted 0, maxFileSz 1048576, lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16 starting
7f9ef2872700: Action 0x7f9ef315a490: queue 0x7f9ef315a5d0 created
7f9ef2872700: selector line successfully processed
rsyslogd: End of config validation run. Bye.

Habitual · 09-18-2014, 09:50 AM

Quote:

Originally Posted by Dig

#cat /etc/rsyslog.conf

Code:

$template filename, "/var/log/routers/%fromhost-ip%-%fromhost%.log"
$template format,  "\nHost:%fromhost%; Time:%timereported%; Message:%msg%\n"
*.* ?filename; format

$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat
$ModLoad imklog
$ModLoad imuxsock
$ModLoad imudp.so  # provides UDP syslog reception
$UDPServerRun 514 # start a UDP syslog server at standard port 514

*.info;mail.none;authpriv.none;cron.none                /var/log/messages
authpriv.*                                              /var/log/secure
mail.*                                                  -/var/log/maillog
cron.*                                                  /var/log/cron
*.emerg                                                 *
uucp,news.crit                                          /var/log/spooler
local7.*                                                /var/log/boot.log

Is that all of it?

No ruleset to act upon the template?
here's my /etc/rsyslog.conf on my syslog-server for comparison:

Code:

## Modules
module(load="imuxsock") 
module(load="imklog")   
module(load="imudp") 

# Debug options from http://www.rsyslog.com/doc/debug.html
#$DebugFile /kibana/syslog.debug 
#$DebugLevel 2

$template RemoteHost, "/kibana/%HOSTNAME%/%HOSTNAME%.log"
*.* -?RemoteHost

$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat

## Rulesets
# Local Logging
$RuleSet local
kern.*                                                  /var/log/messages
*.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
$DefaultRuleset local

# Remote Logging
$RuleSet remote
*.info;mail.none;authpriv.none;cron.none                ?RemoteHost

## Listeners
$InputUDPServerBindRuleset remote
### UDP Listener
$UDPServerRun 514

It may yield a clue, I don't know.

Dig · 09-18-2014, 01:59 PM

Hi

I produced the same configuration on virtual machines lab and everything works fine when set selinux to disabled. the problem that i can't do this on this node because selinux to be disabled need physical restart. although its set to be permissive but it cause this strange behavior over rsyslog. dynamic files can't be created, log can't be inserted

#getenforce
Permissive

drwxrw-rw-. ro root unconfined_u

bject_r:var_log_t:s0 ../routers/

and all dynamic files inherited same context "unconfined_u

bject_r:var_log_t:s0" to files, i tried to search but all i can find is bugs

between selinux and rsyslog

i will try to dig more on the selinux policies to avoid restart ! What they were thinking when they create the selinux !!

unSpawn · 09-18-2014, 03:42 PM

Quote:

Originally Posted by Dig

Hi unSpawn, nice to see you again

Likewise, it's been a while...

Quote:

Originally Posted by Dig

the first related to .so it will not impact.

Indeed. It doesn't. Bummer.

unSpawn · 09-18-2014, 03:49 PM

Quote:

Originally Posted by Dig

drwxrw-rw-. ro root unconfined_u:object_r:var_log_t:s0 ../routers/
and all dynamic files inherited same context "unconfined_u:object_r:var_log_t:s0" to files, i tried to search but all i can find is bugs :D between selinux and rsyslog

Nice one.

Code:

chown -R root.root /var/log/routers
chmod 0750 /var/log/routers
chcon -u system_u -r object_r -t var_log_t -R /var/log/routers

and your /etc/selinux/targeted/contexts/files/file_contexts.local should then contain a line like:

Code:

/var/log/routers(/.*)?    system_u:object_r:var_log_t:s0

(prolly should be done using semanage but I don't have the right incantation right now.)