qcow base image apparmor rule missing in artful

[Christian Ehrhardt ]

Our automated tests spotted an issue with the last libvirt upload.

In uvtool the setup is using a qcow with a base device:
So the (generated) aa profiles for the guests used to have an entry like:
  "/var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxMw==" r,

This is the base device referenced "from" the qcow device owned by the guest.

This rule is missing and thereby causing an issue like:
uvt-kvm create --template /root/guesttemplate.xml --password=ubuntu --ssh-public-key-file /home/ubuntu/.ssh/authorized_keys kvmguest-artful-normal release=artful arch=ppc64el label=daily
Warning: using --password from the command line is not secure and should be used for debugging only.
Warning: '/home/ubuntu/.ssh/authorized_keys' not found; instance will be started with no ssh access by default.
uvt-kvm: error: libvirt: internal error: process exited while connecting to monitor: 2017-07-17T12:00:43.068460Z qemu-system-ppc64: -drive file=/var/lib/uvtool/libvirt/images/kvmguest-artful-normal.qcow,format=qcow2,if=none,id=drive-virtio-disk0: Could not open backing file: Could not open '/var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxMw==': Permission denied

[Christian Ehrhardt  (paelzer)]

So an apparmor issue that seems to have started with Artful (working before).
Could be a 3.5 issue as the older errors were different.

Generated rules have:
  "/var/lib/uvtool/libvirt/images/kvmguest-artful-normal.qcow" rw,
  "/var/lib/uvtool/libvirt/images/kvmguest-artful-normal-ds.qcow" rw,

The offending path is the base file qcow that makes the main disk.

Working on zesty with libvirt 2-5
- as expected no such deny message
- in addition has:
  "/var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxMw==" r,

So the new libvirt no more generates that line.
We had no own change in that area.

[Christian Ehrhardt  (paelzer)]

gdb break on "vah_add_file" which is the generic path adder for most calls.
A debuggable call is like:
  /usr/lib/libvirt/virt-aa-helper --create --dryrun --uuid 'libvirt-0b4a7877-7bd2-4059-8ab3-9d02a763a682' < kvmguest-artful-normal.xml

Trace of the old code that added it is:
Breakpoint 1, add_file_path (disk=0x10005fb8d10,
    path=0x10005fcd160 "/var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxMw==",
    depth=1, opaque=0x3fffe38cb760) at ../../../src/security/virt-aa-helper.c:894
894 in ../../../src/security/virt-aa-helper.c
(gdb) bt
#0 add_file_path (disk=0x10005fb8d10,
    path=0x10005fcd160 "/var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxMw==",
    depth=1, opaque=0x3fffe38cb760) at ../../../src/security/virt-aa-helper.c:894
#1 0x00003fffa8977c50 in virDomainDiskDefForeachPath (disk=0x10005fb8d10, ignoreOpenFailure=<optimized out>, iter=0x2f121dc0 <add_file_path>,
    opaque=0x3fffe38cb760) at ../../../src/conf/domain_conf.c:24875
#2 0x000000002f11cd80 in get_files (ctl=0x3fffe38cb778) at ../../../src/security/virt-aa-helper.c:947
#3 vahParseArgv (argv=<optimized out>, argc=<optimized out>, ctl=0x3fffe38cb778) at ../../../src/security/virt-aa-helper.c:1260
#4 main (argc=<optimized out>, argv=<optimized out>) at ../../../src/security/virt-aa-helper.c:1309

Uses the iterator of "virDomainDiskDefForeachPath" with a call from aa-helper
  virDomainDiskDefForeachPath(disk, true, add_file_path, &buf)

