[rsyslog] rsyslog stats

david at lang.hm david at lang.hm
Wed Sep 8 19:39:11 CEST 2010


On Wed, 8 Sep 2010, Rainer Gerhards wrote:

>> -----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.

I am thinking that we have two timestamps with each message.

1. the timestamp from the message itself

2. the timestamp of when rsyslog received the message (not when it got put 
in a particular queue, but when the input module processed it)

I would expect that even with async processing, the timestamp of when 
rsyslog received the message would probably be within a small number of 
seconds of the oldest message.

I wouldn't expect the value of this timestamp to be significant from a 
monitoring perspective until it's at least a couple of minutes old.

David Lang



More information about the rsyslog mailing list