[systemd-devel] High CPU usage of journald

[Lennart Poettering]

On Sun, 17.02.13 17:54, Holger Freyther (holger at freyther.de) wrote:

> So where does _int_malloc come from? I have used gdb to 'sample'
> it by hand. So the answer is from a lot of places. Do you consider
> cutting back on how you dynamically allocate strings? E.g. stop
> using fopen, fgets, only have one dynamically tmp string for the
> various format routines one is using sequentially?

Well this depends. Dynamically allocating strings makes code generally
more readable and just sidesteps the whole "how long should I make this
buffer" issue. As long as these allocations never show up in inner loops
this is a non-issue.

There are many cases where we can easily get rid of dynamic string
allocation. For example, in the various calls that access
/proc/$PID/foobar, we can certainly generate that path string on the
stack, since the PID number is finite.

So, the answer is: it depends on the case. If something is used in inner
loops an doesn't fuck up readability entirely I am more than happy to
merge a patch. In many cases asprintf() can already be replaced by
strjoin() and strappend() which actually is already a major
speed-up. Moving to strings allocated on stack in many cases where the
string is known to have a reasonable max size anyway is good too (but
please, don't just blindly allocate "char buf[256]" everywhere...).

Blindly replacing all uses of asprintf() however, nah, not sure I like
that too much... It does make things a lot more readable.

> Samples:
> Breakpoint 1, _int_malloc (av=av at entry=0x4ddae8e4 <main_arena>, 
>     bytes=bytes at entry=15) at malloc.c:3241
> 3241	malloc.c: No such file or directory.
> (gdb) bt
> #0  _int_malloc (av=av at entry=0x4ddae8e4 <main_arena>, bytes=bytes at entry=15)
>     at malloc.c:3241
> #1  0x4dce2fdc in __GI___libc_malloc (bytes=bytes at entry=15) at malloc.c:2859
> #2  0x4dce7c60 in __GI___strdup (s=s at entry=0x4dd999fc "/etc/localtime")
>     at strdup.c:42
> #3  0x4dcfcdd4 in tzset_internal (always=<optimized out>, 
>     explicit=explicit at entry=1) at tzset.c:441
> #4  0x4dcfd210 in __tz_convert (timer=timer at entry=0xbefc0754, 
>     use_localtime=use_localtime at entry=1, tp=0x4ddb16cc <_tmbuf>) at tzset.c:629
> #5  0x4dcfb618 in __GI_localtime (t=t at entry=0xbefc0754) at localtime.c:42
> #6  0x0000e694 in server_forward_syslog (s=s at entry=0xbefc0b48, 

Please note that this one is a glibc internal issue. It's the
implementation of localtime().

Lennart

-- 
Lennart Poettering - Red Hat, Inc.