[rsyslog] Possible bug in 5.3.6: Multiple $Ruleset, :omruleset cause random output destination selection.

[Rainer Gerhards]

Ryan,

thanks again for the bug report. I managed to fix it. Details in the
tracker:

http://bugzilla.adiscon.com/show_bug.cgi?id=179

Rainer

On Sat, 2010-02-06 at 06:13 +0100, Ryan Lynch wrote:
> I'm trying to use multiple rulesets and omruleset actions to send a
> single incoming log message to two different log files, at the same
> time. I think my config file will help explain it:
> 
> #  BEGIN rsyslog.conf
> 
> $ModLoad imuxsock
> $ModLoad imklog
> $ModLoad immark
> $ModLoad omruleset
> 
> $MarkMessagePeriod 1
> 
> $template TP_ToFile,"%inputname% %timegenerated:::date-rfc3339%
> %timereported:::date-rfc3339% %hostname% %fromhost%
> %syslogfacility-text% %syslogseverity-text% %syslogtag% %programname%
> %msg%\n"
> 
> #  FIRST: I set up two parallel rulesets, 'RS_Alfa' and 'RS_Bravo',
> each of which writes output to its own, separate file ('RS_Alfa.log'
> and 'RS_Bravo.log', respectively) using an action with a *.* selector.
> 
> $Ruleset RS_Bravo
> $RulesetCreateMainQueue on
> $ActionResumeInterval 1
> *.* /var/log/rsyslog/.__LOG/RS_Bravo.log;TP_ToFile
> $Ruleset RSYSLOG_DefaultRuleset
> 
> $Ruleset RS_Alfa
> $RulesetCreateMainQueue on
> $ActionResumeInterval 1
> *.* /var/log/rsyslog/.__LOG/RS_Alfa.log;TP_ToFile
> $Ruleset RSYSLOG_DefaultRuleset
> 
> #  SECOND: I create a pair of actions (in the default ruleset), both
> with *.* selectors and the action ':omruleset:', but preceded by
> different '$ActionOmrulesetRulesetName' values ('RS_Alfa' and
> 'RS_Bravo', respectively
> 
> $ActionOmrulesetRulesetName RS_Bravo
> $ActionResumeInterval 1
> *.* :omruleset:
> 
> $ActionOmrulesetRulesetName RS_Alfa
> $ActionResumeInterval 1
> *.* :omruleset:
> 
> #  END rsyslog.conf
> 
> Based on the documentation, I believe that incoming log messages
> should be processed by the default ruleset, which sends the message to
> both 'RS_Alfa' and 'RS_Bravo'. If I understand this correctly, I
> should see a copy of each log message written to each of the two
> output files, and each output file should have identical contents.
> 
> But that isn't the result I'm getting, here. I get two copies of each
> message, but almost all of them are written to the file 'RS_Alfa'.
> Only the occasional lone random message is written to 'RS_Bravo'. (If
> I reverse the order of the :omrulset: actions, I see the oppositie
> pattern.) The exact proportion varies, but only about 1 in 20 messages
> makes it to the 1st (Bravo) output file. All different types of
> messages (facility, priority, hostname, etc.) end up in the 'RS_Bravo'
> file--again, it seems completely random to me.
> 
> I never get more total messages logged than I should, though. If I run
> rsyslog long enough to let 10 incoming messages appear, I will see a
> total of 20 messages when I combine the contents of 'RS_Alfa' and
> 'RS_Bravo'--they just end up in the wrong files.
> 
> I turned on debug logging during a short session and captured the
> results to a file, which I've attached, along with the rsyslog output
> files from that session. The host in question runs Centos Linux 5.4 as
> an x86_64 KVM virtual guest on an x86_64 Intel Xeon machine.
> 
> If there is any more info I can provide, or any other debugging steps
> I should take, please let me know.
> 
> Ryan B. Lynch
> ryan.b.lynch at gmail.com
> 
>