Linux基础——测试BC21.10系统logger格式化输出脚本

Linux日志收集及问题处理逻辑

1. 初步排查
rsyslog服务状态检查：多次重启rsyslog.service服务无效，排除了服务未运行的可能性
配置文件验证：检查/etc/rsyslog.conf配置正确，且重启服务应已重载配置
omfile模块怀疑：推测可能是omfile模块未能正常写入对应文件

2. 深入分析
根据正常机器的debug日志分析，rsyslog处理流程应包括：
logger → /dev/log → imuxsock/imjournal → ruleset → omfile → /var/log/messages
故障可能发生在以下环节：
日志接收阶段：imuxsock/imjournal模块未能接收logger日志
规则匹配阶段：日志未能匹配到正确规则
文件写入阶段：omfile模块未能写入文件

3. 关键发现
重启主机后功能恢复，表明：
配置文件本身无问题
可能是进程级别的资源问题或内核socket缓冲区问题

4. 技术推测
最可能的原因是：
/dev/log socket缓冲区已满或损坏：logger写入的日志无法被rsyslog接收
imuxsock模块内部状态异常：虽然服务运行，但未能正确处理输入
文件描述符泄漏：rsyslog进程可能耗尽了可用fd，无法打开新文件




Linux日志收集环境
服务：/usr/lib/systemd/system/rsyslog.service
配置：/etc/rsyslog.conf，定义收集日志规则和逻辑，通过重启服务生效；
日志存放路径：/var/log目录；

[root@sysmt ~]# logger --help

Usage:
logger [options] [<message>]

Enter messages into the system log.

Options:
-i log the logger command's PID
--id[=<id>] log the given <id>, or otherwise the PID
-f, --file <file> log the contents of this file
-e, --skip-empty do not log empty lines when processing files
--no-act do everything except the write the log
-p, --priority <prio> mark given message with this priority
--octet-count use rfc6587 octet counting
--prio-prefix look for a prefix on every line read from stdin
-s, --stderr output message to standard error as well
-S, --size <size> maximum size for a single message
-t, --tag <tag> mark every line with this tag
-n, --server <name> write to this remote syslog server
-P, --port <port> use this port for UDP or TCP connection
-T, --tcp use TCP only
-d, --udp use UDP only
--rfc3164 use the obsolete BSD syslog protocol
--rfc5424[=<snip>] use the syslog protocol (the default for remote);
<snip> can be notime, or notq, and/or nohost
--sd-id <id> rfc5424 structured data ID
--sd-param <data> rfc5424 structured data name=value
--msgid <msgid> set rfc5424 message id field
-u, --socket <socket> write to this Unix socket
--socket-errors[=<on|off|auto>]
print connection errors when using Unix sockets
--journald[=<file>] write journald entry

-h, --help display this help
-V, --version display version

For more details see logger(1).

**options (选项)：**

-d, --udp

使用数据报(UDP)而不是使用默认的流连接(TCP)

-i, --id

逐行记录每一次logger的进程ID

-f, --file file_name

记录特定的文件

-h, --help

显示帮助文本并退出

-n， --server

写入指定的远程syslog服务器，使用UDP代替内装式syslog的例程

-s， --stderr

输出标准错误到系统日志。

-t， --tag tag

指定标记记录

-u， --socket socket

写入指定的socket，而不是到内置系统日志例程。

-V, --version

显示版本信息并退出

-P， --port port_num

使用指定的UDP端口。默认的端口号是514

-p， --priority priority_level

指定输入消息日志级别，优先级可以是数字或者指定为 " facility.level" 的格式。　



-p，指定输入消息日志级别，优先级可以是数字或者指定为 " facility.level" 的格式。比如：" -p local3.info " local3 这个设备的消息级别为 info。默认级别是 "user.notice"
facility：是用来定义由谁产生的日志信息：那个软件、子系统运行过程中产生的日志信息。
             auth：             用户授权
             authpriv：         授权和安全
             cron：             计划任务
             daemon：           系统守护进程
             kern：             与内核有关的信息
             lpr                与打印服务有关的信息
             mail               与电子邮件有关的信息
             news               来自新闻服务器的信息
             syslog             由syslog生成的信息
             user               用户的程序生成的信息，默认
             ftp
             uucp               由uucp生成的信息
             local0~7           用来定义本地策略

level：是用来定义记录什么类型的日志信息。alert需要立即采取动作。

debug(7)            调试
info(6)             正常消息
notice(5)           正常但是要注意
warning(4)
error(3)            错误状态
crit(2)             临界状态
alert(1)
emerg(0)            系统不可用

# 1、添加logger脚本到/etc/bashrc末尾

# Add content in /etc/bashrc
# Log bash user login and command history
sdc_up_src_ip=`(who am i|cut -d$ -f2|cut -d$ -f1)`
sdc_up_log_time=`(date -d now +"%Y-%m-%d %T")`
if [ "`who -m|awk '{print $1}'`" = "`whoami`" ] && [ -n "`echo $sdc_up_src_ip|awk '($1 ~/[0-9]+.[0-9]+.[0-9]+.[0-9]+/)'`" ] ; then
logger -p user.notice -- class=\"HOST_LOGIN\" type=\"2\" time=\"$sdc_up_log_time\" src_ip=\"$sdc_up_src_ip\" dst_ip=\"192.168.190.110\" primary_user=\"\" secondary_user=\"$(whoami)\" operation=\"$0\" content=\"login successful\" authen_status=\"success\" log_level=\"1\" session_id=\"$$\" 2>/dev/null;
else
logger -p user.notice -- class=\"HOST_COMMAND\" type=\"4\" time=\"$(date -d now +"%Y-%m-%d %T")\" src_ip=\"$sdc_up_src_ip\" dst_ip=\"192.168.190.110\" primary_user=\"\" secondary_user=\"$(whoami)\" operation=\"$0\" content=\"$(ps -p $$ -o command= | cut -c 1-200)\" authen_status=\"\" log_level=\"1\" session_id=\"$$\" 2>/dev/null;
fi
export PROMPT_COMMAND='{ logger -p user.notice -- class=\"HOST_COMMAND\" type=\"3\" time=\"$(date -d now +"%Y-%m-%d %T")\" src_ip=\"$sdc_up_src_ip\" dst_ip=\"192.168.190.110\" primary_user=\"\" secondary_user=\"$(whoami)\" operation=\"$(history 1 | { read x y; echo $y; })\" content=\"command\" authen_status=\"\" log_level=\"1\" session_id=\"$$\" 2>/dev/null; }'

# 解释：
# sdc_up_src_ip：日志写入目的主机ip；
# sdc_up_log_time：记录当前日志时间；
# if语句匹配条件：登入会话的用户=当前用户，与会话中ip同时存在，即可通过logger工具输出定制格式化的日志信息；


# 2、添加配置/etc/rsyslog.conf
auth.info;user.notice /var/log/authlog_new.log

# 3、重启rsyslog.service
systemctl restart rsyslog.service
systemctl status rsyslog.service

[root@harbor ~]# sudo rsyslogd -dn -f /etc/rsyslog.conf 2>&1 | grep -A5 'ruleset\|action'

4523.471383068:main thread : omfile.c: omfile: using transactional output interface.

4523.471393919:main thread : modules.c: module builtin:omfile of type 1 being loaded (keepType=0).

4523.471395391:main thread : modules.c: module config name is 'omfile'

4523.471396233:main thread : modules.c: module builtin:omfile supports rsyslog v6 config interface

4523.471397656:main thread : omfile.c: entry point 'activateCnfPrePrivDrop' not present in module

4523.471399339:main thread : omfile.c: entry point 'doHUPWrkr' not present in module

--

4523.471401954:main thread : omfile.c: entry point 'endTransaction' not present in module

4523.471404950:main thread : modules.c: module builtin:ompipe of type 1 being loaded (keepType=0).

4523.471406322:main thread : modules.c: module config name is 'ompipe'

4523.471407154:main thread : modules.c: module builtin:ompipe supports rsyslog v6 config interface

4523.471408496:main thread : ompipe.c: entry point 'activateCnfPrePrivDrop' not present in module

4523.471409979:main thread : ompipe.c: entry point 'doHUPWrkr' not present in module

--

4523.471411562:main thread : ompipe.c: entry point 'beginTransaction' not present in module

4523.471412444:main thread : ompipe.c: entry point 'commitTransaction' not present in module

4523.471413225:main thread : ompipe.c: entry point 'endTransaction' not present in module

4523.471415249:main thread : modules.c: module builtin-shell of type 1 being loaded (keepType=0).

4523.471416281:main thread : omshell.c: entry point 'setModCnf' not present in module

4523.471417063:main thread : omshell.c: entry point 'getModCnfName' not present in module

4523.471417814:main thread : omshell.c: entry point 'beginCnfLoad' not present in module

4523.471419227:main thread : omshell.c: entry point 'doHUP' not present in module

--

4523.471421431:main thread : omshell.c: entry point 'beginTransaction' not present in module

4523.471422233:main thread : omshell.c: entry point 'commitTransaction' not present in module

4523.471423134:main thread : omshell.c: entry point 'endTransaction' not present in module

4523.471423906:main thread : omshell.c: entry point 'newActInst' not present in module

4523.471425088:main thread : modules.c: module builtin:omdiscard of type 1 being loaded (keepType=0).

4523.471426070:main thread : omdiscard.c: entry point 'setModCnf' not present in module

4523.471426952:main thread : omdiscard.c: entry point 'getModCnfName' not present in module

4523.471427703:main thread : omdiscard.c: entry point 'beginCnfLoad' not present in module

--

4523.471431200:main thread : omdiscard.c: entry point 'beginTransaction' not present in module

4523.471431991:main thread : omdiscard.c: entry point 'commitTransaction' not present in module

4523.471432723:main thread : omdiscard.c: entry point 'endTransaction' not present in module

4523.471433464:main thread : omdiscard.c: entry point 'newActInst' not present in module

4523.471435528:main thread : modules.c: source file omfwd.c requested reference for module 'lmnet', reference count now 3

4523.471444455:main thread : modules.c: module builtin:omfwd of type 1 being loaded (keepType=0).

4523.471445818:main thread : modules.c: module config name is 'omfwd'

