Unable to set AppArmor profile [...] no such file or directory

Bug #1384532 reported by Don Bowman
44
This bug affects 9 people
Affects Status Importance Assigned to Milestone
libvirt (Ubuntu)
Fix Released
Medium
Unassigned
Xenial
Won't Fix
Medium
Unassigned
Artful
Fix Released
Medium
Unassigned
Bionic
Fix Released
Medium
Unassigned

Bug Description

=================================================
Bugs are not infrequently reported along the lines of
Unable to set Apparmor Profile for [emulator]: No such file or directory

It is frequently (always?) the result of some value (a cdrom or disk file) which has spaces of odd characters which mess up virt-aa-helper or libvirt itself.

We should attempt to detect this early on. Perhaps we can use a qemu hook, or add a check in virt-aa-helper.
=================================================

/usr/bin/kvm-spice is a soft-link to /usr/bin/kvm

in /etc/apparmor.d/abstractions/libvirt-qemu there is no line for kvm-spice.

This leads rise to the error:
libvirt: error : unable to set AppArmor profile 'libvirt-224075ba-a31a-48e9-98fe-337146e9f4f1' for '/usr/bin/kvm-spice': No such file or directory

when using e.g. OpenStack

$ lsb_release -rd
Description: Ubuntu 14.10
Release: 14.10

$ dpkg -l|grep libvirt-bin
ii libvirt-bin 1.2.8-0ubuntu11 amd64 programs for the libvirt library

Revision history for this message
Serge Hallyn (serge-hallyn) wrote :

Thanks for reporting this bug. I can't reproduce it on my laptop. Could you please provide the full .xml for a failing VM?

Please also show the results (on the compute node) of:

ls -l /usr/bin/kvm*

Changed in libvirt (Ubuntu):
importance: Undecided → High
status: New → Incomplete
Revision history for this message
Don Bowman (donbowman) wrote :
Download full text (5.3 KiB)

osadmin-don@nubo-7:~$ ls -l /usr/bin/kvm*
-rwxr-xr-x 1 root root 52 Jul 30 23:06 /usr/bin/kvm
lrwxrwxrwx 1 root root 3 Oct 16 09:59 /usr/bin/kvm-spice -> kvm
$ sudo apt-file search kvm-spice
qemu-kvm: /usr/bin/kvm-spice

<domain type='kvm' id='12'>
  <name>instance-00000563</name>
  <uuid>5750b2a4-6679-4965-85c8-bb8273e029b0</uuid>
  <metadata>
    <nova:instance xmlns:nova="http://openstack.org/xmlns/libvirt/nova/1.0">
      <nova:package version="2014.2"/>
      <nova:name>exp-win7</nova:name>
      <nova:creationTime>2014-10-21 08:40:50</nova:creationTime>
      <nova:flavor name="m1.5G">
        <nova:memory>1024</nova:memory>
        <nova:disk>5</nova:disk>
        <nova:swap>0</nova:swap>
        <nova:ephemeral>0</nova:ephemeral>
        <nova:vcpus>1</nova:vcpus>
      </nova:flavor>
      <nova:owner>
        <nova:user uuid="56801ce4202d46b88a0bd25d5d376965">admin</nova:user>
        <nova:project uuid="f6984377a66d418880696d901fd9f41c">admin</nova:project>
      </nova:owner>
      <nova:root type="image" uuid="e02bc933-f240-482e-9df4-2a3da4e96e47"/>
    </nova:instance>
  </metadata>
  <memory unit='KiB'>1048576</memory>
  <currentMemory unit='KiB'>1048576</currentMemory>
  <vcpu placement='static' cpuset='1,3,5,7,9,11,13,15,17,19,21,23'>1</vcpu>
  <resource>
    <partition>/machine</partition>
  </resource>
    <sysinfo type='smbios'>
      <system>
        <entry name='manufacturer'>OpenStack Foundation</entry>
        <entry name='product'>OpenStack Nova</entry>
        <entry name='version'>2014.2</entry>
        <entry name='serial'>57ddf2ff-3374-c04c-002e-b22b53ee7e7f</entry>
        <entry name='uuid'>5750b2a4-6679-4965-85c8-bb8273e029b0</entry>
      </system>
    </sysinfo>
  <os>
    <type arch='x86_64' machine='pc-i440fx-utopic'>hvm</type>
    <boot dev='hd'/>
    <smbios mode='sysinfo'/>
  </os>
  <features>
    <acpi/>
    <apic/>
  </features>
  <cpu mode='host-model'>
    <model fallback='allow'/>
    <topology sockets='1' cores='1' threads='1'/>
  </cpu>
  <clock offset='utc'>
    <timer name='pit' tickpolicy='delay'/>
    <timer name='rtc' tickpolicy='catchup'/>
    <timer name='hpet' present='no'/>
  </clock>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>destroy</on_crash>
  <devices>
    <emulator>/usr/bin/kvm-spice</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2' cache='none'/>
      <source file='/var/lib/nova/instances/5750b2a4-6679-4965-85c8-bb8273e029b0/disk'/>
      <backingStore type='file' index='1'>
        <format type='raw'/>
        <source file='/var/lib/nova/instances/_base/25c59c84252c22479aefb0bad5a5fecdc4fcde40'/>
        <backingStore/>
      </backingStore>
      <target dev='vda' bus='virtio'/>
      <alias name='virtio-disk0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
    </disk>
    <disk type='file' device='cdrom'>
      <driver name='qemu' type='raw' cache='none'/>
      <source file='/var/lib/nova/instances/5750b2a4-6679-4965-85c8-bb8273e029b0/disk.config'/>
      <backingStore/>
      <target dev='hdd' bus='ide'/>
      <readonly/>
      <alias name='ide0-1-1'/>
      <a...

