[rsyslog] rsyslog stats

Rainer Gerhards rgerhards at hq.adiscon.com
Wed Sep 8 07:57:37 CEST 2010


> -----Original Message-----
> From: rsyslog-bounces at lists.adiscon.com [mailto:rsyslog-
> bounces at lists.adiscon.com] On Behalf Of david at lang.hm
> Sent: Tuesday, September 07, 2010 11:38 PM
> To: rsyslog-users
> Subject: Re: [rsyslog] rsyslog stats
> 
> On Tue, 7 Sep 2010, Rainer Gerhards wrote:
> 
> > Finding the age of the oldest message is not necessarily cheap -
> think about out of order processing and delays. The one at queue top is
> not necessarily the oldest one...
> 
> even with out of order processing, it would still have arrived in that
> queue at or before the time of any other message in the queue.

Jup, but as I said in my first message, we do not have a timestamp for
"arrived at queue". All we have is the message creation timestamp (or the
timestamp from the message itself, which I think does not help here). This
timestamp does not respect queue enqueue time.

> 
> the OoO processing would mean that it may not be the next message to be
> processed (especially if there was a delivery problem for that
> message),
> but I don't see how an earlier message could end up elsewhere in the
> queue.

When you look only at the ruleset main queues, this is true for the most
part. Still, task switching may come into our way, e.g. we receive a 64K
buffer of tcp messages, process them, then control is switched to UDP
receiver. We may have tcpmsgms1-udpmsg-tcpmsgs2 inside the queue, where
udpmsgs is actually earlier than tcpmsgs2 (but obviously in close proximity).

> with secondary queues, you could have something that's not the oldest
> message in the main queue go into the secondary queue before the oldest
> message from the main queue. I think that we are still 'good enough'
> just
> providing the timestamp of the oldest message in the secondary queue as
> I
> expect that the messages will move fast enough that the timestamp of
> the
> 'earliest message to arrive in the queue' will be very close to the
> oldest.
> 
> the reason for wanting the time of the oldest message in the queue is
> to
> get an idea of how far behind (time wise) rsyslog is in it's output vs
> it's input. I don't think it needs to be precise.

Well, if a rough indication is OK and we could live with the fact that in
some cases the information is taken with a big grain of salt, we could do
this. We would still have issues with disk queues, because I need to do i/o
in order to "peek" at a message (peek is not supported at all). A solution
would probably be to forbid this for disk queues.

Rainer

> 
> David Lang
> 
> 
> > rainer
> >
> > ----- Urspr?ngliche Nachricht -----
> > Von: david at lang.hm <david at lang.hm>
> > Gesendet: Dienstag, 7. September 2010 22:58
> > An: rsyslog-users <rsyslog at lists.adiscon.com>
> > Betreff: Re: [rsyslog] rsyslog stats
> >
> > On Tue, 7 Sep 2010, Joe Williams wrote:
> >
> >> On Sep 7, 2010, at 11:11 AM, Aaron Wiebe wrote:
> >>
> >>> On Tue, Sep 7, 2010 at 2:07 PM,  <david at lang.hm> wrote:
> >>>>
> >>>> 1. stats that are cheap to gather, generate
> >>>>  examples  current length of queues, age of oldest message in each
> queue,
> >>>> number of messages processed (possibly even per output)
> >>>> 2. stats that are expensive to gather or generate
> >>>>  examples: average length of queues, average time to process
> messages
> >>>
> >>> Expensive stats shouldn't be the responsibility of rsyslog though -
> >>> trending over time and the like should be the responsibility of a
> >>> third party product (ie, cacti/mrtg).  As long as the stats are
> easily
> >>> made available through snmp or other methods, the trending should
> be
> >>> done outside rsyslog.
> >>>
> >>
> >>
> >
> >> Agreed, rsyslog should just report the current stats and any
> >> trending/analysis should be done externally. No different than
> running
> >> iostat or other tools.
> >
> > iostat and vmstat actually provide some of these expensive stats.
> >
> > an example of an expensive stat would be the average age of messages
> in
> > the queue.
> >
> > finding the age of the oldest message is relativly cheap (one lookup
> to
> > the oldest message in the queue, that lookup may delay something
> > processing the message so it's only 'relativly' cheap)
> >
> > but finding the average age of all messages in the queue will require
> > looking up the age of every message in the queue, and probably
> freezing
> > the queue while you do so to make sure that it's not changing under
> you.
> >
> >> One other timing stat I would love to see is the amount of time in
> each
> >> step of the pipeline (time to read the message from the socket, time
> >> processing it through any rules, time spent in any queues, time
> spent
> >> writing to disk, etc). Haproxy has a good example of this in it's
> >> logging (8.2.3. HTTP log format -
> >> http://haproxy.1wt.eu/download/1.4/doc/configuration.txt).
> >
> > message processing in rsyslog is done at such a high rate that you
> can get
> > a noticable performance improvement by doing one gettimeofday call
> for
> > every 10 messages instead of one call per message. looking up the
> time at
> > different stages within rsyslog definantly qualifies as an expensive
> stat
> > to gather.
> >
> > cheap things to gather are things that can be gathered by modifying a
> > per-thread variable.
> >
> > relativly cheap things to gather are things that require locking to
> gather
> > (either to update a central variable, or to prevent other threads
> from
> > modifying what you are reading)
> >
> > expensive things to gather include things that require syscalls
> > (for example, gettimeofday()), or that require looking at a lot of
> data
> > (average age of all messages in a queue)
> >
> > David Lang
> > _______________________________________________
> > rsyslog mailing list
> > http://lists.adiscon.net/mailman/listinfo/rsyslog
> > http://www.rsyslog.com
> > _______________________________________________
> > rsyslog mailing list
> > http://lists.adiscon.net/mailman/listinfo/rsyslog
> > http://www.rsyslog.com
> >
> _______________________________________________
> rsyslog mailing list
> http://lists.adiscon.net/mailman/listinfo/rsyslog
> http://www.rsyslog.com



More information about the rsyslog mailing list