Bug 896013 - Libvirt is not relabelling qcow2 backing files
Libvirt is not relabelling qcow2 backing files
Status: CLOSED ERRATA
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: libvirt (Show other bugs)
6.4
x86_64 Linux
urgent Severity urgent
: rc
: 6.4
Assigned To: Eric Blake
Omri Hochman
: Regression, Triaged, ZStream
: 896706 922683 (view as bug list)
Depends On:
Blocks: 915349
  Show dependency treegraph
 
Reported: 2013-01-16 08:25 EST by Omri Hochman
Modified: 2013-11-21 03:40 EST (History)
17 users (show)

See Also:
Fixed In Version: libvirt-0.10.2-19.el6
Doc Type: Bug Fix
Doc Text:
Cause: In RHEL 6.4, libvirt started caching storage file backing chains. However, the code only populated the cache when cgroups were in use. Consequence: Without cgroups, a missing cache meant sVirt was unable to properly label backing chain files, preventing guest startup. Fix: Populating the cache was moved earlier, independent of cgroups. Result: More efficient sVirt operations, regardless of cgroups.
Story Points: ---
Clone Of:
: 910806 913197 (view as bug list)
Environment:
Last Closed: 2013-11-21 03:40:13 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)
Output of sesearch (34.69 KB, text/plain)
2013-02-04 14:15 EST, Lon Hohberger
no flags Details
SELinux policy module (678 bytes, text/plain)
2013-02-04 16:18 EST, Lon Hohberger
no flags Details
x86 failures (82.47 KB, text/plain)
2013-02-13 09:42 EST, Lon Hohberger
no flags Details
Just the AVC failures (2.32 KB, text/plain)
2013-02-13 09:46 EST, Lon Hohberger
no flags Details
compute.log (36.56 KB, text/x-log)
2013-02-17 06:33 EST, Omri Hochman
no flags Details

  None (edit)
Description Omri Hochman 2013-01-16 08:25:13 EST
[nova]: 'nova boot' of new instance caused AVC Errors in /var/log/messages. 

Environment:
------------
openstack-nova-compute-2012.2.1-2.el6ost.noarch
openstack-nova-scheduler-2012.2.1-2.el6ost.noarch
openstack-nova-cert-2012.2.1-2.el6ost.noarch
openstack-nova-objectstore-2012.2.1-2.el6ost.noarch
openstack-nova-network-2012.2.1-2.el6ost.noarch
openstack-nova-console-2012.2.1-2.el6ost.noarch
openstack-nova-2012.2.1-2.el6ost.noarch
python-nova-2012.2.1-2.el6ost.noarch
openstack-nova-api-2012.2.1-2.el6ost.noarch
openstack-nova-volume-2012.2.1-2.el6ost.noarch
openstack-nova-novncproxy-0.4-2.el6.noarch
python-novaclient-2.10.0-1.el6ost.noarch
openstack-nova-common-2012.2.1-2.el6ost.noarc

Description:
------------
When I attempted to boot new instance Using 'nova boot, Just before the Instance changed to 'ACTIVE', I noticed a rsyslogd message, looking at the /var/log/messages there were AVC  Errors


Scenario:
---------
Attempted to perform : 'nova boot --flavor 1 --key_name oskey --image af12e3e3-54ff-40e2-a3ad-2174b3a385da fedora'

/var/log/messages :
---------------------
Jan 16 10:15:43 cougar02 kernel: kvm: 8010: cpu0 unhandled rdmsr: 0xc0010001
Jan 16 10:15:54 cougar02 kernel: device vnet3 entered promiscuous mode
Jan 16 10:15:54 cougar02 kernel: br100: port 5(vnet3) entering forwarding state
Jan 16 10:15:54 cougar02 kernel: type=1400 audit(1358331354.924:30855): avc:  denied  { read } for  pid=8481 comm="qemu-kvm" name="bde2f390c0dd0d2c59bc0c85682b293f1169f5d
0_20" dev=dm-0 ino=11011616 scontext=unconfined_u:system_r:svirt_t:s0:c902,c925 tcontext=unconfined_u:object_r:nova_var_lib_t:s0 tclass=file
Jan 16 10:15:54 cougar02 kernel: type=1400 audit(1358331354.924:30856): avc:  denied  { open } for  pid=8481 comm="qemu-kvm" name="bde2f390c0dd0d2c59bc0c85682b293f1169f5d
0_20" dev=dm-0 ino=11011616 scontext=unconfined_u:system_r:svirt_t:s0:c902,c925 tcontext=unconfined_u:object_r:nova_var_lib_t:s0 tclass=file
Jan 16 10:15:54 cougar02 kernel: type=1400 audit(1358331354.924:30857): avc:  denied  { ioctl } for  pid=8481 comm="qemu-kvm" path="/var/lib/nova/instances/_base/bde2f390
c0dd0d2c59bc0c85682b293f1169f5d0_20" dev=dm-0 ino=11011616 scontext=unconfined_u:system_r:svirt_t:s0:c902,c925 tcontext=unconfined_u:object_r:nova_var_lib_t:s0 tclass=fil
e
Jan 16 10:15:54 cougar02 kernel: type=1400 audit(1358331354.924:30858): avc:  denied  { getattr } for  pid=8481 comm="qemu-kvm" path="/var/lib/nova/instances/_base/bde2f3
90c0dd0d2c59bc0c85682b293f1169f5d0_20" dev=dm-0 ino=11011616 scontext=unconfined_u:system_r:svirt_t:s0:c902,c925 tcontext=unconfined_u:object_r:nova_var_lib_t:s0 tclass=f
ile
Jan 16 10:15:56 cougar02 ntpd[30083]: Listening on interface #13 vnet3, fe80::fc16:3eff:fe12:47aa#123 Enabled
Jan 16 10:15:56 cougar02 1> 

