In addition, not all actions support multithreading, it's possible the dynafile action doesn't allow multiple threads. I could definantly see outputting to one file from multiple threads getting into trouble (or at the very least, requireing locking that would be expensive enough to make it not worth having multiple threads). I don't know the code well enough to know if this output can multithread or not.
$Ruleset appLog $ActionQueueType LinkedList $ActionQueueWorkerThreads 64 $ActionQueueWorkerThreadMinimumMessages 10000 $ActionQueueSize 400000 *.* ?appLogDynFile;**appLogHadoopTemplatedo you have any idea how many different files this is generating? One possible issue could be that rsyslog can't keep that many files open and so is spending a lot of time opening and closing the file. If you can do a strace on the thread for a few seconds and see if it's doing a lot of writes, a lot of open,write,close or something else.
Looking in the documentation for the omfile module at http://www.rsyslog.com/doc/omfile.html
It looks like there is a parameter DynaFileCacheSize that is incorrectly documented as defining the temptate to be used, when instead I believe it allocates memory to keep track of what files are being kept open so they can be written to again.
IOBuffersize may be interesting (how large are your messages, how likely is it that you will have multiple messages arriving together that go to the same destination)
It would be interesting to enable ASyncWriting, this would show you the cost of writing to disk vs formatting the message. My discussion of trying to simplify the regex was based on the thinking that you are spending most of your time processing the regex. If instead you are spending your time opening/closing files (needing a larger dynafilecachesize) I think that enabling this would show this pretty clearly.
David Lang On Fri, 14 Jun 2013, Timothy Ehlers wrote:
Well James and i both work on this. We will try and reduce the regex but we both do not understand why this cannot be multi-threaded. Why does setting an ActionQue to 10 worker threads not actually spawn 10. On Fri, Jun 14, 2013 at 6:18 PM, David Lang <[email protected]> wrote:Given that with one exception, all his rulesets are essentually single actions, and he has multiple action queues, I think it is effectivly tied to the ruleset in this case. I origionally assumed that different rulesets used different main queues. It looks like that may not be the case, but it could also just be that this one horribly bad rule was eating so much of the system that top only showed this one. That's a question that I'll clarify with Rainer next week sometime. David Lang On Fri, 14 Jun 2013, Boylan, James wrote: Is the action queue thread tied to the ruleset?-- James ----- Reply message ----- From: "David Lang" <[email protected]> To: "rsyslog-users" <[email protected]> Subject: [rsyslog] client connectivity issues syslog-ng -> rsyslog 7.x Date: Fri, Jun 14, 2013 6:13 pm I've found that FixedArray queues are noticably faster than LinkedList. That probably won't completely solve the problem, but it may help. If I'm seeing this correctly, this is the message template $template appLogHadoopTemplate,"<%PRI%>%**TIMESTAMP% %FROMHOST% app=%programname:R,ERE,1,DFLT:**([A-Za-z0-9]+)-.*-.*_.*--end%|** bucket=%programname:R,ERE,1,**DFLT:.*-.*-.*_([A-Za-z0-9]+)--** end%%msg%\n" and this is the filename template $template appLogDynFile,"/log/app-logs/%****programname:R,ERE,0,DFLT:[A-* *Za-z0-9]+--end%/%FROMHOST%/%$****YEAR%/%$MONTH%/%$DAY%/%** PROGRAMNAME%.log" Both of these are heavy users of regex parsing, which is a pretty expensive operation One thing that I think I'm seeing, it that you do the same regex multiple times. With an ugly regex like this, you would probably gain significantly by setting a variable and using that set $!shortname = "%programname:R,ERE,1,DFLT:([** A-Za-z0-9]+)-.*-.*_.*--end%" $template appLogHadoopTemplate,"<%PRI%>%**TIMESTAMP% %FROMHOST% app=%$!shortname%|bucket=%$!**shortname%%msg%\n" the other thing is, can you simplify the regex? it looks like you are trying to pull any alphanumeric value ahead of a -, but if that's the case, why are you matching things after that? will the following give you what you need? set $!shortname = "%programname:R,ERE,1,DFLT:^([**A-Za-z0-9]+)-%" I anchor the regex to the beginning of the string, and then pull everything before the - David Lang On Fri, 14 Jun 2013, Timothy Ehlers wrote: Date: Fri, 14 Jun 2013 17:50:05 -0500From: Timothy Ehlers <[email protected]> Reply-To: rsyslog-users <[email protected]> To: rsyslog-users <[email protected]> Subject: Re: [rsyslog] client connectivity issues syslog-ng -> rsyslog 7.x Yeah it helped in staging but with the higher volume of prod ruleset 2 seems to be the problem... I still only see 1 thread and its pegged at 100% $Ruleset appLog $ActionQueueType LinkedList $ActionQueueWorkerThreads 64 $**ActionQueueWorkerThreadMinimum**Messages 10000 $ActionQueueSize 400000 *.* ?appLogDynFile;**appLogHadoopTemplate There must be something i do not understand about the Queue system. On Fri, Jun 14, 2013 at 4:45 PM, David Lang <[email protected]> wrote: Interesting, I did not expect that action queues would help this much,given that you have the rulesets bound to different interfaces, I would have expected that their output processing would be independant. But the fact that putting in action queues (I assume one queue per ruleset??) splits up the work so much says that I was wrong. Which output is the action 3 queue that's using so much more CPU than anything else? David Lang On Fri, 14 Jun 2013, Timothy Ehlers wrote: I put ActionQueus into the config and in staging it looks better now.12773 root 20 0 1919m 231m 1848 R 34.8 0.5 0:19.06 rs:action 3 que 12772 root 20 0 1919m 231m 1848 S 10.6 0.5 0:09.51 rs:action 2 que 12751 root 20 0 1919m 231m 1848 S 1.7 0.5 0:01.29 rs:main Q:Reg 12742 root 20 0 1919m 231m 1848 S 0.7 0.5 0:00.72 in:imtcp 12767 root 20 0 1919m 231m 1848 S 0.7 0.5 0:00.21 rs:action 5 que 12774 root 20 0 1919m 231m 1848 S 0.7 0.5 0:00.70 rs:action 4 que I will try this in production with the Higher volume after a peer review. On Fri, Jun 14, 2013 at 4:32 PM, Timothy Ehlers <[email protected]> wrote: 52mb/sec inbound trafficHadoop stream is showing: 25k msg per second.. i do not know how accurate this is. $OptimizeForUniprocessor off $MaxMessageSize 2048k # Rsyslog plugins $ModLoad immark # provides --MARK-- message capability $ModLoad imudp # provides UDP syslog reception $ModLoad imtcp # provides TCP syslog reception $ModLoad imuxsock # provides support for local system logging (e.g. via logger command) $ModLoad imklog # provides kernel logging support (previously done by rklogd) $ModLoad imrelp # Provides RELP syslog reception $ModLoad omrelp # Provides RELP syslog transmission # Rsyslog Stats $ModLoad impstats $PStatInterval 60 $PStatSeverity 7 # Queue configuration $ActionQueueSize 2000000 $MainMsgQueueSize 40000000 # File Creation Permissions $umask 0000 $DirCreateMode 0755 $FileCreateMode 0644 # Remote Log Processing Ruleset $PreserveFQDN on $template appLogDynFile,"/log/app-logs/%****programname:R,ERE,0,DFLT:[A-**** Za-z0-9]+--end%/%FROMHOST%/%$****YEAR%/%$MONTH%/%$DAY%/%** PROGRAMNAME%.log" $template currLogStatsDynFile,"/log/app-****logs/logstats/%FROMHOST%/%$**** YEAR%/%$MONTH%/%$DAY%/****logstats.log.%$HOUR%00" $template currAppLogDynFile,"/log/app-****logs/%msg:R,ERE,1,DFLT:^([A-** Za-z0-9._-]+)\|([A-Za-z0-9._-]****+)\|([A-Za-z0-9._]+)[-_]*([**A-** Za-z0-9]*)([\^])--end%/%****FROMHOST%/%$YEAR%/%$MONTH%/%$**** DAY%/%msg:R,ERE,1,DFLT:^([A-****Za-z0-9._-]+)\|([A-Za-z0-9._-]**** +)\|([A-Za-z0-9._]+)[-_]*([A-****Za-z0-9]*)([\^])--end%-%msg:**R,** ERE,2,DFLT:^([A-Za-z0-9._-]+)\****|([A-Za-z0-9._-]+)\|([A-Za-**z0-** 9._]+)[-_]*([A-Za-z0-9]*)([\^]****)--end%-%msg:R,ERE,3,DFLT:^(**[** A-Za-z0-9._-]+)\|([A-Za-z0-9._****-]+)\|([A-Za-z0-9._]+)[-_]*(**[** A-Za-z0-9]*)([\^])--end%-%msg:****R,ERE,4,DFLT:^([A-Za-z0-9._-**]+** )\|([A-Za-z0-9._-]+)\|([A-Za-****z0-9._]+)[-_]*([A-Za-z0-9]*)(**[** \^])--end%.log.%$HOUR%00" $template currAppLoggTemplate,"%msg:R,****ERE,1,DFLT:^[A-Za-z0-9._-]+\|[**** A-Za-z0-9._-]+\|[A-Za-z0-9._]+****[-_]*[A-Za-z0-9]*[\^](.*)--*** *end%\n" $template currAppLoggTemplate2,"%msg%\n" $template currentappLogHadoopTemplate,"<****%PRI%>%TIMESTAMP:date-** rfc3164% %FROMHOST% %msg%\n" $template currentappLogNewHadoopTemplate****,"<%PRI%>%TIMESTAMP% %FROMHOST% app=%msg:R,ERE,1,DFLT:^([A-Za-****z0-9._-]+)\|([A-Za-z0-9._-]+**)\** |([A-Za-z0-9.]+)[-_]*([A-Za-****z0-9]*)--end%|bucket=%msg:R,** ERE,4,DFLT:^([A-Za-z0-9._-]+)\****|([A-Za-z0-9._-]+)\|([A-Za-**z0-** 9.]+)[-_]*([A-Za-z0-9]*)--end% %msg%\n" $template appLogHadoopTemplate,"<%PRI%>%****TIMESTAMP% %FROMHOST% app=%programname:R,ERE,1,DFLT:****([A-Za-z0-9]+)-.*-.*_.*--**end%|** bucket=%programname:R,ERE,1,****DFLT:.*-.*-.*_([A-Za-z0-9]+)--**** end%%msg%\n" $template remoteMessagesDynFile,"/log/****system-logs/%FROMHOST%/%$YEAR%**** /%$MONTH%/%$DAY%/messages" $template remoteSecureDynFile,"/log/****secure-system-logs/%FROMHOST%/**** %$YEAR%/%$MONTH%/%$DAY%/****secure" $template remoteMaillogDynFile,"/log/****system-logs/%FROMHOST%/%$YEAR%**** /%$MONTH%/%$DAY%/maillog" $template remoteEmergDynFile,"/log/****system-logs/%FROMHOST%/%$YEAR%**** /%$MONTH%/%$DAY%/emergency" $template remoteCronDynFile,"/log/****system-logs/%FROMHOST%/%$YEAR%**** /%$MONTH%/%$DAY%/cron" $template remoteSpoolerDynFile,"/log/****system-logs/%FROMHOST%/%$YEAR%**** /%$MONTH%/%$DAY%/spooler" $template remoteBootDynFile,"/log/****system-logs/%FROMHOST%/%$YEAR%**** /%$MONTH%/%$DAY%/boot.log" $Ruleset appLog *.* ?appLogDynFile;****appLogHadoopTemplate # Forward to Hadoop #*.* @@ wmhdcollector01s.stag.**timste**sting.net:5003<http://timstesting.net:5003> <http://**wmhdcollector01s.stag.**timstesting.net:5003<http://wmhdcollector01s.stag.timstesting.net:5003>; $Ruleset currAppLog *.* ?currAppLogDynFile;****currAppLoggTemplate # Forward to Hadoop *.* @@hadoopcollectors.prod.****timstesting.net:5003;** currentappLogHadoopTemplate $Ruleset currLogStats *.* ?currLogStatsDynFile # Forward to Hadoop #*.* @@hadoopcollectors.prod.****timstesting.net:5003;** currentappLogHadoopTemplate # Remote System Log Processing Ruleset $Ruleset remoteSysLogs # Log all kernel messages to the console. # Logging much else clutters up the screen. #kern.* /dev/console # Log anything (except mail) of level info or higher. # Don't log private authentication messages! $DirCreateMode 0755 $FileCreateMode 0644 *.info;local1.none;local6.****none;mail.none;authpriv.none;*** *cron.none ?remoteMessagesDynFile # The authpriv file has restricted access. $DirCreateMode 0700 $FileCreateMode 0600 authpriv.* ?remoteSecureDynFile # Log all the mail messages in one place. $DirCreateMode 0755 $FileCreateMode 0644 mail.* ?remoteMaillogDynFile # Log cron stuff $DirCreateMode 0755 $FileCreateMode 0644 cron.* ?remoteCronDynFile # Everybody gets emergency messages $DirCreateMode 0755 $FileCreateMode 0644 *.emerg ?remoteEmergDynFile # Save news errors of level crit and higher in a special file. $DirCreateMode 0755 $FileCreateMode 0644 uucp,news.crit ?remoteSpoolerDynFile # Save boot messages also to boot.log $DirCreateMode 0755 $FileCreateMode 0644 local7.* ?remoteBootDynFile # Local Log Processing Ruleset $Ruleset local # Log all kernel messages to the console. # Logging much else clutters up the screen. #kern.* /dev/console # Log anything (except mail) of level info or higher. # Don't log private authentication messages! *.info;local1.none;local6.****none;mail.none;authpriv.none;*** *cron.none /var/log/messages syslog.=debug /log/rsyslog-stats # The authpriv file has restricted access. authpriv.* /var/log/secure # Log all the mail messages in one place. mail.* -/var/log/maillog # Log cron stuff cron.* /var/log/cron # Everybody gets emergency messages *.emerg :omusrmsg:* # Save news errors of level crit and higher in a special file. uucp,news.crit /var/log/spooler # Save boot messages also to boot.log local7.* /var/log/boot.log # Assign default Ruleset $DefaultRuleset local # New AppLog Process RELP Collector $InputRELPServerBindRuleset appLog $InputRELPServerRun 20514 # Current AppLog TCP Collector $InputTCPServerBindRuleset currAppLog $InputTCPServerRun 20516 # Current LogStats TCP Collector $InputTCPServerBindRuleset currLogStats $InputTCPServerRun 20518 # SystemLog TCP Collector $InputTCPServerBindRuleset remoteSysLogs $InputTCPServerRun 20515 # SystemLog UDP Collector $InputUDPServerBindRuleset remoteSysLogs $UDPServerRun 514______________________________****_________________rsyslog mailing list http://lists.adiscon.net/****mailman/listinfo/rsyslog<http://lists.adiscon.net/**mailman/listinfo/rsyslog> <http:**//lists.adiscon.net/mailman/**listinfo/rsyslog<http://lists.adiscon.net/mailman/listinfo/rsyslog>http://www.rsyslog.com/****professional-services/<http://www.rsyslog.com/**professional-services/> <http://**www.rsyslog.com/professional-**services/<http://www.rsyslog.com/professional-services/>What's up with rsyslog? Follow https://twitter.com/rgerhards NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE THAT.______________________________**_________________rsyslog mailing list http://lists.adiscon.net/**mailman/listinfo/rsyslog<http://lists.adiscon.net/mailman/listinfo/rsyslog> http://www.rsyslog.com/**professional-services/<http://www.rsyslog.com/professional-services/> What's up with rsyslog? Follow https://twitter.com/rgerhards NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE THAT. ______________________________**_________________ rsyslog mailing list http://lists.adiscon.net/**mailman/listinfo/rsyslog<http://lists.adiscon.net/mailman/listinfo/rsyslog> http://www.rsyslog.com/**professional-services/<http://www.rsyslog.com/professional-services/> What's up with rsyslog? Follow https://twitter.com/rgerhards NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE THAT. ______________________________**_________________rsyslog mailing list http://lists.adiscon.net/**mailman/listinfo/rsyslog<http://lists.adiscon.net/mailman/listinfo/rsyslog> http://www.rsyslog.com/**professional-services/<http://www.rsyslog.com/professional-services/> What's up with rsyslog? Follow https://twitter.com/rgerhards NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE THAT.
_______________________________________________ rsyslog mailing list http://lists.adiscon.net/mailman/listinfo/rsyslog http://www.rsyslog.com/professional-services/ What's up with rsyslog? Follow https://twitter.com/rgerhards NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE THAT.
