libvirt error starting domin: could not remove profile for

[Bryan McLellan]

libvirt-bin=0.7.5-5ubuntu27
kvm=1:84+dfsg-0ubuntu16+0.12.3+noroms+0ubuntu9.2
linux-generic=2.6.32.23.24

# virsh start iadoptdc02
error: Failed to start domain iadoptdc02
error: could not remove profile for 'libvirt-177bb534-7d9c-91ad-e6bf-89cd76d1e1bb'

This error continues even if AppArmor is disabled using '/etc/init.d/apparmor stop'

This is a fresh lucid install that is about a week old. This domain was created without issue, although a matching server did have the same problem with a domain when first created, which I resolved by purging kvm + libvirt and reinstalling. After a maintenance reboot, this domain no longer starts.

[Bryan McLellan (btm)]

1) stopped libvirt via the libvirt-bin init script
2) started 'libvirtd -v' manually hoping to see some debugging output
3) started the guest okay.
4) destroyed the guest
5) canceled the manual libvirt
6) started libvirt-bin again with the init script
7) started the guest okay.

Note that AppArmor was off for this process, so the workaround was either:

a) restarting libvirt
b) restarting libvirt with apparmor off (would this matter?)
c) started libvirt by hand (clearing something?)
d) magic

[Mathias Gug (mathiaz)]

Could you attach the xml profile of the failing guest (iadoptdc02)?

[Bryan McLellan (btm)]

Yes, although it's working at the moment.

<domain type='kvm'>
  <name>iadoptdc02</name>
  <uuid>177bb534-7d9c-91ad-e6bf-89cd76d1e1bb</uuid>
  <memory>1048576</memory>
  <currentMemory>1048576</currentMemory>
  <vcpu>2</vcpu>
  <os>
    <type arch='x86_64' machine='pc-0.12'>hvm</type>
    <boot dev='hd'/>
  </os>
  <features>
    <acpi/>
    <apic/>
    <pae/>
  </features>
  <clock offset='localtime'/>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>restart</on_crash>
  <devices>
    <emulator>/usr/bin/kvm</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='raw'/>
      <source file='/var/lib/libvirt/images/iadoptdc02.img'/>
      <target dev='hda' bus='ide'/>
    </disk>
    <interface type='bridge'>
      <mac address='52:54:00:09:71:b1'/>
      <source bridge='br0.54'/>
      <model type='e1000'/>
    </interface>
    <console type='pty'>
      <target port='0'/>
    </console>
    <console type='pty'>
      <target port='0'/>
    </console>
    <input type='tablet' bus='usb'/>
    <input type='mouse' bus='ps2'/>
    <graphics type='vnc' port='-1' autoport='yes'/>
    <video>
      <model type='cirrus' vram='9216' heads='1'/>
    </video>
  </devices>
</domain>

[Bryan McLellan (btm)]

libvirt-bin=0.7.5-5ubuntu27
qemu-kvm=0.12.3+noroms-0ubuntu9.2

root@iadvirt02:~# lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 10.04.1 LTS
Release: 10.04
Codename: lucid

root@iadvirt02:~# uname -a
Linux iadvirt02 2.6.32-24-generic #39-Ubuntu SMP Wed Jul 28 05:14:15 UTC 2010 x86_64 GNU/Linux

root@iadvirt02:~# virsh start iadoptdc02
error: Failed to start domain iadoptdc02
error: could not remove profile for 'libvirt-177bb534-7d9c-91ad-e6bf-89cd76d1e1bb'

root@iadvirt02:~# virsh dumpxml iadoptdc02
<domain type='kvm'>
  <name>iadoptdc02</name>
  <uuid>177bb534-7d9c-91ad-e6bf-89cd76d1e1bb</uuid>
  <memory>1048576</memory>
  <currentMemory>1048576</currentMemory>
  <vcpu>2</vcpu>
  <os>
    <type arch='x86_64' machine='pc-0.12'>hvm</type>
    <boot dev='hd'/>
  </os>
  <features>
    <acpi/>
    <apic/>
    <pae/>
  </features>
  <clock offset='localtime'/>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>restart</on_crash>
  <devices>
    <emulator>/usr/bin/kvm</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='raw'/>
      <source file='/var/lib/libvirt/images/iadoptdc02.img'/>
      <target dev='hda' bus='ide'/>
    </disk>
    <interface type='bridge'>
      <mac address='52:54:00:09:71:b1'/>
      <source bridge='br0.54'/>
      <target dev='vnet0'/>
      <model type='e1000'/>
    </interface>
    <console type='pty'>
      <target port='0'/>
    </console>
    <console type='pty'>
      <target port='0'/>
    </console>
    <input type='tablet' bus='usb'/>
    <input type='mouse' bus='ps2'/>
    <graphics type='vnc' port='-1' autoport='yes'/>
    <video>
      <model type='cirrus' vram='9216' heads='1'/>
    </video>
  </devices>
</domain>