4523.471446619:main thread : modules.c: module builtin:omfwd supports rsyslog v6 config interface

--

4523.471452601:main thread : omfwd.c: entry point 'endTransaction' not present in module

4523.471454114:main thread : modules.c: module builtin:omusrmsg of type 1 being loaded (keepType=0).

4523.471455166:main thread : omusrmsg.c: entry point 'setModCnf' not present in module

4523.471456037:main thread : modules.c: module config name is 'omusrmsg'

4523.471456809:main thread : omusrmsg.c: entry point 'beginCnfLoad' not present in module

4523.471458151:main thread : omusrmsg.c: entry point 'doHUP' not present in module

--

4523.471460355:main thread : omusrmsg.c: entry point 'beginTransaction' not present in module

4523.471461157:main thread : omusrmsg.c: entry point 'commitTransaction' not present in module

4523.471461898:main thread : omusrmsg.c: entry point 'endTransaction' not present in module

4523.471463672:main thread : pmrfc5424.c: rfc5424 parser init called

4523.471464483:main thread : pmrfc5424.c: GetParserName addr 0x5559e4940ad0

4523.471465365:main thread : modules.c: module builtin:pmrfc5424 of type 3 being loaded (keepType=0).

4523.471466257:main thread : pmrfc5424.c: entry point 'setModCnf' not present in module

4523.471466988:main thread : pmrfc5424.c: entry point 'getModCnfName' not present in module

--

4523.471846973:main thread : rainerscript.c: action.reportsuspension: (unset)

4523.471848526:main thread : rainerscript.c: action.reportsuspensioncontinuation: (unset)

4523.471850019:main thread : rainerscript.c: parser.controlcharacterescapeprefix: (unset)

4523.471851432:main thread : rainerscript.c: parser.droptrailinglfonreception: (unset)

4523.471852975:main thread : rainerscript.c: parser.escapecontrolcharactersonreceive: (unset)

4523.471854497:main thread : rainerscript.c: parser.spacelfonreceive: (unset)

4523.471855950:main thread : rainerscript.c: parser.escape8bitcharactersonreceive: (unset)

--

4523.471906046:main thread : rainerscript.c: default.action.queue.timeoutshutdown: (unset)

4523.471907990:main thread : rainerscript.c: default.action.queue.timeoutactioncompletion: (unset)

4523.471910124:main thread : rainerscript.c: default.action.queue.timeoutenqueue: (unset)

4523.471911566:main thread : rainerscript.c: default.action.queue.timeoutworkerthreadshutdown: (unset)

4523.471913270:main thread : rainerscript.c: default.ruleset.queue.timeoutshutdown: (unset)

4523.471914522:main thread : rainerscript.c: default.ruleset.queue.timeoutactioncompletion: (unset)

4523.471915774:main thread : rainerscript.c: default.ruleset.queue.timeoutenqueue: (unset)

4523.471917007:main thread : rainerscript.c: default.ruleset.queue.timeoutworkerthreadshutdown: (unset)

4523.471918249:main thread : rainerscript.c: reverselookup.cache.ttl.default: (unset)

4523.471919491:main thread : rainerscript.c: reverselookup.cache.ttl.enable: (unset)

4523.471920714:main thread : rainerscript.c: shutdown.queue.doublesize: (unset)

4523.471921956:main thread : rainerscript.c: debug.files: (unset)

4523.471923209:main thread : rainerscript.c: debug.whitelist: (unset)

--

4523.472570975:main thread : conf.c: tried selector action for builtin:omfile: 0

4523.472572377:main thread : ../action.c: Module builtin:omfile processes this action.

4523.472574050:main thread : ../action.c: template: 'RSYSLOG_TraditionalFileFormat' assigned

4523.472577707:main thread : action-0-builtin:omfile queue: queue.c: parameter dump:

4523.472578709:main thread : action-0-builtin:omfile queue: queue.c: queue.filename '[NONE]'

4523.472579541:main thread : action-0-builtin:omfile queue: queue.c: queue.size: 1000

4523.472580352:main thread : action-0-builtin:omfile queue: queue.c: queue.dequeuebatchsize: 16

4523.472581414:main thread : action-0-builtin:omfile queue: queue.c: queue.mindequeuebatchsize: 0

4523.472582176:main thread : action-0-builtin:omfile queue: queue.c: queue.mindequeuebatchsize.timeout: 0

4523.472582977:main thread : action-0-builtin:omfile queue: queue.c: queue.maxdiskspace: 104857600

4523.472583739:main thread : action-0-builtin:omfile queue: queue.c: queue.highwatermark: -1

4523.472584470:main thread : action-0-builtin:omfile queue: queue.c: queue.lowwatermark: -1

4523.472585192:main thread : action-0-builtin:omfile queue: queue.c: queue.fulldelaymark: -1

4523.472585923:main thread : action-0-builtin:omfile queue: queue.c: queue.lightdelaymark: -1

4523.472586664:main thread : action-0-builtin:omfile queue: queue.c: queue.takeflowctlfrommsg: 0

4523.472587396:main thread : action-0-builtin:omfile queue: queue.c: queue.discardmark: 980

4523.472588127:main thread : action-0-builtin:omfile queue: queue.c: queue.discardseverity: 8

4523.472588829:main thread : action-0-builtin:omfile queue: queue.c: queue.checkpointinterval: 0

4523.472589550:main thread : action-0-builtin:omfile queue: queue.c: queue.syncqueuefiles: 0

4523.472590362:main thread : action-0-builtin:omfile queue: queue.c: queue.type: 3 [Direct]

4523.472591063:main thread : action-0-builtin:omfile queue: queue.c: queue.workerthreads: 1

4523.472591794:main thread : action-0-builtin:omfile queue: queue.c: queue.timeoutshutdown: 0

4523.472592536:main thread : action-0-builtin:omfile queue: queue.c: queue.timeoutactioncompletion: 1000

4523.472593267:main thread : action-0-builtin:omfile queue: queue.c: queue.timeoutenqueue: 50

4523.472594039:main thread : action-0-builtin:omfile queue: queue.c: queue.timeoutworkerthreadshutdown: 60000

4523.472594770:main thread : action-0-builtin:omfile queue: queue.c: queue.workerthreadminimummessages: -1

4523.472595541:main thread : action-0-builtin:omfile queue: queue.c: queue.maxfilesize: 1048576

4523.472596273:main thread : action-0-builtin:omfile queue: queue.c: queue.saveonshutdown: 1

4523.472596984:main thread : action-0-builtin:omfile queue: queue.c: queue.dequeueslowdown: 0

4523.472597696:main thread : action-0-builtin:omfile queue: queue.c: queue.dequeuetimebegin: 0

4523.472598407:main thread : action-0-builtin:omfile queue: queue.c: queue.dequeuetimeend: 25

4523.472599279:main thread : ../action.c: Action 0x5559e558d740: queue 0x5559e558db70 created

-> $$ = nterm s_act ()

Stack now 0 1 17

Entering state 28

Reducing stack by rule 39 (line 188):

$1 = nterm s_act ()

--

4523.472646709:main thread : conf.c: tried selector action for builtin:omfile: 0

4523.472647481:main thread : ../action.c: Module builtin:omfile processes this action.

4523.472648332:main thread : ../action.c: template: 'RSYSLOG_TraditionalFileFormat' assigned

4523.472649855:main thread : action-1-builtin:omfile queue: queue.c: parameter dump:

4523.472650606:main thread : action-1-builtin:omfile queue: queue.c: queue.filename '[NONE]'

4523.472651328:main thread : action-1-builtin:omfile queue: queue.c: queue.size: 1000

4523.472652099:main thread : action-1-builtin:omfile queue: queue.c: queue.dequeuebatchsize: 16

4523.472652881:main thread : action-1-builtin:omfile queue: queue.c: queue.mindequeuebatchsize: 0

4523.472653592:main thread : action-1-builtin:omfile queue: queue.c: queue.mindequeuebatchsize.timeout: 0

4523.472654324:main thread : action-1-builtin:omfile queue: queue.c: queue.maxdiskspace: 104857600

4523.472655025:main thread : action-1-builtin:omfile queue: queue.c: queue.highwatermark: -1

4523.472655736:main thread : action-1-builtin:omfile queue: queue.c: queue.lowwatermark: -1

4523.472656438:main thread : action-1-builtin:omfile queue: queue.c: queue.fulldelaymark: -1

4523.472657129:main thread : action-1-builtin:omfile queue: queue.c: queue.lightdelaymark: -1

4523.472657830:main thread : action-1-builtin:omfile queue: queue.c: queue.takeflowctlfrommsg: 0

4523.472658552:main thread : action-1-builtin:omfile queue: queue.c: queue.discardmark: 980

4523.472659263:main thread : action-1-builtin:omfile queue: queue.c: queue.discardseverity: 8

4523.472659954:main thread : action-1-builtin:omfile queue: queue.c: queue.checkpointinterval: 0

4523.472660656:main thread : action-1-builtin:omfile queue: queue.c: queue.syncqueuefiles: 0

4523.472661387:main thread : action-1-builtin:omfile queue: queue.c: queue.type: 3 [Direct]

4523.472662088:main thread : action-1-builtin:omfile queue: queue.c: queue.workerthreads: 1

4523.472662790:main thread : action-1-builtin:omfile queue: queue.c: queue.timeoutshutdown: 0

4523.472663491:main thread : action-1-builtin:omfile queue: queue.c: queue.timeoutactioncompletion: 1000

4523.472664182:main thread : action-1-builtin:omfile queue: queue.c: queue.timeoutenqueue: 50

4523.472664894:main thread : action-1-builtin:omfile queue: queue.c: queue.timeoutworkerthreadshutdown: 60000

4523.472665585:main thread : action-1-builtin:omfile queue: queue.c: queue.workerthreadminimummessages: -1

4523.472666296:main thread : action-1-builtin:omfile queue: queue.c: queue.maxfilesize: 1048576

4523.472667419:main thread : action-1-builtin:omfile queue: queue.c: queue.saveonshutdown: 1

4523.472668130:main thread : action-1-builtin:omfile queue: queue.c: queue.dequeueslowdown: 0

4523.472668821:main thread : action-1-builtin:omfile queue: queue.c: queue.dequeuetimebegin: 0

