Mailing List Archive

Hi David,

On Thu, 2008-12-18 at 21:38 -0800, david@lang.hm wrote:
> with messages appearing out-of-order the 'last message repeated X times'
> is pretty useless.

Not really. Please note that form the perspective of the output module,
messages do not appear out of order. The output module receives a stream
of messages, and the "last message repeated x times" logic works on that
stream. So no matter if messages are re-ordered by async queues (or UDP
or whatever), the "last ... times" correctly reflects the way things
were handed to the output module.

But I concur that this feature, in its current state, is very
questionable. I've talked about this on the mailing list quite some
time, I think there is also at least one blog post about it.

>
> I think I remember reading about an option to disable this, but another
> work-around to the problem is to change the output so that it becomes
> 'last message repeated X times %msg%', so you can see (most, if not all)
> of the message being repeated in the line telling you that it was
> repeated.

As I said, the message in front of this message is either another repeat
message or the message that is being repeated. So you can always trace
back to what was repeated (but it is painful).

Given the feedback I received on this feature (use cases), it should
probably (and v4 would be an appropriate version to do so) be redisigned
to be a rate-limiting feature on the input side. That would pretty much
simplify code, too.

Rainer

_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com

On Fri, 2008-12-19 at 03:46 -0800, david@lang.hm wrote:
> On Thu, 18 Dec 2008, Rainer Gerhards wrote:
>
> > Hi David,
> >
> > On Thu, 2008-12-18 at 21:38 -0800, david@lang.hm wrote:
> >> with messages appearing out-of-order the 'last message repeated X times'
> >> is pretty useless.
> >
> > Not really. Please note that form the perspective of the output module,
> > messages do not appear out of order. The output module receives a stream
> > of messages, and the "last message repeated x times" logic works on that
> > stream. So no matter if messages are re-ordered by async queues (or UDP
> > or whatever), the "last ... times" correctly reflects the way things
> > were handed to the output module.
>
> but if the output module is then relaying to another system, that other
> system (or the transport between them) can also re-order the messages

ah, ok, remote scenario. Of course, that can happen. But that's "just"
one use case where it is problematic.

> > But I concur that this feature, in its current state, is very
> > questionable. I've talked about this on the mailing list quite some
> > time, I think there is also at least one blog post about it.
> >
> >>
> >> I think I remember reading about an option to disable this, but another
> >> work-around to the problem is to change the output so that it becomes
> >> 'last message repeated X times %msg%', so you can see (most, if not all)
> >> of the message being repeated in the line telling you that it was
> >> repeated.
> >
> > As I said, the message in front of this message is either another repeat
> > message or the message that is being repeated. So you can always trace
> > back to what was repeated (but it is painful).
> >
> > Given the feedback I received on this feature (use cases), it should
> > probably (and v4 would be an appropriate version to do so) be redisigned
> > to be a rate-limiting feature on the input side. That would pretty much
> > simplify code, too.
>
> but since things can be re-ordered after the input module is done with
> them (multiple threads pulling from the queue, or relaying) it is still
> useful for the 'message repeated' message to have more info about what it
> is referring to.

That makes sense, at least for scenarios where it is expected behaviour.
For others, it would probably break analysers. So it needs to be
optional. And probably on a per-action basis. I'll see if it is
sufficiently simple, but the whole "last message repeated" thing is
broken anyhow (IMO), I don't like the idea to invest any more than maybe
an hour into that feature, especially in the light that the whole idea
must be replaced in the not so distant future...

Rainer
>
> David Lang
>
> > Rainer
> >
> > _______________________________________________
> > 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

> -----Original Message-----
> From: rsyslog-bounces@lists.adiscon.com [mailto:rsyslog-
> bounces@lists.adiscon.com] On Behalf Of david@lang.hm
> Sent: Friday, December 19, 2008 1:04 PM
> To: rsyslog-users
> Subject: Re: [rsyslog] suggested tweak to rsyslog

> it's definantly a pain for analysers

Full ack

> (a _lot_ of them really only look
> at
> one line at a time), that's why I started tweaking this on sysklogd,
> and
> while in theory just disabling it is the right answer, the ability to
> take
> a flood of inbound messages and reduce them to a much smaller number
> can
> save your logging system when things go wrong
>
> I'll watch to see what happens.

I just dug out a the relevant link, please follow also to the mailing
list discussion:

http://kb.monitorware.com/post5789.html

Rainer
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com

On Thu, 18 Dec 2008, Rainer Gerhards wrote:

> Hi David,
>
> On Thu, 2008-12-18 at 21:38 -0800, david@lang.hm wrote:
>> with messages appearing out-of-order the 'last message repeated X times'
>> is pretty useless.
>
> Not really. Please note that form the perspective of the output module,
> messages do not appear out of order. The output module receives a stream
> of messages, and the "last message repeated x times" logic works on that
> stream. So no matter if messages are re-ordered by async queues (or UDP
> or whatever), the "last ... times" correctly reflects the way things
> were handed to the output module.

