rsyslogd spins CPU on some kernels

Bug #523610 reported by Mathias Gug
312
This bug affects 65 people
Affects Status Importance Assigned to Milestone
rsyslog (Ubuntu)
Fix Released
High
Scott James Remnant (Canonical)
Lucid
Fix Released
High
Scott James Remnant (Canonical)

Bug Description

While running 20100218 EC2 image (ami-0512fe6c) rsyslog is constantly the following message (found in /var/log/kern.log):

Feb 18 05:01:52 ubuntu kernel: imklog 4.2.0, log source = /proc/kmsg started.
Feb 18 05:01:52 ubuntu kernel: Cannot read proc file system: 1 - Operation not permitted.
Feb 18 05:02:22 ubuntu kernel: last message repeated 643668 times
Feb 18 05:03:22 ubuntu kernel: last message repeated 1865459 times
Feb 18 05:04:22 ubuntu kernel: last message repeated 1327321 times
Feb 18 05:05:22 ubuntu kernel: last message repeated 1644146 times
Feb 18 05:06:23 ubuntu kernel: last message repeated 1826234 times
Feb 18 05:07:23 ubuntu kernel: last message repeated 1817861 times
Feb 18 05:08:23 ubuntu kernel: last message repeated 1807415 times
Feb 18 05:09:23 ubuntu kernel: last message repeated 1813151 times
Feb 18 05:10:23 ubuntu kernel: last message repeated 1857271 times
Feb 18 05:11:23 ubuntu kernel: last message repeated 1810173 times
Feb 18 05:12:23 ubuntu kernel: last message repeated 1826654 times
Feb 18 05:13:23 ubuntu kernel: last message repeated 1825384 times

Related branches

Mathias Gug (mathiaz)
summary: - Cannot read proc file system: 1 - Operation not permitted.
+ 20100218 EC2 image (ami-0512fe6c): Cannot read proc file system: 1 -
+ Operation not permitted.
Revision history for this message
Jeff Waugh (jdub) wrote : Re: 20100218 EC2 image (ami-0512fe6c): Cannot read proc file system: 1 - Operation not permitted.

Also seeing this running lucid's rsyslog 4.2.0-2ubuntu7, on linode's 2.6.32-linode23 paravirt kernel.

Revision history for this message
Jeff Waugh (jdub) wrote :

most likely rsyslog, not the kernel

affects: linux-ec2 (Ubuntu) → rsyslog (Ubuntu)
Revision history for this message
Jeff Waugh (jdub) wrote :

Possible dupe, or related to #460738?

Revision history for this message
Jeff Waugh (jdub) wrote :

rsyslog runs as syslog, can't read /proc/kmsg:

jdub@node:~$ ls /proc/kmsg
-r-------- 1 root root 0 2010-02-18 19:01 /proc/kmsg

Revision history for this message
Jeff Waugh (jdub) wrote :

Aha -- in its conversion to upstart, the old dd trick wasn't brought over.

Revision history for this message
LCID Fire (lcid-fire) wrote :

Well - since this is pretty much killing my 1,6 G notebook for now my lucid fixup script contains a call to
sudo service rsyslog stop

Revision history for this message
LCID Fire (lcid-fire) wrote :

Might be dup of #460738!?

Revision history for this message
Matt Zimmerman (mdz) wrote :

The changelog says this should work with newer kernels:

rsyslog (4.2.0-2ubuntu6) lucid; urgency=low

  * debian/rsyslog.rsyslog-kmsg.upstart:
    - Drop this additional job; kernel changes have meant that rsyslog
      may read from /proc/kmsg directly after dropping privileges.
      LP: #517773
  * debian/rsyslog.preinst:
    - Remove on upgrade
  * debian/rsyslog.conf:
    - Restore to reading from /proc/kmsg

 -- Scott James Remnant <email address hidden> Wed, 17 Feb 2010 12:23:01 +0000

I'm running 2.6.32-12-generic #16-Ubuntu and it definitely does not work there. Even if it works in the latest kernels, this will be a problem for upgrades from Karmic, because rsyslog gets restarted before the kernel is upgraded.

