Bug 922153 - libvirt spams audit log with unneeded failures
libvirt spams audit log with unneeded failures
Status: CLOSED ERRATA
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: libvirt (Show other bugs)
6.4
Unspecified Unspecified
urgent Severity urgent
: rc
: ---
Assigned To: Eric Blake
Virtualization Bugs
: ZStream
Depends On:
Blocks: 958837
  Show dependency treegraph
 
Reported: 2013-03-15 11:15 EDT by Eric Blake
Modified: 2013-11-21 03:51 EST (History)
10 users (show)

See Also:
Fixed In Version: libvirt-0.10.2-19.el6
Doc Type: Bug Fix
Doc Text:
Previously, libvirt made control group (cgroup) requests on files that it should not have. With older kernels, such nonsensical cgroup requests were ignored; however, newer kernels are stricter, resulting in libvirt logging spurious warnings and failures to the libvirtd and audit logs. The audit log failures displayed by the ausearch tool were similar to the following: root [date] - failed cgroup allow path rw /dev/kqemu With this update, libvirt no longer attempts the nonsensical cgroup actions, leaving only valid attempts in the libvirtd and audit logs (making it easier to search for real cases of failure).
Story Points: ---
Clone Of:
Environment:
Last Closed: 2013-11-21 03:51:25 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Eric Blake 2013-03-15 11:15:40 EDT
Description of problem:
Recent kernels are stricter about validating use of cgroups, where older kernels would silently ignore bogus data.  As a result, libvirt is now spamming audit logs with failure messages, which can cause a false sense of doubt about a compromised system.

Version-Release number of selected component (if applicable):
libvirt-0.10.2-18.el6

How reproducible:
100%

Steps to Reproduce:
1. virsh start domain
2. cat /var/log/libvirt/libvirtd.log
2. auvirt --start today --all-events
3.
  
Actual results:
2. libvirt log includes a scary-looking:
2012-12-30 13:21:38.752+0000: 9113: warning : virCgroupMoveTask:885 : no vm cgroup in controller 3
2012-12-30 13:21:38.752+0000: 9113: warning : virCgroupMoveTask:885 : no vm cgroup in controller 4
2012-12-30 13:21:38.752+0000: 9113: warning : virCgroupMoveTask:885 : no vm cgroup in controller 6
3. audit log includes a scary-looking:
res   fedora_18-32             	root       	Wed Mar 13 18:31 - failed          	cgroup      	allow     	path	rw	/dev/kqemu


Expected results:
These results are not fatal (we intentionally don't create sub-cgroups for all controllers, and /dev/kqemu doesn't exist), so they shouldn't be logged

Additional info:
Upstream patches:
commit 7f544a4c8f0353e4ff9ca08aafbb86ff8f60da0a
Author: Daniel P. Berrange <berrange@redhat.com>
Date:   Wed Feb 27 16:57:16 2013 +0000

    Don't try to add non-existant devices to ACL
    
    The QEMU driver has a list of devices nodes that are whitelisted
    for all guests. The kernel has recently started returning an
    error if you try to whitelist a device which does not exist.
    This causes a warning in libvirt logs and an audit error for
1-7d50-e41ee6cd897b cgroup="/sys/fs/cgroup/devices/libvirt/qemu/vm031714/" class=path path=/dev/kqemu rdev=? acl=rw
    
    Signed-off-by: Daniel P. Berrange <berrange@redhat.com>
commit 279336c5d8c44f28956b3427ab2bf207d06878e2
Author: Daniel P. Berrange <berrange@redhat.com>
Date:   Wed Feb 27 16:51:04 2013 +0000

    Avoid spamming logs with cgroups warnings
    
    The code for putting the emulator threads in a separate cgroup
    would spam the logs with warnings
    
    2013-02-27 16:08:26.731+0000: 29624: warning : virCgroupMoveTask:887 : no vm cgroup in controller 3.731+0000: 29624: warning : virCgroupMoveTask:887 : no vm cgroup in controller 4.732+0000: 29624: warning : virCgroupMoveTask:887 : no vm cgroup in controller 6
    This is because it has only created child cgroups for 3 of the
    controllers, but was trying to move the processes from all the
    controllers. The fix is to only try to move threads in the
    controllers we actually created. Also remove the warning and
    make it return a hard error to avoid such lazy callers in the
    future.
    
    Signed-off-by: Daniel P. Berrange <berrange@redhat.com>