root@iadvirt02:~# virsh capabilities
<capabilities>

  <host>
    <cpu>
      <arch>x86_64</arch>
      <model>core2duo</model>
      <topology sockets='4' cores='4' threads='1'/>
      <feature name='lahf_lm'/>
      <feature name='rdtscp'/>
      <feature name='popcnt'/>
      <feature name='dca'/>
      <feature name='xtpr'/>
      <feature name='cx16'/>
      <feature name='tm2'/>
      <feature name='est'/>
      <feature name='vmx'/>
      <feature name='ds_cpl'/>
      <feature name='pbe'/>
      <feature name='tm'/>
      <feature name='ht'/>
      <feature name='ss'/>
      <feature name='acpi'/>
      <feature name='ds'/>
    </cpu>
    <migration_features>
      <live/>
      <uri_transports>
        <uri_transport>tcp</uri_transport>
      </uri_transports>
    </migration_features>
    <secmodel>
      <model>apparmor</model>
      <doi>0</doi>
    </secmodel>
  </host>

  <guest>
    <os_type>hvm</os_type>
    <arch name='i686'>
      <wordsize>32</wordsize>
      <emulator>/usr/bin/qemu</emulator>
      <machine>pc-0.12</machine>
      <machine canonical='pc-0.12'>pc</machine>
      <machine>pc-0.11</machine>
      <machine>pc-0.10</machine>
      <machine>isapc</machine>
      <domain type='qemu'>
      </domain>
      <domain type='kvm'>
        <emulator>/usr/bin/kvm</emulator>
        <machine>pc-0.12</machine>
        <machine canonical='pc-0.12'>pc</machine>
        <machine>pc-0...

[Bryan McLellan (btm)]

Actually, it does looks like an apparmor problem. Putting Apparmor in complain mode allows the domain to start, returning it to enforce brings back the original state.

root@iadvirt02:~# aa-complain /etc/apparmor.d/usr.sbin.libvirtd
Setting /etc/apparmor.d/usr.sbin.libvirtd to complain mode.
root@iadvirt02:~# virsh start iadoptdc02
Domain iadoptdc02 started
root@iadvirt02:~# virsh destroy iadoptdc02
Domain iadoptdc02 destroyed

root@iadvirt02:~# aa-enforce /etc/apparmor.d/usr.sbin.libvirtd
Setting /etc/apparmor.d/usr.sbin.libvirtd to enforce mode.
root@iadvirt02:~# virsh start iadoptdc02
error: Failed to start domain iadoptdc02
error: could not remove profile for 'libvirt-177bb534-7d9c-91ad-e6bf-89cd76d1e1bb'

audit log:

Aug 12 23:48:15 iadvirt02 kernel: [ 1658.487839] type=1505 audit(1281656895.909:705): operation="profile_replace" pid=11447 name="/usr/sbin/libvirtd"
Aug 12 23:48:20 iadvirt02 kernel: [ 1663.423350] device vnet0 entered promiscuous mode
Aug 12 23:48:20 iadvirt02 kernel: [ 1663.425192] br0.54: port 2(vnet0) entering forwarding state
Aug 12 23:48:20 iadvirt02 kernel: [ 1663.426730] type=1502 audit(1281656900.859:706): operation="chown" pid=11458 parent=1 profile="/usr/sbin/libvirtd//null-1a" requested_mask="w::" denied_mask="w::" fsuid=0 ouid=0 name="/var/lib/libvirt/images/iadoptdc02.img"
Aug 12 23:48:20 iadvirt02 kernel: [ 1663.426743] type=1502 audit(1281656900.859:707): operation="capable" pid=11458 parent=1 profile="/usr/sbin/libvirtd//null-1a" name="chown"
Aug 12 23:48:20 iadvirt02 kernel: [ 1663.426854] type=1502 audit(1281656900.859:708): operation="open" pid=11458 parent=1 profile="/usr/sbin/libvirtd//null-1a" requested_mask="::r" denied_mask="::r" fsuid=116 ouid=0 name="/proc/11458/status"
Aug 12 23:48:20 iadvirt02 kernel: [ 1663.426996] type=1502 audit(1281656900.859:709): operation="exec" pid=11458 parent=1 profile="/usr/sbin/libvirtd//null-1a" requested_mask="::x" denied_mask="::x" fsuid=116 ouid=0 name="/usr/bin/qemu-system-x86_64" name2="/usr/sbin/libvirtd//null-1a//null-1b"
Aug 12 23:48:20 iadvirt02 kernel: [ 1663.427400] type=1502 audit(1281656900.859:710): operation="open" pid=11458 parent=1 profile="/usr/sbin/libvirtd//null-1a//null-1b" requested_mask="::r" denied_mask="::r" fsuid=116 ouid=0 name="/etc/ld.so.cache"
Aug 12 23:48:20 iadvirt02 kernel: [ 1663.427432] type=1502 audit(1281656900.859:711): operation="open" pid=11458 parent=1 profile="/usr/sbin/libvirtd//null-1a//null-1b" requested_mask="::r" denied_mask="::r" fsuid=116 ouid=0 name="/lib/librt-2.11.1.so"
Aug 12 23:48:20 iadvirt02 kernel: [ 1663.427451] type=1502 audit(1281656900.859:712): operation="file_mmap" pid=11458 parent=1 profile="/usr/sbin/libvirtd//null-1a//null-1b" requested_mask="::mr" denied_mask="::mr" fsuid=116 ouid=0 name="/lib/librt-2.11.1.so"
Aug 12 23:48:20 iadvirt02 kernel: [ 1663.427492] type=1502 audit(1281656900.859:713): operation="open" pid=11458 parent=1 profile="/usr/sbin/libvirtd//null-1a//null-1b" requested_mask="::r" denied_mask="::r" fsuid=116 ouid=0 name="/lib/libpthread-2.11.1.so"
Aug 12 23:48:20 iadvirt02 kernel: [ 1663.427507] type=1502 audit(1281656900.859:714): operation="file_mmap" pid=11458 parent=1 pr...

