2014-11-30 6:44 GMT+01:00 David Lang <[email protected]>: > try opening and writing /dev/log directly rather than through the syslog() > call > > You can do that via liblogging-stdlog, if you prefer. Full doc in the repo:
https://github.com/rsyslog/liblogging Rainer > for historical reasons, the syslog() call is supposed to block until the > syslog daemon reports that the message is safe on disk (or whatever it > considers 'accepted'), so I would not be surprised to find that the glibc > code is a lot more complicated than it needs to be to just write to a unix > socket. > > rsyslog can read from files, but all the other IPC mechanisms are > substantially higher overhead than a unix socket. > > David Lang > > On Sat, 29 Nov 2014, Mehrdad Pazooki wrote: > > Date: Sat, 29 Nov 2014 11:34:09 -0500 >> >> From: Mehrdad Pazooki <[email protected]> >> Reply-To: rsyslog-users <[email protected]> >> To: rsyslog-users <[email protected]> >> Subject: Re: [rsyslog] Calling syslog() is slow - it takes +100usec >> >> Is there a way to bypass /dev/log and do something writing to IPC and then >> let rsyslog read from it? so I will avoid calling syslog() and rsyslog >> becomes the consumer of ipc queue with multiple workers reading from it. >> You are right that it's not a rsyslog issue but if the only interface to >> get messages to rsyslog is by calling syslog() then it's a limitation for >> rsyslog. >> Are there other clients that I can use instead of syslog to handle that >> volume of messages? >> >> >> >> On Sat, Nov 29, 2014 at 4:25 AM, Rainer Gerhards < >> [email protected]> >> wrote: >> >> 2014-11-29 10:06 GMT+01:00 David Lang <[email protected]>: >>> >>> but why should this cause the latency to increase based on the number of >>>> simultanious writers? >>>> >>> >>> >>> I'd assume that's locking contention. After all, there seem to be 500 >>> writes plus 1 reader (rsyslog) contenting on that socket. >>> >>> >>> that's what makes me think that rsyslog may not be acking the messages >>>> >>> one >>> >>>> at a time, but instead is acking all of them that it's processing in one >>>> batch. >>>> >>>> >>>> No, it just waits for the socket to become ready and than does single >>> reads >>> until no more messages are available. Have a look here: >>> >>> >>> https://github.com/rsyslog/rsyslog/blob/master/plugins/ >>> imuxsock/imuxsock.c#L1379 >>> >>> The read loop is inside readSocket(). >>> >>> That's why I conclude this whole problem is totally outside of rsyslog. >>> >>> Rainer >>> >>> David Lang >>>> >>>> >>>> On Sat, 29 Nov 2014, Rainer Gerhards wrote: >>>> >>>> I think that's an issue with the syslog () api. It is synchronous, so >>>> >>>>> blocking is expected. I guess the rest of the problem is that linux >>>>> puts >>>>> mutexes around the /dev/log writes (after all, writes are atomic). >>>>> >>>>> Sent from phone, thus brief. >>>>> Am 28.11.2014 23:57 schrieb "David Lang" <[email protected]>: >>>>> >>>>> Hmm, I wonder if the batch size is what you are seeing (where rsyslog >>>>> >>>>>> processes multiple messages at once). >>>>>> >>>>>> We'll need to wait until Rainer can comment for sure, but you may want >>>>>> >>>>> to >>> >>>> try setting the batch size very low (say 5) and see if that puts a cap >>>>>> >>>>> on >>> >>>> the latency that you see. >>>>>> >>>>>> We've done a lot of testing for throughput, both from a single process >>>>>> and >>>>>> from multiple processes, but I don't remember every looking at >>>>>> per-process >>>>>> latency before. >>>>>> >>>>>> David Lang >>>>>> >>>>>> On Fri, 28 Nov 2014, Mehrdad Pazooki wrote: >>>>>> >>>>>> I am using: >>>>>> >>>>>> >>>>>>> rsyslogd 8.4.2.ad1, compiled with: >>>>>>> FEATURE_REGEXP: Yes >>>>>>> GSSAPI Kerberos 5 support: No >>>>>>> FEATURE_DEBUG (debug build, slow code): No >>>>>>> 32bit Atomic operations supported: Yes >>>>>>> 64bit Atomic operations supported: Yes >>>>>>> memory allocator: system default >>>>>>> Runtime Instrumentation (slow code): No >>>>>>> uuid support: Yes >>>>>>> Number of Bits in RainerScript integers: 32 (due to too-old json-c >>>>>>> lib) >>>>>>> >>>>>>> It is handling a very high volume but syslog() blocks and the >>>>>>> blocking >>>>>>> time >>>>>>> is not constant, so as I add more processes that are making a >>>>>>> syslog() >>>>>>> call >>>>>>> the blocking time increases by 10usec per process on my machine. >>>>>>> >>>>>>> >>>>>>> >>>>>>> >>>>>>> On Fri, Nov 28, 2014 at 4:50 PM, David Lang <[email protected]> wrote: >>>>>>> >>>>>>> what version of rsyslog are you running? >>>>>>> >>>>>>> >>>>>>>> rsyslog should be able to keep up with a very high volume of logs >>>>>>>> >>>>>>> being >>> >>>> delivered to /dev/log, but there are significant improvements between >>>>>>>> the >>>>>>>> version of rsyslog that was shipped in 12.05 (which I think was 5.x) >>>>>>>> and >>>>>>>> the current 8.x versions >>>>>>>> >>>>>>>> David Lang >>>>>>>> >>>>>>>> >>>>>>>> On Fri, 28 Nov 2014, Mehrdad Pazooki wrote: >>>>>>>> >>>>>>>> Date: Fri, 28 Nov 2014 10:14:30 -0500 >>>>>>>> >>>>>>>> From: Mehrdad Pazooki <[email protected]> >>>>>>>> >>>>>>>>> Reply-To: rsyslog-users <[email protected]> >>>>>>>>> To: rsyslog-users <[email protected]> >>>>>>>>> Subject: Re: [rsyslog] Calling syslog() is slow - it takes +100usec >>>>>>>>> >>>>>>>>> >>>>>>>>> There is no systemd on this platform. >>>>>>>>> >>>>>>>>> More details about the platform: >>>>>>>>> >>>>>>>>> Description: Ubuntu 12.04.1 LTS >>>>>>>>> Release: 12.04 >>>>>>>>> Codename: precise >>>>>>>>> >>>>>>>>> Linux 3.13.0-39-generic #66-Ubuntu SMP >>>>>>>>> >>>>>>>>> >>>>>>>>> On Fri, Nov 28, 2014 at 7:14 AM, Mehrdad Pazooki < >>>>>>>>> >>>>>>>> [email protected] >>> >>>> >>>>>>>>>> wrote: >>>>>>>>> >>>>>>>>> It's running in Ubuntu (precise). I'll check it for systemd. I >>>>>>>>> >>>>>>>> think >>> >>>> >>>>>>>>> syslog call is blocking because of /dev/log . if I use UDP >>>>>>>>> locally, >>>>>>>>> >>>>>>>>>> will >>>>>>>>>> that bypass /Dev/log? >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> On Fri, Nov 28, 2014, 04:08 Rainer Gerhards < >>>>>>>>>> [email protected]> >>>>>>>>>> wrote: >>>>>>>>>> >>>>>>>>>> which platform is this running on? Is systemd journal active? >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> Rainer >>>>>>>>>>> >>>>>>>>>>> 2014-11-27 22:37 GMT+01:00 Mehrdad Pazooki <[email protected] >>>>>>>>>>> >: >>>>>>>>>>> >>>>>>>>>>> Hi, >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> I am calling syslog in c++ using syslog.h . the time it takes on >>>>>>>>>>>> each >>>>>>>>>>>> >>>>>>>>>>>> call >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>> is too long. I am comparing it with IPC Queue and there is >>>>>>>>>>> almost >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>>> 100usec >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>> overhead when I call syslog() vs ipc. >>>>>>>>>>> >>>>>>>>>>> I did some benchmarking, when I use a single process for hitting >>>>>>>>>>>> syslog >>>>>>>>>>>> >>>>>>>>>>>> the >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>> performance is great it stays at avg 11usec/record for 1m >>>>>>>>>>> records >>>>>>>>>>> on >>>>>>>>>>> >>>>>>>>>>> my >>>>>>>>>>>> system. but if I run 10 of these processes the time will >>>>>>>>>>>> increase >>>>>>>>>>>> to >>>>>>>>>>>> >>>>>>>>>>>> about >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>> 100usec/record. >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>>> Another problem is that memory usage remains really low ~0% so >>>>>>>>>>>> >>>>>>>>>>> that >>> >>>> >>>>>>>>>>>> tells >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>> me syslog() is somehow blocking and using cpu rather than do a >>>>>>>>>>> >>>>>>>>>> set >>> >>>> an >>>>>>>>>>> >>>>>>>>>>> forget to the queue and process it later on. another issue is >>>>>>>>>>>> >>>>>>>>>>> that >>> >>>> all >>>>>>>>>>>> workers are not engage. I see 5 workers but only 3 are working. >>>>>>>>>>>> The way I'm using it in prod is about 500 threads hit syslog(). >>>>>>>>>>>> I >>>>>>>>>>>> need >>>>>>>>>>>> >>>>>>>>>>>> to >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>> keep the time it takes for a syslog() call to a constant of >>>>>>>>>>> >>>>>>>>>> 10usec >>> >>>> >>>>>>>>>>> >>>>>>>>>>>> ideal to >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>> max 40usec. >>>>>>>>>>> >>>>>>>>>>> Also, I am not doing openlog() before calling syslog() >>>>>>>>>>>> >>>>>>>>>>>> This is my configuration: >>>>>>>>>>>> >>>>>>>>>>>> # /etc/rsyslog.conf Configuration file for rsyslog. >>>>>>>>>>>> # >>>>>>>>>>>> # For more information see >>>>>>>>>>>> # /usr/share/doc/rsyslog-doc/ >>>>>>>>>>>> html/rsyslog_conf.html >>>>>>>>>>>> # >>>>>>>>>>>> # Default logging rules can be found in >>>>>>>>>>>> /etc/rsyslog.d/50-default.conf >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> ################# >>>>>>>>>>>> #### MODULES #### >>>>>>>>>>>> ################# >>>>>>>>>>>> $ModLoad imuxsock # provides support for local system logging >>>>>>>>>>>> $ModLoad imklog # provides kernel logging support (previously >>>>>>>>>>>> done >>>>>>>>>>>> by >>>>>>>>>>>> rklogd) >>>>>>>>>>>> #$ModLoad immark # provides --MARK-- message capability >>>>>>>>>>>> >>>>>>>>>>>> # provides UDP syslog reception >>>>>>>>>>>> #$ModLoad imudp >>>>>>>>>>>> #$UDPServerRun 514 >>>>>>>>>>>> >>>>>>>>>>>> # provides TCP syslog reception >>>>>>>>>>>> #$ModLoad imtcp >>>>>>>>>>>> #$InputTCPServerRun 514 >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> # For debug only >>>>>>>>>>>> # module(load="impstats" interval="1" severity="8") >>>>>>>>>>>> >>>>>>>>>>>> ########################### >>>>>>>>>>>> #### GLOBAL DIRECTIVES #### >>>>>>>>>>>> ########################### >>>>>>>>>>>> >>>>>>>>>>>> # >>>>>>>>>>>> # Use traditional timestamp format. >>>>>>>>>>>> # To enable high precision timestamps, comment out the following >>>>>>>>>>>> line. >>>>>>>>>>>> # >>>>>>>>>>>> $ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat >>>>>>>>>>>> >>>>>>>>>>>> # Filter duplicated messages >>>>>>>>>>>> $RepeatedMsgReduction off >>>>>>>>>>>> >>>>>>>>>>>> # >>>>>>>>>>>> # Set the default permissions for all log files. >>>>>>>>>>>> # >>>>>>>>>>>> $FileOwner root >>>>>>>>>>>> $FileGroup adm >>>>>>>>>>>> $FileCreateMode 0640 >>>>>>>>>>>> $DirCreateMode 0755 >>>>>>>>>>>> $Umask 0022 >>>>>>>>>>>> $PrivDropToUser root >>>>>>>>>>>> $PrivDropToGroup root >>>>>>>>>>>> >>>>>>>>>>>> # >>>>>>>>>>>> # Where to place spool files >>>>>>>>>>>> # >>>>>>>>>>>> $WorkDirectory /var/spool/rsyslog >>>>>>>>>>>> >>>>>>>>>>>> $ActionResumeRetryCount -1 # infinite >>>>>>>>>>>> >>>>>>>>>>>> retries if >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>> host is down >>>>>>>>>>> >>>>>>>>>>> $SystemLogRateLimitInterval 0 >>>>>>>>>>>> $SystemLogRateLimitBurst 0 >>>>>>>>>>>> $MaxMessageSize 4k >>>>>>>>>>>> >>>>>>>>>>>> main_queue( >>>>>>>>>>>> queue.Type="LinkedList" >>>>>>>>>>>> queue.Size="1000000" >>>>>>>>>>>> queue.workerThreads="8" >>>>>>>>>>>> queue.workerThreadMinimumMessages="10000" >>>>>>>>>>>> queue.SaveOnShutdown="on" >>>>>>>>>>>> ) >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> template(name="localone" type="string" string="%msg:2:$%\n") # >>>>>>>>>>>> ":2:$" >>>>>>>>>>>> >>>>>>>>>>>> --> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>> tells rsyslog to ignore the leading char, b/c rsyslog adds a >>>>>>>>>>> leading >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>>> space >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>> to every message >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>>> if $syslogfacility-text == 'local1' then { >>>>>>>>>>>> action( >>>>>>>>>>>> type="omfile" >>>>>>>>>>>> template="localone" >>>>>>>>>>>> file="/var/log/local1.log" >>>>>>>>>>>> flushOnTXEnd="off" >>>>>>>>>>>> asyncWriting="on" >>>>>>>>>>>> ioBufferSize="64k" >>>>>>>>>>>> queue.type="LinkedList" >>>>>>>>>>>> queue.size="1000000" >>>>>>>>>>>> queue.dequeueBatchSize="4096" >>>>>>>>>>>> queue.workerThreads="8" >>>>>>>>>>>> queue.workerThreadMinimumMessages="10000" >>>>>>>>>>>> queue.SaveOnShutdown="on" >>>>>>>>>>>> action.ResumeRetryCount="-1" >>>>>>>>>>>> ) >>>>>>>>>>>> stop >>>>>>>>>>>> } >>>>>>>>>>>> >>>>>>>>>>>> #if $syslogtag contains 'rsyslogd-pstats' then { >>>>>>>>>>>> # action( >>>>>>>>>>>> # type="omfile" >>>>>>>>>>>> # queue.type="LinkedList" >>>>>>>>>>>> # queue.discardmark="1000" >>>>>>>>>>>> # name="pstats" >>>>>>>>>>>> # file="/var/log/pstats.log" >>>>>>>>>>>> # ) >>>>>>>>>>>> # stop >>>>>>>>>>>> #} >>>>>>>>>>>> _______________________________________________ >>>>>>>>>>>> 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. >>>>>>>>>>>> >>>>>>>>>>>> _______________________________________________ >>>>>>>>>>>> >>>>>>>>>>>> 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. >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> _______________________________________________ >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>> 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. >>>>>>>>> >>>>>>>>> _______________________________________________ >>>>>>>>> >>>>>>>>> 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. >>>>>>>> >>>>>>>> _______________________________________________ >>>>>>>> >>>>>>>> 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. >>>>>>> >>>>>>> _______________________________________________ >>>>>>> >>>>>>> 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. >>>>>> >>>>>> _______________________________________________ >>>>>> >>>>> 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. >>>>> >>>>> _______________________________________________ >>>>> >>>> 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. >>>> >>>> _______________________________________________ >>> 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. >>> >>> _______________________________________________ >> 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. >> >> _______________________________________________ > 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. > _______________________________________________ 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.
