Mailing List Archive

On Sat, 17 Jan 2009, Michael Biebl wrote:

> Hi,
>
> I'm running rsyslog 3.20.2
>
> I noticed the following:
> # /etc/init.d/rsyslog restart
> VSZ RSS (as reported by ps)
> 27100 1184
> # logger foo
> 27100 1196
> # logger foo (1000x)
> 27100 1200
> # logger foo (1000x)
> 27100 1204
> # logger foo (1000x)
> 27100 1208
>
> and so on.
>
>
> This made me wonder, if rsyslog is leaking memory somewhere.

I have run rsyslog through stress tests where I have sent it 1B log
messages and do not think that there is a memory leak.

what I think that you are seeing is that the default rsyslog memory queue
only uses as much ram as it needs to hold the data (even though it's
described as a array it seems to grow dynamicly, I'm not sure about it
shrinking)

when you log a bunch of messages via logger you push data into the array
faster then it gets extracted, so it takes more memory (up until you hit
the max size of the array, which I think is 1000 entries)

> I also noticed, that for each loaded module, rsyslog resevers exactly
> 8 Mb of anoymous memory (pmap -d `pgrep rsyslog`)
> With a couple of loaded modules you easily get over 50Mb VSZ.

I haven't tried doing stuff with different modules, so I don't know about
this.

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

On Sat, 2009-01-17 at 16:55 -0800, david@lang.hm wrote:
> On Sat, 17 Jan 2009, Michael Biebl wrote:
>
> > Hi,
> >
> > I'm running rsyslog 3.20.2
> >
> > I noticed the following:
> > # /etc/init.d/rsyslog restart
> > VSZ RSS (as reported by ps)
> > 27100 1184
> > # logger foo
> > 27100 1196
> > # logger foo (1000x)
> > 27100 1200
> > # logger foo (1000x)
> > 27100 1204
> > # logger foo (1000x)
> > 27100 1208
> >
> > and so on.
> >
> >
> > This made me wonder, if rsyslog is leaking memory somewhere.
>
> I have run rsyslog through stress tests where I have sent it 1B log
> messages and do not think that there is a memory leak.

I am using valgrind's excellent memory debugger routinely during
development. That brings up leaks and invalid memory access rather
quickly. In fact, code quality has much improved when I started to use
valgrind routinely roughly a year ago. From time to time I also do
specific tests for leaks, both using valgrind and the traditional
analysis technics.

>From what I have seen so far, I, too, doubt there is a leak. However,
there are various levels of testing. For example, the postgres output
module and the GSSAPI code is contributed and I do not even have a test
environment. So these are not checked using that procedure. The libdbi
code is only checked every now and then and not with all backends (e.g.
no Oracle at hand ... and so on...). If I ever get over to a full
testing suite (no collaborators found so far...), I'll probably be able
to do more consitent testing of all modules.

>
> what I think that you are seeing is that the default rsyslog memory queue
> only uses as much ram as it needs to hold the data (even though it's
> described as a array it seems to grow dynamicly, I'm not sure about it
> shrinking)

If you use "fixedarray" mode, the pointer array is allocated statically,
no matter how many messages are in the queue. HOWEVER, this is only the
pointers, so quite few memory. Actual messages are dynamically allocated
and freed when processed - in any mode.

>
> when you log a bunch of messages via logger you push data into the array
> faster then it gets extracted, so it takes more memory (up until you hit
> the max size of the array, which I think is 1000 entries)
>
> > I also noticed, that for each loaded module, rsyslog resevers exactly
> > 8 Mb of anoymous memory (pmap -d `pgrep rsyslog`)
> > With a couple of loaded modules you easily get over 50Mb VSZ.
>
> I haven't tried doing stuff with different modules, so I don't know about
> this.

I am not sure where it comes from, but I'd think into the dlload
direction. Could also very well be the runtime stack for each thread
(not dug into the details).

Rainer

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

On Sun, 2009-01-18 at 04:33 -0800, david@lang.hm wrote:
> On Sun, 18 Jan 2009, Rainer Gerhards wrote:
>
> > On Sat, 2009-01-17 at 16:55 -0800, david@lang.hm wrote:
> >
> >>
> >> what I think that you are seeing is that the default rsyslog memory queue
> >> only uses as much ram as it needs to hold the data (even though it's
> >> described as a array it seems to grow dynamicly, I'm not sure about it
> >> shrinking)
> >
> > If you use "fixedarray" mode, the pointer array is allocated statically,
> > no matter how many messages are in the queue. HOWEVER, this is only the
> > pointers, so quite few memory. Actual messages are dynamically allocated
> > and freed when processed - in any mode.
>
> that makes sense. It would be interesting to see what would happen to the
> enqueue/dequeue timings if the message memory was staticly allocated
>
> from what I remember seeing of the memory footprint it does appear as if
> you allocate the max size for the message each time, not the minimum sized
> needed to hold the message
>
yes, that's right. This is done to prevent an additional copy to clean
things up (realloc might work, too) and memory fragmentation. The later
is really nasty, I've seen that some memory areas remain allocated for
quite some while due to fragmentation.