Read more...

Changed in libvirt (Ubuntu):
status: Incomplete → New
Revision history for this message
Serge Hallyn (serge-hallyn) wrote :

Thanks for the information. Sorry, I was misreading the message. The file which does not exist is not kvm-spice, but the libvirt profile.

Could you please reproduce the issue, then show both the xml file for the failing vm and show the result of "ls -l /etc/apparmor.d/libvirt/" on the compute node?

Revision history for this message
Don Bowman (donbowman) wrote :
Download full text (9.3 KiB)

The ls has:
total 192
-rw-r--r-- 1 root root 265 Sep 15 18:46 libvirt-06bba064-b57e-4cf5-a1e3-c39567895aab
-rw-r--r-- 1 root root 1140 Oct 28 03:09 libvirt-06bba064-b57e-4cf5-a1e3-c39567895aab.files
-rw-r--r-- 1 root root 265 Oct 14 04:07 libvirt-0cb7d575-9a0b-4000-b6d2-3901a4d44f7c
-rw-r--r-- 1 root root 1077 Oct 28 03:09 libvirt-0cb7d575-9a0b-4000-b6d2-3901a4d44f7c.files
-rw-r--r-- 1 root root 265 Oct 23 13:40 libvirt-0cd2e54a-1c6e-419b-974b-06ec713f3794
-rw-r--r-- 1 root root 1077 Oct 28 03:08 libvirt-0cd2e54a-1c6e-419b-974b-06ec713f3794.files
-rw-r--r-- 1 root root 265 Oct 23 13:40 libvirt-0dc31de4-0271-48e0-9c34-b5ec4869015a
-rw-r--r-- 1 root root 1098 Oct 28 03:08 libvirt-0dc31de4-0271-48e0-9c34-b5ec4869015a.files
-rw-r--r-- 1 root root 265 Oct 14 04:07 libvirt-136a90ad-7e8a-4060-9b8a-602aed4b5fb8
-rw-r--r-- 1 root root 1161 Oct 28 03:09 libvirt-136a90ad-7e8a-4060-9b8a-602aed4b5fb8.files
-rw-r--r-- 1 root root 265 Sep 15 18:59 libvirt-5170f30d-8835-4e28-aa24-3230476fb1ad
-rw-r--r-- 1 root root 1077 Oct 29 21:44 libvirt-5170f30d-8835-4e28-aa24-3230476fb1ad.files
-rw-r--r-- 1 root root 265 Sep 15 18:46 libvirt-5750b2a4-6679-4965-85c8-bb8273e029b0
-rw-r--r-- 1 root root 1077 Oct 28 03:09 libvirt-5750b2a4-6679-4965-85c8-bb8273e029b0.files
-rw-r--r-- 1 root root 265 Oct 23 13:40 libvirt-598b9e83-ce0a-47a8-8555-b62a252ee3bb
-rw-r--r-- 1 root root 1098 Oct 28 03:08 libvirt-598b9e83-ce0a-47a8-8555-b62a252ee3bb.files
-rw-r--r-- 1 root root 265 Sep 15 18:46 libvirt-67541f7c-fe64-4125-876f-3e06667df53b
-rw-r--r-- 1 root root 1098 Oct 28 03:08 libvirt-67541f7c-fe64-4125-876f-3e06667df53b.files
-rw-r--r-- 1 root root 265 Oct 29 20:44 libvirt-6a16064d-cf87-40c8-8ae0-703c51cf184f
-rw-r--r-- 1 root root 1098 Oct 29 20:44 libvirt-6a16064d-cf87-40c8-8ae0-703c51cf184f.files
-rw-r--r-- 1 root root 265 Oct 14 04:06 libvirt-84a2b12b-3f3b-494c-abd2-aa42236ef844
-rw-r--r-- 1 root root 1140 Oct 28 03:09 libvirt-84a2b12b-3f3b-494c-abd2-aa42236ef844.files
-rw-r--r-- 1 root root 265 Oct 29 16:14 libvirt-89d5121b-5c5f-4548-83b3-a187d751a5bc
-rw-r--r-- 1 root root 1140 Oct 29 16:14 libvirt-89d5121b-5c5f-4548-83b3-a187d751a5bc.files
-rw-r--r-- 1 root root 265 Oct 28 20:32 libvirt-8a699639-3311-4567-bf21-ce381a4e8783
-rw-r--r-- 1 root root 1098 Oct 28 20:32 libvirt-8a699639-3311-4567-bf21-ce381a4e8783.files
-rw-r--r-- 1 root root 265 Oct 23 13:40 libvirt-8bda3eb5-420c-4822-84a5-fa2fe6e92e71
-rw-r--r-- 1 root root 1161 Oct 28 03:08 libvirt-8bda3eb5-420c-4822-84a5-fa2fe6e92e71.files
-rw-r--r-- 1 root root 265 Oct 29 09:59 libvirt-8f0e3112-db6a-4ad9-8598-01cc24f1a4cf
-rw-r--r-- 1 root root 1161 Oct 29 09:59 libvirt-8f0e3112-db6a-4ad9-8598-01cc24f1a4cf.files
-rw-r--r-- 1 root root 265 Sep 15 18:46 libvirt-a9ac1393-0462-43af-a7db-1a48bdc521f7
-rw-r--r-- 1 root root 1098 Oct 28 03:08 libvirt-a9ac1393-0462-43af-a7db-1a48bdc521f7.files
-rw-r--r-- 1 root root 265 Oct 14 04:06 libvirt-bae8f71e-b10d-4598-a33b-1e9443e0876d
-rw-r--r-- 1 root root 1077 Oct 28 03:09 libvirt-bae8f71e-b10d-4598-a33b-1e9443e0876d.files
-rw-r--r-- 1 root root 265 Oct 23 13:41 libvirt-bfce9b50-f66a-47c6-affc-ca860463bd45
-rw-r--r-- 1 root root 1098 Oct 28 03:08 libvirt-bfce9b50-f66a-47c...