4523.472669513:main thread : action-1-builtin:omfile queue: queue.c: queue.dequeuetimeend: 25

4523.472670294:main thread : ../action.c: Action 0x5559e558e240: queue 0x5559e558e6d0 created

-> $$ = nterm s_act ()

Stack now 0 1 17

Entering state 28

Reducing stack by rule 39 (line 188):

$1 = nterm s_act ()

--

4523.472708267:main thread : conf.c: tried selector action for builtin:omfile: 0

4523.472708958:main thread : ../action.c: Module builtin:omfile processes this action.

4523.472709739:main thread : ../action.c: template: 'RSYSLOG_TraditionalFileFormat' assigned

4523.472712144:main thread : action-2-builtin:omfile queue: queue.c: parameter dump:

4523.472712986:main thread : action-2-builtin:omfile queue: queue.c: queue.filename '[NONE]'

4523.472713717:main thread : action-2-builtin:omfile queue: queue.c: queue.size: 1000

4523.472714428:main thread : action-2-builtin:omfile queue: queue.c: queue.dequeuebatchsize: 16

4523.472715130:main thread : action-2-builtin:omfile queue: queue.c: queue.mindequeuebatchsize: 0

4523.472715831:main thread : action-2-builtin:omfile queue: queue.c: queue.mindequeuebatchsize.timeout: 0

4523.472716542:main thread : action-2-builtin:omfile queue: queue.c: queue.maxdiskspace: 104857600

4523.472717224:main thread : action-2-builtin:omfile queue: queue.c: queue.highwatermark: -1

4523.472717905:main thread : action-2-builtin:omfile queue: queue.c: queue.lowwatermark: -1

4523.472718606:main thread : action-2-builtin:omfile queue: queue.c: queue.fulldelaymark: -1

4523.472719288:main thread : action-2-builtin:omfile queue: queue.c: queue.lightdelaymark: -1

4523.472719979:main thread : action-2-builtin:omfile queue: queue.c: queue.takeflowctlfrommsg: 0

4523.472720680:main thread : action-2-builtin:omfile queue: queue.c: queue.discardmark: 980

4523.472721351:main thread : action-2-builtin:omfile queue: queue.c: queue.discardseverity: 8

4523.472722053:main thread : action-2-builtin:omfile queue: queue.c: queue.checkpointinterval: 0

4523.472722744:main thread : action-2-builtin:omfile queue: queue.c: queue.syncqueuefiles: 0

4523.472723455:main thread : action-2-builtin:omfile queue: queue.c: queue.type: 3 [Direct]

4523.472724137:main thread : action-2-builtin:omfile queue: queue.c: queue.workerthreads: 1

4523.472724828:main thread : action-2-builtin:omfile queue: queue.c: queue.timeoutshutdown: 0

4523.472725529:main thread : action-2-builtin:omfile queue: queue.c: queue.timeoutactioncompletion: 1000

4523.472726221:main thread : action-2-builtin:omfile queue: queue.c: queue.timeoutenqueue: 50

4523.472727112:main thread : action-2-builtin:omfile queue: queue.c: queue.timeoutworkerthreadshutdown: 60000

4523.472727824:main thread : action-2-builtin:omfile queue: queue.c: queue.workerthreadminimummessages: -1

4523.472728545:main thread : action-2-builtin:omfile queue: queue.c: queue.maxfilesize: 1048576

4523.472729237:main thread : action-2-builtin:omfile queue: queue.c: queue.saveonshutdown: 1

4523.472729928:main thread : action-2-builtin:omfile queue: queue.c: queue.dequeueslowdown: 0

4523.472730609:main thread : action-2-builtin:omfile queue: queue.c: queue.dequeuetimebegin: 0

4523.472731300:main thread : action-2-builtin:omfile queue: queue.c: queue.dequeuetimeend: 25

4523.472732092:main thread : ../action.c: Action 0x5559e558eda0: queue 0x5559e558f230 created

-> $$ = nterm s_act ()

Stack now 0 1 17

Entering state 28

Reducing stack by rule 39 (line 188):

$1 = nterm s_act ()

--

4523.472769433:main thread : conf.c: tried selector action for builtin:omfile: 0

4523.472770125:main thread : ../action.c: Module builtin:omfile processes this action.

4523.472770896:main thread : ../action.c: template: 'RSYSLOG_TraditionalFileFormat' assigned

4523.472773531:main thread : action-3-builtin:omfile queue: queue.c: parameter dump:

4523.472774343:main thread : action-3-builtin:omfile queue: queue.c: queue.filename '[NONE]'

4523.472775064:main thread : action-3-builtin:omfile queue: queue.c: queue.size: 1000

4523.472775775:main thread : action-3-builtin:omfile queue: queue.c: queue.dequeuebatchsize: 16

4523.472776487:main thread : action-3-builtin:omfile queue: queue.c: queue.mindequeuebatchsize: 0

4523.472777188:main thread : action-3-builtin:omfile queue: queue.c: queue.mindequeuebatchsize.timeout: 0

4523.472777899:main thread : action-3-builtin:omfile queue: queue.c: queue.maxdiskspace: 104857600

4523.472778601:main thread : action-3-builtin:omfile queue: queue.c: queue.highwatermark: -1

4523.472779292:main thread : action-3-builtin:omfile queue: queue.c: queue.lowwatermark: -1

4523.472779993:main thread : action-3-builtin:omfile queue: queue.c: queue.fulldelaymark: -1

4523.472780695:main thread : action-3-builtin:omfile queue: queue.c: queue.lightdelaymark: -1

4523.472781396:main thread : action-3-builtin:omfile queue: queue.c: queue.takeflowctlfrommsg: 0

4523.472782107:main thread : action-3-builtin:omfile queue: queue.c: queue.discardmark: 980

4523.472782799:main thread : action-3-builtin:omfile queue: queue.c: queue.discardseverity: 8

4523.472783510:main thread : action-3-builtin:omfile queue: queue.c: queue.checkpointinterval: 0

4523.472784201:main thread : action-3-builtin:omfile queue: queue.c: queue.syncqueuefiles: 0

4523.472784923:main thread : action-3-builtin:omfile queue: queue.c: queue.type: 3 [Direct]

4523.472785614:main thread : action-3-builtin:omfile queue: queue.c: queue.workerthreads: 1

4523.472786386:main thread : action-3-builtin:omfile queue: queue.c: queue.timeoutshutdown: 0

4523.472787097:main thread : action-3-builtin:omfile queue: queue.c: queue.timeoutactioncompletion: 1000

4523.472787798:main thread : action-3-builtin:omfile queue: queue.c: queue.timeoutenqueue: 50

4523.472788510:main thread : action-3-builtin:omfile queue: queue.c: queue.timeoutworkerthreadshutdown: 60000

4523.472789221:main thread : action-3-builtin:omfile queue: queue.c: queue.workerthreadminimummessages: -1

4523.472789942:main thread : action-3-builtin:omfile queue: queue.c: queue.maxfilesize: 1048576

4523.472790644:main thread : action-3-builtin:omfile queue: queue.c: queue.saveonshutdown: 1

4523.472791345:main thread : action-3-builtin:omfile queue: queue.c: queue.dequeueslowdown: 0

4523.472792036:main thread : action-3-builtin:omfile queue: queue.c: queue.dequeuetimebegin: 0

4523.472792738:main thread : action-3-builtin:omfile queue: queue.c: queue.dequeuetimeend: 25

4523.472793509:main thread : ../action.c: Action 0x5559e558f900: queue 0x5559e558fd90 created

-> $$ = nterm s_act ()

Stack now 0 1 17

Entering state 28

Reducing stack by rule 39 (line 188):

$1 = nterm s_act ()

--

4523.472830750:main thread : conf.c: tried selector action for builtin:omfile: -2001

4523.472831722:main thread : conf.c: tried selector action for builtin:ompipe: -2001

4523.472832624:main thread : conf.c: tried selector action for builtin-shell: -2001

4523.472833485:main thread : conf.c: tried selector action for builtin:omdiscard: -2001

4523.472834968:main thread : conf.c: tried selector action for builtin:omfwd: -2001

4523.472835910:main thread : omusrmsg.c: write-alltried selector action for builtin:omusrmsg: 0

4523.472837203:main thread : ../action.c: Module builtin:omusrmsg processes this action.

4523.472838064:main thread : ../action.c: template: ' WallFmt' assigned

4523.472839567:main thread : action-4-builtin:omusrmsg queue: queue.c: parameter dump:

4523.472840318:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.filename '[NONE]'

4523.472841040:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.size: 1000

4523.472841741:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.dequeuebatchsize: 16

4523.472842433:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.mindequeuebatchsize: 0

4523.472843134:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.mindequeuebatchsize.timeout: 0

4523.472843835:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.maxdiskspace: 104857600

4523.472844526:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.highwatermark: -1

4523.472845208:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.lowwatermark: -1

4523.472845909:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.fulldelaymark: -1

4523.472846881:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.lightdelaymark: -1

4523.472847592:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.takeflowctlfrommsg: 0

4523.472848294:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.discardmark: 980

4523.472848985:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.discardseverity: 8

4523.472849686:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.checkpointinterval: 0

4523.472850378:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.syncqueuefiles: 0

4523.472965497:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.type: 3 [Direct]

4523.472966599:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.workerthreads: 1

4523.472967321:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.timeoutshutdown: 0

4523.472968032:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.timeoutactioncompletion: 1000

4523.472968723:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.timeoutenqueue: 50

4523.472969445:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.timeoutworkerthreadshutdown: 60000

4523.472970156:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.workerthreadminimummessages: -1

4523.472970858:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.maxfilesize: 1048576

4523.472971549:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.saveonshutdown: 1

4523.472972220:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.dequeueslowdown: 0

4523.472972901:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.dequeuetimebegin: 0

4523.472973573:main thread : action-4-builtin:omusrmsg queue: queue.c: queue.dequeuetimeend: 25

4523.472974484:main thread : ../action.c: Action 0x5559e5590590: queue 0x5559e5590920 created

-> $$ = nterm s_act ()

Stack now 0 1 17

Entering state 28

Reducing stack by rule 39 (line 188):

$1 = nterm s_act ()

--

4523.473016956:main thread : conf.c: tried selector action for builtin:omfile: 0