> if that shows a noticable difference it may be worth allocating the memory
> in chunks substantially larger than a single message

That's a good suggestion. The basic classes are able to trim strings. It
may be worth putting a config option into it. The current approach works
well for small queues, but obviously does provide sub-optimal
performance as soon as the queues grow considerably. So it may even make
sense to start trimming messages only after a certain amount of messages
are in-queue.

Rainer

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

On Sun, 18 Jan 2009, Rainer Gerhards wrote:

> On Sat, 2009-01-17 at 16:55 -0800, david@lang.hm wrote:
>
>>
>> what I think that you are seeing is that the default rsyslog memory queue
>> only uses as much ram as it needs to hold the data (even though it's
>> described as a array it seems to grow dynamicly, I'm not sure about it
>> shrinking)
>
> If you use "fixedarray" mode, the pointer array is allocated statically,
> no matter how many messages are in the queue. HOWEVER, this is only the
> pointers, so quite few memory. Actual messages are dynamically allocated
> and freed when processed - in any mode.

that makes sense. It would be interesting to see what would happen to the
enqueue/dequeue timings if the message memory was staticly allocated

from what I remember seeing of the memory footprint it does appear as if
you allocate the max size for the message each time, not the minimum sized
needed to hold the message

if that shows a noticable difference it may be worth allocating the memory
in chunks substantially larger than a single message

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

On Sun, 2009-01-18 at 17:30 -0800, david@lang.hm wrote:
> I'm not sure that we're saying the same thing. let me try again.

You are right, we weren't...

>
> what I was thinking was that instead of allocating memory for one message
> at a time, initially allocate memory for 100 messages, then if this needs
> to be extended increase the allocation by 50-100%. this minimizes the
> number of allocations needed and the fragmentation of system memory.
>
> just like the fixed-array queue option is significantly faster than the
> linked list queue option (I assume from a combination of having to chase
> pointers and allocate/deallocate memory), there may be similar benifits
> from doing the same thing for the message content itself.

I have to admit I am skeptic about this. The reason is that there are
many non-fixed fields within the message and they are allocated as
needed (with some initial size that fits most messages, but it may
extend on an as-needed basis). So there is no real fixed size for any
message. It also depends on template formatting and other factors.

I think if I'd try to prealloc at least the initial chunks, I'd probably
do pretty much the same that the malloc()/free() runtime does. That,
however, will probably be less performant than the runtime is (at least
I hope so, these parts of the code should be heavily tweaked). This is
also an error-prone task.

There may be a compromise in between (e.g. allocating a fixed chunk of
message text together with the message blobs), but I still think the
necessary complexity is not outweight by similar benefits.

All in all, I think, we have seen that the in-user-space computing needs
(and malloc counts as such) are not really the bottlenecks. Implementing
e.g. a "bunch writer" (which enables submission of multiple messages at
once to an action) seems to be (just) equally complex but promises far
better results.

In any case, I'd finally like to track down that dangling race before I
do any further optimization. It looks like Lorenzo seems to have a
relatively stable environment for reproduction and I'd like to take
advantage of that.

Rainer

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

On Sun, 18 Jan 2009, Rainer Gerhards wrote:

> On Sun, 2009-01-18 at 04:33 -0800, david@lang.hm wrote:
>> On Sun, 18 Jan 2009, Rainer Gerhards wrote:
>>
>>> On Sat, 2009-01-17 at 16:55 -0800, david@lang.hm wrote:
>>>
>>>>
>>>> what I think that you are seeing is that the default rsyslog memory queue
>>>> only uses as much ram as it needs to hold the data (even though it's
>>>> described as a array it seems to grow dynamicly, I'm not sure about it
>>>> shrinking)
>>>
>>> If you use "fixedarray" mode, the pointer array is allocated statically,
>>> no matter how many messages are in the queue. HOWEVER, this is only the
>>> pointers, so quite few memory. Actual messages are dynamically allocated
>>> and freed when processed - in any mode.
>>
>> that makes sense. It would be interesting to see what would happen to the
>> enqueue/dequeue timings if the message memory was staticly allocated
>>
>> from what I remember seeing of the memory footprint it does appear as if
>> you allocate the max size for the message each time, not the minimum sized
>> needed to hold the message
>>
> yes, that's right. This is done to prevent an additional copy to clean
> things up (realloc might work, too) and memory fragmentation. The later
> is really nasty, I've seen that some memory areas remain allocated for
> quite some while due to fragmentation.
>
>> if that shows a noticable difference it may be worth allocating the memory
>> in chunks substantially larger than a single message
>
> That's a good suggestion. The basic classes are able to trim strings. It
> may be worth putting a config option into it. The current approach works
> well for small queues, but obviously does provide sub-optimal
> performance as soon as the queues grow considerably. So it may even make
> sense to start trimming messages only after a certain amount of messages
> are in-queue.

I'm not sure that we're saying the same thing. let me try again.

what I was thinking was that instead of allocating memory for one message
at a time, initially allocate memory for 100 messages, then if this needs
to be extended increase the allocation by 50-100%. this minimizes the
number of allocations needed and the fragmentation of system memory.