---------------------------------------------------------------------------
[root@cougar02 ~]# ls -Z /var/lib/nova/instances/_base/bde2f390c0dd0d2c59bc0c85682b293f1169f5d0_20
-rw-r--r--. nova nova unconfined_u:object_r:nova_var_lib_t:s0 /var/lib/nova/instances/_base/bde2f390c0dd0d2c59bc0c85682b293f1169f5d0_20
Comment 1 Yaniv Kaul 2013-01-16 08:38:48 EST
selinux RPMs versions?
Comment 2 Lon Hohberger 2013-01-30 13:58:46 EST
Also

ls -lZ /var/lib/nova/instances 
ls -lZ /var/lib/nova/instances/_base
Comment 3 Lon Hohberger 2013-01-31 15:45:45 EST
Reproduced:

[root@thunderfury ~]# rpm -qa | grep selinux-policy
selinux-policy-3.7.19-195.el6.noarch
selinux-policy-targeted-3.7.19-195.el6.noarch

[root@thunderfury ~]# grep AVC /var/log/audit/audit.log 
type=AVC msg=audit(1359664847.973:425): avc:  denied  { read } for  pid=3219 comm="qemu-kvm" name="disk" dev=dm-0 ino=160890 scontext=system_u:system_r:qemu_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nova_var_lib_t:s0 tclass=file
type=AVC msg=audit(1359664847.973:425): avc:  denied  { open } for  pid=3219 comm="qemu-kvm" name="disk" dev=dm-0 ino=160890 scontext=system_u:system_r:qemu_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nova_var_lib_t:s0 tclass=file
type=AVC msg=audit(1359664847.974:426): avc:  denied  { ioctl } for  pid=3219 comm="qemu-kvm" path="/var/lib/nova/instances/instance-00000002/disk" dev=dm-0 ino=160890 scontext=system_u:system_r:qemu_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nova_var_lib_t:s0 tclass=file
type=AVC msg=audit(1359664847.974:427): avc:  denied  { getattr } for  pid=3219 comm="qemu-kvm" path="/var/lib/nova/instances/instance-00000002/disk" dev=dm-0 ino=160890 scontext=system_u:system_r:qemu_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nova_var_lib_t:s0 tclass=file
type=AVC msg=audit(1359664847.976:428): avc:  denied  { dac_override } for  pid=3219 comm="qemu-kvm" capability=1  scontext=system_u:system_r:qemu_t:s0-s0:c0.c1023 tcontext=system_u:system_r:qemu_t:s0-s0:c0.c1023 tclass=capability
type=AVC msg=audit(1359664847.976:428): avc:  denied  { write } for  pid=3219 comm="qemu-kvm" name="disk" dev=dm-0 ino=160890 scontext=system_u:system_r:qemu_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nova_var_lib_t:s0 tclass=file

[root@thunderfury ~]# ls -lZ /var/lib/nova/instances/instance-00000002/
-rw-rw----. qemu qemu system_u:object_r:svirt_image_t:s0:c604,c739 console.log
-rw-r--r--. qemu qemu system_u:object_r:virt_content_t:s0 disk
-rw-r--r--. nova nova system_u:object_r:nova_var_lib_t:s0 libvirt.xml