Comment 3 EricLee 2013-04-17 03:25:03 EDT
I can reproduce this bug with newest z stream package : libvirt-0.10.2-18.el6_4.4.x86_64:

# virsh start qcow2
Domain qcow2 started

# tailf /var/log/libvirt/libvirtd.log

2013-04-17 15:04:03.906+0000: 16187: warning : virCgroupMoveTask:885 : no vm cgroup in controller 3
2013-04-17 15:04:03.906+0000: 16187: warning : virCgroupMoveTask:885 : no vm cgroup in controller 4
2013-04-17 15:04:03.906+0000: 16187: warning : virCgroupMoveTask:885 : no vm cgroup in controller 6

# auvirt --start today --all-events
...
res   qcow2                    	root       	Wed Apr 17 23:04 - failed          	cgroup      	allow     	path	rw	/dev/kqemu
...
Comment 4 Eric Blake 2013-04-19 13:45:54 EDT
Moving to POST since 6.5 will pick this up via rebase.
When backporting to 6.4.z, we should also pick up bug 922203
Comment 6 CongDong 2013-05-15 04:57:33 EDT
I can't reproduce.

libvirt-0.10.2-18.el6_4.5.x86_64

Steps:
1. virsh start domain
2. cat /var/log/libvirt/libvirtd.log
2. auvirt --start today --all-events

Result:   No message about /dev/kqemu
...
res   rhel-test                	root       	Wed May 15 16:54                   	cgroup      	deny      	all		
res   rhel-test                	root       	Wed May 15 16:54                   	cgroup      	allow     	major	rw	pty
res   rhel-test                	root       	Wed May 15 16:54                   	cgroup      	allow     	path	rw	"/dev/null"
res   rhel-test                	root       	Wed May 15 16:54                   	cgroup      	allow     	path	rw	"/dev/full"
res   rhel-test                	root       	Wed May 15 16:54                   	cgroup      	allow     	path	rw	"/dev/zero"
res   rhel-test                	root       	Wed May 15 16:54                   	cgroup      	allow     	path	rw	"/dev/random"
res   rhel-test                	root       	Wed May 15 16:54                   	cgroup      	allow     	path	rw	"/dev/urandom"
res   rhel-test                	root       	Wed May 15 16:54                   	cgroup      	allow     	path	rw	"/dev/ptmx"
res   rhel-test                	root       	Wed May 15 16:54                   	cgroup      	allow     	path	rw	"/dev/kvm"
res   rhel-test                	root       	Wed May 15 16:54                   	cgroup      	allow     	path	rw	"/dev/rtc"
res   rhel-test                	root       	Wed May 15 16:54                   	cgroup      	allow     	path	rw	"/dev/hpet"
res   rhel-test                	root       	Wed May 15 16:54                   	disk        	start     	/var/lib/libvirt/images/rhel.img
res   rhel-test                	root       	Wed May 15 16:54                   	net         	start     	52:54:00:02:B3:A9
res   rhel-test                	root       	Wed May 15 16:54                   	mem         	start     	1048576
res   rhel-test                	root       	Wed May 15 16:54                   	vcpu        	start     	1
Comment 7 CongDong 2013-05-16 03:23:20 EDT
I can reproduce with : libvirt-0.10.2-18.el6

Steps:
1. virsh start domain
2. cat /var/log/libvirt/libvirtd.log
2. auvirt --start today --all-events

Result:

# cat /var/log/libvirt/libvirtd.log
..
2013-05-16 07:15:20.126+0000: 3544: warning : virCgroupMoveTask:885 : no vm cgroup in controller 3
2013-05-16 07:15:20.126+0000: 3544: warning : virCgroupMoveTask:885 : no vm cgroup in controller 4
2013-05-16 07:15:20.126+0000: 3544: warning : virCgroupMoveTask:885 : no vm cgroup in controller 6

# auvirt --start today --all-events
...
res   rhel-test                	root       	Thu May 16 15:15 - failed          	cgroup      	allow     	path	rw	/dev/kqemu
...
Comment 9 CongDong 2013-07-09 08:47:18 EDT
I can reproduce this bug:
Version:
# rpm -qa libvirt
libvirt-0.10.2-18.el6_4.3.x86_64

Steps:
Steps:
1. virsh start domain
2. cat /var/log/libvirt/libvirtd.log
2. auvirt --start today --all-events

result:
step2:
2013-07-09 12:39:00.713+0000: 11350: warning : virCgroupMoveTask:885 : no vm cgroup in controller 3
2013-07-09 12:39:00.713+0000: 11350: warning : virCgroupMoveTask:885 : no vm cgroup in controller 4
2013-07-09 12:39:00.713+0000: 11350: warning : virCgroupMoveTask:885 : no vm cgroup in controller 6
step3:

res   rhel6.4                  	root       	Tue Jul  9 20:39 - failed          	cgroup      	allow     	path	rw	/dev/kqemu


Verify:
Version:# rpm -qa libvirt
libvirt-0.10.2-19.el6.x86_64

Steps:
As the steps above

Result:
step2. there is no log like :
2013-07-09 12:39:00.713+0000: 11350: warning : virCgroupMoveTask:885 : no vm cgroup in controller 6

Step3:
there is no "/dev/kqemu" failed log.

res   rhel6.4                  	root       	Tue Jul  9 20:44                   	cgroup      	deny      	all		
res   rhel6.4                  	root       	Tue Jul  9 20:44                   	cgroup      	allow     	major	rw	pty
res   rhel6.4                  	root       	Tue Jul  9 20:44                   	cgroup      	allow     	path	rw	"/dev/null"
res   rhel6.4                  	root       	Tue Jul  9 20:44                   	cgroup      	allow     	path	rw	"/dev/full"
res   rhel6.4                  	root       	Tue Jul  9 20:44                   	cgroup      	allow     	path	rw	"/dev/zero"
res   rhel6.4                  	root       	Tue Jul  9 20:44                   	cgroup      	allow     	path	rw	"/dev/random"
res   rhel6.4                  	root       	Tue Jul  9 20:44                   	cgroup      	allow     	path	rw	"/dev/urandom"
res   rhel6.4                  	root       	Tue Jul  9 20:44                   	cgroup      	allow     	path	rw	"/dev/ptmx"
res   rhel6.4                  	root       	Tue Jul  9 20:44                   	cgroup      	allow     	path	rw	"/dev/kvm"
res   rhel6.4                  	root       	Tue Jul  9 20:44                   	cgroup      	allow     	path	rw	"/dev/rtc"
res   rhel6.4                  	root       	Tue Jul  9 20:44                   	cgroup      	allow     	path	rw	"/dev/hpet"
res   rhel6.4                  	root       	Tue Jul  9 20:44                   	disk        	start     	/var/lib/libvirt/images/rhel6.4.img
res   rhel6.4                  	root       	Tue Jul  9 20:44                   	net         	start     	52:54:00:A4:02:FF
res   rhel6.4                  	root       	Tue Jul  9 20:44                   	mem         	start     	1048576
res   rhel6.4                  	root       	Tue Jul  9 20:44                   	vcpu        	start     	1


As the result, change to verified
Comment 11 errata-xmlrpc 2013-11-21 03:51:25 EST
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHBA-2013-1581.html

Note You need to log in before you can comment on or make changes to this bug.