[Bryan McLellan (btm)]

I'm not sure how this state gets created but:

root@iadvirt02:/etc/apparmor.d/libvirt# ls -l
total 8
-rw-r--r-- 1 root root 265 2010-07-15 19:44 libvirt-177bb534-7d9c-91ad-e6bf-89cd76d1e1bb
-rw-r--r-- 1 root root 164 2010-04-22 16:57 TEMPLATE
root@iadvirt02:/etc/apparmor.d/libvirt# virsh start iadoptdc02
error: Failed to start domain iadoptdc02
error: could not remove profile for 'libvirt-177bb534-7d9c-91ad-e6bf-89cd76d1e1bb'
root@iadvirt02:/etc/apparmor.d/libvirt# rm libvirt-177bb534-7d9c-91ad-e6bf-89cd76d1e1bb
root@iadvirt02:/etc/apparmor.d/libvirt# virsh start iadoptdc02
error: Failed to start domain iadoptdc02
error: could not remove profile for 'libvirt-177bb534-7d9c-91ad-e6bf-89cd76d1e1bb'
root@iadvirt02:/etc/apparmor.d/libvirt# ls
TEMPLATE

Apparently apparmor still knows about this profile, but I don't know where or how to flush it.

[Jamie Strandboge (jdstrand)]

Bryan,

Is this still a problem for you? If so, can you put apparmor back into enforce mode, then try to reproduce. If you can still reproduce the bug, please attach /var/log/kern.log.

[Sven Fischer (sepreh)]

Hi Jamie,

I ran into exactly the same problem. My syslog output:

Aug 28 18:51:18 facitserver kernel: [ 2492.386304] device vnet0 entered promiscuous mode
Aug 28 18:51:18 facitserver kernel: [ 2492.387292] virbr0: topology change detected, propagating
Aug 28 18:51:18 facitserver kernel: [ 2492.387297] virbr0: port 1(vnet0) entering forwarding state
Aug 28 18:51:18 facitserver kernel: [ 2492.387299] virbr0: port 1(vnet0) entering forwarding state
Aug 28 18:51:18 facitserver kernel: [ 2492.445879] virbr0: port 1(vnet0) entering forwarding state
Aug 28 18:51:18 facitserver kernel: [ 2492.483768] device vnet0 left promiscuous mode
Aug 28 18:51:18 facitserver kernel: [ 2492.483772] virbr0: port 1(vnet0) entering disabled state
Aug 28 18:51:18 facitserver libvirtd: 18:51:18.630: 871: error : qemudReadLogOutput:1649 : internal error Process exited while reading console log output: libvir: Security Labeling error : internal error error calling aa_change_profile()#012
Aug 28 18:51:18 facitserver libvirtd: 18:51:18.647: 871: error : virRunWithHook:886 : internal error '/usr/lib/libvirt/virt-aa-helper -R -u libvirt-cb810e54-fa44-979b-2337-338fd9867dba' exited with non-zero status 1 and signal 0: virt-aa-helper: error: apparmor_parser exited with error#012
Aug 28 18:51:18 facitserver libvirtd: 18:51:18.647: 871: error : AppArmorRestoreSecurityAllLabel:572 : internal error could not remove profile for 'libvirt-cb810e54-fa44-979b-2337-338fd9867dba

In the kern.log file there is no additional output than the kernel: lines in the syslog (for sure ;-)

The problem is: It was working before the one of the last updates for natty came onto the server - I am sorry, but I don't know which version exactly breaks the system, becase we rarely reboot and so it may be a new kernel that causes the problems...

[Jamie Strandboge (jdstrand)]

Sven, what version of libvirt and Ubuntu are you using? Can you attach the output of 'virsh dumpxml <your problem domain>'? Thanks

[Serge Hallyn (serge-hallyn)]

Marking this bug invalid as we needed more information to act on.