4523.473017767:main thread : ../action.c: Module builtin:omfile processes this action.

4523.473018869:main thread : ../action.c: template: 'RSYSLOG_TraditionalFileFormat' assigned

4523.473021013:main thread : action-5-builtin:omfile queue: queue.c: parameter dump:

4523.473021775:main thread : action-5-builtin:omfile queue: queue.c: queue.filename '[NONE]'

4523.473022486:main thread : action-5-builtin:omfile queue: queue.c: queue.size: 1000

4523.473023197:main thread : action-5-builtin:omfile queue: queue.c: queue.dequeuebatchsize: 16

4523.473023959:main thread : action-5-builtin:omfile queue: queue.c: queue.mindequeuebatchsize: 0

4523.473024660:main thread : action-5-builtin:omfile queue: queue.c: queue.mindequeuebatchsize.timeout: 0

4523.473025362:main thread : action-5-builtin:omfile queue: queue.c: queue.maxdiskspace: 104857600

4523.473026434:main thread : action-5-builtin:omfile queue: queue.c: queue.highwatermark: -1

4523.473027145:main thread : action-5-builtin:omfile queue: queue.c: queue.lowwatermark: -1

4523.473027836:main thread : action-5-builtin:omfile queue: queue.c: queue.fulldelaymark: -1

4523.473028528:main thread : action-5-builtin:omfile queue: queue.c: queue.lightdelaymark: -1

4523.473029209:main thread : action-5-builtin:omfile queue: queue.c: queue.takeflowctlfrommsg: 0

4523.473029900:main thread : action-5-builtin:omfile queue: queue.c: queue.discardmark: 980

4523.473030582:main thread : action-5-builtin:omfile queue: queue.c: queue.discardseverity: 8

4523.473031263:main thread : action-5-builtin:omfile queue: queue.c: queue.checkpointinterval: 0

4523.473031944:main thread : action-5-builtin:omfile queue: queue.c: queue.syncqueuefiles: 0

4523.473032665:main thread : action-5-builtin:omfile queue: queue.c: queue.type: 3 [Direct]

4523.473033337:main thread : action-5-builtin:omfile queue: queue.c: queue.workerthreads: 1

4523.473034008:main thread : action-5-builtin:omfile queue: queue.c: queue.timeoutshutdown: 0

4523.473034689:main thread : action-5-builtin:omfile queue: queue.c: queue.timeoutactioncompletion: 1000

4523.473035371:main thread : action-5-builtin:omfile queue: queue.c: queue.timeoutenqueue: 50

4523.473036062:main thread : action-5-builtin:omfile queue: queue.c: queue.timeoutworkerthreadshutdown: 60000

4523.473036733:main thread : action-5-builtin:omfile queue: queue.c: queue.workerthreadminimummessages: -1

4523.473037435:main thread : action-5-builtin:omfile queue: queue.c: queue.maxfilesize: 1048576

4523.473038106:main thread : action-5-builtin:omfile queue: queue.c: queue.saveonshutdown: 1

4523.473038787:main thread : action-5-builtin:omfile queue: queue.c: queue.dequeueslowdown: 0

4523.473039458:main thread : action-5-builtin:omfile queue: queue.c: queue.dequeuetimebegin: 0

4523.473040140:main thread : action-5-builtin:omfile queue: queue.c: queue.dequeuetimeend: 25

4523.473040901:main thread : ../action.c: Action 0x5559e5591050: queue 0x5559e55914c0 created

-> $$ = nterm s_act ()

Stack now 0 1 17

Entering state 28

Reducing stack by rule 39 (line 188):

$1 = nterm s_act ()

--

4523.473079325:main thread : conf.c: tried selector action for builtin:omfile: 0

4523.473080016:main thread : ../action.c: Module builtin:omfile processes this action.

4523.473080797:main thread : ../action.c: template: 'RSYSLOG_TraditionalFileFormat' assigned

4523.473083172:main thread : action-6-builtin:omfile queue: queue.c: parameter dump:

4523.473083963:main thread : action-6-builtin:omfile queue: queue.c: queue.filename '[NONE]'

4523.473084665:main thread : action-6-builtin:omfile queue: queue.c: queue.size: 1000

4523.473127627:main thread : action-6-builtin:omfile queue: queue.c: queue.dequeuebatchsize: 16

4523.473128478:main thread : action-6-builtin:omfile queue: queue.c: queue.mindequeuebatchsize: 0

4523.473129190:main thread : action-6-builtin:omfile queue: queue.c: queue.mindequeuebatchsize.timeout: 0

4523.473129911:main thread : action-6-builtin:omfile queue: queue.c: queue.maxdiskspace: 104857600

4523.473130602:main thread : action-6-builtin:omfile queue: queue.c: queue.highwatermark: -1

4523.473131294:main thread : action-6-builtin:omfile queue: queue.c: queue.lowwatermark: -1

4523.473131995:main thread : action-6-builtin:omfile queue: queue.c: queue.fulldelaymark: -1

4523.473132696:main thread : action-6-builtin:omfile queue: queue.c: queue.lightdelaymark: -1

4523.473133398:main thread : action-6-builtin:omfile queue: queue.c: queue.takeflowctlfrommsg: 0

4523.473134089:main thread : action-6-builtin:omfile queue: queue.c: queue.discardmark: 980

4523.473134780:main thread : action-6-builtin:omfile queue: queue.c: queue.discardseverity: 8

4523.473135482:main thread : action-6-builtin:omfile queue: queue.c: queue.checkpointinterval: 0

4523.473136173:main thread : action-6-builtin:omfile queue: queue.c: queue.syncqueuefiles: 0

4523.473136884:main thread : action-6-builtin:omfile queue: queue.c: queue.type: 3 [Direct]

4523.473137576:main thread : action-6-builtin:omfile queue: queue.c: queue.workerthreads: 1

4523.473138277:main thread : action-6-builtin:omfile queue: queue.c: queue.timeoutshutdown: 0

4523.473138978:main thread : action-6-builtin:omfile queue: queue.c: queue.timeoutactioncompletion: 1000

4523.473139680:main thread : action-6-builtin:omfile queue: queue.c: queue.timeoutenqueue: 50

4523.473140391:main thread : action-6-builtin:omfile queue: queue.c: queue.timeoutworkerthreadshutdown: 60000

4523.473141082:main thread : action-6-builtin:omfile queue: queue.c: queue.workerthreadminimummessages: -1

4523.473141794:main thread : action-6-builtin:omfile queue: queue.c: queue.maxfilesize: 1048576

4523.473142475:main thread : action-6-builtin:omfile queue: queue.c: queue.saveonshutdown: 1

4523.473143176:main thread : action-6-builtin:omfile queue: queue.c: queue.dequeueslowdown: 0

4523.473143868:main thread : action-6-builtin:omfile queue: queue.c: queue.dequeuetimebegin: 0

4523.473144559:main thread : action-6-builtin:omfile queue: queue.c: queue.dequeuetimeend: 25

4523.473145391:main thread : ../action.c: Action 0x5559e5591bc0: queue 0x5559e5592050 created

-> $$ = nterm s_act ()

Stack now 0 1 17

Entering state 28

Reducing stack by rule 39 (line 188):

$1 = nterm s_act ()

--

4523.473186299:main thread : ruleset.c: begin ruleset optimization phase

4523.473187341:main thread : ruleset.c: ruleset 'RSYSLOG_DefaultRuleset' before optimization:

4523.473188533:main thread : ruleset 0x5559e557bec0: ruleset.c: rsyslog ruleset RSYSLOG_DefaultRuleset:

4523.473189655:main thread : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.473190316:main thread : 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

4523.473201127:main thread : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.473202429:main thread : rainerscript.c: END PRIFILT

4523.473203151:main thread : rainerscript.c: PRIFILT 'authpriv.*'

--

4523.473274858:main thread : ruleset 0x5559e557bec0: ruleset.c: ruleset RSYSLOG_DefaultRuleset assigned parser list:

4523.473276350:main thread : rainerscript.c: optimizing cnfstmt type 4001

4523.473277162:main thread : rainerscript.c: optimizing cnfstmt type 4004

4523.473277893:main thread : rainerscript.c: optimizing cnfstmt type 4001

4523.473278545:main thread : rainerscript.c: optimizing cnfstmt type 4004

4523.473279196:main thread : rainerscript.c: optimizing cnfstmt type 4001

--

4523.473285738:main thread : ruleset.c: ruleset 'RSYSLOG_DefaultRuleset' after optimization:

4523.473286400:main thread : ruleset 0x5559e557bec0: ruleset.c: rsyslog ruleset RSYSLOG_DefaultRuleset:

4523.473287241:main thread : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.473287852:main thread : 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

4523.473298182:main thread : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.473299244:main thread : rainerscript.c: END PRIFILT

4523.473299885:main thread : rainerscript.c: PRIFILT 'authpriv.*'

--

4523.473371031:main thread : ruleset 0x5559e557bec0: ruleset.c: ruleset RSYSLOG_DefaultRuleset assigned parser list:

4523.473371793:main thread : ruleset.c: ruleset optimization phase finished.

4523.473372614:main thread : rsconf.c: Number of actions in this configuration: 7

4523.473373335:main thread : rsconf.c: telling rsyslog core that config load for 0x5559e5578050 is done

4523.473374688:main thread : glbl.c: Timezone information table (0 entries):

4523.473384236:main thread : rsconf.c: telling modules that config load for 0x5559e5578050 is done

4523.473385168:main thread : rsconf.c: beginCnfLoad(0x5559e493c8b0) for module 'builtin:omfile'

4523.473385859:main thread : rsconf.c: calling endCnfLoad() for module 'builtin:omfile'

--

4523.473409915:main thread : ruleset.c: All Rulesets:

4523.473410617:main thread : ruleset 0x5559e557bec0: ruleset.c: rsyslog ruleset RSYSLOG_DefaultRuleset:

4523.473411348:main thread : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.473411949:main thread : 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

4523.473422189:main thread : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.473423271:main thread : rainerscript.c: END PRIFILT

4523.473423912:main thread : rainerscript.c: PRIFILT 'authpriv.*'

--

4523.473494807:main thread : ruleset 0x5559e557bec0: ruleset.c: ruleset RSYSLOG_DefaultRuleset assigned parser list:

4523.473495539:main thread : ruleset.c: End of Rulesets.

4523.473496170:main thread : rsconf.c:

4523.473496921:main thread : ../template.c: Template: Name='RSYSLOG_DebugFormat'

4523.473498053:main thread : ../template.c: Entry(5559e557e980): type 1, (CONSTANT), value: 'Debug line with all properties:

FROMHOST: ''

4523.473499576:main thread : ../template.c: Entry(5559e557ea40): type 2, (FIELD), value: '7'

--

4523.473783358:main thread : rsconf.c: Main queue timeouts: shutdown: 1500, action completion shutdown: 1000, enq: 2000

4523.473784240:main thread : rsconf.c: Main queue watermarks: high: 80000, low: 20000, discard: 98000, discard-severity: 8

4523.473784961:main thread : rsconf.c: Main queue save on shutdown 1, max disk space allowed 0

4523.473785732:main thread : rsconf.c: Work Directory: '/var/lib/rsyslog'.

4523.473786574:main thread : rsconf.c: Modules used in this configuration:

4523.473787285:main thread : rsconf.c: builtin:omfile

--

4523.473932863:main thread : ruleset.c: iterateAllActions calling into action 0x5559e558d740

4523.473934887:main thread : action-0-builtin:omfile queue: queue.c: starting queue

4523.473937772:main thread : action-0-builtin:omfile queue: queue.c: params: type 3, enq-only 0, disk assisted 0, spoolDir '/var/lib/rsyslog', maxFileSz 1048576, maxQSize 1000, lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16, min deq batch size 0, high wtrmrk 900, low wtrmrk 700, discardmrk 980, max wrkr 1, min msgs f. wrkr 1000 takeFlowCtlFromMsg 0

4523.473946720:main thread : ../action.c: Action builtin:omfile[0x5559e558d740]: queue 0x5559e558db70 started

4523.473947541:main thread : ruleset.c: iterateAllActions calling into action 0x5559e558e240

4523.473948383:main thread : action-1-builtin:omfile queue: queue.c: starting queue

4523.473950126:main thread : action-1-builtin:omfile queue: queue.c: params: type 3, enq-only 0, disk assisted 0, spoolDir '/var/lib/rsyslog', maxFileSz 1048576, maxQSize 1000, lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16, min deq batch size 0, high wtrmrk 900, low wtrmrk 700, discardmrk 980, max wrkr 1, min msgs f. wrkr 1000 takeFlowCtlFromMsg 0

4523.473951028:main thread : ../action.c: Action builtin:omfile[0x5559e558e240]: queue 0x5559e558e6d0 started

4523.473951699:main thread : ruleset.c: iterateAllActions calling into action 0x5559e558eda0

4523.473952320:main thread : action-2-builtin:omfile queue: queue.c: starting queue

4523.473953833:main thread : action-2-builtin:omfile queue: queue.c: params: type 3, enq-only 0, disk assisted 0, spoolDir '/var/lib/rsyslog', maxFileSz 1048576, maxQSize 1000, lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16, min deq batch size 0, high wtrmrk 900, low wtrmrk 700, discardmrk 980, max wrkr 1, min msgs f. wrkr 1000 takeFlowCtlFromMsg 0

4523.473954705:main thread : ../action.c: Action builtin:omfile[0x5559e558eda0]: queue 0x5559e558f230 started

4523.473955386:main thread : ruleset.c: iterateAllActions calling into action 0x5559e558f900

4523.473956007:main thread : action-3-builtin:omfile queue: queue.c: starting queue

4523.473957470:main thread : action-3-builtin:omfile queue: queue.c: params: type 3, enq-only 0, disk assisted 0, spoolDir '/var/lib/rsyslog', maxFileSz 1048576, maxQSize 1000, lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16, min deq batch size 0, high wtrmrk 900, low wtrmrk 700, discardmrk 980, max wrkr 1, min msgs f. wrkr 1000 takeFlowCtlFromMsg 0

4523.473958312:main thread : ../action.c: Action builtin:omfile[0x5559e558f900]: queue 0x5559e558fd90 started

4523.473958973:main thread : ruleset.c: iterateAllActions calling into action 0x5559e5590590

4523.473959584:main thread : action-4-builtin:omusrmsg queue: queue.c: starting queue

4523.473961047:main thread : action-4-builtin:omusrmsg queue: queue.c: params: type 3, enq-only 0, disk assisted 0, spoolDir '/var/lib/rsyslog', maxFileSz 1048576, maxQSize 1000, lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16, min deq batch size 0, high wtrmrk 900, low wtrmrk 700, discardmrk 980, max wrkr 1, min msgs f. wrkr 1000 takeFlowCtlFromMsg 0

4523.473961919:main thread : ../action.c: Action builtin:omusrmsg[0x5559e5590590]: queue 0x5559e5590920 started

4523.473962580:main thread : ruleset.c: iterateAllActions calling into action 0x5559e5591050

4523.473963191:main thread : action-5-builtin:omfile queue: queue.c: starting queue

4523.473964624:main thread : action-5-builtin:omfile queue: queue.c: params: type 3, enq-only 0, disk assisted 0, spoolDir '/var/lib/rsyslog', maxFileSz 1048576, maxQSize 1000, lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16, min deq batch size 0, high wtrmrk 900, low wtrmrk 700, discardmrk 980, max wrkr 1, min msgs f. wrkr 1000 takeFlowCtlFromMsg 0

4523.473965475:main thread : ../action.c: Action builtin:omfile[0x5559e5591050]: queue 0x5559e55914c0 started

4523.473966127:main thread : ruleset.c: iterateAllActions calling into action 0x5559e5591bc0

4523.473966748:main thread : action-6-builtin:omfile queue: queue.c: starting queue

4523.473968170:main thread : action-6-builtin:omfile queue: queue.c: params: type 3, enq-only 0, disk assisted 0, spoolDir '/var/lib/rsyslog', maxFileSz 1048576, maxQSize 1000, lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16, min deq batch size 0, high wtrmrk 900, low wtrmrk 700, discardmrk 980, max wrkr 1, min msgs f. wrkr 1000 takeFlowCtlFromMsg 0

4523.473969002:main thread : ../action.c: Action builtin:omfile[0x5559e5591bc0]: queue 0x5559e5592050 started

4523.473970104:main thread : ruleset.c: Activating Ruleset Queue[(nil)] for Ruleset RSYSLOG_DefaultRuleset

4523.473970876:main thread : rsconf.c: activateMainQueue: mainq cnf obj ptr is (nil)

4523.473972429:main thread : main Q: queue.c: starting queue

4523.473978109:main thread : main Q: queue.c: is NOT disk-assisted

4523.473979853:main thread : main Q: queue.c: params: type 0, enq-only 0, disk assisted 0, spoolDir '/var/lib/rsyslog', maxFileSz 1048576, maxQSize 100000, lqsize 0, pqsize 0, child 0, full delay 97000, light delay 70000, deq batch size 256, min deq batch size 0, high wtrmrk 80000, low wtrmrk 20000, discardmrk 98000, max wrkr 2, min msgs f. wrkr 40000 takeFlowCtlFromMsg 0

4523.473982959:main thread : wtp.c: main Q:Reg: finalizing construction of worker thread pool (numworkerThreads 2)

4523.473984672:main thread : wti.c: main Q:Reg/w0: finalizing construction of worker instance data (for 7 actions)

4523.473987387:main thread : wti.c: main Q:Reg/w1: finalizing construction of worker instance data (for 7 actions)

4523.473989050:main thread : main Q: queue.c: queue finished initialization

4523.473991124:main thread : rsconf.c: Main processing queue is initialized and running

4523.473992276:main thread : rsconf.c: running module imuxsock with config 0x5559e558bfb0, term mode: cooperative/SIGTTIN

4523.474029578:main thread : rsconf.c: running module imjournal with config 0x5559e558d1b0, term mode: cooperative/SIGTTIN

4523.474044666:main thread : rsconf.c: configuration 0x5559e5578050 activated

--

4523.476127335:main Q:Reg/w0 : ruleset.c: processBATCH: batch of 17 elements must be processed

4523.476128948:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 0: run-user-993.mount: Succeeded.

4523.476130501:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.476132916: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

4523.476145079:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.476146011:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.476148526:main Q:Reg/w0 : ruleset.c: executing action 0

# action 子系统收到指令，发现该动作未挂起（susp 0/0），
# 并且工作在 direct queue 模式（direct q 1），即 同步、无内存队列，消息直接落盘。

4523.476150229:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

# omfile 被声明为“事务型”输出；rsyslog 会先把一批消息攒在内存，
# 然后在 commit 阶段一次性写入磁盘，提高吞吐。

4523.476155188:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

# actionPrepare 负责打开文件、检查外部状态文件、申请写缓存等前期动作；
# 成功后才会调用 commitTransaction 把数据 flush 到 /var/log/messages。

4523.476156271:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.476157242:main Q:Reg/w0 : ../action.c: wti 0x5559e5592720: we need to create a new action worker instance for action 0

4523.476158685:main Q:Reg/w0 : ../action.c: wti 0x5559e5592720: created action worker instance 1 for action 0

4523.476159567:main Q:Reg/w0 : ../action.c: checking external state file

4523.476160338:main Q:Reg/w0 : ../action.c: done checking external state file, iRet=0

4523.476161801:main Q:Reg/w0 : ../action.c: action[action-0-builtin:omfile] transitioned to state: itx

4523.476162603:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.476163474:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.476164867: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

4523.476175247:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476176038:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.476177511: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

4523.476187801:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476189113:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.476190486: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

4523.476200745:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476201437:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.476202829: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

4523.476216295:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476217527:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.476220012: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

4523.476233468:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476234540:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.476236494: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

4523.476251081:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476252805:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 1: [ 1112.704882] audit: type=1131 audit(1762824492.047:265): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=user-runtime-dir

4523.476253847:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.476255560: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

4523.476267042:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.476267673:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.476269196:main Q:Reg/w0 : ruleset.c: executing action 0

4523.476270028:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.476271190:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.476271901:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.476272923:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.476273574:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.476274957: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

4523.476285347:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476285968:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.476287321: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

4523.476297720:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476298332:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.476299694: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

4523.476310044:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476310655:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.476312008: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