just like the fixed-array queue option is significantly faster than the
linked list queue option (I assume from a combination of having to chase
pointers and allocate/deallocate memory), there may be similar benifits
from doing the same thing for the message content itself.

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

On Sun, 18 Jan 2009, Rainer Gerhards wrote:

> On Sun, 2009-01-18 at 17:30 -0800, david@lang.hm wrote:
>>
>> what I was thinking was that instead of allocating memory for one message
>> at a time, initially allocate memory for 100 messages, then if this needs
>> to be extended increase the allocation by 50-100%. this minimizes the
>> number of allocations needed and the fragmentation of system memory.
>>
>> just like the fixed-array queue option is significantly faster than the
>> linked list queue option (I assume from a combination of having to chase
>> pointers and allocate/deallocate memory), there may be similar benifits
>> from doing the same thing for the message content itself.
>
> I have to admit I am skeptic about this. The reason is that there are
> many non-fixed fields within the message and they are allocated as
> needed (with some initial size that fits most messages, but it may
> extend on an as-needed basis). So there is no real fixed size for any
> message. It also depends on template formatting and other factors.
>
> I think if I'd try to prealloc at least the initial chunks, I'd probably
> do pretty much the same that the malloc()/free() runtime does. That,
> however, will probably be less performant than the runtime is (at least
> I hope so, these parts of the code should be heavily tweaked). This is
> also an error-prone task.
>
> There may be a compromise in between (e.g. allocating a fixed chunk of
> message text together with the message blobs), but I still think the
> necessary complexity is not outweight by similar benefits.
>
> All in all, I think, we have seen that the in-user-space computing needs
> (and malloc counts as such) are not really the bottlenecks. Implementing
> e.g. a "bunch writer" (which enables submission of multiple messages at
> once to an action) seems to be (just) equally complex but promises far
> better results.

always possible.

> In any case, I'd finally like to track down that dangling race before I
> do any further optimization. It looks like Lorenzo seems to have a
> relatively stable environment for reproduction and I'd like to take
> advantage of that.

agreed, tracking down a reproducable problem takes precidence over new
improvements/tweaks any day.

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

FYI: Based on a forum thread, I just created this page:

http://wiki.rsyslog.com/index.php/Reducing_memory_usage

I think it actually describes the source of the 8MB memory blocks.

Rainer

> -----Original Message-----
> From: rsyslog-bounces@lists.adiscon.com [mailto:rsyslog-
> bounces@lists.adiscon.com] On Behalf Of Michael Biebl
> Sent: Saturday, January 17, 2009 11:11 AM
> To: rsyslog-users
> Subject: [rsyslog] Is rsyslog leaking memory?
>
> Hi,
>
> I'm running rsyslog 3.20.2
>
> I noticed the following:
> # /etc/init.d/rsyslog restart
> VSZ RSS (as reported by ps)
> 27100 1184
> # logger foo
> 27100 1196
> # logger foo (1000x)
> 27100 1200
> # logger foo (1000x)
> 27100 1204
> # logger foo (1000x)
> 27100 1208
>
> and so on.
>
>
> This made me wonder, if rsyslog is leaking memory somewhere.
>
> I also noticed, that for each loaded module, rsyslog resevers exactly
> 8 Mb of anoymous memory (pmap -d `pgrep rsyslog`)
> With a couple of loaded modules you easily get over 50Mb VSZ.
>
>
> Michael
> --
> Why is it that all of the instruments seeking intelligent life in the
> universe are pointed away from Earth?
> _______________________________________________
> 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

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On Sun, 18 Jan 2009 12:01:53 +0100
Rainer Gerhards <rgerhards@hq.adiscon.com> wrote:

> From what I have seen so far, I, too, doubt there is a leak. However,
> there are various levels of testing. For example, the postgres output
> module and the GSSAPI code is contributed and I do not even have a
> test environment. So these are not checked using that procedure. The
> libdbi code is only checked every now and then and not with all
> backends (e.g. no Oracle at hand ... and so on...). If I ever get
> over to a full testing suite (no collaborators found so far...), I'll
> probably be able to do more consitent testing of all modules.

As I'm the one who wrote (or rather ported) the postgres module, I
would be willing to help debugging/valgrinding it.

Unfortunately, I have not yet completely understood how the
files tests/ work. To be honest, I have just started looking at it.

What would you suggest as a way to test ompgqsl in particular? Simply
run rsyslogd with valgrind and throw messages against it?

Regarding GSSAPI: As I'm a big fan of Kerberos I will definitely give
it a try as soon as I have some spare time, maybe I can help in
valgrinding it, too.

Regards,
Jakob (aka sur5r)
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (GNU/Linux)

iEYEARECAAYFAkl/TU0ACgkQ1YAhDic+ada31QCgu1f54fx4XMNpLjrASZ2fGIJ8
V8sAoKD8hRx7tuRzpwkajg5PPCDkwnLY
=luw3
-----END PGP SIGNATURE-----
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com