7.4.4-1ubuntu2.1 makes rsyslogd to take all the CPU in OpenVZ

[Patrice]

Test Case
---------
* Install rsyslog 7.4.4-1ubuntu2.1 on an Ubuntu system that runs inside an OpenVZ container (If necessary, use ProxMox to quickly establish an OpenVZ container environment)
* Verify that '$KLogPermitNonKernelFacility on' is set in /etc/rsyslog.conf
* Restart rsyslog to make sure any changes to the binaries/config are picked up
* Run 'top' and observe that the rsyslogd process is running at 100% CPU. When working properly, the rsyslogd process should generally be idle.

---------------------------------------------------------------------

After updating rsyslog from 7.4.4-1ubuntu2 to 7.4.4-1ubuntu2.1 the rsyslogd process started to take all the CPU on my machine.
The modification made by this release is described in #1274444, it is the activation of KLogPermitNonKernelFacility option.
I don't know exactly the effect of this option but it seems to have a permanent effect : even after downgrading the package or manually removing the option from /etc/rsyslog.conf the issue remains.
My syslog is full of :
Sep 8 10:28:40 sentry rsyslogd: imklog: error reading kernel log - shutting down: Bad file descriptor
Sep 8 10:28:40 sentry rsyslogd: message repeated 498 times: [imklog: error reading kernel log - shutting down: Bad file descriptor]
Sep 8 10:28:46 sentry rsyslogd-2177: rsyslogd[internal_messages]: 519517 messages lost due to rate-limiting
I guess this is what causes the CPU load.

I am running Ubuntu 14.04.1 LTS in an OpenVZ container on Proxmox 3.2. The kernel is 2.6.32-28-pve
---
ApportVersion: 2.14.1-0ubuntu3.3
Architecture: amd64DistroRelease: Ubuntu 14.04
Package: rsyslog 7.4.4-1ubuntu2.1
PackageArchitecture: amd64
Tags: trusty
Uname: Linux 2.6.32-28-pve x86_64
UpgradeStatus: No upgrade log present (probably fresh install)
UserGroups:

_MarkForUpload: True

[Brad Figg (brad-figg)]

This bug is missing log files that will aid in diagnosing the problem. From a terminal window please run:

apport-collect 1366829

and then change the status of the bug to 'Confirmed'.

If, due to the nature of the issue you have encountered, you are unable to run this command, please add a comment stating that fact and change the bug status to 'Confirmed'.

This change has been made by an automated script, maintained by the Ubuntu Kernel Team.

[Chris J Arges (arges)]

I wonder if this is a related issue:
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=738686

[Chris J Arges (arges)]

@Patrice:
Running 'apport-collect 1366829' as mentioned above would help to debug the issue. Please do so when you get a chance.
Thanks,

The commit that fixes the debian issue above is:
https://github.com/rsyslog/rsyslog/commit/ff091b7ea963b63130cfb77af57f137e632bf765
However, I'm unsure if this is the same issue.

[Patrice (patrice-g)]

apport information

[Patrice (patrice-g)]

apport information

[Siri Vias Singh Khalsa (sirivias)]

I saw the same issue rolling out a new VM using 14.04.1
I was able to resolve the issue by commenting out this line in rsyslog.conf:

#$ModLoad imklog # provides kernel logging support

log example: (repeated millions of times)

Sep 17 00:15:43 mi2 rsyslogd: message repeated 498 times: [imklog: error reading kernel log - shutting down: Bad file descriptor]
Sep 17 00:15:49 mi2 rsyslogd-2177: rsyslogd[internal_messages]: 4572709 messages lost due to rate-limiting
Sep 17 00:15:49 mi2 rsyslogd: imklog: error reading kernel log - shutting down: Bad file descriptor
Sep 17 00:15:49 mi2 rsyslogd: message repeated 498 times: [imklog: error reading kernel log - shutting down: Bad file descriptor]
Sep 17 00:15:55 mi2 rsyslogd-2177: rsyslogd[internal_messages]: 4692976 messages lost due to rate-limiting
Sep 17 00:15:55 mi2 rsyslogd: imklog: error reading kernel log - shutting down: Bad file descriptor

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Paul Donohue (s-launchpad-paulsd-com)]

Fixed here: https://github.com/rsyslog/rsyslog/pull/138

[Ubuntu Foundations Team Bug Bot (crichton)]

The attachment "Upstream fix" seems to be a patch. If it isn't, please remove the "patch" flag from the attachment, remove the "patch" tag, and if you are a member of the ~ubuntu-reviewers, unsubscribe the team.

[This is an automated message performed by a Launchpad user owned by ~brian-murray, for any issues please contact him.]

[Brian Murray (brian-murray)]

I'm happy to upload this fix to Trusty and Utopic but we will need a test case in the bug description so that the fix can be verified. Could somebody please provide one following the example at http://wiki.ubuntu.com/StableReleaseUpdates? Thanks!

[Launchpad Janitor (janitor)]

This bug was fixed in the package rsyslog - 7.4.4-1ubuntu13