Changed in rsyslog (Ubuntu):
status: New → Triaged
importance: Undecided → High
tags: added: regression-potential
Changed in rsyslog (Ubuntu Lucid):
assignee: nobody → Scott James Remnant (scott)
milestone: none → lucid-alpha-3
Revision history for this message
Martin Pitt (pitti) wrote :

Regression from bug 517773, which was not completely implemented.

rsyslog needs to check if it can read from /proc/kmsg as non-root, and not drop privileges if not. In other works, seteuid(), read() -> on fail, seteuid(0) and keep it that way, on success -> setuid() -> permanently drop privs.

summary: - 20100218 EC2 image (ami-0512fe6c): Cannot read proc file system: 1 -
- Operation not permitted.
+ rsyslogd spins CPU on older kernels
Revision history for this message
mpcd (mpcd) wrote : Re: rsyslogd spins CPU on older kernels

Happens for me on 2.6.33-020633rc8-generic from kernel-ppa

Revision history for this message
Alessandro Ghersi (alessandro-ghersi) wrote :

After this recent upgrade, rsyslogd takes 50% of my cpu, see also bug #524382

Revision history for this message
Alessandro Ghersi (alessandro-ghersi) wrote :

I installed right now the 4.2.0-2ubuntu5.1 version and the high usage of cpu doesn't happen

Fail2Ban (failtoban)
tags: added: regression-release
removed: regression-potential
Revision history for this message
Anders Kaseorg (andersk) wrote :

