Bug 597293

Summary: rsyslog using 100% cpu.
Product: [openSUSE] openSUSE 11.3 Reporter: Marcus Rückert <mrueckert>
Component: OtherAssignee: Marius Tomaschewski <mt>
Status: RESOLVED FIXED QA Contact: E-mail List <qa-bugs>
Severity: Major    
Priority: P5 - None CC: alam.aby.b, cyberorg, forgotten_Si7ddX0wxG, kkaempf, lchiquitto, Sascha.Manns
Version: Factory   
Target Milestone: ---   
Hardware: Other   
OS: Other   
Whiteboard:
Found By: Development Services Priority:
Business Priority: Blocker: ---
Marketing QA Status: --- IT Deployment: ---
Attachments: patch from upstream git.

Description Marcus Rückert 2010-04-16 12:13:31 UTC
using the factory package on my 11.2 server.
config:
[[[
> grep -vE '^(#.*|\s*)$' /etc/rsyslog.conf
$ModLoad imuxsock.so # provides support for local system logging (e.g. via logger command)
$ModLoad imklog.so   # kernel logging (may be also provided by /sbin/klogd)
$IncludeConfig /var/run/rsyslog/additional-log-sockets.conf
$IncludeConfig /etc/rsyslog.d/*.conf
kern.warning;*.err;authpriv.none         /dev/tty10;RSYSLOG_TraditionalFileFormat
kern.warning;*.err;authpriv.none        |/dev/xconsole;RSYSLOG_TraditionalFileFormat
*.emerg                                  *
if      ($syslogfacility-text == 'kern') and \
        ($msg contains 'IN=' and $msg contains 'OUT=') then \
        -/var/log/firewall;RSYSLOG_TraditionalFileFormat
if      ($syslogfacility-text == 'kern') and \
        ($msg contains 'IN=' and $msg contains 'OUT=') then \
        ~
if      ($programname == 'acpid' or $syslogtag == '[acpid]:') and \
        ($syslogseverity <= 5) then \
        -/var/log/acpid;RSYSLOG_TraditionalFileFormat
if      ($programname == 'acpid' or $syslogtag == '[acpid]:') then \
        ~
if      ($programname == 'NetworkManager') or \
        ($programname startswith 'nm-') then \
        -/var/log/NetworkManager;RSYSLOG_TraditionalFileFormat
if      ($programname == 'NetworkManager') or \
        ($programname startswith 'nm-') then \
        ~
mail.*                                  -/var/log/mail;RSYSLOG_TraditionalFileFormat
mail.info                               -/var/log/mail.info;RSYSLOG_TraditionalFileFormat
mail.warning                            -/var/log/mail.warn;RSYSLOG_TraditionalFileFormat
mail.err                                 /var/log/mail.err;RSYSLOG_TraditionalFileFormat
news.crit                               -/var/log/news/news.crit;RSYSLOG_TraditionalFileFormat
news.err                                -/var/log/news/news.err;RSYSLOG_TraditionalFileFormat
news.notice                             -/var/log/news/news.notice;RSYSLOG_TraditionalFileFormat
*.=warning;*.=err                       -/var/log/warn;RSYSLOG_TraditionalFileFormat
*.crit                                   /var/log/warn;RSYSLOG_TraditionalFileFormat
*.*;mail.none;news.none                 -/var/log/messages;RSYSLOG_TraditionalFileFormat
local0,local1.*                         -/var/log/localmessages;RSYSLOG_TraditionalFileFormat
local2,local3.*                         -/var/log/localmessages;RSYSLOG_TraditionalFileFormat
local4,local5.*                         -/var/log/localmessages;RSYSLOG_TraditionalFileFormat
local6,local7.*                         -/var/log/localmessages;RSYSLOG_TraditionalFileFormat
]]]

after running for a few minutes it starts using 100% cpu. if you strace it you see it trying to write to the /dev/xconsole FD, but it fails with EAGAIN. removing the line for the xconsole fixes it.

this didnt happen with the 11.2 version of rsyslog.

Marius found out it happens after about 500 message/128k data.
Comment 1 Marius Tomaschewski 2010-04-20 08:02:36 UTC
The upstream bug report about is:

http://bugzilla.adiscon.com/show_bug.cgi?id=186
Comment 2 Dominique Leuenberger 2010-04-27 11:13:13 UTC
Created attachment 357077 [details]
patch from upstream git.

The upstream bug reports claims having this fixed in commit http://git.adiscon.com/?p=rsyslog.git;a=commitdiff;h=eec894fbc5eb263e6def1f2e35f9882967c95a88

The patch created by this commit is attached hereto.
Comment 3 Marius Tomaschewski 2010-04-27 11:42:59 UTC
Yes, the patch is applied in Base:System/rsyslog in the meantime.

It does not build at the moment because of broken openssl-devel package.
Comment 4 Marius Tomaschewski 2010-04-27 14:00:10 UTC
Test packages are in:

https://build.opensuse.org/platform/show?name=openSUSE_Factory&project=home%3Amtomaschewski%3Asyslog

AFAIS the loop does not happen any more, but when I start xconsole later,
it does not show any messages... it seems to "dicsonnect" it forever...
Comment 5 Leonardo Chiquitto 2010-04-29 17:11:31 UTC
*** Bug 600998 has been marked as a duplicate of this bug. ***
Comment 6 Forgotten User Si7ddX0wxG 2010-05-01 06:08:09 UTC
100 % cpu usage for me as well on 11.3 milestone6

 PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                            
 2809 root      20   0  118m 1200  828 S  100  0.0   6:28.95 rsyslogd

 # uname -a
Linux linux 2.6.34-rc5-6-desktop #1 SMP PREEMPT 2010-04-22 21:18:20 +0200 x86_64 x86_64 x86_64 GNU/Linux

# rpm -qa | grep -i  rsyslog
rsyslog-5.4.0-1.1.x86_64

In the end I did this
# kill -9 2809
Comment 7 Klaus Kämpf 2010-05-01 13:27:17 UTC
Seeing it too in 'top'.

And root cannot strace it (attach: ptrace(PTRACE_ATTACH, ...): Operation not permitted) - Weird
Comment 8 Klaus Kämpf 2010-05-01 13:30:39 UTC
Killing it brings udevd to 100% cpu usage :-/

Trying the package from comment comment #4 now.
Comment 9 Klaus Kämpf 2010-05-01 13:35:02 UTC
Update does *not* work flawless:

# rpm -Uhv rsyslog-5.4.0-24.1.i586.rpm 
warning: rsyslog-5.4.0-24.1.i586.rpm: Header V3 DSA/SHA1 Signature, key ID 53e8057e: NOKEY
Preparing...                ########################################### [100%]
   1:rsyslog                ########################################### [100%]
Updating etc/sysconfig/syslog...
Updating etc/sysconfig/syslog...
insserv: warning: current start runlevel(s) (5) of script `earlysyslog' overwrites defaults (2 3 5).
insserv: warning: current stop runlevel(s) (5) of script `earlysyslog' overwrites defaults (2 3 5).
Updating etc/sysconfig/syslog...
 Already running.
startproc:  exit status of parent of /sbin/rsyslogd: 1
..failed

-> this leaves the system without rsyslogd and a udevd (comment #8) at 97% :-/
Comment 10 Klaus Kämpf 2010-05-01 13:45:52 UTC
After reboot, things are back to normal.
udevd behaviour filed as bnc#601715
Comment 11 Jigish Gohil 2010-05-08 06:02:05 UTC
https://build.opensuse.org/package/show?package=rsyslog&project=home%3Amtomaschewski%3Asyslog

Package from that repo fixed the issue on M6.
Comment 12 Marius Tomaschewski 2010-05-10 13:46:15 UTC
I've submitted the package:

 39733  State:new     By:mtomaschewski When:2010-05-10T15:17:32
        submit:       Base:System/rsyslog  ->                            openSUSE:Factory       
        Descr: fixes for bnc#593699,bnc#593699,bnc#597293
Comment 13 Marius Tomaschewski 2010-05-17 09:17:33 UTC
*** Bug 606181 has been marked as a duplicate of this bug. ***
Comment 14 Marius Tomaschewski 2010-07-12 10:14:12 UTC
It is fixed on 11.3 already a while.
Comment 15 Bernhard Wiedemann 2016-04-15 11:37:52 UTC
This is an autogenerated message for OBS integration:
This bug (597293) was mentioned in
https://build.opensuse.org/request/show/39733 Factory / rsyslog