openstack-nova-2012.2.2-6.el6ost.noarch
Comment 4 Lon Hohberger 2013-01-31 16:02:24 EST
Deleting the '--key_name oskey' allows images to be created w/o error (presumably, this is why the WUI works, since it doesn't seem to let you create an image with a key?)

Reproduced with Dashboard - simply adding a keypair and launching a VM with that keypair is what is doing it.
Comment 8 Lon Hohberger 2013-02-04 14:15:18 EST
Created attachment 692957 [details]
Output of sesearch
Comment 12 Lon Hohberger 2013-02-04 16:18:00 EST
Created attachment 693001 [details]
SELinux policy module
Comment 17 Lon Hohberger 2013-02-13 09:41:40 EST
Derek found that there are several new / different AVCs; the primary difference between his installation and where I performed testing is that his occur on x86 VMs
Comment 18 Lon Hohberger 2013-02-13 09:42:17 EST
Created attachment 696818 [details]
x86 failures
Comment 19 Lon Hohberger 2013-02-13 09:44:08 EST
audit2allow spat out the following, given the above:

#============= svirt_t ==============
allow svirt_t nova_var_lib_t:file { read ioctl open getattr };
Comment 20 Lon Hohberger 2013-02-13 09:46:48 EST
Created attachment 696820 [details]
Just the AVC failures
Comment 21 Lon Hohberger 2013-02-13 10:07:57 EST
This is using qemu-system-x86_64, as it is launched within a VM:

[root@ps2 ~(keystone_admin)]$ ps -efZ | grep -i qemu
unconfined_u:system_r:svirt_t:s0:c96,c669 qemu 26359 1 73 10:01 ?      00:00:25 /usr/bin/qemu-system-x86_64 -name instance-0000000c -S -M rhel6.4.0 -no-kvm -m 512 -smp 1,sockets=1,cores=1,threads=1 -uuid 310d8061-d96d-4461-9e07-46c10bdef9e8 -smbios type=1,manufacturer=Red Hat,, Inc.,product=Red Hat OpenStack Nova,version=2012.2.2-9.el6ost,serial=8d9c3cd0-140e-41c7-8536-7558161e038d,uuid=310d8061-d96d-4461-9e07-46c10bdef9e8 -nodefconfig -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/instance-0000000c.monitor,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc -no-shutdown -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -drive file=/var/lib/nova/instances/instance-0000000c/disk,if=none,id=drive-virtio-disk0,format=qcow2,cache=none -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x4,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,fd=25,id=hostnet0 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=fa:16:3e:77:37:d1,bus=pci.0,addr=0x3 -chardev file,id=charserial0,path=/var/lib/nova/instances/instance-0000000c/console.log -device isa-serial,chardev=charserial0,id=serial0 -chardev pty,id=charserial1 -device isa-serial,chardev=charserial1,id=serial1 -device usb-tablet,id=input0 -vnc 192.168.0.36:0 -k en-us -vga cirrus -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x5

My bare-metal openstack deployment does not exhibit this behavior:

system_u:system_r:svirt_t:s0:c300,c621 qemu 15689  1  6 09:58 ?        00:00:29 /usr/libexec/qemu-kvm -name instance-0000000d -S -M rhel6.4.0 -cpu core2duo,+lahf_lm,+dca,+pdcm,+xtpr,+cx16,+tm2,+est,+vmx,+ds_cpl,+dtes64,+pbe,+tm,+ht,+ss,+acpi,+ds,-nx -enable-kvm -m 512 -smp 1,sockets=1,cores=1,threads=1 -uuid 23b53c2a-d411-422e-8b7b-04d019247f7a -smbios type=1,manufacturer=Red Hat,, Inc.,product=Red Hat OpenStack Nova,version=2012.2.2-9.el6ost,serial=44454c4c-4400-1039-8031-b6c04f544331,uuid=23b53c2a-d411-422e-8b7b-04d019247f7a -nodefconfig -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/instance-0000000d.monitor,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc,driftfix=slew -no-kvm-pit-reinjection -no-shutdown -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -drive file=/var/lib/nova/instances/instance-0000000d/disk,if=none,id=drive-virtio-disk0,format=qcow2,cache=none -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x4,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,fd=29,id=hostnet0,vhost=on,vhostfd=30 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=fa:16:3e:6c:ad:57,bus=pci.0,addr=0x3 -chardev file,id=charserial0,path=/var/lib/nova/instances/instance-0000000d/console.log -device isa-serial,chardev=charserial0,id=serial0 -chardev pty,id=charserial1 -device isa-serial,chardev=charserial1,id=serial1 -device usb-tablet,id=input0 -vnc 10.16.60.37:3 -k en-us -vga cirrus -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x5
Comment 22 Lon Hohberger 2013-02-13 10:09:49 EST
Could this be the problem?

[root@ps2 ~(keystone_admin)]$ ls -lZ /usr/libexec/qemu-kvm
-rwxr-xr-x. root root system_u:object_r:qemu_exec_t:s0 /usr/libexec/qemu-kvm
[root@ps2 ~(keystone_admin)]$ ls -lZ /usr/bin/qemu-system-x86_64 
lrwxrwxrwx. root root system_u:object_r:bin_t:s0       /usr/bin/qemu-system-x86_64 -> /usr/libexec/qemu-kvm
Comment 23 Daniel Walsh 2013-02-13 10:11:39 EST
No

SELinux is still transitioning properly.  The problem is the target is either mislabeled, IE libvirt did not relabal content in /var/lib/nova/instances

Or all virt machines need to be able to read content in /var/lib/nova/instances
Comment 24 Lon Hohberger 2013-02-13 10:51:57 EST
This is new/different than the original issue; I'm going to split it.
Comment 27 Lon Hohberger 2013-02-13 16:54:15 EST
Basic developer testing results:

All checks done in Horizon using a non-administrative account on a baremetal installation.

Imported keypair from SSH - OK
Imported i386 Fedora 18 image - OK
Imported x86_64 Fedora 18 image - OK
Created four Fedora VMs:
  i386, without key - OK
  i386, with key - OK
  x86_64, without key - OK
  x86_64, with key - OK
Created a 20GB volume - OK
Attached 20GB volume to x86_64 with no key - OK
Created a 20GB ext2fs in 20GB volume - OK
Detached volume from x86_64 - OK
Attached 20GB volume to x86_64 with ssh key - OK
Mounted ext2 volume - OK
Touched file in volume - OK
Unmounted file system - OK
Detached volume from x86_64 - OK
Deleted volume - OK (took awhile)
Terminated i386 F18 images - OK
Paused x86_64 instance - OK
Unpaused x86_64 instance - OK
Suspended x86_64 instance - OK

There were no AVC denials.
Comment 29 Omri Hochman 2013-02-17 06:29:33 EST
Reproduce with: openstack-nova-2012.2.3-1.el6ost.noarch.  

When booting an instance It's status switch to ERROR,  
Attach compute.log
Comment 30 Omri Hochman 2013-02-17 06:33:33 EST
Created attachment 698513 [details]
compute.log
Comment 31 Daniel Walsh 2013-02-18 11:09:33 EST
Any new avc messages?
Comment 32 Lon Hohberger 2013-02-18 15:12:59 EST
We need /var/log/audit/audit.log; on my system, this works fine using the same version of openstack-nova that Omri noted.

[root@ayanami lhh]# rpm -q openstack-nova-compute openstack-nova openstack-selinux selinux-policy
openstack-nova-compute-2012.2.3-1.el6ost.noarch
openstack-nova-2012.2.3-1.el6ost.noarch
openstack-selinux-0.1.2-3.el6ost.noarch
selinux-policy-3.7.19-195.el6.noarch
Comment 33 Lon Hohberger 2013-02-18 15:14:15 EST
Additionally, the version of libvirt and selinux-policy would be useful.
Comment 34 Lon Hohberger 2013-02-18 15:25:57 EST
*** Bug 896706 has been marked as a duplicate of this bug. ***
Comment 35 Lon Hohberger 2013-02-18 15:43:51 EST
Also, did you use SSH or certificates?  I'll try with certificates - I've been testing with ssh.
Comment 36 Lon Hohberger 2013-02-18 15:47:27 EST
My apologies, in the previous comment, I meant imported vs. generated keypairs.  Both worked in my environment with no AVC denials or instances ending up in the 'error' state.
Comment 37 Daniel Berrange 2013-02-19 15:10:19 EST
Please confirm what libvirt version is in use. The current RHEL-6.4 builds have a fatal regression wrt labelling of qcow2 backing files, which could explain the AVCs above. This is hoped to be fixed in a z-stream

http://post-office.corp.redhat.com/archives/rhvirt-patches/2013-February/msg00162.html
Comment 38 Daniel Berrange 2013-02-19 15:14:14 EST
On second thoughts, this probably isn't the problem, since the flaw only affects files with relative paths, and IIUC, OpenStack uses absolute paths.
Comment 39 Lon Hohberger 2013-02-19 16:46:06 EST
Note that Omri's machines, once rebooted, operated fine.
Comment 40 Omri Hochman 2013-02-20 07:05:11 EST
(In reply to comment #39)
> Note that Omri's machines, once rebooted, operated fine.


Re-test: boot instance after clean installation (using packstack), Instance status to switch to Error. Looking at a system after boot 2 VM's before reboot and 3 VM's after reboot:

root@puma04 instances(keystone_admin)]$ nova list

+--------------------------------------+----------+--------+---------------------------+
| ID                                   | Name     | Status | Networks                  |
+--------------------------------------+----------+--------+---------------------------+
| 520b5417-3064-4d9c-9379-e6c8b9ea73a6 | VM-FED17 | ERROR  |                           |
| bff4a826-77e4-477c-ad95-9e1b869b4a0e | VM-FED17 | ERROR  |                           |
| d5d65148-cb74-4f44-b132-9201e7142553 | VM-FED17 | ACTIVE | net_vlan_190=10.35.175.11 |
| f409f7d3-180d-4e6d-9c2c-63b33bf99cdc | VM-FED17 | ACTIVE | net_vlan_190=10.35.175.3  |
| 660d3842-e7a0-4b8d-b6d6-e9b705d21823 | dan1     | ACTIVE | net_vlan_190=10.35.175.4  |
+--------------------------------------+----------+--------+---------------------------+

It seems that before rebooting the host, the new Instances do not inherit the folder label :
---------------------------------------------------------------------------
[root@puma04 ~(keystone_admin)]$ ls -Z /var/lib/nova/
drwxr-xr-x. nova nova system_u:object_r:nova_var_lib_t:s0 instances
 

[root@puma04 ~(keystone_admin)]$ ls -Z /var/lib/nova/instances/
drwxr-xr-x. nova nova unconfined_u:object_r:nova_var_lib_t:s0 _base
drwxr-xr-x. nova nova unconfined_u:object_r:nova_var_lib_t:s0 instance-00000003
drwxr-xr-x. nova nova unconfined_u:object_r:nova_var_lib_t:s0 instance-00000004
drwxr-xr-x. nova nova system_u:object_r:nova_var_lib_t:s0 instance-00000005
drwxr-xr-x. nova nova system_u:object_r:nova_var_lib_t:s0 instance-00000006
drwxr-xr-x. nova nova system_u:object_r:nova_var_lib_t:s0 instance-00000007

-----------------------------------------------------------------------------
Comment 41 Daniel Berrange 2013-02-20 07:31:29 EST
After turning on libvirt debugging I see this

2013-02-20 12:25:28.941+0000: 18096: debug : virSecuritySELinuxGenSecurityLabel:523 : label=QEMU
2013-02-20 12:25:28.941+0000: 18096: debug : virSecuritySELinuxGenSecurityLabel:545 : type=2
2013-02-20 12:25:28.941+0000: 18096: debug : virSecuritySELinuxMCSFind:202 : Using sensitivity level 's0' cat min 0 max 1023 range 1024
2013-02-20 12:25:28.941+0000: 18096: debug : virSecuritySELinuxMCSFind:207 : Try cat s0:c205,c368
2013-02-20 12:25:28.941+0000: 18096: debug : virSecuritySELinuxMCSFind:233 : Found context 's0:c205,c368'
2013-02-20 12:25:28.941+0000: 18096: debug : virSecuritySELinuxGenNewContext:293 : basecontext=system_u:system_r:svirt_t:s0 mcs=s0:c205,c368 isObjectContext=0
2013-02-20 12:25:28.941+0000: 18096: debug : virSecuritySELinuxGenNewContext:306 : process=unconfined_u:system_r:virtd_t:s0-s0:c0.c1023
2013-02-20 12:25:28.941+0000: 18096: debug : virSecuritySELinuxGenNewContext:347 : Generated context 'unconfined_u:system_r:svirt_t:s0:c205,c368'
2013-02-20 12:25:28.941+0000: 18096: debug : virSecuritySELinuxGenNewContext:293 : basecontext=system_u:object_r:svirt_image_t:s0 mcs=s0:c205,c368 isObjectContext=1
2013-02-20 12:25:28.941+0000: 18096: debug : virSecuritySELinuxGenNewContext:306 : process=unconfined_u:system_r:virtd_t:s0-s0:c0.c1023
2013-02-20 12:25:28.941+0000: 18096: debug : virSecuritySELinuxGenNewContext:347 : Generated context 'unconfined_u:object_r:svirt_image_t:s0:c205,c368'
2013-02-20 12:25:28.941+0000: 18096: debug : virSecuritySELinuxGenSecurityLabel:631 : model=selinux label=unconfined_u:system_r:svirt_t:s0:c205,c368 imagelabel=unconfined_u:object_r:svirt_image_t:s0:c205,c368 baselabel=(null)
2013-02-20 12:25:31.587+0000: 18096: info : virSecuritySELinuxSetFileconHelper:794 : Setting SELinux context on '/var/lib/nova/instances/instance-0000000c/disk' to 'unconfined_u:object_r:svirt_image_t:s0:c205,c368'
2013-02-20 12:25:31.588+0000: 18096: info : virSecuritySELinuxSetFileconHelper:794 : Setting SELinux context on '/var/lib/nova/instances/instance-0000000c/console.log' to 'unconfined_u:object_r:svirt_image_t:s0:c205,c368'
2013-02-20 12:25:31.589+0000: 18096: info : virSecurityDACSetOwnership:271 : Setting DAC user and group on '/var/lib/nova/instances/instance-0000000c/disk' to '107:107'
2013-02-20 12:25:31.589+0000: 18096: info : virSecurityDACSetOwnership:271 : Setting DAC user and group on '/var/lib/nova/instances/instance-0000000c/console.log' to '107:107'
2013-02-20 12:25:31.789+0000: 18096: error : qemuProcessReadLogOutput:1458 : internal error Process exited while reading console log output: char device redirected to /dev/pts/6
qemu-kvm: -drive file=/var/lib/nova/instances/instance-0000000c/disk,if=none,id=drive-virtio-disk0,format=qcow2,cache=none: could not open disk image /var/lib/nova/instances/instance-0000000c/disk: Permission denied

The disk image it labels here has a backing file as shown by qemu-img:

# qemu-img info /var/lib/nova/instances/instance-0000000c/disk
image: /var/lib/nova/instances/instance-0000000c/disk
file format: qcow2
virtual size: 20G (21474836480 bytes)
disk size: 136K
cluster_size: 65536
backing file: /var/lib/nova/instances/_base/2775cd65c9bad70ab764019d32c5e7af3c8c7205_20


And Nova clearly tells libvirt it is a qcow2 format disk:

2013-02-20 12:30:19.504+0000: 19043: debug : virDomainDefineXML:7940 : conn=0x7f9e40000c30, xml=<domain type="kvm">
  <uuid>e879a03b-2ddc-4e35-82a0-f5378f034627</uuid>
  <name>instance-0000000d</name>
  <memory>2097152</memory>
  <vcpu>1</vcpu>
  <sysinfo type="smbios">
    <system>
      <entry name="manufacturer">Red Hat,, Inc.</entry>
      <entry name="product">Red Hat OpenStack Nova</entry>
      <entry name="version">2012.2.3-1.el6ost</entry>
      <entry name="serial">36303930-3935-435a-3332-313142363536</entry>
      <entry name="uuid">e879a03b-2ddc-4e35-82a0-f5378f034627</entry>
    </system>
  </sysinfo>
  <os>
    <type>hvm</type>
    <boot dev="hd"/>
    <smbios mode="sysinfo"/>
  </os>
  <features>
    <acpi/>
  </features>
  <clock offset="utc">
    <timer name="pit" tickpolicy="delay"/>
    <timer name="rtc" tickpolicy="catchup"/>
  </clock>
  <cpu mode="host-model" match="exact"/>
  <devices>
    <disk type="file" device="disk">
      <driver name="qemu" type="qcow2" cache="none"/>
      <source file="/var/lib/nova/instances/instance-0000000d/disk"/>
      <target bus="virtio" dev="vda"/>
    </disk>
    <interface type="bridge">
      <mac address="fa:16:3e:55:6c:17"/>
      <model type="virtio"/>
      <source bridge="br100"/>
      <filterref filter="nova-instance-instance-0000000d-fa163e556c17">
        <parameter name="IP" value="192.168.32.12"/>
        <parameter name="DHCPSERVER" value="192.168.32.1"/>
        <parameter name="PROJNET" value="192.168.32.0"/>
        <parameter name="PROJMASK" value="255.255.255.0"/>
      </filterref>
    </interface>
    <serial type="file">
      <source path="/var/lib/nova/instances/instance-0000000d/console.log"/>
    </serial>
    <serial type="pty"/>
    <input type="tablet" bus="usb"/>
    <graphics type="vnc" autoport="yes" keymap="en-us" listen="10.35.160.11"/>
  </devices>
</domain>

2013-02-20 12:30:19.561+0000: 19043: debug : virDomainFree:2281 : dom=0x7f9e38008f80, (VM: name=instance-0000000d, uuid=e879a03b-2ddc-4e35-82a0-f5378f034627)
2013-02-20 12:30:19.562+0000: 19042: debug : virDomainCreateWithFlags:8353 : dom=0x7f9e440a7460, (VM: name=instance-0000000d, uuid=e879a03b-2ddc-4e35-82a0-f5378f03462


So libvirt should have inspected the backing file & relabelled it.

The libvirt version is libvirt-0.10.2-18.el6.x86_64
Comment 43 Daniel Berrange 2013-02-20 07:40:27 EST
The root cause is that the code which determines the backing files is only being run if the cgroups devices controller is present:

int qemuSetupCgroup(virQEMUDriverPtr driver,
                    virDomainObjPtr vm,
                    virBitmapPtr nodemask)

    ...snip....

    if (qemuCgroupControllerActive(driver, VIR_CGROUP_CONTROLLER_DEVICES)) {
        ...snip....

        for (i = 0; i < vm->def->ndisks ; i++) {
            if (qemuDomainDetermineDiskChain(driver, vm->def->disks[i],
                                             false) < 0 ||
                qemuSetupDiskCgroup(vm, cgroup, vm->def->disks[i]) < 0)
                goto cleanup;
        }


This is completely bogus. The call to qemuDomainDetermineDiskChain must be done unconditionally in qemuProcessStart since far more than just cgroups requires the backing chain to be present.
Comment 46 Eric Blake 2013-02-20 08:24:20 EST
bug 896685 tracks the same issue in Fedora 18
Comment 47 Lon Hohberger 2013-02-20 09:54:46 EST
I think I need to wipe and reinstall; my XML looks a bit different.


<domain type='kvm' id='3'>
  <name>instance-00000010</name>
  <uuid>f46cfa91-4778-4160-9146-e3e63c976ff8</uuid>
  <memory unit='KiB'>524288</memory>
  <currentMemory unit='KiB'>524288</currentMemory>
  <vcpu placement='static'>1</vcpu>
  <sysinfo type='smbios'>
    <system>
      <entry name='manufacturer'>Red Hat,, Inc.</entry>
      <entry name='product'>Red Hat OpenStack Nova</entry>
      <entry name='version'>2012.2.3-1.el6ost</entry>
      <entry name='serial'>44454c4c-4400-1039-8031-b6c04f544331</entry>
      <entry name='uuid'>f46cfa91-4778-4160-9146-e3e63c976ff8</entry>
    </system>
  </sysinfo>
  <os>
    <type arch='x86_64' machine='rhel6.4.0'>hvm</type>
    <boot dev='hd'/>
    <smbios mode='sysinfo'/>
  </os>
  <features>
    <acpi/>
  </features>
  <cpu mode='host-model'>
    <model fallback='allow'/>
  </cpu>
  <clock offset='utc'>
    <timer name='pit' tickpolicy='delay'/>
    <timer name='rtc' tickpolicy='catchup'/>
  </clock>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>destroy</on_crash>
  <devices>
    <emulator>/usr/libexec/qemu-kvm</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2' cache='none'/>
      <source file='/var/lib/nova/instances/instance-00000010/disk'/>
      <target dev='vda' bus='virtio'/>
      <alias name='virtio-disk0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
    </disk>
    <controller type='usb' index='0'>
      <alias name='usb0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x2'/>
    </controller>
    <interface type='bridge'>
      <mac address='fa:16:3e:59:3e:c6'/>
      <source bridge='br100'/>
      <target dev='vnet0'/>
      <model type='virtio'/>
      <filterref filter='nova-instance-instance-00000010-fa163e593ec6'>
        <parameter name='DHCPSERVER' value='172.31.4.1'/>
        <parameter name='IP' value='172.31.4.4'/>
        <parameter name='PROJMASK' value='255.255.255.0'/>
        <parameter name='PROJNET' value='172.31.4.0'/>
      </filterref>
      <alias name='net0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </interface>
    <serial type='file'>
      <source path='/var/lib/nova/instances/instance-00000010/console.log'/>
      <target port='0'/>
      <alias name='serial0'/>
    </serial>
    <serial type='pty'>
      <source path='/dev/pts/0'/>
      <target port='1'/>
      <alias name='serial1'/>
    </serial>
    <console type='file'>
      <source path='/var/lib/nova/instances/instance-00000010/console.log'/>
      <target type='serial' port='0'/>
      <alias name='serial0'/>
    </console>
    <input type='tablet' bus='usb'>
      <alias name='input0'/>
    </input>
    <input type='mouse' bus='ps2'/>
    <graphics type='vnc' port='5900' autoport='yes' listen='10.16.60.37' keymap='en-us'>
      <listen type='address' address='10.16.60.37'/>
    </graphics>
    <video>
      <model type='cirrus' vram='9216' heads='1'/>
      <alias name='video0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </video>
    <memballoon model='virtio'>
      <alias name='balloon0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
    </memballoon>
  </devices>
  <seclabel type='dynamic' model='selinux' relabel='yes'>
    <label>system_u:system_r:svirt_t:s0:c302,c386</label>
    <imagelabel>system_u:object_r:svirt_image_t:s0:c302,c386</imagelabel>
  </seclabel>
</domain>
Comment 49 Eric Blake 2013-02-20 17:39:35 EST
Proposed upstream patch:
https://www.redhat.com/archives/libvir-list/2013-February/msg01174.html
Comment 50 Huang Wenlong 2013-02-21 00:25:57 EST
I can reproduce this bug with disable cgroup service
libvirt-0.10.2-18.el6.x86_64

1)stop cgroup service 
#service cgconfig stop 

2) restart libvirtd service 
#service libvirtd restart 

3) start a domain 