Read more...

Revision history for this message
Serge Hallyn (serge-hallyn) wrote :

Thanks for the information.

Oddly, for the example in comment #4, the apparmor policy *is* in fact in the listing of /etc/apparmor.d/libvirt.

Are you certain that instance also failed to boot?

I fear the log information will be overwhelming, but i think we'll need full libvirt debug output. Please edit /etc/libvirt/libvirtd.conf on a compute node where such a VM is defined (that won't start up), and add the line

log_level = 1

then "sudo stop libvirt-bin; sudo start libvirt-bin"

and start the vm, then attach the file /var/log/libvirt/libvirtd.log.

Changed in libvirt (Ubuntu):
status: New → Incomplete
Revision history for this message
Don Bowman (donbowman) wrote :

sigh, the kvm-spice entry in apparmor.d/libivrt is my workaround. i added it manually and forget to mention that when attaching above.
w/o that entry, openstack will not start an instance.
with it, it is fine.

Revision history for this message
Serge Hallyn (serge-hallyn) wrote :

No, I believe that is spurious. According to the message in the Description, I believe that the failure happens when the apparmor profile fails to be generated on the compute node. I believe that if adding kvm-spice sometimes seemed to fix it, that was an accident.

To check whether I'm right, can you take a vm which does work, remove the kvm-spice line, and check that it now indeed fails to start?

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

[Expired for libvirt (Ubuntu) because there has been no activity for 60 days.]

Changed in libvirt (Ubuntu):
status: Incomplete → Expired
Revision history for this message
Artyum (arwi) wrote :
Download full text (3.8 KiB)

I have the same poblem. It occures while I try to install Windows 2012 Server R2. When the ISO is loaded into IDE CDROM the vm can't start. When I remove the ISO image from CDROM, I instantly get SeaBIOS.. no botable device.

Here is log from /var/log/libvirt/libvirtd.log:
2015-01-24 18:31:36.241+0000: 30485: error : virCommandHandshakeWait:2516 : Child quit during startup handshake: Input/output error
2015-01-24 18:31:36.241+0000: 30485: error : qemuProcessReadChildErrors:1623 : internal error: Process exited prior to exec: libvirt: error : unable to set AppArmor profile 'libvirt-4a85eac1-5631-40dc-a25e-927e2daa3a2f' for '/usr/bin/kvm-spice': No such file or directory

VM was created with virt-manager.