The code around that is still the same, but there is a difference
Old:
24871 /* execute the callback only for local storage */
24872 if (actualType != VIR_STORAGE_TYPE_NETWORK &&
24873 actualType != VIR_STORAGE_TYPE_VOLUME &&
24874 tmp->path) {
24875 if (iter(disk, tmp->path, depth, opaque) < 0)
New:
26003 /* execute the callback only for local storage */
26004 if (virStorageSourceIsLocalStorage(tmp) &&
26005 tmp->path) {
26006 if (iter(disk, tmp->path, depth, opaque) < 0)

The new function defaults to false and there are various conditions that might not more call the iterator now.
Assumption is that the base file is one of them.

[Christian Ehrhardt  (paelzer)]

The function is rather old:
dc12cec6 Wed Sep 3 18:54:56 2014 util: storage: Convert disk locality check to switch statement

But the usage of it from the iterator is not:
commit c3a83bad2aa69a26d03ee8a0b817234f0f78b4a5
Author: Michal Privoznik <email address hidden>
Date: Thu Mar 30 17:02:39 2017 +0200

    virDomainDiskDefForeachPath: Prefer virStorageSourceIsLocalStorage

    Signed-off-by: Michal Privoznik <email address hidden>

diff --git a/src/conf/domain_conf.c b/src/conf/domain_conf.c
index 1b0a55b..01553b5 100644
--- a/src/conf/domain_conf.c
+++ b/src/conf/domain_conf.c
@@ -25342,10 +25342,8 @@ virDomainDiskDefForeachPath(virDomainDiskDefPtr disk,
     }

     for (tmp = disk->src; tmp; tmp = tmp->backingStore) {
- int actualType = virStorageSourceGetActualType(tmp);
         /* execute the callback only for local storage */
- if (actualType != VIR_STORAGE_TYPE_NETWORK &&
- actualType != VIR_STORAGE_TYPE_VOLUME &&
+ if (virStorageSourceIsLocalStorage(tmp) &&
             tmp->path) {
             if (iter(disk, tmp->path, depth, opaque) < 0)
                 goto cleanup;

[Christian Ehrhardt  (paelzer)]

Effective change from:
        if (actualType != VIR_STORAGE_TYPE_NETWORK &&
            actualType != VIR_STORAGE_TYPE_VOLUME &&

to:
    switch (type) {
    case VIR_STORAGE_TYPE_FILE:
    case VIR_STORAGE_TYPE_BLOCK:
    case VIR_STORAGE_TYPE_DIR:
        return true;

    case VIR_STORAGE_TYPE_NETWORK:
    case VIR_STORAGE_TYPE_VOLUME:
    case VIR_STORAGE_TYPE_LAST:
    case VIR_STORAGE_TYPE_NONE:
        return false;
    }

    return false

[Christian Ehrhardt  (paelzer)]

Note on test triggers:
s390x
https://jenkins.ubuntu.com/server/view/Virt/job/virt-in-release-s390x-a/19/consoleText
https://jenkins.ubuntu.com/server/view/Virt/job/virt-in-release-s390x-a/20/consoleText
https://jenkins.ubuntu.com/server/view/Virt/job/virt-in-release-s390x-a/21/consoleText
ppc64el
https://jenkins.ubuntu.com/server/view/Virt/job/virt-in-release-ppc64el-a/16/consoleText
https://jenkins.ubuntu.com/server/view/Virt/job/virt-in-release-ppc64el-a/17/consoleText

Always blocked on permission denied on s390x

s390x:
+ lxc exec testkvm-artful-from -- uvt-kvm create --template /root/guesttemplate.xml --password=ubuntu --ssh-public-key-file /home/ubuntu/.ssh/authorized_keys kvmguest-artful-normal release=artful arch=s390x label=daily
Warning: using --password from the command line is not secure and should be used for debugging only.
uvt-kvm: error: libvirt: internal error: process exited while connecting to monitor: 2017-07-13T23:24:42.730722Z qemu-system-s390x: -drive file=/var/lib/uvtool/libvirt/images/kvmguest-artful-normal.qcow,format=qcow2,if=none,id=drive-virtio-disk0: Could not open backing file: Could not open '/var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6czM5MHggMjAxNzA3MTE=': Permission denied

ppc:
+ lxc exec testkvm-artful-from -- uvt-kvm create --template /root/guesttemplate.xml --password=ubuntu --ssh-public-key-file /home/ubuntu/.ssh/authorized_keys kvmguest-artful-normal release=artful arch=ppc64el label=daily
Warning: using --password from the command line is not secure and should be used for debugging only.
uvt-kvm: error: libvirt: internal error: qemu unexpectedly closed the monitor: 2017-07-15T12:25:27.690715Z qemu-system-ppc64: -drive file=/var/lib/uvtool/libvirt/images/kvmguest-artful-normal.qcow,format=qcow2,if=none,id=drive-virtio-disk0: Could not open backing file: Could not open '/var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxMw==': Permission denied

[Christian Ehrhardt  (paelzer)]

Interestingly if just parsing the same XML on 2.5 and 3.5 they behave the same:

Test xml:
<domain type='kvm' id='2'>
        <name>kvmguest-artful-normal</name>
        <uuid>0b4a7877-7bd2-4059-8ab3-9d02a763a682</uuid>
        <memory unit='KiB'>524288</memory>
        <os>
                <type arch='ppc64le' machine='pseries-zesty'>hvm</type>
                <boot dev='hd'/>
        </os>
        <devices>
                <emulator>/usr/bin/kvm</emulator>
                <disk type='file' device='disk'>
                        <driver name='qemu' type='qcow2'/>
                        <source file='/var/lib/uvtool/libvirt/images/kvmguest-artful-normal.qcow'/>
                        <backingStore type='file' index='1'>
                                <format type='qcow2'/>
                                <source file='/var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxMw=='/>
                                <backingStore/>
                        </backingStore>
                        <target dev='vda' bus='virtio'/>
                        <alias name='virtio-disk0'/>
                        <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
                </disk>
        </devices>
</domain>

On both:
$ /usr/lib/libvirt/virt-aa-helper --create --dryrun --uuid 'libvirt-0b4a7877-7bd2-4059-8ab3-9d02a763a682' < kvmguest-artful-normal.xml 2>&1 | grep b64
  "/var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxMw==" r,

So the actual parsing from virt-aa-helper is ok.
Maybe the extending of the xml doesn't work correctly when defining it.

[Christian Ehrhardt  (paelzer)]

type analysis (only as doc, current theory is on uvt change missing to add the path)

The first disk is the base qcow disk which refers to the base file.
The loop iterates through backing stores.

Debugging types in old code on the loop:
Print all relevant Data in the loop
  printf "type: %ld path %s (srcpool %p)\n", tmp->type, tmp->path, tmp->srcpool
data is ready at:
  b ../../../src/conf/domain_conf.c:24870
Iter Call would be:
  b ../../../src/conf/domain_conf.c:24875

Breakpoint 5, virDomainDiskDefForeachPath (disk=0x1000495d0a0, ignoreOpenFailure=<optimized out>, iter=0x59531dc0 <add_file_path>,
    opaque=0x3fffeed9cb40) at ../../../src/conf/domain_conf.c:24870
24870 ../../../src/conf/domain_conf.c: No such file or directory.
(gdb) printf "type: %ld path %s (srcpool %p)\n", tmp->type, tmp->path, tmp->srcpool
type: 1 path /var/lib/uvtool/libvirt/images/kvmguest-artful-normal.qcow (srcpool (nil))
(gdb) c
Continuing.

Breakpoint 5, virDomainDiskDefForeachPath (disk=0x1000495d0a0, ignoreOpenFailure=<optimized out>, iter=0x59531dc0 <add_file_path>,
    opaque=0x3fffeed9cb40) at ../../../src/conf/domain_conf.c:24870
24870 in ../../../src/conf/domain_conf.c
(gdb) printf "type: %ld path %s (srcpool %p)\n", tmp->type, tmp->path, tmp->srcpool
type: 1 path /var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxMw== (srcpool (nil))
(gdb) c
Continuing.

=> Both are type 1, since there was no srcpool no replacement with def->srcpool->actualtype is done

[Christian Ehrhardt  (paelzer)]

Using the uvt-kvm option "--no-start" (only in artful) lets one create the system (iage files, xml in libvirt) without running into the error and therefore without the cleanup on error.

Comparing Zesty with Artful:
Zesty:
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2'/>
      <source file='/var/lib/uvtool/libvirt/images/kvmguest-artful-normal.qcow'/>
      <backingStore type='file' index='1'>
        <format type='qcow2'/>
        <source file='/var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxMw=='/>
        <backingStore/>
      </backingStore>
      <target dev='vda' bus='virtio'/>
      <alias name='virtio-disk0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </disk>

Artful:
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2'/>
      <source file='/var/lib/uvtool/libvirt/images/kvmguest-artful-normal.qcow'/>
      <target dev='vda' bus='virtio'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </disk>

The backingStore is missing.
Was uvtool adding that, or would that have been added on the actual start (it is already defined, so the usual auto-addition of attributes is done)

[Christian Ehrhardt  (paelzer)]

The backing file itself is properly registered in both cases:

$ qemu-img info /var/lib/uvtool/libvirt/images/kvmguest-artful-normal.qcow
image: /var/lib/uvtool/libvirt/images/kvmguest-artful-normal.qcow
file format: qcow2
[...]
backing file: /var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxMw==
backing file format: qcow2

[Christian Ehrhardt  (paelzer)]

The extra info of the backing file info is added on "instantiating" the guest.
So even on zesty a defined guest doesn't have the section:
      <backingStore type='file' index='1'>
        <format type='qcow2'/>
        <source file='/var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxMw=='/>
        <backingStore/>
      </backingStore>

Only after starting it this is generated for the "live" xml content.

So it is not a uvtool issue as the base content is the same in both cases.
Yet OTOH it is also not a virt-aa-helper issue which would generate the rule if the entry would be there.
It seems that the issue is to no more auto-detect the path and adding it to the live xml is the root casue we need to find.

[Christian Ehrhardt  (paelzer)]

Setting the per-guest profile to complain is hard if there is no guest profile yet :-/

But still that works:
sudo aa-complain /etc/apparmor.d/libvirt/libvirt-7e8d7cf7-b06b-47c3-8cf7-197ddd8be8b1

To be able to do so you need to fail-start it once so the files are laid out.
Then set it to complain and you can start the guest.

Now in this way to start it is adding the section:
      <backingStore type='file' index='1'>
        <format type='qcow2'/>
        <source file='/var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxMw=='/>
        <backingStore/>
      </backingStore>
Just as we need it.

So maybe the timing when this info gets added changed.
And at the point virt-aa-helper calls the iterator it is not yet added and therefore does not get a rule added.
Later on it still seems to be added thou as seen by the example in aa-complain mode.

[Christian Ehrhardt  (paelzer)]

Note: denial is like:
[340347.918044] audit: type=1400 audit(1500300438.529:12580): apparmor="DENIED" operation="open" namespace="root//lxd-testkvm-artful-from_<var-lib-lxd>" profile="libvirt-5399edf1-5e84-4969-86b3-17c21125713b" name="/var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxMw==" pid=5547 comm="qemu-system-ppc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0

[Christian Ehrhardt  (paelzer)]

AppArmorGenSecurityLabel is called on qemudStartVMDaemon
That calls load_profile
And that does a check on the xml if it can be generated.
  xml = virDomainDefFormat(def, NULL, VIR_DOMAIN_DEF_FORMAT_SECURE);
  => is the backingStore missing as I assume?
Also track the command that is executed in
  cmd = virCommandNewArgList(VIRT_AA_HELPER, "-p", probe, ...
  => any change in arguments?

Before gdb'ing that down too much.
Just place custom wrapper and dump args as well as stdin.

# disable AA for debugging
# save orig
$ mv /usr/lib/libvirt/virt-aa-helper /usr/lib/libvirt/virt-aa-helper.orig
$ cat /usr/lib/libvirt/virt-aa-helper
#!/bin/bash
exec >> /tmp/virt-aa-helper.log
exec 2>&1

echo "ARGS"
echo $@

echo "STDIN"
while read l
do
  echo $l
done

2.5 and 3.5 seem to have an empty backing store on the call.
<disk type='file' device='disk'>
<driver name='qemu' type='qcow2'/>
<source file='/var/lib/uvtool/libvirt/images/kvmguest-artful-normal-z2.qcow'/>
<backingStore/>
<target dev='vda' bus='virtio'/>
<address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
</disk>

so TL;DR: the raw xml content that is passed is the same.
Need to debug the actual parsing if the object references differ e.g. in the in memory representation of "disks" when going into the loop that iterates into the subelements.

[Christian Ehrhardt  (paelzer)]

Based on the last few updates I could corner the isssue just to virt-aa-helper.
There is no active instance of libvirt involved which hopefully eases the debugging.

Here what I just sent to upstream: https://www.redhat.com/archives/libvir-list/2017-July/msg00627.html

I was mislead by my former assumption on the lifecycle.
As virt-aa-helper gets his xml passed into stdin.
I captured that and found that in both cases it had the same content.
Below steps to reproduce based on that:

Test -Xml:
<domain type='kvm' id='1'>
        <name>kvmguest-artful-normal-a2</name>
        <uuid>f4239a92-f933-4bd3-b9fb-b9c260a7dc65</uuid>
        <memory unit='KiB'>524288</memory>
        <vcpu placement='static'>1</vcpu>
        <os>
                <type arch='ppc64le' machine='pseries-zesty'>hvm</type>
                <boot dev='hd'/>
        </os>
        <devices>
                <emulator>/usr/bin/kvm</emulator>
                <disk type='file' device='disk'>
                        <driver name='qemu' type='qcow2'/>
                        <source file='/var/lib/uvtool/libvirt/images/kvmguest-artful-normal-a2.qcow'/>
                        <backingStore/>
                        <target dev='vda' bus='virtio'/>
                        <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
                </disk>
        </devices>
        <seclabel type='dynamic' model='apparmor' relabel='yes'>
                <label>libvirt-f4239a92-f933-4bd3-b9fb-b9c260a7dc65</label>
                <imagelabel>libvirt-f4239a92-f933-4bd3-b9fb-b9c260a7dc65</imagelabel>
        </seclabel>
</domain>

File:
qemu-img info /var/lib/uvtool/libvirt/images/kvmguest-artful-normal-a2.qcow
image: /var/lib/uvtool/libvirt/images/kvmguest-artful-normal-a2.qcow
file format: qcow2
virtual size: 8.0G (8589934592 bytes)
disk size: 200M
cluster_size: 65536
backing file: /var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxNg==
backing file format: qcow2
Format specific information:
    compat: 0.10
    refcount bits: 1

To be sure I undefined the guest to not have "a different source" or information.

Generate a new profile:
$ /usr/lib/libvirt/virt-aa-helper --create --dryrun --uuid 'libvirt-f4239a92-f933-4bd3-b9fb-b9c260a7dc65' < test-virt-aa-helper.xml

In 3.5 this is no more having the line:
/var/lib/uvtool/libvirt/images/x-uvt-b64-Y29tLnVidW50dS5jbG91ZC5kYWlseTpzZXJ2ZXI6MTcuMTA6cHBjNjRlbCAyMDE3MDcxNg==

[Christian Ehrhardt  (paelzer)]

Ok, I was able to confirm with latest upstream master which rules out Ubuntu apparmor delta as the source of the issue.
But I can build and run to check so worst case I can bisect.

[Christian Ehrhardt  (paelzer)]

Still very reproducible, running automated bisect over night ...

[Christian Ehrhardt  (paelzer)]

Breaking change identified as
commit f813fe810fc3f0ce839f450e662e0173d40a5ce1 (refs/bisect/bad)
Author: Peter Krempa <email address hidden>
Date: Fri Jan 13 16:50:11 2017 +0100

    storage: backend: Refactor registration of the backend drivers

Peter said he will take a look: "Hmmm, in that case probably the registration of the storage driver APIs in the aa-helper does not take place properly, and thus the detection of the backing chain will be wrong."

[Launchpad Janitor (janitor)]

This bug was fixed in the package libvirt - 3.5.0-1ubuntu2

---------------
libvirt (3.5.0-1ubuntu2) artful; urgency=medium

  * d/p/u/aa-helper-Properly-link-with-storage-driver.patch (LP: #1704782)
    Fix to be able to follow BackinStorage chains when creating per
    guest apparmor rules.

 -- Christian Ehrhardt <email address hidden> Tue, 18 Jul 2017 16:34:57 +0200