#virsh start sss

4) create a disk-only snapshot 
# virsh snapshot-create-as --disk-only sss s1

5) check selinux lable 
# ll -Z
-rw-------. qemu qemu unconfined_u:object_r:svirt_image_t:s0:c371,c822 sss.img
-rw-------. qemu qemu unconfined_u:object_r:svirt_image_t:s0:c371,c822 sss.s1

6) destroy domain and try to start it 
#virsh destroy sss

# ll -Z
-rw-------. qemu qemu unconfined_u:object_r:svirt_image_t:s0:c371,c822 sss.img
-rw-------. root root system_u:object_r:virt_image_t:s0 sss.s1

# virsh start sss
error: Failed to start domain sss
error: internal error Process exited while reading console log output: char device redirected to /dev/pts/2
qemu-kvm: -drive file=/var/lib/libvirt/images/sss.s1,if=none,id=drive-ide0-0-0,format=qcow2,cache=none: could not open disk image /var/lib/libvirt/images/sss.s1: Permission denied

7)check cgroup service 
# service cgconfig status
Stopped

8) start cgroup then restart libvirtd the domain can start 
]# /etc/init.d/cgconfig start
Starting cgconfig service:                                 [  OK  ]

# /etc/init.d/libvirtd restart
Stopping libvirtd daemon:                                  [  OK  ]
Starting libvirtd daemon:                                  [  OK  ]

# virsh start sss
Domain sss started
Comment 51 Eric Blake 2013-02-21 15:14:36 EST
In POST for 6.5 by virtue of rebase picking up:
commit 82d5fe543720da6d83c1d6bfa1c347d7d9fda278
Author: Eric Blake <eblake@redhat.com>
Date:   Wed Feb 20 15:34:48 2013 -0700

    qemu: check backing chains even when cgroup is omitted
    
    https://bugzilla.redhat.com/show_bug.cgi?id=896685 points out
    a regression caused by commit 38c4a9c - libvirt only labels
    the backing chain if the backing chain cache is populated, but
    the code to populate the cache was only conditionally performed
    if cgroup labeling was necessary.
    
    * src/qemu/qemu_cgroup.c (qemuSetupCgroup): Hoist cache setup...
    * src/qemu/qemu_process.c (qemuProcessStart): ...earlier into
    caller, where it is now unconditional.
Comment 53 Jiri Denemark 2013-03-18 10:54:09 EDT
*** Bug 922683 has been marked as a duplicate of this bug. ***
Comment 54 Jiri Denemark 2013-03-18 10:56:06 EDT
The patch from comment 51 causes a regression (originally filed as bug 922683) which is fixed by commit v1.0.3-88-gef3cd64:

commit ef3cd6473f5227fcc89ac4fd1fc4f8485ffae314
Author: Jiri Denemark <jdenemar@redhat.com>
Date:   Mon Mar 18 14:11:58 2013 +0100

    qemu: Fix startupPolicy regression
    
    Commit 82d5fe543720da6d83c1d6bfa1c347d7d9fda278
    
        qemu: check backing chains even when cgroup is omitted
    
    added backing file checks just before the code that removes optional
    disks if they are not present. However, the backing chain code fails in
    case the disk file does not exist, which makes qemuProcessStart fail
    regardless on configured startupPolicy.
    
    Note that startupPolicy implementation is still wrong after this patch
    since it only check the first file in a possible chain. It should rather
    check the complete backing chain. But this is an existing limitation
    that can be solved later. After all, startupPolicy is most useful for
    CDROM images and they won't make use of backing files in most cases.