4523.476323520:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476324141:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.476325493: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

4523.476335923:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476336534:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.476337867: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

4523.476348227:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476349018:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 2: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=user-runtime-dir@993 comm="systemd" exe="/usr/lib/systemd/syst

4523.476349720:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.476351062: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

4523.476362334:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.476362945:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.476364398:main Q:Reg/w0 : ruleset.c: executing action 0

4523.476365199:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.476366071:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.476366762:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.476367453:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.476368075:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.476369417: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

4523.476379737:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476380348:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.476382061: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

4523.476398643:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476400396:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.476402611: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

4523.476417840:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476418661:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.476420575: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

4523.476435393:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476436776:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.476438128: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

4523.476448268:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476448899:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.476450261: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

4523.476460311:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476461172:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 3: run-user-993.mount: Succeeded.

4523.476461803:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.476463106: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

4523.476476622:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.476477413:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.476479257:main Q:Reg/w0 : ruleset.c: executing action 0

4523.476480409:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.476482433:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.476483866:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.476484968:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.476486230:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.476488054: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

4523.476498514:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476499135:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.476500457: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

4523.476513853:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476514644:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.476516708: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

4523.476529974:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476530585:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.476531907: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

4523.476654832:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476660342:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.476662446: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

4523.476677124:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476678146:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.476679719: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

4523.476692504:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476693896:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 4: user-runtime-dir@993.service: Succeeded.

4523.476694768:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.476696501: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

4523.476711610:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.476712291:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.476713864:main Q:Reg/w0 : ruleset.c: executing action 0

4523.476714736:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.476716570:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.476718493:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.476719325:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.476719986:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.476721349: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

4523.476736578:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476737610:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.476739463: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

4523.476750224:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476750845:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.476752268: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

4523.476762577:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476763209:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.476764561: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

4523.476776193:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476776815:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.476778157: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

4523.476788557:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476789168:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.476790511: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

4523.476800840:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476801842:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 5: Stopped User Runtime Directory /run/user/993.

4523.476802463:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.476803806: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

4523.476815128:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.476815739:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.476817192:main Q:Reg/w0 : ruleset.c: executing action 0

4523.476817993:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.476818855:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.476819546:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.476820257:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.476820879:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.476822241: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

4523.476832701:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476833322:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.476834645: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

4523.476845065:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476845676:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.476847019: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

4523.476857408:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476858019:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.476859362: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

4523.476871295:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476871916:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.476873269: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

4523.476883688:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476884300:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.476885642: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

4523.476896052:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476896834:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 6: Removed slice User Slice of UID 993.

4523.476897445:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.476898787: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

4523.476910159:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.476910770:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.476912243:main Q:Reg/w0 : ruleset.c: executing action 0

4523.476913044:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.476913916:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.476914607:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.476915309:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.476915940:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.476917293: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

4523.476927722:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476928344:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.476929686: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

4523.476940166:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476940787:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.476942130: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

4523.476952570:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476953191:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.476954534: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

4523.476966206:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476966827:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.476968170: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

4523.476978710:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476979331:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.476980674: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

4523.476991113:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.476991905:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 7: [ 1144.111140] audit: type=1101 audit(1762824523.454:266): pid=9125 uid=0 auid=0 ses=1 msg='op=PAM:accounting grantors=pam_unix,

4523.476992536:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.476993869: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

4523.477005301:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.477005922:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.477007384:main Q:Reg/w0 : ruleset.c: executing action 0

4523.477008166:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.477009509:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.477010200:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.477010901:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.477011532:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.477012895: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

4523.477023335:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477023956:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.477025309: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

4523.477035829:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477036440:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.477037793: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

4523.477048273:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477048884:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.477050236: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

4523.477061989:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477062610:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.477063952: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

4523.477074523:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477075144:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.477076486: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

4523.477087006:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477087748:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 8: [ 1144.111145] audit: type=1123 audit(1762824523.454:267): pid=9125 uid=0 auid=0 ses=1 msg='cwd="/root" cmd=727379736C6F6764202D

4523.477088379:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.477089732: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

4523.477101143:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.477101765:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.477103227:main Q:Reg/w0 : ruleset.c: executing action 0

4523.477104019:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.477104881:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.477105572:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.477106263:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.477106894:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.477108247: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

4523.477118697:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477119318:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.477120671: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

4523.477131121:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477131732:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.477133084: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

4523.477143534:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477144777:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.477146149: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

4523.477157912:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477158543:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.477159885: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

4523.477170365:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477170987:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.477172329: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

4523.477182749:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477183551:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 9: [ 1144.111147] audit: type=1110 audit(1762824523.454:268): pid=9125 uid=0 auid=0 ses=1 msg='op=PAM:setcred grantors=pam_env,pam_

4523.477184172:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.477185514: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

4523.477196946:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.477197567:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.477199030:main Q:Reg/w0 : ruleset.c: executing action 0

4523.477199832:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.477200653:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.477201355:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.477202046:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.477202677:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.477204030: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

4523.477214480:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477215101:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.477216433: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

4523.477226863:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477227484:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.477228827: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

4523.477239317:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477239938:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.477241281: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

4523.477253023:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477253634:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.477254987: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

4523.477265547:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477266168:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.477267511: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

4523.477278011:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477278792:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 10: USER_ACCT pid=9125 uid=0 auid=0 ses=1 msg='op=PAM:accounting grantors=pam_unix,pam_faillock,pam_localuser acct="root" exe="/usr/

4523.477279414:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.477280766: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

4523.477292579:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.477293270:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.477294743:main Q:Reg/w0 : ruleset.c: executing action 0

4523.477295534:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.477296396:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.477297077:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.477297769:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.477298390:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.477299732: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

4523.477310162:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477310783:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.477312126: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

4523.477322576:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477323187:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.477324530: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

4523.477334970:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477335581:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.477336933: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

4523.477348636:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477349257:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.477350599: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

4523.477361019:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477361630:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.477362983: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

4523.477373333:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477374204:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 11: USER_CMD pid=9125 uid=0 auid=0 ses=1 msg='cwd="/root" cmd=727379736C6F6764202D646E202D66202F6574632F727379736C6F672E636F6E66 exe

4523.477374826:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.477376178: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

4523.477387560:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.477388181:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.477389634:main Q:Reg/w0 : ruleset.c: executing action 0

4523.477390425:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.477391327:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.477392018:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.477392710:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.477393341:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.477394694: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

4523.477406897:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477407929:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.477410003: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

4523.477424070:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477425142:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.477426504: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

4523.477436734:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477437335:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.477438647: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

4523.477450099:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477450710:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.477452033: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

4523.477462292:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477462894:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.477464216: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

4523.477474366:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477475528:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 12: CRED_REFR pid=9125 uid=0 auid=0 ses=1 msg='op=PAM:setcred grantors=pam_env,pam_faillock,pam_unix acct="root" exe="/usr/bin/sudo"

4523.477476159:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.477477461: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

4523.477488543:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.477489144:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.477490596:main Q:Reg/w0 : ruleset.c: executing action 0

4523.477491378:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.477492370:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.477493051:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.477493742:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.477494374:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.477495686: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

4523.477505906:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477506517:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.477507849: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

4523.477518039:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477518650:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.477519963: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

4523.477530092:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477530693:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.477532006: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

4523.477543467:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477544079:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.477545391: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

4523.477555591:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477556202:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.477557514: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

4523.477567644:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477568545:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 13: root : TTY=pts/0 ; PWD=/root ; USER=root ; COMMAND=/usr/sbin/rsyslogd -dn -f /etc/rsyslog.conf

4523.477569307:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.477570649: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

4523.477688173:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477689145:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.477690628: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

4523.477700878:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.477701509:main Q:Reg/w0 : rainerscript.c: ACTION 1 [builtin:omfile:/var/log/secure]

4523.477703202:main Q:Reg/w0 : ruleset.c: executing action 1

4523.477704124:main Q:Reg/w0 : ../action.c: action 'action-1-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.477711979:main Q:Reg/w0 : ../action.c: action 'action-1-builtin:omfile': is transactional - executing in commit phase

4523.477712770:main Q:Reg/w0 : ../action.c: actionPrepare[action-1-builtin:omfile]: enter

4523.477713562:main Q:Reg/w0 : ../action.c: wti 0x5559e5592720: we need to create a new action worker instance for action 1

4523.477714644:main Q:Reg/w0 : ../action.c: wti 0x5559e5592720: created action worker instance 1 for action 1

4523.477715706:main Q:Reg/w0 : ../action.c: checking external state file

4523.477716367:main Q:Reg/w0 : ../action.c: done checking external state file, iRet=0

4523.477717169:main Q:Reg/w0 : ../action.c: action[action-1-builtin:omfile] transitioned to state: itx

4523.477717910:main Q:Reg/w0 : ../action.c: action 'action-1-builtin:omfile': set suspended state to 0

4523.477718571:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.477719904: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

4523.477729883:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477730484:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.477731777: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

4523.477741646:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477742237:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.477743539: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

4523.477754620:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477755211:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.477756524: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

4523.477766463:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477767064:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.477768377: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

4523.477778225:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477779327:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 14: USER_START pid=9125 uid=0 auid=0 ses=1 msg='op=PAM:session_open grantors=pam_keyinit,pam_limits,pam_keyinit,pam_limits,pam_syste

4523.477780039:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.477781351: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

4523.477792242:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.477792853:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.477794276:main Q:Reg/w0 : ruleset.c: executing action 0

4523.477795047:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.477796310:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.477797011:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.477797702:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.477798294:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.477799606: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

4523.477809465:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477810066:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.477811359: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

4523.477821197:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477821788:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.477823081: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

4523.477832920:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477833511:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.477834803: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

4523.477845774:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477846375:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.477847668: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

4523.477857587:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477858188:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.477859470: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

4523.477869309:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477870652:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 15: [ 1144.123871] audit: type=1105 audit(1762824523.465:269): pid=9125 uid=0 auid=0 ses=1 msg='op=PAM:session_open grantors=pam_key

4523.477871253:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.477872535: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

4523.477883246:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.477883837:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.477885240:main Q:Reg/w0 : ruleset.c: executing action 0

4523.477886021:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.477886933:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.477887614:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.477888315:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.477888917:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.477890239: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

4523.477900198:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477900789:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.477902092: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