Fail2Ban: This is a regression in a development release, not a stable release; hence regression-potential, not regression-release. (See https://wiki.ubuntu.com/QATeam/RegressionTracking .)

tags: added: regression-potential
removed: regression-release
Revision history for this message
Gary Trakhman (gary-trakhman) wrote :

Debian Sid's rsyslog_4.4.2 seems to fix it for me.

http://packages.debian.org/sid/rsyslog

Revision history for this message
Gary Trakhman (gary-trakhman) wrote :

I'm running 2.6.31 btw. But it's lucid otherwise.

Revision history for this message
Gary Trakhman (gary-trakhman) wrote :

and... it's the same version that's in squeeze

Revision history for this message
zika (4zika4) wrote :

Putting stop rsyslog in /etc/rc.local tamed it...

Revision history for this message
Dana Goyette (danagoyette) wrote :

This also happens on the kernel-ppa 2.6.32-rc8 kernel (which means that kernel must lack some necessary kernel patch, or something.)
The line that keeps repeating:
Feb 21 12:55:49 EliteBook kernel: Cannot read proc file system: 1 - Operation not permitted.
Feb 21 12:56:19 EliteBook kernel: last message repeated 3932924 times
Feb 21 12:57:19 EliteBook kernel: last message repeated 6246228 times
Feb 21 12:58:19 EliteBook kernel: last message repeated 6210564 times
Feb 21 12:59:19 EliteBook kernel: last message repeated 6559527 times
Feb 21 13:00:19 EliteBook kernel: last message repeated 5978876 times
Feb 21 13:00:40 EliteBook kernel: last message repeated 2155624 times

Revision history for this message
Ben Blout (bdb-new) wrote :

I am seeing the problem also. Running a kernel from the mainline-ppa (I was requested to in bug #521260). Uname -a indicates: 2.6.33-999-generic #201002201003 SMP

dpkg --print-avail says I am running rsyslog_4.2.0-2ubuntu5.1_i386

Revision history for this message
Whinis (john-p-turner) wrote :

I too am having this problem running a custom kernel based off of 2.6.31.12 and I merely increased the frequency timer. However rsyslog seems to immediately jump up to 2 cores of my i7 after the recent update.

Revision history for this message
Gary Trakhman (gary-trakhman) wrote : Re: [Bug 523610] Re: rsyslogd spins CPU on older kernels

I was testing on 2.6.31-rt-9 and I have this issue, looks like the
1kHz timer is what we have in common?

On Mon, Feb 22, 2010 at 9:55 PM, Whinis <email address hidden> wrote:
> I too am having this problem running a custom kernel based off of
> 2.6.31.12 and I merely increased the frequency timer. However rsyslog
> seems to immediately jump up to 2 cores of my i7 after the recent
> update.
>
> --
> rsyslogd spins CPU on older kernels
> https://bugs.launchpad.net/bugs/523610
> You received this bug notification because you are a direct subscriber
> of a duplicate bug.
>

Revision history for this message
Jonathande2 (jonathan-slob) wrote : Re: rsyslogd spins CPU on older kernels

also experiencing this with my intel t2390 processor.
I am experiencing this issue with the current lucid kernel (2.6.32.8) but also in the new kernel (downloaded from ubuntu's kernel ppa) the version of 23 february 2010

Revision history for this message
Geoff123 (gsking1) wrote :

Same here on lucid with both the ubuntu-studio RT kernel package 2.6.31-rt and custom 2.6.33-rc8 (1000HZ, low-latency desktop, BFS scheduler patch).

Revision history for this message
RK (kubuntu-rk) wrote :

Same here on 2.6.33-020633rc8-generic; downgrading to 4.2.0-2ubuntu5 fixes it. I'd say 2.6.33 isn't an "older" kernel...

summary: - rsyslogd spins CPU on older kernels
+ rsyslogd spins CPU on some kernels
Revision history for this message
Michael Marley (mamarley) wrote :

Yeah, same here. I have the problem with 2.6.33 as well.

Revision history for this message
Scott James Remnant (Canonical) (canonical-scott) wrote :

Something like this seems the sanest approach.

After opening /proc/kmsg, attempt a zero-byte read from it - if that fails with EPERM then we don't load the klog module

Revision history for this message
Scott James Remnant (Canonical) (canonical-scott) wrote :

That patch isn't right, needs to seteuid() around the read() call, but the module doesn't know what the uid is going to be; wondering whether hard-coding some number in there will upset pitti

Revision history for this message
Gary Trakhman (gary-trakhman) wrote : Re: [Bug 523610] Re: rsyslogd spins CPU on some kernels

why not upgrade rsyslogd? Using debian testing's 4.4.2 package fixed it for me.

On Wed, Feb 24, 2010 at 12:41 PM, Scott James Remnant
<email address hidden> wrote:
> Something like this seems the sanest approach.
>
> After opening /proc/kmsg, attempt a zero-byte read from it - if that
> fails with EPERM then we don't load the klog module
>
> ** Attachment added: "deroot.patchpatch"
>   http://launchpadlibrarian.net/39737237/deroot.patchpatch
>
> --
> rsyslogd spins CPU on some kernels
> https://bugs.launchpad.net/bugs/523610
> You received this bug notification because you are a direct subscriber
> of a duplicate bug.
>

Revision history for this message
Scott James Remnant (Canonical) (canonical-scott) wrote :

Better version of the patch

Revision history for this message
Scott James Remnant (Canonical) (canonical-scott) wrote :

Gary: because upgrading doesn't actually fix the problem - if you use Debian's package, your rsyslog is running as *root* - the whole point of this exercise is to make it not need to. If we were to merge rsyslog, we'd still use our deroot.patch, so would still hit the same bug

Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package rsyslog - 4.2.0-2ubuntu8

---------------
rsyslog (4.2.0-2ubuntu8) lucid; urgency=low

  * debian/patches/deroot.patch:
    - After opening /proc/kmsg, set the effective user to an unprivileged
      one and attempt a zero-byte read from the file. If this succeeds, we
      know that this will work de-rooted; if this fails, we don't enable
      kernel-message logging. LP: #523610.
 -- Scott James Remnant <email address hidden> Wed, 24 Feb 2010 18:21:54 +0000

Changed in rsyslog (Ubuntu Lucid):
status: Triaged → Fix Released
tags: added: iso-testing
Revision history for this message
Dave Martin (dave-martin-arm) wrote :

@Scott

Just to check --- is there a risk that the patch to rsyslog will in effect disable kernel logging on any final lucid release, bearing in mind that not all the kernels are in sync (particularly armel imx51)

That would surely be bad, but I've probably misunderstood here...

Revision history for this message
Gianvito Cavasoli (janvitus) wrote :

This bug still persist on Lucid:

"localhost kernel: imklog: Cannot read proc file system, 1."

I have a kernel vanilla 2.6.33.2 without patches and rsyslog 4.2.0-2ubuntu8.

Rocko (rockorequin)
Changed in rsyslog (Ubuntu Lucid):
status: Fix Released → Confirmed
Revision history for this message
Rocko (rockorequin) wrote :

I confirm Gianvito's findings with 2.6.33.2, ie that the problem is NOT resolved. rsyslog isn't using up CPU cycles, but it is failing to read kmsg.

What I suspect is happening is that attempting a zero-byte read from ksmg always succeeds, so rsyslog is using the wrong test, eg:

sudo python
>>> import os
>>> f=open('/proc/kmsg')
>>> os.seteuid(1000)
>>> f.read(0)
''
>>> f.read(1)
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
IOError: [Errno 1] Operation not permitted

ie rsyslog should try and read at least one byte for its test whether the user can read /proc/kmsg.

Oddly, it looks like the patch (see comment 1 in bug #515623) to allow user "read file" access to /proc/kmsg is incorporated in 2.6.33.2, but it simply isn't working.

Revision history for this message
Scott James Remnant (Canonical) (canonical-scott) wrote :

On Sat, 2010-04-17 at 06:18 +0000, Rocko wrote:

> I confirm Gianvito's findings with 2.6.33.2, ie that the problem is NOT
> resolved. rsyslog isn't using up CPU cycles, but it is failing to read
> kmsg.
>
Then this isn't the reported bug!

 status fixreleased

Note that the fact it doesn't read kmsg on older kernels is *DELIBERATE*
and will not be fixed.

Scott
--
Scott James Remnant
<email address hidden>

Revision history for this message
Rocko (rockorequin) wrote :

Apologies, I'll report it as another bug then.

Is it also the intention that rsyslog won't read kmsg on newer kernels? (2.6.33 is a newer kernel, not an older kernel).

Changed in rsyslog (Ubuntu Lucid):
status: Confirmed → Fix Released
Revision history for this message
Rocko (rockorequin) wrote :

Just to correct an earlier comment I made: that patch in bug #515623 (comment 1) ISN'T in 2.6.33.2. I applied it to 2.6.33.2 and kernel logging now works again. It looks like the patch will be in the vanilla 2.6.34, though. So hopefully 2.6.33 will be the only newer kernel that doesn't allow kernel logging in Lucid.

Revision history for this message
Scott James Remnant (Canonical) (canonical-scott) wrote :

Right, that's my understanding as well

The design of rsyslog made it very hard to "fall back" to not de-rooting in the case of an unpatched kernel

Revision history for this message
Thomas Zahreddin (thomas-zahreddin) wrote :

I solved this issue for me (no kernel hacker) with going back to the last Version 4.2.0-2ubuntu5.

(Just want to mention this for other newbies like my)

Revision history for this message
simonm (simon-mullis) wrote :

Just to add another option in the spirit of #39. I couldn't find a simple solution and ended up solving this issue by removing rsyslog entirely and now use syslog-ng which does everything I need (only issue when installing was to chown a few logs to root.adm).

Revision history for this message
mokabar (tim-klingt) wrote :

the -rt kernel is still based on 2.6.33. a natty-based system with the -rt kernel is still prone to this issue

Revision history for this message
EntityReborn (entityreborn) wrote :

This is still active in 11.04. I am running this under a VPS, running kernel 2.6.32.19-0.2.99.17.22250fd-xen

Revision history for this message
Andrew Savory (7-launchpad-andrewsavory-com) wrote :

I see this issue running 11.10; kernel 2.6.32.33-kvm-i386-20110317-dirty.
Temporary workaround was to downgrade to maverick's rsyslogd via: apt-get install rsyslog=4.2.0-2ubuntu8

Revision history for this message
XabiX (xdealmeida) wrote :

it happens to me on a VPS with :
Linux x.santrex.net 2.6.31.6 #3 SMP Mon May 3 19:58:57 UTC 2010 i686 i686 i386 GNU/Linux

Revision history for this message
panticz.de (panticz.de) wrote :

same problem under debian squeeze 64bit xen kernel:
Linux oneiric 2.6.32-5-xen-amd64 #1 SMP Thu Nov 3 05:42:31 UTC 2011 x86_64 x86_64 x86_64 GNU/Linux

fixed with:
wget http://mirror.netcologne.de/ubuntu/pool/main/r/rsyslog/rsyslog_4.2.0-2ubuntu8_amd64.deb -O /tmp/rsyslog_4.2.0-2ubuntu8_amd64.deb
dpkg -i /tmp/rsyslog_4.2.0-2ubuntu8_amd64.deb

Revision history for this message
Malte S. Stretz (mss) wrote :

Still happens when running 11.10 on Proxmox VE 2.0-beta1 in an OpenVZ container:
Linux lorentz-s19 2.6.32-7-pve #1 SMP Thu Feb 16 09:00:32 CET 2012 i686 athlon i386 GNU/Linux

Revision history for this message
Justin Delegard (justdelegard) wrote :

I just upgraded from 10.04 to 12.04 and encountered this problem. As it turns out I was still using the 10.04 kernel and my Grub menu was woefully out of date and so was my kernel. I ran

apt-get install grub2

and that fixed my loader problems and also fixed the rsyslogd issue. I assume that the loader was expected to have upgraded between my release revisions but was not upgraded as part of the script or some such issue.

Revision history for this message
Callum Macdonald (chmac) wrote :

I had what I believe to be the same issue on 12.04 Precise 2.6.32-12-pve x86_64 running in a Proxmox container. I downloaded http://archive.ubuntu.com/ubuntu/pool/main/r/rsyslog/rsyslog_4.2.0-2ubuntu8_amd64.deb, installed, and now the error messages are no longer appearing.

Does this bug need to be re-opened? A new bug filed? It's showing fix-released but apparently the issue (or a variation) still exists.

Revision history for this message
Simon Déziel (sdeziel) wrote :

For those running OpenVZ/Proxmox containers, one simple workaround is to disable the imklog module using this :

  sed -i -e 's/^\$ModLoad imklog/#\$ModLoad imklog/g' /etc/rsyslog.conf

This fixes the 100% CPU usage of rsyslog in Natty, Oneiric and Precise containers.

Revision history for this message
Jarl (jarl-dk) wrote :

I am still experiencing this on 12.04 (rackspace hosting)

$lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 12.04.1 LTS
Release: 12.04
Codename: precise

$uname -a
Linux ex-test 2.6.32.1-rscloud #15 SMP Mon Feb 22 13:22:15 UTC 2010 x86_64 x86_64 x86_64 GNU/Linux

$aptitude show rsyslog | grep Version
Version: 5.8.6-1ubuntu8

Revision history for this message
FloSoft (flosoft) wrote :

same problem here :/

Revision history for this message
Moses Moore (moses-mozai) wrote :

Upgraded from 10.04 LTS to 12.04 LTS, and I was surprised to see my load average at >= 2.00 for days.

OpenVZ virtual private server
`lsb_release -a |grep Desc`: Ubuntu 12.04.1 LTS
`uname -a`: Linux 2.6.32-042stab057.1 x86_64
`dpkg -l rsyslog`: 5.8.6-1ubuntu8

I used the solution suggested in comment #49 above by sdeziel; after disabling that module, rsyslogd is no longer hoarding CPU time, and load average has dropped.

big question: after disabling 'imklog', is rsyslog now acquring *less* information than the Ubuntu 10.04 version? I'd like to know what I'm missing out on, if anything.

Revision history for this message
Simon Déziel (sdeziel) wrote :

@Moses, from what I could see, rsyslog is unable to get the "kernel" syslog facility regardless of the imklog module presence, even in 10.04. I think the OpenVZ kernel blocks access to this syslog facility for guests.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers