[PKG-Openstack-devel] Bug#892431: AppArmor denies access for libvirt to nova instances directory
aradian at tma-0.net
aradian at tma-0.net
Fri Mar 9 05:46:57 UTC 2018
Package: nova-compute
Version: 2:16.0.3-10
User: pkg-apparmor-team at lists.alioth.debian.org
Usertags: new-profile
When launching a QEMU KVM instance, an error occurs immediately upon
launching the qemu process:
Could not open backing file: Could not open
'/var/lib/nova/instances/_base/affe96668a4c64ef380ff1c71b4caec17039080e':
Permission denied
This is caused because the AppArmor profile for libvirt does not include
access to nova's instances directory (/var/lib/nova/instances).
This error was fixed by adding the following lines to
/etc/apparmor.d/usr.lib.libvirt.virt-aa-helper:
/var/lib/nova/instances/_base/ r,
/var/lib/nova/instances/_base/* r,
/var/lib/nova/instances/** rw,
and running:
sudo apparmor_parser -r /etc/apparmor.d/usr.lib.libvirt.virt-aa-helper
Probably it would be more appropriate to put that in a separate profile?
This is on a system installed as debian-stretch, then upgraded to
debian-buster.
$ uname -a
Linux callisto 4.14.0-3-amd64 #1 SMP Debian 4.14.17-1 (2018-02-14)
x86_64 GNU/Linux
AppArmor DENIED messages from /var/log/syslog:
Mar 8 21:31:09 callisto kernel: [688136.384367] audit: type=1400
audit(1520566269.565:85): apparmor="DENIED" operation="open"
profile="virt-aa-helper"
name="/var/lib/nova/instances/_base/affe96668a4c64ef380ff1c71b4caec17039080e"
pid=30420 comm="virt-aa-helper" requested_mask="r" denied_mask="r"
fsuid=0 ouid=64055
Mar 8 21:31:09 callisto kernel: [688136.609529] audit: type=1400
audit(1520566269.789:87): apparmor="DENIED" operation="open"
profile="virt-aa-helper"
name="/var/lib/nova/instances/_base/affe96668a4c64ef380ff1c71b4caec17039080e"
pid=30426 comm="virt-aa-helper" requested_mask="r" denied_mask="r"
fsuid=0 ouid=64055
Mar 8 21:31:10 callisto kernel: [688136.854752] audit: type=1400
audit(1520566270.033:89): apparmor="DENIED" operation="open"
profile="virt-aa-helper"
name="/var/lib/nova/instances/_base/affe96668a4c64ef380ff1c71b4caec17039080e"
pid=30432 comm="virt-aa-helper" requested_mask="r" denied_mask="r"
fsuid=0 ouid=64055
Mar 8 21:31:10 callisto kernel: [688137.075108] audit: type=1400
audit(1520566270.253:91): apparmor="DENIED" operation="open"
profile="virt-aa-helper"
name="/var/lib/nova/instances/_base/affe96668a4c64ef380ff1c71b4caec17039080e"
pid=30438 comm="virt-aa-helper" requested_mask="r" denied_mask="r"
fsuid=0 ouid=64055
Mar 8 21:31:10 callisto kernel: [688137.603399] audit: type=1400
audit(1520566270.781:94): apparmor="DENIED" operation="open"
profile="libvirt-39477509-a5d2-4f52-a751-bef5013484e4"
name="/var/lib/nova/instances/_base/affe96668a4c64ef380ff1c71b4caec17039080e"
pid=30475 comm="qemu-system-x86" requested_mask="r" denied_mask="r"
fsuid=0 ouid=0
Relevant part of /var/log/nova/nova-compute.log:
2018-03-02T05:15:27.083155Z qemu-system-x86_64: -drive
file=/var/lib/nova/instances/9ac0d3ec-35ad-4420-ae20-f6c0c9845f05/disk,format=qcow2,if=none,id=drive-virtio-disk0,cache=none:
Could not open backing file: Could not open
'/var/lib/nova/instances/_base/affe96668a4c64ef380ff1c71b4caec17039080e':
Permission denied
2018-03-01 23:15:27.373 2376 ERROR nova.virt.libvirt.driver
[req-3cb9fbc5-8f4e-4244-8b14-b52ac1f0494b
a6f48b630f634371ba94558f3ba576b8 5f46526ffab3410a9cf71b37fa242e11 -
default default] [instance: 9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] Failed
to start libvirt guest: libvirtError: internal error: process exited
while connecting to monitor: outputs=1,bus=pci.0,addr=0x2 -device
virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x6 -msg timestamp=on
2018-03-02T05:15:27.083155Z qemu-system-x86_64: -drive
file=/var/lib/nova/instances/9ac0d3ec-35ad-4420-ae20-f6c0c9845f05/disk,format=qcow2,if=none,id=drive-virtio-disk0,cache=none:
Could not open backing file: Could not open
'/var/lib/nova/instances/_base/affe96668a4c64ef380ff1c71b4caec17039080e':
Permission denied
2018-03-01 23:15:27.374 2376 INFO os_vif
[req-3cb9fbc5-8f4e-4244-8b14-b52ac1f0494b
a6f48b630f634371ba94558f3ba576b8 5f46526ffab3410a9cf71b37fa242e11 -
default default] Successfully unplugged vif
VIFBridge(active=False,address=fa:16:3e:b4:ed:53,bridge_name='brq03b5dd02-ac',has_traffic_filtering=True,id=042a5f68-01bb-453e-bb2a-2d798b7691d5,network=Network(03b5dd02-ac2f-49f0-b1ff-fa26059f352c),plugin='linux_bridge',port_profile=<?>,preserve_on_delete=False,vif_name='tap042a5f68-01')
2018-03-01 23:15:27.434 2376 INFO nova.virt.libvirt.driver
[req-3cb9fbc5-8f4e-4244-8b14-b52ac1f0494b
a6f48b630f634371ba94558f3ba576b8 5f46526ffab3410a9cf71b37fa242e11 -
default default] [instance: 9ac0d3ec-35ad-4420-ae20-f6c0c9845f05]
Deleting instance files
/var/lib/nova/instances/9ac0d3ec-35ad-4420-ae20-f6c0c9845f05_del
2018-03-01 23:15:27.436 2376 INFO nova.virt.libvirt.driver
[req-3cb9fbc5-8f4e-4244-8b14-b52ac1f0494b
a6f48b630f634371ba94558f3ba576b8 5f46526ffab3410a9cf71b37fa242e11 -
default default] [instance: 9ac0d3ec-35ad-4420-ae20-f6c0c9845f05]
Deletion of
/var/lib/nova/instances/9ac0d3ec-35ad-4420-ae20-f6c0c9845f05_del
complete
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager
[req-3cb9fbc5-8f4e-4244-8b14-b52ac1f0494b
a6f48b630f634371ba94558f3ba576b8 5f46526ffab3410a9cf71b37fa242e11 -
default default] [instance: 9ac0d3ec-35ad-4420-ae20-f6c0c9845f05]
Instance failed to spawn: libvirtError: internal error: process exited
while connecting to monitor: outputs=1,bus=pci.0,addr=0x2 -device
virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x6 -msg timestamp=on
2018-03-02T05:15:27.083155Z qemu-system-x86_64: -drive
file=/var/lib/nova/instances/9ac0d3ec-35ad-4420-ae20-f6c0c9845f05/disk,format=qcow2,if=none,id=drive-virtio-disk0,cache=none:
Could not open backing file: Could not open
'/var/lib/nova/instances/_base/affe96668a4c64ef380ff1c71b4caec17039080e':
Permission denied
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] Traceback (most recent call last):
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 2192,
in _build_resources
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] yield resources
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 2007,
in _build_and_run_instance
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05]
block_device_info=block_device_info)
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line
2814, in spawn
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] destroy_disks_on_failure=True)
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line
5294, in _create_domain_and_network
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] destroy_disks_on_failure)
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in
__exit__
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] self.force_reraise()
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in
force_reraise
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] six.reraise(self.type_,
self.value, self.tb)
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line
5264, in _create_domain_and_network
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05]
post_xml_callback=post_xml_callback)
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line
5182, in _create_domain
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] guest.launch(pause=pause)
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/nova/virt/libvirt/guest.py", line 144,
in launch
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] self._encoded_xml,
errors='ignore')
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in
__exit__
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] self.force_reraise()
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in
force_reraise
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] six.reraise(self.type_,
self.value, self.tb)
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/nova/virt/libvirt/guest.py", line 139,
in launch
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] return
self._domain.createWithFlags(flags)
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 186, in doit
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] result =
proxy_call(self._autowrap, f, *args, **kwargs)
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 144, in
proxy_call
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] rv = execute(f, *args,
**kwargs)
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 125, in
execute
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] six.reraise(c, e, tb)
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 83, in
tworker
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] rv = meth(*args, **kwargs)
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] File
"/usr/lib/python2.7/dist-packages/libvirt.py", line 1099, in
createWithFlags
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] if ret == -1: raise
libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] libvirtError: internal error:
process exited while connecting to monitor: outputs=1,bus=pci.0,addr=0x2
-device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x6 -msg
timestamp=on
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] 2018-03-02T05:15:27.083155Z
qemu-system-x86_64: -drive
file=/var/lib/nova/instances/9ac0d3ec-35ad-4420-ae20-f6c0c9845f05/disk,format=qcow2,if=none,id=drive-virtio-disk0,cache=none:
Could not open backing file: Could not open
'/var/lib/nova/instances/_base/affe96668a4c64ef380ff1c71b4caec17039080e':
Permission denied
2018-03-01 23:15:27.813 2376 ERROR nova.compute.manager [instance:
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05]
2018-03-01 23:15:27.815 2376 INFO nova.compute.manager
[req-3cb9fbc5-8f4e-4244-8b14-b52ac1f0494b
a6f48b630f634371ba94558f3ba576b8 5f46526ffab3410a9cf71b37fa242e11 -
default default] [instance: 9ac0d3ec-35ad-4420-ae20-f6c0c9845f05]
Terminating instance
2018-03-01 23:15:27.822 2376 INFO nova.virt.libvirt.driver [-]
[instance: 9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] Instance destroyed
successfully.
2018-03-01 23:15:27.824 2376 INFO os_vif
[req-3cb9fbc5-8f4e-4244-8b14-b52ac1f0494b
a6f48b630f634371ba94558f3ba576b8 5f46526ffab3410a9cf71b37fa242e11 -
default default] Successfully unplugged vif
VIFBridge(active=False,address=fa:16:3e:b4:ed:53,bridge_name='brq03b5dd02-ac',has_traffic_filtering=True,id=042a5f68-01bb-453e-bb2a-2d798b7691d5,network=Network(03b5dd02-ac2f-49f0-b1ff-fa26059f352c),plugin='linux_bridge',port_profile=<?>,preserve_on_delete=False,vif_name='tap042a5f68-01')
2018-03-01 23:15:28.107 2376 INFO nova.virt.libvirt.driver
[req-3cb9fbc5-8f4e-4244-8b14-b52ac1f0494b
a6f48b630f634371ba94558f3ba576b8 5f46526ffab3410a9cf71b37fa242e11 -
default default] [instance: 9ac0d3ec-35ad-4420-ae20-f6c0c9845f05]
Deletion of
/var/lib/nova/instances/9ac0d3ec-35ad-4420-ae20-f6c0c9845f05_del
complete
2018-03-01 23:15:28.501 2376 INFO nova.compute.manager
[req-3cb9fbc5-8f4e-4244-8b14-b52ac1f0494b
a6f48b630f634371ba94558f3ba576b8 5f46526ffab3410a9cf71b37fa242e11 -
default default] [instance: 9ac0d3ec-35ad-4420-ae20-f6c0c9845f05] Took
0.68 seconds to destroy the instance on the hypervisor.
2018-03-01 23:15:29.721 2376 WARNING nova.scheduler.client.report
[req-3cb9fbc5-8f4e-4244-8b14-b52ac1f0494b
a6f48b630f634371ba94558f3ba576b8 5f46526ffab3410a9cf71b37fa242e11 -
default default] Unable to delete allocation for instance
9ac0d3ec-35ad-4420-ae20-f6c0c9845f05: (500 {"computeFault": {"message":
"The server has either erred or is incapable of performing the requested
operation.", "code": 500}})
2018-03-01 23:15:29.721 2376 WARNING nova.compute.manager
[req-3cb9fbc5-8f4e-4244-8b14-b52ac1f0494b
a6f48b630f634371ba94558f3ba576b8 5f46526ffab3410a9cf71b37fa242e11 -
default default] 6 consecutive build failures
More information about the Openstack-devel
mailing list