---------------
rsyslog (7.4.4-1ubuntu13) vivid; urgency=medium

  * Applied upstream patch fixing infinite loop on OpenVZ VMs. Thanks to Paul
    Donohue for the patch. (LP: #1366829)
 -- Brian Murray <email address hidden> Thu, 18 Dec 2014 15:20:23 -0800

[Paul Donohue (s-launchpad-paulsd-com)]

Test case:
* Install rsyslog 7.4.4-1ubuntu2.1 on an Ubuntu system that runs inside an OpenVZ container (If necessary, use ProxMox to quickly establish an OpenVZ container environment)
* Verify that '$KLogPermitNonKernelFacility on' is set in /etc/rsyslog.conf
* Restart rsyslog to make sure any changes to the binaries/config are picked up
* Run 'top' and observe that the rsyslogd process is running at 100% CPU. When working properly, the rsyslogd process should generally be idle.

[Brian Murray (brian-murray)]

I've uploaded fixes to the SRU queue for Trusty and Utopic, thanks!

[Brian Murray (brian-murray)]

Hello Patrice, or anyone else affected,

Accepted rsyslog into utopic-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/rsyslog/7.4.4-1ubuntu11.1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

[Brian Murray (brian-murray)]

Hello Patrice, or anyone else affected,

Accepted rsyslog into trusty-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/rsyslog/7.4.4-1ubuntu2.4 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

[Simon Déziel (sdeziel)]

Just tested with an existing Trusty VZ and rsyslog (7.4.4-1ubuntu2.4) keeps taking ~100% CPU. I had to re-enable the previous workaround of disabling the imklog module loading.

The host is a 64bit Precise KVM running the OpenVZ upstream kernel from their apt repo: 2.6.32-openvz-042stab102.8-amd64

[Paul Donohue (s-launchpad-paulsd-com)]

Sorry, there were two issues:
1) The condition that the fix was testing for (EBADF on read before dropping privileges) was not a reliable indicator of the underlying problem. I should really have tested for EPERM on read after dropping privileges.
2) I only applied the fix to imkmsg, it also needed to be applied to imklog.

I've submitted an new pull request upstream:
https://github.com/rsyslog/rsyslog/pull/138

[Paul Donohue (s-launchpad-paulsd-com)]

Oops, wrong url for the new pull request upstream. It is:
https://github.com/rsyslog/rsyslog/pull/198

[Paul Donohue (s-launchpad-paulsd-com)]

Pull request has been accepted upstream.

Since there are now a bunch of upstream commits involved in the complete fix, I'm attaching an updated 11-fix-infinite-loop-openvz-vms.patch file for the ubuntu packages which contains all the necessary changes.

I also posted updated ubuntu package branches here: https://code.launchpad.net/~s-launchpad-paulsd-com/rsyslog/
But feel free to ignore my branch merge requests if you would prefer to update the package branches yourself.

[Brian Murray (brian-murray)]

I've uploaded the updated patch from comment #21 to the utopic and trusty proposed queues for review by the SRU team.

[Brian Murray (brian-murray)]

Oh the vivid task wasn't closed again because it was already closed.

rsyslog (7.4.4-1ubuntu14) vivid; urgency=medium

  * Applied updated upstream patch fixing infinite loop on OpenVZ VMs.
    (LP: #1366829)
 -- Paul Donohue <> Fri, 09 Jan 2015 10:50:36 -0500

[Brian Murray (brian-murray)]

Hello Patrice, or anyone else affected,

Accepted rsyslog into utopic-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/rsyslog/7.4.4-1ubuntu11.2 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

[Brian Murray (brian-murray)]

Hello Patrice, or anyone else affected,

Accepted rsyslog into trusty-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/rsyslog/7.4.4-1ubuntu2.5 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

[Simon Déziel (sdeziel)]

Great work Paul, thanks!

[Brian Murray (brian-murray)]

@Simon - Did you verify it on both release that the fix is pending for or only one of them? If only one, which one?

[Simon Déziel (sdeziel)]

Oh right, I could verify the fix on Trusty.

[Simon Déziel (sdeziel)]

You convinced me to test it on Utopic too. So I verified it on Trusty and Utopic and marked the bug as verified-done. I dropped the verification-done-precise as so far this SRU didn't target Precise.

[Paul Donohue (s-launchpad-paulsd-com)]

I have also verified the fix on Trusty.

[Patrice (patrice-g)]

Hello,

I have just installed rsyslog version 7.4.4-1ubuntu2.5 in the OpenVZ container where rsyslogd were taking all CPU and I confirm that after the update it was not the case anymore.
Thanks everyone for fixing this issue!

[Chris J Arges (arges)]

The verification of the Stable Release Update for rsyslog has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.

[Launchpad Janitor (janitor)]

This bug was fixed in the package rsyslog - 7.4.4-1ubuntu11.2

---------------
rsyslog (7.4.4-1ubuntu11.2) utopic; urgency=medium

  * Applied updated upstream patch fixing infinite loop on OpenVZ VMs.
    (LP: #1366829)
 -- Paul Donohue <email address hidden> Fri, 09 Jan 2015 10:50:36 -0500

[Launchpad Janitor (janitor)]

This bug was fixed in the package rsyslog - 7.4.4-1ubuntu2.5

---------------
rsyslog (7.4.4-1ubuntu2.5) trusty; urgency=medium

  * Applied updated upstream patch fixing infinite loop on OpenVZ VMs.
    (LP: #1366829)
 -- Paul Donohue <email address hidden> Fri, 09 Jan 2015 10:50:36 -0500