breaking the apparmor profile leads to misleading error messages

[Christian Ehrhardt ]

Certain cases are mis-debugged for quite a while and users are confused on a bad apparmor profile (for a guest) being reporte as:

error: internal error: Process exited prior to exec: libvirt: error : unable to set AppArmor profile 'libvirt-5a0e5825-717b-4edb-857a-b7bab2f7083a' for '/usr/bin/kvm-spice': No such file or directory

To reproduce use a forbidden char, so any of the bad chars [1] in e.g. a file name of an image.
Then start the domain.

The error should be more descriptive to what failed.

[1]: https://libvirt.org/git/?p=libvirt.git;a=blobdiff;f=src/security/virt-aa-helper.c;h=07ece730e27d2be4be92adcabb54d788825659f0;hp=ee3913d66ac3a867bae6af71609ebcd25dd25ae2;hb=a150b86c4c3afc82e2d2f591ae19328b1c81bf7e;hpb=a50b45a2971a4c70f005a8e8821ea7a794e87e7b

[Christian Ehrhardt  (paelzer)]

Note: bug 1772538 is another testcase where such a message could have been better.

[Christian Ehrhardt  (paelzer)]

There are other reasons this could trigger, but one is e.g. adding e.g. a disk with:
  <source file='/var/lib/libvirt/images/break,^*[]&quot;, foo&quot;me.qcow'/>

You need to create the file or libvirt will detect and exit before that.
$ sudo qemu-img create -f qcow2 '/var/lib/libvirt/images/break,^*[]", foo"me.qcow' 10M

Error (on most recent libvirt) is like:
error: Failed to start domain c
error: internal error: cannot load AppArmor profile 'libvirt-8763795d-f056-4373-9d57-3d3bad391e5a'

The same used as hotplug device will trigger:
error: Failed to attach device from disk.xml
error: internal error: cannot update AppArmor profile 'libvirt-8763795d-f056-4373-9d57-3d3bad391e5a'

I have found no way with recent versions to get the misleading pointer to the "qemu-... does not exists".
Setting incomplete.

[Christian Ehrhardt  (paelzer)]

Actually, if we could have a filename that makes it bad it would be nice, but at low prio

[Christian Ehrhardt  (paelzer)]

virt-aa-helper reports actually already a good message internally:

  virt-aa-helper: error: skipped restricted file
  virt-aa-helper: error: invalid VM definition

You'd already see it in journal or on a systemctl to libvirtd:
Jun 19 11:35:53 c libvirtd[25978]: 2018-06-19 11:35:53.415+0000: 25979: error : virCommandWait:2601 : internal error: Child process (LIBVIRT_LOG_OUTPUTS=3:stderr /usr/lib/libvirt/virt-aa-helper -p 0 -r -u libvirt-8763795d-f056-4373-9d57-3d3bad391e5a -f '/var/lib/libvirt/images/break,^*[]", foo"me.qcow') unexpected exit status 1: virt-aa-helper: error: /var/lib/libvirt/images/break,^*[]", foo"me.qcow
Jun 19 11:35:53 c libvirtd[25978]: virt-aa-helper: error: skipped restricted file
Jun 19 11:35:53 c libvirtd[25978]: virt-aa-helper: error: invalid VM definition
Jun 19 11:35:53 c libvirtd[25978]: 2018-06-19 11:35:53.415+0000: 25979: error : AppArmorSetSecurityImageLabel:843 : internal error: cannot update AppArmor profile 'libvirt-8763795d-f056-4373-9d57-3d3bad391e5a'

[Christian Ehrhardt  (paelzer)]

So, TL;DR we have all we need (there are plenty of other cases it might fail and all report error values from virt-aa-helper to stdout/stderr.

But the virCommandRun in security does only let those errors to the log but not forwards them.
So capture output/error and in bad-rc case report it.

This means it reports whatever virt-aa-helper said, followed by the upper laye message of "can't load/update profile" ...

That should be just what we want.

One has to be careful as there are no guarantees output/error is set on bad execution, but we can check and only report if set.
It also needs a free on the exit path.

I had a test, but then remembered that virsh by-design is intended to not flood you with errors.
Essentially on a virsh error you get the LAST raised error, but everything more is in the log.

This was by design as in the past if e.g. there were loops or other long issues all that flooded the console and made it unreadable.

[Christian Ehrhardt  (paelzer)]

We made a bikeshedding session how to best resolve but not planngin to flood the console.
The problem is that "see libvirtd log" can mean so much as https://libvirt.org/logging.html can be quite complex and configurable.

The best is to give the user some hint where he can find more.
And that can be on a wiki page where we can explain the issue and help the user to resolve.

(see https://wiki.ubuntu.com/LibvirtApparmorIssues for help)

That can be Ubuntu custom, and therefore explain the issue much better (as we can refer to how ubuntu is configured usually).

[Christian Ehrhardt  (paelzer)]

Due to translations this might be harder to maintain than it is worth (code-wise).
Yet I created the wiki page and if it is helpful, then it will be recommended more often and show up more in searches.

I'll consider it fix-released due to the documentation and instead of the code change will also add an askubuntu entry pointing to the wiki page.

[Christian Ehrhardt  (paelzer)]

Filed https://askubuntu.com/questions/1048157/libvirt-kvm-guest-failing-due-issues-in-the-apparmorprofile/1048158#1048158 in case people search there first.