4523.477912031:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477912622:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.477913924: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

4523.477923863:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477924985:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.477926538: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

4523.477937880:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477938641:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.477940264: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

4523.477951265:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477952017:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.477953630: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

4523.477964521:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477965693:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 16: pam_unix(sudo:session): session opened for user root(uid=0) by root(uid=0)

4523.477966304:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.477967587: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

4523.477978287:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.477978888:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.477980161: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

4523.477990029:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.477990631:main Q:Reg/w0 : rainerscript.c: ACTION 1 [builtin:omfile:/var/log/secure]

4523.477992043:main Q:Reg/w0 : ruleset.c: executing action 1

4523.477992805:main Q:Reg/w0 : ../action.c: action 'action-1-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.477993606:main Q:Reg/w0 : ../action.c: action 'action-1-builtin:omfile': is transactional - executing in commit phase

4523.477994278:main Q:Reg/w0 : ../action.c: actionPrepare[action-1-builtin:omfile]: enter

4523.477994949:main Q:Reg/w0 : ../action.c: action 'action-1-builtin:omfile': set suspended state to 0

4523.477995550:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.477996852: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

4523.478006751:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.478007353:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.478008635: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

4523.478018544:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.478019135:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.478020407: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

4523.478031479:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.478032080:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.478033352: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

4523.478043321:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.478043912:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.478045195: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

4523.478055054:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.478055835:main Q:Reg/w0 : ruleset.c: END batch execution phase, entering to commit phase [processed 17 of 17 messages]

4523.478056727:main Q:Reg/w0 : ../action.c: actionCommitAllDirect: action 0, state 1, nbr to commit 15 isTransactional 1

4523.478057709:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: enter, 15 msgs

4523.478654497:imjournal.c : main Q: queue.c: EnqueueMsg advised worker start

4523.503289919:imjournal.c : main Q: queue.c: EnqueueMsg advised worker start

4523.478058410:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: processing...

4523.503377817:main Q:Reg/w0 : ../action.c: actionTryCommit[action-0-builtin:omfile] enter

4523.503379420:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.503380542:main Q:Reg/w0 : ../action.c: doTransaction: have commitTransaction IF, using that, pWrkrInfo 0x5559e55927d0

4523.503381634:main Q:Reg/w0 : ../action.c: entering actionCallCommitTransaction[action-0-builtin:omfile], state: itx, nMsgs 15

4523.503395651:main Q:Reg/w0 : stream.c: file stream messages params: flush interval 0, async write 0

4523.503399729:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7f3fb80025d0, lenBuf 66, strt data Nov 11 09:28:12 harbor systemd[1]: run-user-993.mount: Succeeded.

4523.503401632:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7f3fb80025d0, lenBuf 252, strt data Nov 11 09:28:12 harbor kernel: [ 1112.704882] audit: type=1131 audit(1762824492.047:265): pid=1 uid=0 auid=4294967295 ses=429496

4523.503402985:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7f3fb80025d0, lenBuf 208, strt data Nov 11 09:28:12 harbor audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=user-runtime-dir@993 comm="sy

--

4523.503459302:main Q:Reg/w0 : ../action.c: actionCallCommitTransaction[action-0-builtin:omfile] state: itx mod commitTransaction returned 0

4523.503460424:main Q:Reg/w0 : ../action.c: action[action-0-builtin:omfile] transitioned to state: rdy

4523.503461436:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: return actionTryCommit 0

4523.503462338:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: done, iRet 0

4523.503464011:main Q:Reg/w0 : ../action.c: actionCommitAllDirect: action 1, state 1, nbr to commit 0 isTransactional 1

4523.503465093:main Q:Reg/w0 : ../action.c: actionCommit[action-1-builtin:omfile]: enter, 2 msgs

4523.503465795:main Q:Reg/w0 : ../action.c: actionCommit[action-1-builtin:omfile]: processing...

4523.503466466:main Q:Reg/w0 : ../action.c: actionTryCommit[action-1-builtin:omfile] enter

4523.503467127:main Q:Reg/w0 : ../action.c: actionPrepare[action-1-builtin:omfile]: enter

4523.503467798:main Q:Reg/w0 : ../action.c: doTransaction: have commitTransaction IF, using that, pWrkrInfo 0x5559e5592840

4523.503468550:main Q:Reg/w0 : ../action.c: entering actionCallCommitTransaction[action-1-builtin:omfile], state: itx, nMsgs 2

4523.503471205:main Q:Reg/w0 : stream.c: file stream secure params: flush interval 0, async write 0

4523.503483579:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7f3fb8004910, lenBuf 133, strt data Nov 11 09:28:43 harbor sudo[9125]: root : TTY=pts/0 ; PWD=/root ; USER=root ; COMMAND=/usr/sbin/rsyslogd -dn -f /etc/rsyslog.

4523.503484931:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7f3fb8004910, lenBuf 110, strt data Nov 11 09:28:43 harbor sudo[9125]: pam_unix(sudo:session): session opened for user root(uid=0) by root(uid=0)

4523.503486294:main Q:Reg/w0 : strm 0x7f3fb8004910: stream.c: file -1 strmFlush

--

4523.503498156:main Q:Reg/w0 : ../action.c: actionCallCommitTransaction[action-1-builtin:omfile] state: itx mod commitTransaction returned 0

4523.503498858:main Q:Reg/w0 : ../action.c: action[action-1-builtin:omfile] transitioned to state: rdy

4523.503499629:main Q:Reg/w0 : ../action.c: actionCommit[action-1-builtin:omfile]: return actionTryCommit 0

4523.503500300:main Q:Reg/w0 : ../action.c: actionCommit[action-1-builtin:omfile]: done, iRet 0

4523.503501302:main Q:Reg/w0 : ruleset.c: processBATCH: batch of 17 elements has been processed

4523.503502735:main Q:Reg/w0 : queue.c: regular consumer finished, iret=0, szlog 2 sz phys 19

4523.503504358:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: etry 0 state 3

4523.503507244:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: etry 1 state 3

4523.503509067:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: etry 2 state 3

4523.503510991:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: etry 3 state 3

--

4523.503547380:main Q:Reg/w0 : ruleset.c: processBATCH: batch of 2 elements must be processed

4523.503548212:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 0: [origin software="rsyslogd" swVersion="8.2006.0" x-pid="9127" x-info="https://www.rsyslog.com "] start

4523.503549975:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.503552420: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

4523.503564523:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.503565234:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.503567268:main Q:Reg/w0 : ruleset.c: executing action 0

4523.503568541:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.503572027:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.503572829:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.503573771:main Q:Reg/w0 : ../action.c: checking external state file

4523.503574562:main Q:Reg/w0 : ../action.c: done checking external state file, iRet=0

4523.503575344:main Q:Reg/w0 : ../action.c: action[action-0-builtin:omfile] transitioned to state: itx

4523.503576185:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.503577027:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.503578409: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

4523.503589040:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.503589881:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.503591344: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

4523.503601874:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.503602706:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.503604119: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

4523.503614589:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.503615280:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.503616703: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

4523.503629126:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.503629858:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.503631220: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

4523.503641770:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.503642552:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.503644045: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