but if the output module is then relaying to another system, that other
system (or the transport between them) can also re-order the messages

> But I concur that this feature, in its current state, is very
> questionable. I've talked about this on the mailing list quite some
> time, I think there is also at least one blog post about it.
>
>>
>> I think I remember reading about an option to disable this, but another
>> work-around to the problem is to change the output so that it becomes
>> 'last message repeated X times %msg%', so you can see (most, if not all)
>> of the message being repeated in the line telling you that it was
>> repeated.
>
> As I said, the message in front of this message is either another repeat
> message or the message that is being repeated. So you can always trace
> back to what was repeated (but it is painful).
>
> Given the feedback I received on this feature (use cases), it should
> probably (and v4 would be an appropriate version to do so) be redisigned
> to be a rate-limiting feature on the input side. That would pretty much
> simplify code, too.

but since things can be re-ordered after the input module is done with
them (multiple threads pulling from the queue, or relaying) it is still
useful for the 'message repeated' message to have more info about what it
is referring to.

David Lang

> Rainer
>
> _______________________________________________
> 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

David,

one thing I can do rather quickly. Maybe it's good enough. I've done a
tester, which lacks proper configuration, but I would appreciate
feedback on it:

http://git.adiscon.com/?p=rsyslog.git;a=commitdiff;h=a185665be4cf6997525
89d81ef6e396dd61f68b6

Details in git commit comment.

Rainer

> -----Original Message-----
> From: rsyslog-bounces@lists.adiscon.com [mailto:rsyslog-
> bounces@lists.adiscon.com] On Behalf Of david@lang.hm
> Sent: Friday, December 19, 2008 1:04 PM
> To: rsyslog-users
> Subject: Re: [rsyslog] suggested tweak to rsyslog
>
> On Thu, 18 Dec 2008, Rainer Gerhards wrote:
>
> > On Fri, 2008-12-19 at 03:46 -0800, david@lang.hm wrote:
> >> On Thu, 18 Dec 2008, Rainer Gerhards wrote:
> >>
> >>> Hi David,
> >>>
> >>> On Thu, 2008-12-18 at 21:38 -0800, david@lang.hm wrote:
> >>>> with messages appearing out-of-order the 'last message repeated X
> times'
> >>>> is pretty useless.
> >>>
> >>> Not really. Please note that form the perspective of the output
> module,
> >>> messages do not appear out of order. The output module receives a
> stream
> >>> of messages, and the "last message repeated x times" logic works
on
> that
> >>> stream. So no matter if messages are re-ordered by async queues
(or
> UDP
> >>> or whatever), the "last ... times" correctly reflects the way
> things
> >>> were handed to the output module.
> >>
> >> but if the output module is then relaying to another system, that
> other
> >> system (or the transport between them) can also re-order the
> messages
> >
> > ah, ok, remote scenario. Of course, that can happen. But that's
> "just"
> > one use case where it is problematic.
> >
> >>> But I concur that this feature, in its current state, is very
> >>> questionable. I've talked about this on the mailing list quite
some
> >>> time, I think there is also at least one blog post about it.
> >>>
> >>>>
> >>>> I think I remember reading about an option to disable this, but
> another
> >>>> work-around to the problem is to change the output so that it
> becomes
> >>>> 'last message repeated X times %msg%', so you can see (most, if
> not all)
> >>>> of the message being repeated in the line telling you that it was
> >>>> repeated.
> >>>
> >>> As I said, the message in front of this message is either another
> repeat
> >>> message or the message that is being repeated. So you can always
> trace
> >>> back to what was repeated (but it is painful).
> >>>
> >>> Given the feedback I received on this feature (use cases), it
> should
> >>> probably (and v4 would be an appropriate version to do so) be
> redisigned
> >>> to be a rate-limiting feature on the input side. That would pretty
> much
> >>> simplify code, too.
> >>
> >> but since things can be re-ordered after the input module is done
> with
> >> them (multiple threads pulling from the queue, or relaying) it is
> still
> >> useful for the 'message repeated' message to have more info about
> what it
> >> is referring to.
> >
> > That makes sense, at least for scenarios where it is expected
> behaviour.
> > For others, it would probably break analysers. So it needs to be
> > optional. And probably on a per-action basis. I'll see if it is
> > sufficiently simple, but the whole "last message repeated" thing is
> > broken anyhow (IMO), I don't like the idea to invest any more than
> maybe
> > an hour into that feature, especially in the light that the whole
> idea
> > must be replaced in the not so distant future...
>
> it's definantly a pain for analysers (a _lot_ of them really only look
> at
> one line at a time), that's why I started tweaking this on sysklogd,
> and
> while in theory just disabling it is the right answer, the ability to
> take
> a flood of inbound messages and reduce them to a much smaller number
> can
> save your logging system when things go wrong
>
> I'll watch to see what happens.
>
> 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

On Thu, 18 Dec 2008, Rainer Gerhards wrote:

> On Fri, 2008-12-19 at 03:46 -0800, david@lang.hm wrote:
>> On Thu, 18 Dec 2008, Rainer Gerhards wrote:
>>
>>> Hi David,
>>>
>>> On Thu, 2008-12-18 at 21:38 -0800, david@lang.hm wrote:
>>>> with messages appearing out-of-order the 'last message repeated X times'
>>>> is pretty useless.
>>>
>>> Not really. Please note that form the perspective of the output module,
>>> messages do not appear out of order. The output module receives a stream
>>> of messages, and the "last message repeated x times" logic works on that
>>> stream. So no matter if messages are re-ordered by async queues (or UDP
>>> or whatever), the "last ... times" correctly reflects the way things
>>> were handed to the output module.
>>
>> but if the output module is then relaying to another system, that other
>> system (or the transport between them) can also re-order the messages
>
> ah, ok, remote scenario. Of course, that can happen. But that's "just"
> one use case where it is problematic.
>
>>> But I concur that this feature, in its current state, is very
>>> questionable. I've talked about this on the mailing list quite some
>>> time, I think there is also at least one blog post about it.
>>>
>>>>
>>>> I think I remember reading about an option to disable this, but another
>>>> work-around to the problem is to change the output so that it becomes
>>>> 'last message repeated X times %msg%', so you can see (most, if not all)
>>>> of the message being repeated in the line telling you that it was
>>>> repeated.
>>>
>>> As I said, the message in front of this message is either another repeat
>>> message or the message that is being repeated. So you can always trace
>>> back to what was repeated (but it is painful).
>>>
>>> Given the feedback I received on this feature (use cases), it should
>>> probably (and v4 would be an appropriate version to do so) be redisigned
>>> to be a rate-limiting feature on the input side. That would pretty much
>>> simplify code, too.
>>
>> but since things can be re-ordered after the input module is done with
>> them (multiple threads pulling from the queue, or relaying) it is still
>> useful for the 'message repeated' message to have more info about what it
>> is referring to.
>
> That makes sense, at least for scenarios where it is expected behaviour.
> For others, it would probably break analysers. So it needs to be
> optional. And probably on a per-action basis. I'll see if it is
> sufficiently simple, but the whole "last message repeated" thing is
> broken anyhow (IMO), I don't like the idea to invest any more than maybe
> an hour into that feature, especially in the light that the whole idea
> must be replaced in the not so distant future...

it's definantly a pain for analysers (a _lot_ of them really only look at
one line at a time), that's why I started tweaking this on sysklogd, and
while in theory just disabling it is the right answer, the ability to take
a flood of inbound messages and reduce them to a much smaller number can
save your logging system when things go wrong

I'll watch to see what happens.

David Lang
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com

On 12/19/2008 12:57 PM, Rainer Gerhards wrote:
> David,
>
> one thing I can do rather quickly. Maybe it's good enough. I've done a
> tester, which lacks proper configuration, but I would appreciate
> feedback on it:
>
> http://git.adiscon.com/?p=rsyslog.git;a=commitdiff;h=a185665be4cf6997525
> 89d81ef6e396dd61f68b6
>
> Details in git commit comment.
>
> Rainer

Hi,

I think there's a small bug in the new code:

- snprintf((char*)szRepMsg, sizeof(szRepMsg), "message repeated %d
times: [%.800]",
+ snprintf((char*)szRepMsg, sizeof(szRepMsg), "message repeated %d
times: [%.800s]",

Tomas
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com

Hi Tomas,

thanks for the patch, looks like I have forgotten a commit ;)

David and others: do you find this functionality useful? If I do not
receive any further comments, I'll conclude it is not and will not
further work on it.

Thanks all,
Rainer

> -----Original Message-----
> From: rsyslog-bounces@lists.adiscon.com [mailto:rsyslog-
> bounces@lists.adiscon.com] On Behalf Of Tomas Heinrich
> Sent: Monday, January 05, 2009 3:53 PM
> To: rsyslog-users
> Subject: Re: [rsyslog] suggested tweak to rsyslog
>
> On 12/19/2008 12:57 PM, Rainer Gerhards wrote:
> > David,
> >
> > one thing I can do rather quickly. Maybe it's good enough. I've done
> a
> > tester, which lacks proper configuration, but I would appreciate
> > feedback on it:
> >
> >
>
http://git.adiscon.com/?p=rsyslog.git;a=commitdiff;h=a185665be4cf699752
> 5
> > 89d81ef6e396dd61f68b6
> >
> > Details in git commit comment.
> >
> > Rainer
>
> Hi,
>
> I think there's a small bug in the new code:
>
> - snprintf((char*)szRepMsg, sizeof(szRepMsg), "message repeated %d
> times: [%.800]",
> + snprintf((char*)szRepMsg, sizeof(szRepMsg), "message repeated %d
> times: [%.800s]",
>
> Tomas
> _______________________________________________
> 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