Comment 55 Nir Magnezi 2013-06-16 08:37:50 EDT
Bug Reproduced with:
====================
openstack-packstack-2013.1.1-0.17.dev631.el6ost.noarch
openstack-nova-compute-2013.1.2-2.el6ost.noarch
libvirt-0.10.2-18.el6.x86_64


Reproduction steps:
===================
1. Install OpenStack via packstack:
   # packstack --allinone

2. Upload an Image to Glance and start an instance
   

Result:
=======
1. Instances Status --> ERROR
2. Nova logs indicates the same errors as in Comment #41:

could not open disk image /var/lib/nova/instances/fc50b33d-21bc-4628-ac05-3d79fd4f523d/disk: Permission denied\n\n'

Additional Info:
================
Restarted cgconfig, libvirtd and openstack-nova-compute resolved the issue.
Comment 56 Shanzhi Yu 2013-07-09 05:23:44 EDT
I can reproduce this bug libvirt-0.10.2-18.el6.x86_64, verify this bug with libvirt-0.10.2-19.el6.x86_64

Steps:
1. stop cgroup
# service cgconfig stop
2. restart libvirt
# service libvirtd restart
3. start a domain
# virsh start kvm-rhel6.4-x86_64-qcow2-virtio
4. create a disk-only snapshot 
# virsh snapshot-create-as kvm-rhel6.4-x86_64-qcow2-virtio s1
5. check selinux label
# ll -Z /var/lib/libvirt/images/
-rw-------. qemu qemu unconfined_u:object_r:svirt_image_t:s0:c70,c942 sss.img
-rw-------. qemu qemu unconfined_u:object_r:svirt_image_t:s0:c70,c942 sss.s1
6.  destroy domain and try to start it 
#virsh destroy kvm-rhel6.4-x86_64-qcow2-virtio

# ll -Z
-rw-------. qemu qemu unconfined_u:object_r:svirt_image_t:s0:c70,c942 sss.img
-rw-------. root root system_u:object_r:virt_image_t:s0 sss.s1

# virsh start kvm-rhel6.4-x86_64-qcow2-virtio
Domain kvm-rhel6.4-x86_64-qcow2-virtio started

So verify this bug.
Comment 58 errata-xmlrpc 2013-11-21 03:40:13 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.