4523.503654595:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.503655366:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 1: imjournal: journal files changed, reloading... [v8.2006.0 try https://www.rsyslog.com/e/0 ]

4523.503655998:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4523.503657350: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

4523.503756329:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4523.503757331:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4523.503758994:main Q:Reg/w0 : ruleset.c: executing action 0

4523.503759906:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4523.503761198:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4523.503761900:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.503762681:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4523.503763362:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4523.503764755: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

4523.503774804:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.503775435:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4523.503776758: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

4523.503786607:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.503787198:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4523.503788490: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

4523.503798319:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.503798910:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4523.503800213: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

4523.503811284:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.503811905:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4523.503813207: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

4523.503823076:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.503823677:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4523.503824970: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

4523.503834759:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4523.503835540:main Q:Reg/w0 : ruleset.c: END batch execution phase, entering to commit phase [processed 2 of 2 messages]

4523.503836392:main Q:Reg/w0 : ../action.c: actionCommitAllDirect: action 0, state 1, nbr to commit 2 isTransactional 1

4523.503837153:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: enter, 2 msgs

4523.503837834:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: processing...

4523.503838486:main Q:Reg/w0 : ../action.c: actionTryCommit[action-0-builtin:omfile] enter

4523.503839688:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4523.503840399:main Q:Reg/w0 : ../action.c: doTransaction: have commitTransaction IF, using that, pWrkrInfo 0x5559e55927d0

4523.503841131:main Q:Reg/w0 : ../action.c: entering actionCallCommitTransaction[action-0-builtin:omfile], state: itx, nMsgs 2

4523.503842063:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7f3fb80025d0, lenBuf 141, strt data Nov 11 09:28:43 harbor rsyslogd[9127]: [origin software="rsyslogd" swVersion="8.2006.0" x-pid="9127" x-info="https://www.rsyslog

4523.503842934:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7f3fb80025d0, lenBuf 132, strt data Nov 11 09:28:43 harbor rsyslogd[9127]: imjournal: journal files changed, reloading... [v8.2006.0 try https://www.rsyslog.com/e/

4523.503843766:main Q:Reg/w0 : strm 0x7f3fb80025d0: stream.c: file 6 strmFlush

4523.503844728:main Q:Reg/w0 : strm 0x7f3fb80025d0: stream.c: strmFlushinternal: file 6(/var/log/messages) flush, buflen 273

4523.503845569:main Q:Reg/w0 : strm 0x7f3fb80025d0: stream.c: file 6(/var/log/messages) doWriteInternal: bFlush 1

--

4523.503851661:main Q:Reg/w0 : ../action.c: actionCallCommitTransaction[action-0-builtin:omfile] state: itx mod commitTransaction returned 0

4523.503852382:main Q:Reg/w0 : ../action.c: action[action-0-builtin:omfile] transitioned to state: rdy

4523.503853124:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: return actionTryCommit 0

4523.503853815:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: done, iRet 0

4523.503854627:main Q:Reg/w0 : ../action.c: actionCommitAllDirect: action 1, state 0, nbr to commit 0 isTransactional 1

4523.503855338:main Q:Reg/w0 : ../action.c: actionCommit[action-1-builtin:omfile]: enter, 0 msgs

4523.503855999:main Q:Reg/w0 : ../action.c: actionCommit[action-1-builtin:omfile]: done, iRet 0

4523.503856710:main Q:Reg/w0 : ruleset.c: processBATCH: batch of 2 elements has been processed

4523.503857602:main Q:Reg/w0 : queue.c: regular consumer finished, iret=0, szlog 0 sz phys 2

4523.503858484:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: etry 0 state 3

4523.503861950:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: etry 1 state 3

4523.503863664:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: we deleted 2 objects and enqueued 0 objects

4523.503864405:main Q:Reg/w0 : queue.c: rger: deleteBatchFromQStore, nElem 2

--

4548.522832851:main Q:Reg/w0 : ruleset.c: processBATCH: batch of 1 elements must be processed

4548.522833823:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 0: [ 1168.853795] perf: interrupt took too long (6843 > 5976), lowering kernel.perf_event_max_sample_rate to 29000

4548.522835376:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'

4548.522837741: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

4548.522850595:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1

4548.522851537:main Q:Reg/w0 : rainerscript.c: ACTION 0 [builtin:omfile:/var/log/messages]

4548.522853721:main Q:Reg/w0 : ruleset.c: executing action 0

4548.522854944:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)

4548.522857308:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase

4548.522858070:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4548.522859172:main Q:Reg/w0 : ../action.c: checking external state file

4548.522859973:main Q:Reg/w0 : ../action.c: done checking external state file, iRet=0

4548.522861005:main Q:Reg/w0 : ../action.c: action[action-0-builtin:omfile] transitioned to state: itx

4548.522861787:main Q:Reg/w0 : ../action.c: action 'action-0-builtin:omfile': set suspended state to 0

4548.522862668:main Q:Reg/w0 : rainerscript.c: PRIFILT 'authpriv.*'

4548.522864081: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

4548.522874741:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4548.522875543:main Q:Reg/w0 : rainerscript.c: PRIFILT 'mail.*'

4548.522876986: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

4548.522887566:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4548.522889009:main Q:Reg/w0 : rainerscript.c: PRIFILT 'cron.*'

4548.522890411: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

4548.522900901:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4548.522901593:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.emerg'

4548.522903005: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

4548.522914808:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4548.522915609:main Q:Reg/w0 : rainerscript.c: PRIFILT 'uucp,news.crit'

4548.522916982: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

4548.522927602:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4548.522928304:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local7.*'

4548.522929736: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

4548.522940206:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0

4548.522941769:main Q:Reg/w0 : ruleset.c: END batch execution phase, entering to commit phase [processed 1 of 1 messages]

4548.522942771:main Q:Reg/w0 : ../action.c: actionCommitAllDirect: action 0, state 1, nbr to commit 1 isTransactional 1

4548.522943613:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: enter, 1 msgs

4548.522944334:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: processing...

4548.522945025:main Q:Reg/w0 : ../action.c: actionTryCommit[action-0-builtin:omfile] enter

4548.522945697:main Q:Reg/w0 : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

4548.522946488:main Q:Reg/w0 : ../action.c: doTransaction: have commitTransaction IF, using that, pWrkrInfo 0x5559e55927d0

4548.522947380:main Q:Reg/w0 : ../action.c: entering actionCallCommitTransaction[action-0-builtin:omfile], state: itx, nMsgs 1

4548.522949163:main Q:Reg/w0 : omfile.c: omfile: write to stream, pData->pStrm 0x7f3fb80025d0, lenBuf 143, strt data Nov 11 09:29:08 harbor kernel: [ 1168.853795] perf: interrupt took too long (6843 > 5976), lowering kernel.perf_event_max_sample

4548.522950646:main Q:Reg/w0 : strm 0x7f3fb80025d0: stream.c: file 6 strmFlush

4548.522952069:main Q:Reg/w0 : strm 0x7f3fb80025d0: stream.c: strmFlushinternal: file 6(/var/log/messages) flush, buflen 143

4548.522953031:main Q:Reg/w0 : strm 0x7f3fb80025d0: stream.c: file 6(/var/log/messages) doWriteInternal: bFlush 1

4548.522953963:main Q:Reg/w0 : stream.c: strmPhysWrite, stream 0x7f3fb80025d0, len 143

--

4548.522958040:main Q:Reg/w0 : ../action.c: actionCallCommitTransaction[action-0-builtin:omfile] state: itx mod commitTransaction returned 0

4548.522958812:main Q:Reg/w0 : ../action.c: action[action-0-builtin:omfile] transitioned to state: rdy

4548.522959613:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: return actionTryCommit 0

4548.522960355:main Q:Reg/w0 : ../action.c: actionCommit[action-0-builtin:omfile]: done, iRet 0

4548.522961186:main Q:Reg/w0 : ../action.c: actionCommitAllDirect: action 1, state 0, nbr to commit 0 isTransactional 1

4548.522962078:main Q:Reg/w0 : ../action.c: actionCommit[action-1-builtin:omfile]: enter, 0 msgs

4548.522962769:main Q:Reg/w0 : ../action.c: actionCommit[action-1-builtin:omfile]: done, iRet 0

4548.522963491:main Q:Reg/w0 : ruleset.c: processBATCH: batch of 1 elements has been processed

4548.522964332:main Q:Reg/w0 : queue.c: regular consumer finished, iret=0, szlog 0 sz phys 1

4548.522965184:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: etry 0 state 3

4548.522967068:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: we deleted 1 objects and enqueued 0 objects

4548.522967769:main Q:Reg/w0 : queue.c: rger: deleteBatchFromQStore, nElem 1

4548.522968530:main Q:Reg/w0 : queue.c: doDeleteBatch: delete batch from store, new sizes: log 0, phys 0

i.截取部分代码
4548.522851537:main Q:Reg/w0  : rainerscript.c:     ACTION 0 [builtin:omfile:/var/log/messages]
4548.522853721:main Q:Reg/w0  : ruleset.c: executing action 0
4548.522854944:main Q:Reg/w0  : ../action.c: action 'action-0-builtin:omfile': called, logging to builtin:omfile (susp 0/0, direct q 1)
4548.522857308:main Q:Reg/w0  : ../action.c: action 'action-0-builtin:omfile': is transactional - executing in commit phase
4548.522858070:main Q:Reg/w0  : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

时间戳	线程	源文件	含义
4548.522851537	main Q:Reg/w0	rainerscript.c	“选中第 0 号动作” ACTION 0 对应规则集里 `*.info;mail.none;authpriv.none;cron.none /var/log/messages` 这一行；`[builtin:omfile:/var/log/messages]` 说明输出插件是内置的 omfile，目标文件 `/var/log/messages`。
4548.522853721	main Q:Reg/w0	ruleset.c	“开始执行这个动作” 规则引擎告诉 action 子系统：“把当前这条消息交给 ACTION 0 处理”。
4548.522854944	main Q:Reg/w0	action.c	“action 被真正调用” action 子系统收到指令，发现该动作未挂起（susp 0/0），并且工作在 direct queue 模式（direct q 1），即同步、无内存队列，消息直接落盘。
4548.522857308	main Q:Reg/w0	action.c	“进入事务提交阶段” omfile 被声明为“事务型”输出；rsyslog 会先把一批消息攒在内存，然后在 commit 阶段一次性写入磁盘，提高吞吐。
4548.522858070	main Q:Reg/w0	action.c	“开始准备事务” actionPrepare 负责打开文件、检查外部状态文件、申请写缓存等前期动作；成功后才会调用 commitTransaction 把数据 flush 到 `/var/log/messages`。

ii.分析结果
这条由 logger 生成的消息已经顺利通过规则筛选，被分配给向 /var/log/messages 写文件的 omfile 动作；当前正在事务框架里做落盘前的最后准备，下一步就是真正的物理写文件。
iii.存在问题

继续观察日志写盘调用过程

omfile: write to stream ... lenBuf 143 —— 真正 write(2) 系统调用
strmFlushinternal: file 6(/var/log/messages) flush —— 内核缓冲区刷盘
actionCallCommitTransaction ... returned 0 —— 事务提交成功，整条链路结束

如果 actionPrepare 或 commitTransaction 返回非 0，就会看到 action suspended 或 action failed，那时日志就会“消失”。

排查工具：strace -p pid和logger DEBUG

strace -p $(pgrep rsyslogd)

rsyslogd -dn -f /etc/rsyslog.conf 2>&1 | grep -A5 'ruleset\|action'


1、# actionPrepare 负责打开文件、检查外部状态文件、申请写缓存等前期动作；
# 成功后才会调用 commitTransaction 把数据 flush 到 /var/log/messages。
4523.476156271:main Q:Reg/w0  : ../action.c: actionPrepare[action-0-builtin:omfile]: enter

在actionPrepare阶段：
i./var/log/messages文件不存在或者文件权限不足问题
　　ls -al /var/log/messages
ii.尝试手动pkill进程rsyslogd
　　ps -ef | grep rsyslogd
　　pkill rsyslogd
　　# 重启服务启动rsyslogd进程
　　systemctl restart rsyslog.service

2、strace跟踪进程, 发现刷屏式的提示too many open files

rsyslog的文件句柄数:

lsof -a -p `pgrep rsyslog` | wc -l

或者:

ls -l /proc/`pgrep rsyslog`/fd/ | wc -l

一个tcp connection一个文件句柄，按理应该不会超过系统默认的ulimit:

$ cat /proc/`pgrep rsyslog`/limits | grep 'Max open files'
Limit                     Soft Limit           Hard Limit           Units
Max open files            1024                 4096                 files

调整文件句柄数为65535

[root@harbor ~]# sudo mkdir -p /etc/systemd/system/rsyslog.service.d
[root@harbor ~]# cat >/etc/systemd/system/rsyslog.service.d/limits.conf <<'EOF'
> [Service]
> LimitNOFILE=65535
> EOF
[root@harbor ~]# sudo systemctl daemon-reload
[root@harbor ~]# sudo systemctl restart rsyslog
[root@harbor ~]# cat /proc/$(pgrep rsyslogd)/limits

一、logger工具概述

二、logger审计脚本

三、logger DEBUG分析

1、DEBUG代码

2、部分堆栈分析

继续观察日志写盘调用过程

附录：问题

导航

公告