Rsyslog keeps logging router's syslog messages to the console
by raku99 from LinuxQuestions.org on (#5RZDY)
Hi there :)
I got Asus RT66N router and i wanted to get its log to be processed and stored on my home "server" (machine running Fedora 35).
In order to achieve that i have enabled syslog output for the router (UDP / port 514) and added
Code:module(load="imudp") # needs to be done just once
input(type="imudp" port="514")to the server's /etc/syslog.conf.
The problem is that all log messages from the router are put not only to /var/log/messages, but also to the console (e.g. when i'm connected via SSH), resulting of corrupting of console content :)
After enabling (for a while) rsyslogd in debug mode i got output similiar to:
Code:
6178.118051009:imudp.c : imudp.c: imudp: epoll_wait() returned with 1 fds
6178.118106113:imudp.c : imudp.c: imudp: recvmmsg returned 4
6178.118122386:imudp.c : imudp.c: recv(4,78),acl:1,msg:<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel spec: 0x1001 (1)
6178.118147320:imudp.c : imudp.c: recv(4,78),acl:1,msg:<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: Adjusted channel spec: 0x1001 (1)
6178.118154234:imudp.c : imudp.c: recv(4,78),acl:1,msg:<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel spec: 0x1001 (1)
6178.118160729:imudp.c : imudp.c: recv(4,95),acl:1,msg:<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: acs_set_chspec: 0x1001 (1) for reason APCS_CSTIMER
6178.118169459:imudp.c : imudp.c: imudp: recvmmsg returned -1
6178.118186570:imudp.c : main Q: queue.c: MultiEnqObj advised worker start
6178.118227567:main Q:Reg/w0 : wti 0x55d3bf7425b0: wti.c: worker awoke from idle processing
6178.118249218:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: we deleted 0 objects and enqueued 0 objects
6178.118254875:main Q:Reg/w0 : queue.c: rger: deleteBatchFromQStore, nElem 0
6178.118261580:main Q:Reg/w0 : queue.c: doDeleteBatch: delete batch from store, new sizes: log 4, phys 4
6178.118268005:main Q:Reg/w0 : main Q: queue.c: entry deleted, size now log 3, phys 4 entries
6178.118274011:main Q:Reg/w0 : main Q: queue.c: entry deleted, size now log 2, phys 4 entries
6178.118278900:main Q:Reg/w0 : main Q: queue.c: entry deleted, size now log 1, phys 4 entries
6178.118284208:main Q:Reg/w0 : main Q: queue.c: entry deleted, size now log 0, phys 4 entries
6178.118290145:main Q:Reg/w0 : main Q: queue.c: dequeued 4 consumable elements, szlog 0 sz phys 4
6178.118300202:main Q:Reg/w0 : parser.c: msg parser: flags 70, from '~NOTRESOLVED~', msg '<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel'
6178.118306907:main Q:Reg/w0 : parser.c: parse using parser list 0x55d3bf70b730 (the default list).
6178.118333376:main Q:Reg/w0 : parser.c: dropped LF at very end of message (DropTrailingLF is set)
6178.118343643:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc5424' returned -2160
6178.118351046:main Q:Reg/w0 : pmrfc3164.c: Message will now be parsed by the legacy syslog parser (offAfterPRI=3, lenMsg=74.
6178.118357751:main Q:Reg/w0 : datetime.c: ParseTIMESTAMP3339: invalid year: 0, pszTS: 'o'
6178.118364665:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc3164' returned 0
6178.118370672:main Q:Reg/w0 : parser.c: msg parser: flags 70, from '~NOTRESOLVED~', msg '<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: Adjusted channel'
6178.118375700:main Q:Reg/w0 : parser.c: parse using parser list 0x55d3bf70b730 (the default list).
6178.118380589:main Q:Reg/w0 : parser.c: dropped LF at very end of message (DropTrailingLF is set)
6178.118391624:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc5424' returned -2160
6178.118397351:main Q:Reg/w0 : pmrfc3164.c: Message will now be parsed by the legacy syslog parser (offAfterPRI=3, lenMsg=74.
6178.118403078:main Q:Reg/w0 : datetime.c: ParseTIMESTAMP3339: invalid year: 0, pszTS: 'o'
6178.118408805:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc3164' returned 0
6178.118414392:main Q:Reg/w0 : parser.c: msg parser: flags 70, from '~NOTRESOLVED~', msg '<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel'
6178.118419141:main Q:Reg/w0 : parser.c: parse using parser list 0x55d3bf70b730 (the default list).
6178.118424519:main Q:Reg/w0 : parser.c: dropped LF at very end of message (DropTrailingLF is set)
6178.118429827:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc5424' returned -2160
6178.118435275:main Q:Reg/w0 : pmrfc3164.c: Message will now be parsed by the legacy syslog parser (offAfterPRI=3, lenMsg=74.
6178.118440583:main Q:Reg/w0 : datetime.c: ParseTIMESTAMP3339: invalid year: 0, pszTS: 'o'
6178.118451338:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc3164' returned 0
6178.118457135:main Q:Reg/w0 : parser.c: msg parser: flags 70, from '~NOTRESOLVED~', msg '<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: acs_set_chspec: '
6178.118462443:main Q:Reg/w0 : parser.c: parse using parser list 0x55d3bf70b730 (the default list).
6178.118468379:main Q:Reg/w0 : parser.c: dropped LF at very end of message (DropTrailingLF is set)
6178.118473897:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc5424' returned -2160
6178.118479065:main Q:Reg/w0 : pmrfc3164.c: Message will now be parsed by the legacy syslog parser (offAfterPRI=3, lenMsg=91.
6178.118484024:main Q:Reg/w0 : datetime.c: ParseTIMESTAMP3339: invalid year: 0, pszTS: 'o'
6178.118489541:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc3164' returned 0
6178.118494500:main Q:Reg/w0 : ruleset.c: processBATCH: batch of 4 elements must be processed
6178.118499668:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 0: <0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel spec: 0x1001 (1)
6178.118505605:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'
6178.118521668:main Q:Reg/w0 : rainerscript.c: pmask: 7F 7F X 7F 7F 7F 7F 7F 7F X X 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F
6178.118592976:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.118598214:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]
6178.118609179:main Q:Reg/w0 : ruleset.c: executing action 0
6178.118633554:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)
6178.118645147:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase
6178.118650665:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter
6178.118656392:main Q:Reg/w0 : ../action.c: checking external state file
6178.118660862:main Q:Reg/w0 : ../action.c: done checking external state file, iRet=0
6178.118667497:main Q:Reg/w0 : ../action.c: action[action-0-builtin:omfile] transitioned to state: itx
6178.118677973:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0
6178.118683351:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'
6178.118692220:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X FF X X X X X X X X X X X X X X X
6178.118760525:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.118766322:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'
6178.118774982:main Q:Reg/w0 : rainerscript.c: pmask: X X FF X X X X X X X X X X X X X X X X X X X X X X X
6178.118836303:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.118840982:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'
6178.118849712:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X FF X X X X X X X X X X X X X X X X
6178.118911941:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.118916620:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'
6178.118925699:main Q:Reg/w0 : rainerscript.c: pmask: 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1
6178.119071039:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.119076556:main Q:Reg/w0 : rainerscript.c: ACTION 4 [builtin:omusrmsg::omusrmsg:*]
6178.119086055:main Q:Reg/w0 : ruleset.c: executing action 4
6178.119106448:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': called, logging to builtin:omusrmsg (susp 0/0, direct q 1)
6178.119116505:main Q:Reg/w0 : ../action.c: actionPrepare[action-4-builtin:omusrmsg]: enter
6178.119122093:main Q:Reg/w0 : ../action.c: wti 0x55d3bf7425b0: we need to create a new action worker instance for action 4
6178.119129007:main Q:Reg/w0 : ../action.c: wti 0x55d3bf7425b0: created action worker instance 1 for action 4
6178.119133756:main Q:Reg/w0 : ../action.c: checking external state file
6178.119138226:main Q:Reg/w0 : ../action.c: done checking external state file, iRet=0
6178.119149331:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: itx
6178.119155197:main Q:Reg/w0 : ../action.c: entering actionCalldoAction(), state: itx, actionNbr 4
6178.119160296:main Q:Reg/w0 : omusrmsg.c:
Message from syslogd@RT-N66U_C1-CDE0--R at Nov 16 10:49:38 ...
acsd: selected channel spec: 0x1001 (1)
6178.119301654:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: rdy
6178.119315972:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': set suspended state to 0
6178.119320721:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'
6178.119330150:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X 7 7 X X X X X X X X X X X X X X X X X
6178.119398315:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.119402784:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'
6178.119411654:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X X X X X X X X X X X X X X FF X X
6178.119488549:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.119510270:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 1: <0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: Adjusted channel spec: 0x1001 (1)
6178.119515508:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'
6178.119524797:main Q:Reg/w0 : rainerscript.c: pmask: 7F 7F X 7F 7F 7F 7F 7F 7F X X 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F
6178.119611400:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.119616498:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]
6178.119625717:main Q:Reg/w0 : ruleset.c: executing action 0
6178.119631235:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)
6178.119637451:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase
6178.119641990:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter
6178.119646740:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0
6178.119656587:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'
6178.119666086:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X FF X X X X X X X X X X X X X X X
6178.119732155:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.119736625:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'
6178.119745425:main Q:Reg/w0 : rainerscript.c: pmask: X X FF X X X X X X X X X X X X X X X X X X X X X X X
6178.119807863:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.119812612:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'
6178.119821203:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X FF X X X X X X X X X X X X X X X X
6178.119883362:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.119888041:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'
6178.119896841:main Q:Reg/w0 : rainerscript.c: pmask: 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1
6178.119961863:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.119967101:main Q:Reg/w0 : rainerscript.c: ACTION 4 [builtin:omusrmsg::omusrmsg:*]
6178.119976041:main Q:Reg/w0 : ruleset.c: executing action 4
6178.119980860:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': called, logging to builtin:omusrmsg (susp 0/0, direct q 1)
6178.119987285:main Q:Reg/w0 : ../action.c: actionPrepare[action-4-builtin:omusrmsg]: enter
6178.119992593:main Q:Reg/w0 : ../action.c: checking external state file
6178.119997272:main Q:Reg/w0 : ../action.c: done checking external state file, iRet=0
6178.120021647:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: itx
6178.120028771:main Q:Reg/w0 : ../action.c: entering actionCalldoAction(), state: itx, actionNbr 4
6178.120033520:main Q:Reg/w0 : omusrmsg.c:
Message from syslogd@RT-N66U_C1-CDE0--R at Nov 16 10:49:38 ...
acsd: Adjusted channel spec: 0x1001 (1)
6178.120119075:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: rdy
6178.120127037:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': set suspended state to 0
6178.120132275:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'
6178.120140936:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X 7 7 X X X X X X X X X X X X X X X X X
6178.120202745:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.120207634:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'
6178.120216923:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X X X X X X X X X X X X X X FF X X
6178.120279361:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.120284320:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 2: <0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel spec: 0x1001 (1)
6178.120288999:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'
6178.120297939:main Q:Reg/w0 : rainerscript.c: pmask: 7F 7F X 7F 7F 7F 7F 7F 7F X X 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F
6178.120400396:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.120405075:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]
6178.120415132:main Q:Reg/w0 : ruleset.c: executing action 0
6178.120420650:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)
6178.120426167:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase
6178.120449005:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter
6178.120453685:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0
6178.120458154:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'
6178.120466186:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X FF X X X X X X X X X X X X X X X
6178.120532186:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.120553837:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'
6178.120563056:main Q:Reg/w0 : rainerscript.c: pmask: X X FF X X X X X X X X X X X X X X X X X X X X X X X
6178.120661951:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.120667468:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'
6178.120676757:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X FF X X X X X X X X X X X X X X X X
6178.120767760:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.120773348:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'
6178.120782078:main Q:Reg/w0 : rainerscript.c: pmask: 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1
6178.120856179:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.120865189:main Q:Reg/w0 : rainerscript.c: ACTION 4 [builtin:omusrmsg::omusrmsg:*]
6178.120875386:main Q:Reg/w0 : ruleset.c: executing action 4
6178.120881043:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': called, logging to builtin:omusrmsg (susp 0/0, direct q 1)
6178.120887398:main Q:Reg/w0 : ../action.c: actionPrepare[action-4-builtin:omusrmsg]: enter
6178.120892916:main Q:Reg/w0 : ../action.c: checking external state file
6178.120897805:main Q:Reg/w0 : ../action.c: done checking external state file, iRet=0
6178.120903112:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: itx
6178.120908141:main Q:Reg/w0 : ../action.c: entering actionCalldoAction(), state: itx, actionNbr 4
6178.120927208:main Q:Reg/w0 : omusrmsg.c:
Message from syslogd@RT-N66U_C1-CDE0--R at Nov 16 10:49:38 ...
acsd: selected channel spec: 0x1001 (1)
6178.121052433:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: rdy
6178.121060884:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': set suspended state to 0
6178.121066611:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'
6178.121075760:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X 7 7 X X X X X X X X X X X X X X X X X
6178.121143296:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.121148325:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'
6178.121157195:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X X X X X X X X X X X X X X FF X X
6178.121237372:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.121257626:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 3: <0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: acs_set_chspec: 0x1001 (1) for reason APCS_CSTIMER
6178.121264750:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'
6178.121274947:main Q:Reg/w0 : rainerscript.c: pmask: 7F 7F X 7F 7F 7F 7F 7F 7F X X 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F
6178.121361340:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.121366369:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]
6178.121375518:main Q:Reg/w0 : ruleset.c: executing action 0
6178.121381175:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)
6178.121387252:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase
6178.121392210:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter
6178.121397309:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0
6178.121406458:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'
6178.121415886:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X FF X X X X X X X X X X X X X X X
6178.121495435:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.121500394:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'
6178.121509823:main Q:Reg/w0 : rainerscript.c: pmask: X X FF X X X X X X X X X X X X X X X X X X X X X X X
6178.121595308:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.121600197:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'
6178.121608858:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X FF X X X X X X X X X X X X X X X X
6178.121690642:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.121695670:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'
6178.121704330:main Q:Reg/w0 : rainerscript.c: pmask: 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1
6178.121807416:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.121813353:main Q:Reg/w0 : rainerscript.c: ACTION 4 [builtin:omusrmsg::omusrmsg:*]
6178.121822432:main Q:Reg/w0 : ruleset.c: executing action 4
6178.121843664:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': called, logging to builtin:omusrmsg (susp 0/0, direct q 1)
6178.121851067:main Q:Reg/w0 : ../action.c: actionPrepare[action-4-builtin:omusrmsg]: enter
6178.121855467:main Q:Reg/w0 : ../action.c: checking external state file
6178.121860006:main Q:Reg/w0 : ../action.c: done checking external state file, iRet=0
6178.121864337:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: itx
6178.121869156:main Q:Reg/w0 : ../action.c: entering actionCalldoAction(), state: itx, actionNbr 4
6178.121874044:main Q:Reg/w0 : omusrmsg.c:
Message from syslogd@RT-N66U_C1-CDE0--R at Nov 16 10:49:38 ...
acsd: acs_set_chspec: 0x1001 (1) for reason APCS_CSTIMER
6178.121980482:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: rdy
6178.122025111:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': set suspended state to 0
6178.122030279:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'
6178.122039568:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X 7 7 X X X X X X X X X X X X X X X X X
6178.122108222:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.122112971:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'
6178.122128825:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X X X X X X X X X X X X X X FF X X
6178.122196920:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.122202508:main Q:Reg/w0 : ruleset.c: END batch execution phase, entering to commit phase [processed 4 of 4 messages]
6178.122207396:main Q:Reg/w0 : ../action.c: actionCommitAllDirect: action 0, state 1, nbr to commit 4 isTransactional 1
6178.122214101:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: enter, 4 msgs
6178.122218920:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: processing...
6178.122239663:main Q:Reg/w0 : ../action.c: actionTryCommit[action-0-builtin:omfile] enter
6178.122245460:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter
6178.122251187:main Q:Reg/w0 : ../action.c: doTransaction: have commitTransaction IF, using that, pWrkrInfo 0x55d3bf72a480
6178.122256006:main Q:Reg/w0 : ../action.c: entering actionCallCommitTransaction[action-0-builtin:omfile], state: itx, nMsgs 4
6178.122262292:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7fa484000e60, lenBuf 75, strt data Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel spec: 0x1001 (1)
6178.122268158:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7fa484000e60, lenBuf 75, strt data Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: Adjusted channel spec: 0x1001 (1)
6178.122273885:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7fa484000e60, lenBuf 75, strt data Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel spec: 0x1001 (1)
6178.122284641:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7fa484000e60, lenBuf 92, strt data Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: acs_set_chspec: 0x1001 (1) for reason APCS_CSTIMER
6178.122290507:main Q:Reg/w0 : strm 0x7fa484000e60: stream.c: file 6 strmFlush
6178.122296514:main Q:Reg/w0 : strm 0x7fa484000e60: stream.c: strmFlushinternal: file 6(/var/log/messages) flush, buflen 317
6178.122302590:main Q:Reg/w0 : strm 0x7fa484000e60: stream.c: file 6(/var/log/messages) doWriteInternal: bFlush 1
6178.122307828:main Q:Reg/w0 : stream.c: strmPhysWrite, stream 0x7fa484000e60, len 317
6178.122362933:main Q:Reg/w0 : strm 0x7fa484000e60: stream.c: file 6 write wrote 317 bytes
6178.122371593:main Q:Reg/w0 : ../action.c: actionCallCommitTransaction[action-0-builtin:omfile] state: itx mod commitTransaction returned 0
6178.122376622:main Q:Reg/w0 : ../action.c: action[action-0-builtin:omfile] transitioned to state: rdy
6178.122381790:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: return actionTryCommit 0
6178.122387028:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: done, iRet 0
6178.122392545:main Q:Reg/w0 : ../action.c: actionCommitAllDirect: action 1, state 0, nbr to commit 0 isTransactional 1
6178.122397434:main Q:Reg/w0 : ../action.c: actionCommit[action-1-builtin:omfile]: enter, 0 msgs
6178.122418526:main Q:Reg/w0 : ../action.c: actionCommit[action-1-builtin:omfile]: done, iRet 0
6178.122424114:main Q:Reg/w0 : ../action.c: actionCommitAllDirect: action 4, state 0, nbr to commit 0 isTransactional 0
6178.122429282:main Q:Reg/w0 : ../action.c: actionCommit[action-4-builtin:omusrmsg]: enter, 128 msgs
6178.122434939:main Q:Reg/w0 : ../action.c: actionCommit[action-4-builtin:omusrmsg]: done, iRet 0
6178.122439968:main Q:Reg/w0 : ruleset.c: processBATCH: batch of 4 elements has been processed
6178.122445764:main Q:Reg/w0 : queue.c: regular consumer finished, iret=0, szlog 0 sz phys 4
6178.122451002:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: etry 0 state 3
6178.122466647:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: etry 1 state 3
6178.122472374:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: etry 2 state 3
6178.122477961:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: etry 3 state 3
6178.122483479:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: we deleted 4 objects and enqueued 0 objects
6178.122488926:main Q:Reg/w0 : queue.c: rger: deleteBatchFromQStore, nElem 4
6178.122494164:main Q:Reg/w0 : queue.c: doDeleteBatch: delete batch from store, new sizes: log 0, phys 0
6178.122499682:main Q:Reg/w0 : main Q: queue.c: dequeued 0 consumable elements, szlog 0 sz phys 0
6178.122504920:main Q:Reg/w0 : queue.c: regular consumer finished, iret=4, szlog 0 sz phys 0
6178.122509669:main Q:Reg/w0 : wti.c: main Q:Reg/w0: worker IDLE, waiting for work.(the above is a result of four router's messages).
Content of my /etc/rsyslog.conf is as follows:
Code:# rsyslog configuration file
# For more information see /usr/share/doc/rsyslog-*/rsyslog_conf.html
# or latest version online at http://www.rsyslog.com/doc/rsyslog_conf.html
# If you experience problems, see http://www.rsyslog.com/doc/troubleshoot.html
#### GLOBAL DIRECTIVES ####
# Where to place auxiliary files
global(workDirectory="/var/lib/rsyslog")
# Use default timestamp format
module(load="builtin:omfile" Template="RSYSLOG_TraditionalFileFormat")
# Include all config files in /etc/rsyslog.d/
include(file="/etc/rsyslog.d/*.conf" mode="optional")
#### MODULES ####
module(load="imuxsock" # provides support for local system logging (e.g. via logger command)
SysSock.Use="off") # Turn off message reception via local log socket;
# local messages are retrieved through imjournal now.
module(load="imjournal" # provides access to the systemd journal
StateFile="imjournal.state") # File to store the position in the journal
#module(load="imklog") # reads kernel messages (the same are read from journald)
#module(load="immark") # provides --MARK-- message capability
# Provides UDP syslog reception
# for parameters see http://www.rsyslog.com/doc/imudp.html
module(load="imudp") # needs to be done just once
input(type="imudp" port="514")
# Provides TCP syslog reception
# for parameters see http://www.rsyslog.com/doc/imtcp.html
module(load="imtcp") # needs to be done just once
input(type="imtcp" port="514")
#### RULES ####
# Log all kernel messages to the console.
# Logging much else clutters up the screen.
#kern.* /dev/console
# Log anything (except mail) of level info or higher.
# Don't log private authentication messages!
*.info;mail.none;authpriv.none;cron.none /var/log/messages
# The authpriv file has restricted access.
authpriv.* /var/log/secure
# Log all the mail messages in one place.
mail.* -/var/log/maillog
# Log cron stuff
cron.* /var/log/cron
# Everybody gets emergency messages
*.emerg :omusrmsg:*
# Save news errors of level crit and higher in a special file.
uucp,news.crit /var/log/spooler
# Save boot messages also to boot.log
local7.* /var/log/boot.log
# ### sample forwarding rule ###
#action(type="omfwd"
# # An on-disk queue is created for this action. If the remote host is
# # down, messages are spooled to disk and sent when it is up again.
#queue.filename="fwdRule1" # unique name prefix for spool files
#queue.maxdiskspace="1g" # 1gb space limit (use as much as possible)
#queue.saveonshutdown="on" # save messages to disk on shutdown
#queue.type="LinkedList" # run asynchronously
#action.resumeRetryCount="-1" # infinite retries if host is down
# # Remote Logging (we use TCP for reliable delivery)
# # remote_host is: name/ip, e.g. 192.168.0.1, port optional e.g. 10514
#Target="remote_host" Port="XXX" Protocol="tcp")Is there anything i am missing?
I suspect that router malforms messages in some way (lack of year in time stamp, no severity ...), but that's not something i can easily fix...
I got Asus RT66N router and i wanted to get its log to be processed and stored on my home "server" (machine running Fedora 35).
In order to achieve that i have enabled syslog output for the router (UDP / port 514) and added
Code:module(load="imudp") # needs to be done just once
input(type="imudp" port="514")to the server's /etc/syslog.conf.
The problem is that all log messages from the router are put not only to /var/log/messages, but also to the console (e.g. when i'm connected via SSH), resulting of corrupting of console content :)
After enabling (for a while) rsyslogd in debug mode i got output similiar to:
Code:
6178.118051009:imudp.c : imudp.c: imudp: epoll_wait() returned with 1 fds
6178.118106113:imudp.c : imudp.c: imudp: recvmmsg returned 4
6178.118122386:imudp.c : imudp.c: recv(4,78),acl:1,msg:<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel spec: 0x1001 (1)
6178.118147320:imudp.c : imudp.c: recv(4,78),acl:1,msg:<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: Adjusted channel spec: 0x1001 (1)
6178.118154234:imudp.c : imudp.c: recv(4,78),acl:1,msg:<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel spec: 0x1001 (1)
6178.118160729:imudp.c : imudp.c: recv(4,95),acl:1,msg:<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: acs_set_chspec: 0x1001 (1) for reason APCS_CSTIMER
6178.118169459:imudp.c : imudp.c: imudp: recvmmsg returned -1
6178.118186570:imudp.c : main Q: queue.c: MultiEnqObj advised worker start
6178.118227567:main Q:Reg/w0 : wti 0x55d3bf7425b0: wti.c: worker awoke from idle processing
6178.118249218:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: we deleted 0 objects and enqueued 0 objects
6178.118254875:main Q:Reg/w0 : queue.c: rger: deleteBatchFromQStore, nElem 0
6178.118261580:main Q:Reg/w0 : queue.c: doDeleteBatch: delete batch from store, new sizes: log 4, phys 4
6178.118268005:main Q:Reg/w0 : main Q: queue.c: entry deleted, size now log 3, phys 4 entries
6178.118274011:main Q:Reg/w0 : main Q: queue.c: entry deleted, size now log 2, phys 4 entries
6178.118278900:main Q:Reg/w0 : main Q: queue.c: entry deleted, size now log 1, phys 4 entries
6178.118284208:main Q:Reg/w0 : main Q: queue.c: entry deleted, size now log 0, phys 4 entries
6178.118290145:main Q:Reg/w0 : main Q: queue.c: dequeued 4 consumable elements, szlog 0 sz phys 4
6178.118300202:main Q:Reg/w0 : parser.c: msg parser: flags 70, from '~NOTRESOLVED~', msg '<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel'
6178.118306907:main Q:Reg/w0 : parser.c: parse using parser list 0x55d3bf70b730 (the default list).
6178.118333376:main Q:Reg/w0 : parser.c: dropped LF at very end of message (DropTrailingLF is set)
6178.118343643:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc5424' returned -2160
6178.118351046:main Q:Reg/w0 : pmrfc3164.c: Message will now be parsed by the legacy syslog parser (offAfterPRI=3, lenMsg=74.
6178.118357751:main Q:Reg/w0 : datetime.c: ParseTIMESTAMP3339: invalid year: 0, pszTS: 'o'
6178.118364665:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc3164' returned 0
6178.118370672:main Q:Reg/w0 : parser.c: msg parser: flags 70, from '~NOTRESOLVED~', msg '<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: Adjusted channel'
6178.118375700:main Q:Reg/w0 : parser.c: parse using parser list 0x55d3bf70b730 (the default list).
6178.118380589:main Q:Reg/w0 : parser.c: dropped LF at very end of message (DropTrailingLF is set)
6178.118391624:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc5424' returned -2160
6178.118397351:main Q:Reg/w0 : pmrfc3164.c: Message will now be parsed by the legacy syslog parser (offAfterPRI=3, lenMsg=74.
6178.118403078:main Q:Reg/w0 : datetime.c: ParseTIMESTAMP3339: invalid year: 0, pszTS: 'o'
6178.118408805:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc3164' returned 0
6178.118414392:main Q:Reg/w0 : parser.c: msg parser: flags 70, from '~NOTRESOLVED~', msg '<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel'
6178.118419141:main Q:Reg/w0 : parser.c: parse using parser list 0x55d3bf70b730 (the default list).
6178.118424519:main Q:Reg/w0 : parser.c: dropped LF at very end of message (DropTrailingLF is set)
6178.118429827:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc5424' returned -2160
6178.118435275:main Q:Reg/w0 : pmrfc3164.c: Message will now be parsed by the legacy syslog parser (offAfterPRI=3, lenMsg=74.
6178.118440583:main Q:Reg/w0 : datetime.c: ParseTIMESTAMP3339: invalid year: 0, pszTS: 'o'
6178.118451338:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc3164' returned 0
6178.118457135:main Q:Reg/w0 : parser.c: msg parser: flags 70, from '~NOTRESOLVED~', msg '<0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: acs_set_chspec: '
6178.118462443:main Q:Reg/w0 : parser.c: parse using parser list 0x55d3bf70b730 (the default list).
6178.118468379:main Q:Reg/w0 : parser.c: dropped LF at very end of message (DropTrailingLF is set)
6178.118473897:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc5424' returned -2160
6178.118479065:main Q:Reg/w0 : pmrfc3164.c: Message will now be parsed by the legacy syslog parser (offAfterPRI=3, lenMsg=91.
6178.118484024:main Q:Reg/w0 : datetime.c: ParseTIMESTAMP3339: invalid year: 0, pszTS: 'o'
6178.118489541:main Q:Reg/w0 : parser.c: Parser 'rsyslog.rfc3164' returned 0
6178.118494500:main Q:Reg/w0 : ruleset.c: processBATCH: batch of 4 elements must be processed
6178.118499668:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 0: <0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel spec: 0x1001 (1)
6178.118505605:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'
6178.118521668:main Q:Reg/w0 : rainerscript.c: pmask: 7F 7F X 7F 7F 7F 7F 7F 7F X X 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F
6178.118592976:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.118598214:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]
6178.118609179:main Q:Reg/w0 : ruleset.c: executing action 0
6178.118633554:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)
6178.118645147:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase
6178.118650665:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter
6178.118656392:main Q:Reg/w0 : ../action.c: checking external state file
6178.118660862:main Q:Reg/w0 : ../action.c: done checking external state file, iRet=0
6178.118667497:main Q:Reg/w0 : ../action.c: action[action-0-builtin:omfile] transitioned to state: itx
6178.118677973:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0
6178.118683351:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'
6178.118692220:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X FF X X X X X X X X X X X X X X X
6178.118760525:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.118766322:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'
6178.118774982:main Q:Reg/w0 : rainerscript.c: pmask: X X FF X X X X X X X X X X X X X X X X X X X X X X X
6178.118836303:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.118840982:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'
6178.118849712:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X FF X X X X X X X X X X X X X X X X
6178.118911941:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.118916620:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'
6178.118925699:main Q:Reg/w0 : rainerscript.c: pmask: 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1
6178.119071039:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.119076556:main Q:Reg/w0 : rainerscript.c: ACTION 4 [builtin:omusrmsg::omusrmsg:*]
6178.119086055:main Q:Reg/w0 : ruleset.c: executing action 4
6178.119106448:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': called, logging to builtin:omusrmsg (susp 0/0, direct q 1)
6178.119116505:main Q:Reg/w0 : ../action.c: actionPrepare[action-4-builtin:omusrmsg]: enter
6178.119122093:main Q:Reg/w0 : ../action.c: wti 0x55d3bf7425b0: we need to create a new action worker instance for action 4
6178.119129007:main Q:Reg/w0 : ../action.c: wti 0x55d3bf7425b0: created action worker instance 1 for action 4
6178.119133756:main Q:Reg/w0 : ../action.c: checking external state file
6178.119138226:main Q:Reg/w0 : ../action.c: done checking external state file, iRet=0
6178.119149331:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: itx
6178.119155197:main Q:Reg/w0 : ../action.c: entering actionCalldoAction(), state: itx, actionNbr 4
6178.119160296:main Q:Reg/w0 : omusrmsg.c:
Message from syslogd@RT-N66U_C1-CDE0--R at Nov 16 10:49:38 ...
acsd: selected channel spec: 0x1001 (1)
6178.119301654:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: rdy
6178.119315972:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': set suspended state to 0
6178.119320721:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'
6178.119330150:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X 7 7 X X X X X X X X X X X X X X X X X
6178.119398315:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.119402784:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'
6178.119411654:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X X X X X X X X X X X X X X FF X X
6178.119488549:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.119510270:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 1: <0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: Adjusted channel spec: 0x1001 (1)
6178.119515508:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'
6178.119524797:main Q:Reg/w0 : rainerscript.c: pmask: 7F 7F X 7F 7F 7F 7F 7F 7F X X 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F
6178.119611400:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.119616498:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]
6178.119625717:main Q:Reg/w0 : ruleset.c: executing action 0
6178.119631235:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)
6178.119637451:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase
6178.119641990:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter
6178.119646740:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0
6178.119656587:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'
6178.119666086:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X FF X X X X X X X X X X X X X X X
6178.119732155:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.119736625:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'
6178.119745425:main Q:Reg/w0 : rainerscript.c: pmask: X X FF X X X X X X X X X X X X X X X X X X X X X X X
6178.119807863:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.119812612:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'
6178.119821203:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X FF X X X X X X X X X X X X X X X X
6178.119883362:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.119888041:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'
6178.119896841:main Q:Reg/w0 : rainerscript.c: pmask: 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1
6178.119961863:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.119967101:main Q:Reg/w0 : rainerscript.c: ACTION 4 [builtin:omusrmsg::omusrmsg:*]
6178.119976041:main Q:Reg/w0 : ruleset.c: executing action 4
6178.119980860:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': called, logging to builtin:omusrmsg (susp 0/0, direct q 1)
6178.119987285:main Q:Reg/w0 : ../action.c: actionPrepare[action-4-builtin:omusrmsg]: enter
6178.119992593:main Q:Reg/w0 : ../action.c: checking external state file
6178.119997272:main Q:Reg/w0 : ../action.c: done checking external state file, iRet=0
6178.120021647:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: itx
6178.120028771:main Q:Reg/w0 : ../action.c: entering actionCalldoAction(), state: itx, actionNbr 4
6178.120033520:main Q:Reg/w0 : omusrmsg.c:
Message from syslogd@RT-N66U_C1-CDE0--R at Nov 16 10:49:38 ...
acsd: Adjusted channel spec: 0x1001 (1)
6178.120119075:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: rdy
6178.120127037:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': set suspended state to 0
6178.120132275:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'
6178.120140936:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X 7 7 X X X X X X X X X X X X X X X X X
6178.120202745:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.120207634:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'
6178.120216923:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X X X X X X X X X X X X X X FF X X
6178.120279361:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.120284320:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 2: <0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel spec: 0x1001 (1)
6178.120288999:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'
6178.120297939:main Q:Reg/w0 : rainerscript.c: pmask: 7F 7F X 7F 7F 7F 7F 7F 7F X X 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F
6178.120400396:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.120405075:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]
6178.120415132:main Q:Reg/w0 : ruleset.c: executing action 0
6178.120420650:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)
6178.120426167:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase
6178.120449005:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter
6178.120453685:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0
6178.120458154:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'
6178.120466186:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X FF X X X X X X X X X X X X X X X
6178.120532186:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.120553837:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'
6178.120563056:main Q:Reg/w0 : rainerscript.c: pmask: X X FF X X X X X X X X X X X X X X X X X X X X X X X
6178.120661951:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.120667468:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'
6178.120676757:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X FF X X X X X X X X X X X X X X X X
6178.120767760:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.120773348:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'
6178.120782078:main Q:Reg/w0 : rainerscript.c: pmask: 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1
6178.120856179:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.120865189:main Q:Reg/w0 : rainerscript.c: ACTION 4 [builtin:omusrmsg::omusrmsg:*]
6178.120875386:main Q:Reg/w0 : ruleset.c: executing action 4
6178.120881043:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': called, logging to builtin:omusrmsg (susp 0/0, direct q 1)
6178.120887398:main Q:Reg/w0 : ../action.c: actionPrepare[action-4-builtin:omusrmsg]: enter
6178.120892916:main Q:Reg/w0 : ../action.c: checking external state file
6178.120897805:main Q:Reg/w0 : ../action.c: done checking external state file, iRet=0
6178.120903112:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: itx
6178.120908141:main Q:Reg/w0 : ../action.c: entering actionCalldoAction(), state: itx, actionNbr 4
6178.120927208:main Q:Reg/w0 : omusrmsg.c:
Message from syslogd@RT-N66U_C1-CDE0--R at Nov 16 10:49:38 ...
acsd: selected channel spec: 0x1001 (1)
6178.121052433:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: rdy
6178.121060884:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': set suspended state to 0
6178.121066611:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'
6178.121075760:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X 7 7 X X X X X X X X X X X X X X X X X
6178.121143296:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.121148325:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'
6178.121157195:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X X X X X X X X X X X X X X FF X X
6178.121237372:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.121257626:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 3: <0>Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: acs_set_chspec: 0x1001 (1) for reason APCS_CSTIMER
6178.121264750:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'
6178.121274947:main Q:Reg/w0 : rainerscript.c: pmask: 7F 7F X 7F 7F 7F 7F 7F 7F X X 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F
6178.121361340:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.121366369:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]
6178.121375518:main Q:Reg/w0 : ruleset.c: executing action 0
6178.121381175:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)
6178.121387252:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase
6178.121392210:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter
6178.121397309:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0
6178.121406458:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'
6178.121415886:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X FF X X X X X X X X X X X X X X X
6178.121495435:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.121500394:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'
6178.121509823:main Q:Reg/w0 : rainerscript.c: pmask: X X FF X X X X X X X X X X X X X X X X X X X X X X X
6178.121595308:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.121600197:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'
6178.121608858:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X FF X X X X X X X X X X X X X X X X
6178.121690642:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.121695670:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'
6178.121704330:main Q:Reg/w0 : rainerscript.c: pmask: 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1
6178.121807416:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
6178.121813353:main Q:Reg/w0 : rainerscript.c: ACTION 4 [builtin:omusrmsg::omusrmsg:*]
6178.121822432:main Q:Reg/w0 : ruleset.c: executing action 4
6178.121843664:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': called, logging to builtin:omusrmsg (susp 0/0, direct q 1)
6178.121851067:main Q:Reg/w0 : ../action.c: actionPrepare[action-4-builtin:omusrmsg]: enter
6178.121855467:main Q:Reg/w0 : ../action.c: checking external state file
6178.121860006:main Q:Reg/w0 : ../action.c: done checking external state file, iRet=0
6178.121864337:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: itx
6178.121869156:main Q:Reg/w0 : ../action.c: entering actionCalldoAction(), state: itx, actionNbr 4
6178.121874044:main Q:Reg/w0 : omusrmsg.c:
Message from syslogd@RT-N66U_C1-CDE0--R at Nov 16 10:49:38 ...
acsd: acs_set_chspec: 0x1001 (1) for reason APCS_CSTIMER
6178.121980482:main Q:Reg/w0 : ../action.c: action[action-4-builtin:omusrmsg] transitioned to state: rdy
6178.122025111:main Q:Reg/w0 : ../action.c: action 'action-4-builtin:omusrmsg': set suspended state to 0
6178.122030279:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'
6178.122039568:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X 7 7 X X X X X X X X X X X X X X X X X
6178.122108222:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.122112971:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'
6178.122128825:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X X X X X X X X X X X X X X FF X X
6178.122196920:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
6178.122202508:main Q:Reg/w0 : ruleset.c: END batch execution phase, entering to commit phase [processed 4 of 4 messages]
6178.122207396:main Q:Reg/w0 : ../action.c: actionCommitAllDirect: action 0, state 1, nbr to commit 4 isTransactional 1
6178.122214101:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: enter, 4 msgs
6178.122218920:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: processing...
6178.122239663:main Q:Reg/w0 : ../action.c: actionTryCommit[action-0-builtin:omfile] enter
6178.122245460:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter
6178.122251187:main Q:Reg/w0 : ../action.c: doTransaction: have commitTransaction IF, using that, pWrkrInfo 0x55d3bf72a480
6178.122256006:main Q:Reg/w0 : ../action.c: entering actionCallCommitTransaction[action-0-builtin:omfile], state: itx, nMsgs 4
6178.122262292:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7fa484000e60, lenBuf 75, strt data Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel spec: 0x1001 (1)
6178.122268158:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7fa484000e60, lenBuf 75, strt data Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: Adjusted channel spec: 0x1001 (1)
6178.122273885:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7fa484000e60, lenBuf 75, strt data Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: selected channel spec: 0x1001 (1)
6178.122284641:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7fa484000e60, lenBuf 92, strt data Nov 16 10:49:38 RT-N66U_C1-CDE0--R acsd: acs_set_chspec: 0x1001 (1) for reason APCS_CSTIMER
6178.122290507:main Q:Reg/w0 : strm 0x7fa484000e60: stream.c: file 6 strmFlush
6178.122296514:main Q:Reg/w0 : strm 0x7fa484000e60: stream.c: strmFlushinternal: file 6(/var/log/messages) flush, buflen 317
6178.122302590:main Q:Reg/w0 : strm 0x7fa484000e60: stream.c: file 6(/var/log/messages) doWriteInternal: bFlush 1
6178.122307828:main Q:Reg/w0 : stream.c: strmPhysWrite, stream 0x7fa484000e60, len 317
6178.122362933:main Q:Reg/w0 : strm 0x7fa484000e60: stream.c: file 6 write wrote 317 bytes
6178.122371593:main Q:Reg/w0 : ../action.c: actionCallCommitTransaction[action-0-builtin:omfile] state: itx mod commitTransaction returned 0
6178.122376622:main Q:Reg/w0 : ../action.c: action[action-0-builtin:omfile] transitioned to state: rdy
6178.122381790:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: return actionTryCommit 0
6178.122387028:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: done, iRet 0
6178.122392545:main Q:Reg/w0 : ../action.c: actionCommitAllDirect: action 1, state 0, nbr to commit 0 isTransactional 1
6178.122397434:main Q:Reg/w0 : ../action.c: actionCommit[action-1-builtin:omfile]: enter, 0 msgs
6178.122418526:main Q:Reg/w0 : ../action.c: actionCommit[action-1-builtin:omfile]: done, iRet 0
6178.122424114:main Q:Reg/w0 : ../action.c: actionCommitAllDirect: action 4, state 0, nbr to commit 0 isTransactional 0
6178.122429282:main Q:Reg/w0 : ../action.c: actionCommit[action-4-builtin:omusrmsg]: enter, 128 msgs
6178.122434939:main Q:Reg/w0 : ../action.c: actionCommit[action-4-builtin:omusrmsg]: done, iRet 0
6178.122439968:main Q:Reg/w0 : ruleset.c: processBATCH: batch of 4 elements has been processed
6178.122445764:main Q:Reg/w0 : queue.c: regular consumer finished, iret=0, szlog 0 sz phys 4
6178.122451002:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: etry 0 state 3
6178.122466647:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: etry 1 state 3
6178.122472374:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: etry 2 state 3
6178.122477961:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: etry 3 state 3
6178.122483479:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: we deleted 4 objects and enqueued 0 objects
6178.122488926:main Q:Reg/w0 : queue.c: rger: deleteBatchFromQStore, nElem 4
6178.122494164:main Q:Reg/w0 : queue.c: doDeleteBatch: delete batch from store, new sizes: log 0, phys 0
6178.122499682:main Q:Reg/w0 : main Q: queue.c: dequeued 0 consumable elements, szlog 0 sz phys 0
6178.122504920:main Q:Reg/w0 : queue.c: regular consumer finished, iret=4, szlog 0 sz phys 0
6178.122509669:main Q:Reg/w0 : wti.c: main Q:Reg/w0: worker IDLE, waiting for work.(the above is a result of four router's messages).
Content of my /etc/rsyslog.conf is as follows:
Code:# rsyslog configuration file
# For more information see /usr/share/doc/rsyslog-*/rsyslog_conf.html
# or latest version online at http://www.rsyslog.com/doc/rsyslog_conf.html
# If you experience problems, see http://www.rsyslog.com/doc/troubleshoot.html
#### GLOBAL DIRECTIVES ####
# Where to place auxiliary files
global(workDirectory="/var/lib/rsyslog")
# Use default timestamp format
module(load="builtin:omfile" Template="RSYSLOG_TraditionalFileFormat")
# Include all config files in /etc/rsyslog.d/
include(file="/etc/rsyslog.d/*.conf" mode="optional")
#### MODULES ####
module(load="imuxsock" # provides support for local system logging (e.g. via logger command)
SysSock.Use="off") # Turn off message reception via local log socket;
# local messages are retrieved through imjournal now.
module(load="imjournal" # provides access to the systemd journal
StateFile="imjournal.state") # File to store the position in the journal
#module(load="imklog") # reads kernel messages (the same are read from journald)
#module(load="immark") # provides --MARK-- message capability
# Provides UDP syslog reception
# for parameters see http://www.rsyslog.com/doc/imudp.html
module(load="imudp") # needs to be done just once
input(type="imudp" port="514")
# Provides TCP syslog reception
# for parameters see http://www.rsyslog.com/doc/imtcp.html
module(load="imtcp") # needs to be done just once
input(type="imtcp" port="514")
#### RULES ####
# Log all kernel messages to the console.
# Logging much else clutters up the screen.
#kern.* /dev/console
# Log anything (except mail) of level info or higher.
# Don't log private authentication messages!
*.info;mail.none;authpriv.none;cron.none /var/log/messages
# The authpriv file has restricted access.
authpriv.* /var/log/secure
# Log all the mail messages in one place.
mail.* -/var/log/maillog
# Log cron stuff
cron.* /var/log/cron
# Everybody gets emergency messages
*.emerg :omusrmsg:*
# Save news errors of level crit and higher in a special file.
uucp,news.crit /var/log/spooler
# Save boot messages also to boot.log
local7.* /var/log/boot.log
# ### sample forwarding rule ###
#action(type="omfwd"
# # An on-disk queue is created for this action. If the remote host is
# # down, messages are spooled to disk and sent when it is up again.
#queue.filename="fwdRule1" # unique name prefix for spool files
#queue.maxdiskspace="1g" # 1gb space limit (use as much as possible)
#queue.saveonshutdown="on" # save messages to disk on shutdown
#queue.type="LinkedList" # run asynchronously
#action.resumeRetryCount="-1" # infinite retries if host is down
# # Remote Logging (we use TCP for reliable delivery)
# # remote_host is: name/ip, e.g. 192.168.0.1, port optional e.g. 10514
#Target="remote_host" Port="XXX" Protocol="tcp")Is there anything i am missing?
I suspect that router malforms messages in some way (lack of year in time stamp, no severity ...), but that's not something i can easily fix...