<domain type='kvm'>
  <name>WinSRV2012R2</name>
  <uuid>4a85eac1-5631-40dc-a25e-927e2daa3a2f</uuid>
  <memory unit='KiB'>4194304</memory>
  <currentMemory unit='KiB'>4194304</currentMemory>
  <vcpu placement='static'>4</vcpu>
  <os>
    <type arch='x86_64' machine='pc-i440fx-trusty'>hvm</type>
  </os>
  <features>
    <acpi/>
    <apic/>
    <pae/>
  </features>
  <cpu mode='custom' match='exact'>
    <model fallback='allow'>SandyBridge</model>
  </cpu>
  <clock offset='utc'>
    <timer name='rtc' tickpolicy='catchup'/>
    <timer name='pit' tickpolicy='delay'/>
    <timer name='hpet' present='no'/>
  </clock>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>restart</on_crash>
  <pm>
    <suspend-to-mem enabled='no'/>
    <suspend-to-disk enabled='no'/>
  </pm>
  <devices>
    <emulator>/usr/bin/kvm-spice</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2'/>
      <source file='/var/lib/libvirt/images/winsrc2012r2.qcow2'/>
      <target dev='hda' bus='ide'/>
      <boot order='2'/>
      <address type='drive' controller='0' bus='0' target='0' unit='0'/>
    </disk>
    <disk type='block' device='cdrom'>
      <driver name='qemu' type='raw'/>
      <target dev='hdb' bus='ide'/>
      <readonly/>
      <boot order='1'/>
      <address type='drive' controller='0' bus='0' target='0' unit='1'/>
    </disk>
    <controller type='usb' index='0' model='ich9-ehci1'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x7'/>
    </controller>
    <controller type='usb' index='0' model='ich9-uhci1'>
      <master startport='0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0' multifunction='on'/>
    </controller>
    <controller type='usb' index='0' model='ich9-uhci2'>
      <master startport='2'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x1'/>
    </controller>
    <controller type='usb' index='0' model='ich9-uhci3'>
      <master startport='4'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x2'/>
    </controller>
    <controller type='pci' index='0' model='pci-root'/>
    <controller type='ide' index='0'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x1'/>
    </controller>
    <interface type='bridge'>
      <mac address='52:54:00:19:f5:3c'/>
      <source bridge='br0'/>
      <model type='rtl8139'/>
      <address type='pci' domain...

Read more...

Revision history for this message
Artyum (arwi) wrote :

for further investigation

Changed in libvirt (Ubuntu):
status: Expired → Incomplete
Revision history for this message
Serge Hallyn (serge-hallyn) wrote :

@arwi,

does /usr/bin/kvm-spice exist on your host?

Revision history for this message
Artyum (arwi) wrote :

yes

# ls -l /usr/bin/kvm-spice
lrwxrwxrwx 1 root root 3 gru 16 15:27 /usr/bin/kvm-spice -> kvm
# ls -l /usr/bin/kvm
-rwxr-xr-x 1 root root 52 lut 4 2014 /usr/bin/kvm

Revision history for this message
Serge Hallyn (serge-hallyn) wrote :

Sorry, that all looks fine, I simply see no reason for what is going on. To get some more log info from libvirt, could you please do:

sudo stop libvirt-bin
sudo rm /var/lib/libvirt/lib*.log
echo "log_level = 1" | sudo tee -a /etc/libvirt/libvirtd.log
sudo start libvirt-bin

Then reproduce this issue and attach the resulting /var/log/libvirt/libvirtd.log and /var/log/libvirt/qemu/$(vm).log ?

Changed in libvirt (Ubuntu):
status: Incomplete → New
status: New → Incomplete
Revision history for this message
Artyum (arwi) wrote :

qemu/$(vm).log
2015-02-01 10:03:05.429+0000: starting up
LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/bin:/usr/sbin:/sbin:/bin QEMU_AUDIO_DRV=none /usr/bin/kvm-spice -name WinSRV2012R2 -S -machine pc-i440fx-trusty,accel=kvm,usb=off -cpu SandyBridge -m 4096 -realtime mlock=off -smp 4,sockets=4,cores=1,threads=1 -uuid 4a85eac1-5631-40dc-a25e-927e2daa3a2f -no-user-config -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/WinSRV2012R2.monitor,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc,driftfix=slew -global kvm-pit.lost_tick_policy=discard -no-hpet -no-shutdown -global PIIX4_PM.disable_s3=1 -global PIIX4_PM.disable_s4=1 -boot strict=on -device ich9-usb-ehci1,id=usb,bus=pci.0,addr=0x4.0x7 -device ich9-usb-uhci1,masterbus=usb.0,firstport=0,bus=pci.0,multifunction=on,addr=0x4 -device ich9-usb-uhci2,masterbus=usb.0,firstport=2,bus=pci.0,addr=0x4.0x1 -device ich9-usb-uhci3,masterbus=usb.0,firstport=4,bus=pci.0,addr=0x4.0x2 -drive file=/var/lib/libvirt/images/winsrc2012r2.qcow2,if=none,id=drive-ide0-0-0,format=qcow2 -device ide-hd,bus=ide.0,unit=0,drive=drive-ide0-0-0,id=ide0-0-0,bootindex=2 -drive file=/home/vm/Pobrane/Windows Server 2012 R2/en_windows_server_2012_r2_with_update_x64_dvd_4065220.iso,if=none,id=drive-ide0-0-1,readonly=on,format=raw -device ide-cd,bus=ide.0,unit=1,drive=drive-ide0-0-1,id=ide0-0-1,bootindex=1 -netdev tap,fd=26,id=hostnet0 -device rtl8139,netdev=hostnet0,id=net0,mac=52:54:00:19:f5:3c,bus=pci.0,addr=0x3 -chardev pty,id=charserial0 -device isa-serial,chardev=charserial0,id=serial0 -vnc 127.0.0.1:3 -device cirrus-vga,id=video0,bus=pci.0,addr=0x2 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x5
libvirt: error : unable to set AppArmor profile 'libvirt-4a85eac1-5631-40dc-a25e-927e2daa3a2f' for '/usr/bin/kvm-spice': No such file or directory
2015-02-01 10:03:05.453+0000: shutting down

libvirtd.log
2015-02-01 10:03:05.453+0000: 7035: error : virCommandHandshakeWait:2516 : Child quit during startup handshake: Input/output error
2015-02-01 10:03:05.453+0000: 7035: error : qemuProcessReadChildErrors:1623 : internal error: Process exited prior to exec: libvirt: error : unable to set AppArmor profile 'libvirt-4a85eac1-5631-40dc-a25e-927e2daa3a2f' for '/usr/bin/kvm-spice': No such file or directory

Revision history for this message
Artyum (arwi) wrote :

I found the solution. The problem "No such file or directory" wasn't related to kvm-spice.
I've checked /etc/apparmor.d/libvirt/libvirt-4a85eac1-5631-40dc-a25e-927e2daa3a2f.files and noticed that the patch to ISO could couse the problem. It folder name contained chars: "- = { }". After changing the folder name to "Windows Server 2012 R2", the vm started.

Changed in libvirt (Ubuntu):
status: Incomplete → Confirmed
importance: High → Low
summary: - libvirt-qemu apparmor profile missing kvm-spice
+ Poor error reporting when cd file not found.
Revision history for this message
Xiang Hui (xianghui) wrote : Re: Poor error reporting when cd file not found.

Hi,

I have met exactly the same issue on Ubuntu vivid with OpenStack vms,

Failed message:
"unable to set AppArmor profile 'libvirt-b5de9738-608d-44df-99e7-596f907dcff2' for '/usr/bin/kvm-spice': No such file or directory"

But actually the profile exists:
$ ll /etc/apparmor.d/libvirt/libvirt-b5de9738-608d-44df-99e7-596f907dcff2
libvirt-b5de9738-608d-44df-99e7-596f907dcff2 libvirt-b5de9738-608d-44df-99e7-596f907dcff2.files

$ ls -l /usr/bin/kvm-spice
lrwxrwxrwx 1 root root 3 Sep 24 20:25 /usr/bin/kvm-spice -> kvm
$ ls -l /usr/bin/kvm
-rwxr-xr-x 1 root root 811 Oct 15 23:03 /usr/bin/kvm

I am not understanding what does 'It folder name contained chars: "- = { }". After changing the folder name to "Windows Server 2012 R2", the vm started.' mean how it work out the problem.

My vm is a cirros, it seems unrelated.

There are also other people hit this problem, but they figure it out temporarily either by disable apparmor or by purge apparmor, please take a look and point me a right solution, thanks a lot.

summary: - Poor error reporting when cd file not found.
+ Unable to set AppArmor profile for /usr/bin/kvm-spice
Revision history for this message
Serge Hallyn (serge-hallyn) wrote : Re: Unable to set AppArmor profile for /usr/bin/kvm-spice

Hi, are you on a systemd host? If so you try starting the vm, then immediately show the output of

sudo journalctl -u libvirt-bin

(If not systemd, then show end of /var/log/libvirt/libvirtd.log)

also attach /var/log/libvirt/qemu/${vmname}.log, though it probably does not exist or is empty.

Revision history for this message
Xiang Hui (xianghui) wrote :

Hi Serge,

Thanks for taking a look, I got it work around by set 'security_group=None' in /etc/libvirt/qemu.conf, but I am still trying to find a right solution to fix it.

Same error:
2015-10-23 15:40:41.821 DEBUG nova.compute.utils [req-f039b3d1-f34f-4f7e-b983-78d730393e6e admin admin] [instance: b0a88061-45b6-417f-9c99-c6f07c115210] internal error: Process exited prior to exec: libvirt: error : unable to set AppArmor profile 'libvirt-b0a88061-45b6-417f-9c99-c6f07c115210' for '/usr/bin/kvm-spice': No such file or directory
 from (pid=12748) notify_about_instance_usage /opt/stack/nova/nova/compute/utils.py:284
2015-10-23 15:40:41.822 DEBUG nova.compute.manager [req-f039b3d1-f34f-4f7e-b983-78d730393e6e admin admin] [instance: b0a88061-45b6-417f-9c99-c6f07c115210] Build of instance b0a88061-45b6-417f-9c99-c6f07c115210 was re-scheduled: internal error: Process exited prior to exec: libvirt: error : unable to set AppArmor profile 'libvirt-b0a88061-45b6-417f-9c99-c6f07c115210' for '/usr/bin/kvm-spice': No such file or directory

2015-10-23 15:40:41.432 TRACE nova.compute.manager [instance: b0a88061-45b6-417f-9c99-c6f07c115210] libvirtError: internal error: Process exited prior to exec: libvirt: error : unable to set AppArmor profile 'libvirt-b0a88061-45b6-417f-9c99-c6f07c115210' for '/usr/bin/kvm-spice': No such file or directory

 -> But actually exists libvirt-b0a88061-45b6-417f-9c99-c6f07c115210:
$ sudo ls /etc/apparmor.d/libvirt/libvirt-b0a88061-45b6-417f-9c99-c6f07c115210
libvirt-b0a88061-45b6-417f-9c99-c6f07c115210 libvirt-b0a88061-45b6-417f-9c99-c6f07c115210.files

Also I debug on the kvm-spice, it's suspicious got wrong at the last line:
exec /usr/bin/qemu-system-x86_64 "${args[@]}"
which finally translater into:
exec /usr/bin/qemu-system-x86_64 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities.pidfile -daemonize
 -> Just guess kvm-spice doesn't have the perssion to access /var/lib/libvirt/qemu

$ sudo ls -l /var/lib/libvirt/qemu/
total 16
drwxr-xr-x 3 root root 4096 Oct 10 09:55 channel
drwxr-xr-x 2 root root 4096 Oct 9 17:13 dump
srwxrwxr-x 1 libvirt-qemu kvm 0 Oct 22 18:22 instance-00000028.monitor
srwxrwxr-x 1 libvirt-qemu kvm 0 Oct 22 21:24 instance-00000029.monitor
drwxr-xr-x 2 libvirt-qemu kvm 4096 Oct 9 17:13 save
drwxr-xr-x 2 libvirt-qemu kvm 4096 Oct 9 17:13 snapshot

For the successfully spawned vms work around by setting security_driver to None, there are instance-xxx.monitor created, so I wonder if the problem is kvm-spice has no permission to create the monitor there or someelse.

libvirt.log and failed vm qemu.log are attached.

Thank you!

Revision history for this message
Serge Hallyn (serge-hallyn) wrote :

Hi,

so I'm getting the feeling that we ought to turn this bug into one for enhancing the transparancy of errors. Too many errors are mis-reported by this line.

For your particular case, could we try an experiment? Please install strace on the compute host, and edit /usr/bin/kvm-spice to read:

#!/bin/sh
exec strace -f -o/run/hugepages/kvm/libvirt/qemu/strace-qemu.out qemu-system-x86_64 -enable-kvm "$@"

Make sure the directory exists,

sudo mkdir -p /run/hugepages/kvm/libvirt/qemu/

Then try running the vm, then attach /run/hugepages/kvm/libvirt/qemu/strace-qemu.out here.

(I'm abusing the hugepages directory to make sure apparmor does not prevent strace from writing to it)

Revision history for this message
Serge Hallyn (serge-hallyn) wrote :

@xianghui,

will you be able to provide the information requested in comment #19?

Revision history for this message
Xiang Hui (xianghui) wrote :

@Serge

Sorry, I was travelling for OpenStack summit last week, testing now and I will open a new bug by following your instruction to make it more clear.

Revision history for this message
Xiang Hui (xianghui) wrote :

@Serge

I have opened a new bug https://bugs.launchpad.net/ubuntu/+source/libvirt/+bug/1513367 to focus on this error, let's discuss there. Thanks a lot.

Revision history for this message
Serge Hallyn (serge-hallyn) wrote :

Thanks for that. I'm going to retitle this bug for the general topic of properly reporting spaces in valius.

summary: - Unable to set AppArmor profile for /usr/bin/kvm-spice
+ Unable to set AppArmor profile [...] no such file or directory
Changed in libvirt (Ubuntu):
importance: Low → High
description: updated
description: updated
Revision history for this message
Prateek khushalani (prateek-khushalani) wrote :

Just to add I think I know a solution to this problem:-

1. The libvirt files created under /etc/apparmor.d/libvirt/ has a <libcvirt-magic-number>.files
2. If the directory of the ISO specified has spaces it will fail.

Workaround-

1. Change the name of the file to a very simple one( windows.iso, ubuntu.iso)
2. Make sure the path of the iso contains no directory name with spaces.
3. It works :)

Revision history for this message
Jean-Pierre van Riel (jpvr) wrote :

I'm running libvirt-bin 1.3.1-1ubuntu10.6 and still getting this error. And it is not related to a space with the directory of a .iso file or something.

This is really bizarre. Like other's, those files do exist have other (world) read access set, so no clue what code is asserting that don't exist (when they do). From virt-manager's perspective, the error in the libvirtd daemon process is not visible...

I found reverting changes in `/etc/apparmor/libvirt/TEMPLATE.qemu` seemed to fix my error.

As per a prior comment above, a related bug is how cumbersome apparmor error handling is. For example, nothing in libvirt nor apparmor had any indicator that something `TEMPLATE.qemu` was putting it off. It even actually generated the per domain apparmor files (as other have observed)

Revision history for this message
untoreh (untoreh) wrote :

this issue still persists. As suggested giving a simple name to the .iso path worked around it.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

Hi,
sorry for chiming in so late, but I haven't seen this issue before - the last update changed that.
Special chars as reported in comment #26 and comment #15 are an issue, but most of them are fixed or at a better error message now.

First of all since Ubuntu 17.10 (~=UCA-Pike) all files in generated rules are in quotes which formerly they were not - that allows for some chars like spaces.

Further some other chars are just plain forbidden and would break the rule - these are mostly apparmor wilcards so these are now rejected since v3.10.0 by a150b86c instead of later failing when loading the profile.

That said it is hard for me to track details of the old issue, but with a recent Ubuntu this should be all fixed.

With space a rule will now look as:
  "/var/lib/uvtool/libvirt/images/a space does not hurt.qcow" rwk,
and work just fine.

But the actual issue - at least with tolerable special chars is fixed in the latter releases. And the apparmor wildcards do not randomly fail, or work or be a security issue - instead they always fail now.

I have to admit the message is still the old misleading one in the remaining failing cases.
I spawned bug 1767934 for this - but at low prio.

Per above I'd set the bug fix releases at least for the latter releases.
Given the long time this bug slumbers before a person is hit by it again and the fact that a simple file rename gets you around makes me not think of SRUs for this atm.
So I'll set won't fix for pre-Artful, but hey - discussions welcome.

Changed in libvirt (Ubuntu):
status: Confirmed → Fix Released
Changed in libvirt (Ubuntu Artful):
status: New → Fix Released
Changed in libvirt (Ubuntu Xenial):
status: New → Won't Fix
Changed in libvirt (Ubuntu Bionic):
importance: High → Medium
Changed in libvirt (Ubuntu Artful):
importance: Undecided → Medium
Changed in libvirt (Ubuntu Xenial):
importance: Undecided → Medium
Revision history for this message
Pascal A. (pascalav) wrote :

I reproduce the same on 18.04 LTS:

Log when starting a KVM VM with 'virt-manager':
--
Error starting domain: internal error: Process exited prior to exec: libvirt: error : unable to set AppArmor profile 'libvirt-a1937a46-2b13-41bd-998b-27ee9a8209a8' for '/usr/bin/kvm-spice': No such file or directory

Traceback (most recent call last):
  File "/usr/share/virt-manager/virtManager/asyncjob.py", line 89, in cb_wrapper
    callback(asyncjob, *args, **kwargs)
  File "/usr/share/virt-manager/virtManager/asyncjob.py", line 125, in tmpcb
    callback(*args, **kwargs)
  File "/usr/share/virt-manager/virtManager/libvirtobject.py", line 82, in newfn
    ret = fn(self, *args, **kwargs)
  File "/usr/share/virt-manager/virtManager/domain.py", line 1508, in startup
    self._backend.create()
  File "/usr/lib/python2.7/dist-packages/libvirt.py", line 1062, in create
    if ret == -1: raise libvirtError ('virDomainCreate() failed', dom=self)
libvirtError: internal error: Process exited prior to exec: libvirt: error : unable to set AppArmor profile 'libvirt-a1937a46-2b13-41bd-998b-27ee9a8209a8' for '/usr/bin/kvm-spice': No such file or directory
--

But the AppArmor profiles exist:
--
$ sudo ls -lah /etc/apparmor.d/libvirt/libvirt-*
-rw-r--r-- 1 root root 293 août 16 23:04 /etc/apparmor.d/libvirt/libvirt-a1937a46-2b13-41bd-998b-27ee9a8209a8
-rw-r--r-- 1 root root 1,8K août 16 23:05 /etc/apparmor.d/libvirt/libvirt-a1937a46-2b13-41bd-998b-27ee9a8209a8.files

$
--

I checked paths the VM relies on (CD-ROM ISOs absolute paths) and they contain no whitespaces.

Tell me if the virt-manager VM XML file is needed for troubleshooting.

A troubleshooting sequence I tried, with no positive result:
  1/ Deeply-deleting '*ibvir*' in '/etc/apparmor.d'
  2/ Reinstalling the 'libvirt-bin' and its dependencies (incl. 'libvirt-daemon-system'), by providing the 'confmiss' DPKG flag: it restored anything libvirt-related in '/etc/apparmor.d'
  2.b/ Did 1/ and 2/ for the 'qemu-kvm' and 'virt-manager' packages also
  3/ Reloaded the 'apparmor' systemd daemon
  4/ Rebooted machine
  5/ Reloaded daemons ('daemon-reload'), the 'libvirtd' and 'qemu-kvm' systemd daemons
  6/ Retried to start the VM

Could a dependency package be the cause of it?

Revision history for this message
Pascal A. (pascalav) wrote :

I forgot to mention the VM never triggered AppArmor errors with 16.04.x LTS. I never checked if AppArmor was really running by the way (this is not a production host, only a developer machine).

Revision history for this message
Pascal A. (pascalav) wrote :

(sorry for spamming multiple-posts)

When the error occurs, 'dmesg' outputs:
--
[ 1835.178954] audit: type=1400 audit(1534455163.959:121): apparmor="DENIED" operation="change_profile" info="label not found" error=-2 profile="/usr/sbin/libvirtd" name="libvirt-a1937a46-2b13-41bd-998b-27ee9a8209a8" pid=4930 comm="libvirtd"
--

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

Hi,
the "file not found" is a red herring - in 99% of the cases it is something in the actual generated profile that is broken.
Maybe newer libvirt generates a rule now for you (which it didn't before) and the config for that element contains something (e.g. a bad name) that makes it break.

To debug we'd need the /etc/apparmor.d/libvirt/libvirt-* files after they got generated and failed loading.

I think with [1] you can even modify the profile (mostly in the one with .files) and reload until you found which rule is breaking it.

I'd assume something like:
$ sudo apparmor_parser -r /etc/apparmor.d/libvirt/libvirt-5fb5b85a-b3ec-4e21-ad70-d663689b9fb5
AppArmor parser error for /etc/apparmor.d/libvirt/libvirt-5fb5b85a-b3ec-4e21-ad70-d663689b9fb5 in /etc/apparmor.d/libvirt/libvirt-5fb5b85a-b3ec-4e21-ad70-d663689b9fb5 at line 11: syntax error, unexpected TOK_CLOSE, expecting TOK_END_OF_RULE

Iterate:
vim /etc/apparmor.d/libvirt/libvirt-<UUID>.files
# adapt rules
sudo apparmor_parser -r /etc/apparmor.d/libvirt/libvirt-<UUID>
# until this works

[1]: https://help.ubuntu.com/community/AppArmor#Reload_one_profile

Revision history for this message
Pascal A. (pascalav) wrote :

Hi Christian,

This is a false-positive reopening of this issue indeed. Still, it may contain useful bits.

The error occurrence I forwarded is now solved, thanks to what you advised on a side-subject at https://bugs.launchpad.net/ubuntu/+source/libvirt/+bug/1786677/comments/6 .

When producing stacktrace in here ( https://bugs.launchpad.net/ubuntu/+source/libvirt/+bug/1384532/comments/28 ), the root cause was that I appended this snippet at the end of '/etc/apparmor.d/abstractions/libvirt-qemu':
--
{dev,run}/shm/ rw,
{dev,run}/shm/* rw,
--

This was a mistake to add those rules, since I should have edited the existing ones (that you stated at https://bugs.launchpad.net/ubuntu/+source/libvirt/+bug/1786677/comments/6 ).

In the end, I kinda duplicated the '{dev,run}/shm' rules when producing the error. With the following diff + a reload of the AppArmor profile, the error vanished:
--
$ sudo diff /etc/apparmor.d/abstractions/libvirt-qemu ~/.sys/bak-custom/etc/apparmor.d/abstractions/libvirt-qemu
56c56,57
< /{dev,run}/shm r,
---
> /{dev,run}/shm rw,
> /{dev,run}/shm/* rw,
--

What I did was just moving the 2 lines initially appended to the files, in order to overwrite the existing rules.

A few asserts when the error was produced:
  - None of 'sudo systemctl reload apparmor', 'sudo systemctl restart apparmor' or 'sudo systemctl status apparmor' (in sequence) returned or shew an error

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

Yeah it is always good to have such insights here to be found by search engines for the next who hits it.

Glad that my recommendations helped.

Revision history for this message
James Gibson (hawruh) wrote :

I had this issue and what I did to solve it was:

Deleted relevant files in /etc/apparmor.d/libvirt, e.g.:

1. sudo rm /etc/apparmor.d/libvirt/libvirt-<vm_id>
2. sudo rm /etc/apparmor.d/libvirt/libvirt-<vm_id>.files
3. Restart machine

And then it worked

Revision history for this message
Christian Ehrhardt  (paelzer) wrote : Re: [Bug 1384532] Re: Unable to set AppArmor profile [...] no such file or directory

> 1. sudo rm /etc/apparmor.d/libvirt/libvirt-<vm_id>
> 2. sudo rm /etc/apparmor.d/libvirt/libvirt-<vm_id>.files
> 3. Restart machine

#1 and #2 are regenerated new on every VM start.
So could it be that it was just 3 for you?

Revision history for this message
Jason Fisher (digitalsanity) wrote :

I also fixed a similar issue that complained about AppArmor and qemu-system-x86_64 by deleting the /etc/apparmor.d/libvirt/libvirt* files. The files were owned by root and the first file was zero bytes long.
 I did not need to restart and was able to start the VM immediately.

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

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.