FAQ Search Today's Posts Mark Forums Read
» Video Reviews

» Linux Archive

Linux-archive is a website aiming to archive linux email lists and to make them easily accessible for linux users/developers.


» Sponsor

» Partners

» Sponsor

Go Back   Linux Archive > Gentoo > Gentoo User

 
 
LinkBack Thread Tools
 
Old 03-23-2009, 02:38 PM
Steve
 
Default Syslog-ng using a spectacular amount of CPU time... (I'm using sshguard)

Has anyone any ideas? The syslog-ng is the usually the first line
reported by top:


4097 root 20 0 3120 1060 708 R 48.3 0.1 677:46.38 syslog-ng

The files in /var/log seem to be growing at an expected slow pace and
aren't reporting anything unexpected. I followed a 'howto' and have
sshguard running. This (comments stripped) is what I have in
/etc/syslog-ng/syslog-ng.conf

options {
chain_hostnames(off);
sync(0);
stats(43200);
};

source src {
unix-stream("/dev/log" max-connections(256));
internal();
file("/proc/kmsg");
};

destination messages { file("/var/log/messages"); };
destination console_all { file("/dev/tty12"); };
log { source(src); destination(messages); };
log { source(src); destination(console_all); };
destination authlog { file("/var/log/auth.log"); };
destination authlog { file("/var/log/auth.log"); };
filter f_authpriv { facility(auth, authpriv); };
log { source(src); filter(f_authpriv); destination(authlog); };
filter sshlogs { facility(auth, authpriv) and match("sshd"); };
destination sshguardproc {
program("/usr/local/sbin/sshguard"
template("$DATE $FULLHOST $MESSAGE
"));
};
log { source(src); filter(sshlogs); destination(sshguardproc); };
 
Old 03-23-2009, 06:27 PM
Steve
 
Default Syslog-ng using a spectacular amount of CPU time... (I'm using sshguard)

Steve wrote:

destination sshguardproc {
program("/usr/local/sbin/sshguard"
template("$DATE $FULLHOST $MESSAGE
"));
};

The presence of the above line is definitely what triggers the excessive
CPU usage - it is almost as-if syslog-ng is 'busy-waiting' for the
sshguard process. The sshguard process is running - but using zero CPU.


I have this problem with syslog-ng versions 2.1.3 and 2.1.4 (the one
with ~x86)...


This is very frustrating... having played around, the syslog-ng tends
towards using 100% CPU when my server is otherwise quiet - if, and only
if, I have the program destination... even if the destination is not used.
 
Old 03-23-2009, 06:31 PM
Steve
 
Default Syslog-ng using a spectacular amount of CPU time... (I'm using sshguard)

Steve wrote:
This is very frustrating... having played around, the syslog-ng tends
towards using 100% CPU when my server is otherwise quiet - if, and
only if, I have the program destination... even if the destination is
not used.


Oh, and strace shows syslog-ng frantically polling file-descriptor 3...
which, I presume, is the pipe to the sshguard process.


poll([{fd=6, events=0}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN},
{fd=3, events=POLLIN}, {fd=13, events=POLLIN}, {fd=14, events=POLLIN},
{fd=7, events=POLLIN}, {fd=8, events=POLLIN}], 8, 1178000) = 1
([{fd=6, revents=POLLERR}])

gettimeofday({1237836567, 385148}, NULL) = 0
gettimeofday({1237836567, 385178}, NULL) = 0
poll([{fd=6, events=0}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN},
{fd=3, events=POLLIN}, {fd=13, events=POLLIN}, {fd=14, events=POLLIN},
{fd=7, events=POLLIN}, {fd=8, events=POLLIN}], 8, 1178000) = 1
([{fd=6, revents=POLLERR}])

gettimeofday({1237836567, 385506}, NULL) = 0
gettimeofday({1237836567, 385712}, NULL) = 0
poll([{fd=6, events=0}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN},
{fd=3, events=POLLIN}, {fd=13, events=POLLIN}, {fd=14, events=POLLIN},
{fd=7, events=POLLIN}, {fd=8, events=POLLIN}], 8, 1178000) = 1
([{fd=6, revents=POLLERR}])

gettimeofday({1237836567, 386027}, NULL) = 0
gettimeofday({1237836567, 386241}, NULL) = 0

Do others get this behaviour - is this a bug in syslog-ng?
 
Old 03-23-2009, 06:43 PM
Alan McKinnon
 
Default Syslog-ng using a spectacular amount of CPU time... (I'm using sshguard)

On Monday 23 March 2009 21:27:15 Steve wrote:
> Steve wrote:
> >> destination sshguardproc {
> >> program("/usr/local/sbin/sshguard"
> >> template("$DATE $FULLHOST $MESSAGE
"));
> >> };
>
> The presence of the above line is definitely what triggers the excessive
> CPU usage - it is almost as-if syslog-ng is 'busy-waiting' for the
> sshguard process. The sshguard process is running - but using zero CPU.
>
> I have this problem with syslog-ng versions 2.1.3 and 2.1.4 (the one
> with ~x86)...
>
> This is very frustrating... having played around, the syslog-ng tends
> towards using 100% CPU when my server is otherwise quiet - if, and only
> if, I have the program destination... even if the destination is not used.

One word:

blocking

I find this is usually the cause for higher than normal CPU load as reported
by top and other tools. If the load is pegged at exactly 100%, it's almost a
sure sign that some process is IO blocking on an idle system, and all the
process is doing is checking if IO is available, see it isn't, goes to sleep,
wakes up, rinse and repeat.

In short: top lies, and load does not mean what most people think it means.
The correct definition is "average number of processes that are waiting for
cpu time within the measurement period."

--
alan dot mckinnon at gmail dot com
 
Old 03-23-2009, 06:49 PM
Steve
 
Default Syslog-ng using a spectacular amount of CPU time... (I'm using sshguard)

Steve wrote:

Do others get this behaviour - is this a bug in syslog-ng?


Sorry for the multiple posts... a slight error on my part. The sshguard
process wasn't running - a /bin/sh process trying to spawn it was
running (there was no link from /usr/local... to the binary) and when
the binary failed to execute - syslog-ng got itself into a tiz.
Everything seems to work fine when I correct the path to the program.


Problem solved - but, I guess, this is a flaw in syslog-ng... I'd have
hoped it would generate an error message rather than behave as it did.
 
Old 03-23-2009, 06:55 PM
Steve
 
Default Syslog-ng using a spectacular amount of CPU time... (I'm using sshguard)

Alan McKinnon wrote:
In short: top lies,


On this occasion, top was telling the truth.
 

Thread Tools




All times are GMT. The time now is 06:38 AM.

VBulletin, Copyright ©2000 - 2014, Jelsoft Enterprises Ltd.
Content Relevant URLs by vBSEO ©2007, Crawlability, Inc.
Copyright 2007 - 2008, www.linux-archive.org