[syslog-ng] payload_reallocs twice the count number of messages.

[Evan Rempel]

No, we didn't really notice a performance issue.
We process approx 3,000 msg/sec
We keep detailed statistics on our hosts, and the CPU change could not really be noticed. Of course, we are running
on an 8 core system, so the CPU may have increased for the one core, but it would only have 1/8 of an affect on the total
CPU % used, so it would be difficult to notice.

We are seeing a different problem though. (happens on both 3.3.7 and 3.4.1 threaded and not threaded)

2013-02-06T23:59:05-08:00 kern.info kernel: syslog-ng[10913]: segfault at 7f819c000168 ip 00007f819c000168 sp 00007f81b33f5a48 error 15
2013-02-06T23:59:05-08:00 syslog.notice syslog-ng[7627]: Syslog connection closed; fd='13', client='AF_INET(142.104.47.145:51679)', local='AF_INET(127.0.0.1:1514)'
2013-02-06T23:59:05-08:00 daemon.crit supervise/syslog-ng[18771]: Daemon exited due to a deadlock/signal/failure, restarting; exitcode='11'

This happens approx once every 4-5 days.

We take ps snapshots every 15 minutes, so the process looked like;

Date     Time   USER PID   PPID  PRI CPU  VSZ    ELAPSED  TIME     COMMAND
------------------------------------------------------------------------------------------
20130206 083101 root 18772 18771 19  -    686668 00:03:28 00:00:24 /usr/local/sbin/syslog-ng
...
20130206 234601 root 18772 18771 19  -    684056 15:18:28 01:52:08 /usr/local/sbin/syslog-ng
... then the restarted process
20130207 000101 root 11019 18771 19  -    687628 00:01:56 00:00:09 /usr/local/sbin/syslog-ng


So there does not seem to be a memory leak, but obviously something goes wrong to get a segfault.

I can't trace this for 4-5 days, so how do we trouble shoot this?

Evan.


On 02/06/2013 09:47 PM, Balazs Scheidler wrote:
> hi,
>
> in that case it might make sense to add a parameter to control initial allocation size or create a heuristic to automatically adjust that.
>
> did you notice performance issues? how many messages are you processing? did the cpu usage of syslog-ng increase dramatically at one point as you were adding more and more name-value pairs?
>
> thanks for the info.
>
> ----- Original message -----
>  > Back in December there was discussion of the payload_reallocs statistic.
>  >
>  > https://lists.balabit.hu/pipermail/syslog-ng/2012-December/019842.html
>  >
>  >
>  >  >
>  >  >> *global;payload_reallocs;;a;processed;760*
>  >  >
>  >  >this counts the number of reallocs of the message payload. syslog-ng
>  > sizes the allocated buffer >with a simple heuristics in the hope that
>  > parsing, rewrite rules will not cause it to grow. >in your case
>  > syslog-ng had to do a realloc for 760 messages. if this happens to be
>  > close to >all messages you processed, it's the cause for performance
>  > degradation. > >if it's a minority then you probably don't have to care.
>  >  >
>  >  >if the first one is true, I'd like to know about it.
>  >  >
>  >  >right now the allocated size is twice the length of the incoming
>  > message. >
>  >
>  >
>  > Well, You wanted to know if this happens for nearly all of the messages
>  > required realloc
>  >
>  > Syslog-ng OSE 3.3.7
>  >
>  > The d_archive destination receives all of our messages;
>  >
>  > global;payload_reallocs;;a;processed;61142004
>  > destination;d_archive;;a;processed;31650382
>  >
>  > about 15 seconds later
>  >
>  > global;payload_reallocs;;a;processed;61197495
>  > destination;d_archive;;a;processed;31680143
>  >
>  > This means that for
>  >
>  > # messages = 29761
>  > # reallocs = 55491
>  >
>  > or approximately 2 reallocs for each message.
>  >
>  > We make heavy use of patternDB to apply meta data to messages,
>  >
>  >
>  >
>


-- 
Evan Rempel                                      erempel at uvic.ca
Senior Systems Administrator                        250.721.7691
Data Centre Services, University Systems, University of Victoria