AppArmor profile for snapd-confine not reloaded on deb update

Hey,

I’am running Ubuntu 16.04 with xenial-proposed enabled and got updated to snapd 2.27.3

If I remember well, I did a reboot after the call to apt upgrade.

After that happened services from my snaps were not starting anymore with the following errors:

Aug 23 11:58:56 nirvana audit[21476]: AVC apparmor="DENIED" operation="mount" info="failed srcname match" error=-13 profile="/usr/lib/snapd/snap-confine" name="/tmp/snap.rootfs_jxIslj/etc/nsswitch.conf" pid=21476 comm="snap-confine" srcname="/snap/core/2462/etc/nsswitch.conf" flags="rw, bind"
Aug 23 11:58:56 nirvana snap[21476]: cannot perform operation: mount --bind /snap/core/current//etc/nsswitch.conf /tmp/snap.rootfs_jxIslj/etc/nsswitch.conf: Permission denied
Aug 23 11:58:56 nirvana kernel: audit: type=1400 audit(1503482336.199:228): apparmor="DENIED" operation="mount" info="failed srcname match" error=-13 profile="/usr/lib/snapd/snap-confine" name="/tmp/snap.rootfs_jxIslj/etc/nsswitch.conf" pid=21476 comm="snap-confine" srcname="/snap/core/2462/etc/nsswitch.conf" flags="rw, bind"

The profile in /etc/apparmor.d/usr.lib.snapd.snap-confine.real was up-to-date and had the necessary rules to allow access to nsswitch.conf

$ cat /etc/apparmor.d/usr.lib.snapd.snap-confine.real | grep nss
    mount options=(rw bind) /snap/{,ubuntu-}core/*/etc/nsswitch.conf -> /tmp/snap.rootfs_*/etc/nsswitch.conf,
    mount options=(rw slave) -> /tmp/snap.rootfs_*/etc/nsswitch.conf,

After a manual

$ apparmor_parser -r /etc/apparmor.d/usr.lib.snapd.snap-confine.real

this was fixed.

A few more details

$ snap --version
snap    2.27.3
snapd   2.27.3
series  16
ubuntu  16.04
kernel  4.10.0-30-generic
$ apt-cache show snapd
Package: snapd
Priority: optional
Section: devel
Installed-Size: 64820
Maintainer: Ubuntu Developers <ubuntu-devel-discuss@lists.ubuntu.com>
Architecture: amd64
Version: 2.27.3
Replaces: snap-confine (<< 2.23), ubuntu-core-launcher (<< 2.22), ubuntu-snappy (<< 1.9), ubuntu-snappy-cli (<< 1.9)
Depends: adduser, apparmor (>= 2.10.95-0ubuntu2.2), ca-certificates, gnupg1 | gnupg, openssh-client, squashfs-tools, systemd, init-system-helpers (>= 1.18~), libc6 (>= 2.17), libudev1 (>= 183)
Conflicts: snap (<< 2013-11-29-1ubuntu1)
Breaks: snap-confine (<< 2.23), ubuntu-core-launcher (<< 2.22), ubuntu-snappy (<< 1.9), ubuntu-snappy-cli (<< 1.9)
Filename: pool/main/s/snapd/snapd_2.27.3_amd64.deb
Size: 10901200
MD5sum: 57f4163f6bf288c72a33ddf41fe715bf
SHA1: 42956973f7917af65b0f925edafc2f578fff3ef6
SHA256: 4cb1712ef7d4d80c6fd05565463fae8ca5b9faf527fcfba445926b600fd61593
Description-en: Tool to interact with Ubuntu Core Snappy.
 Install, configure, refresh and remove snap packages. Snaps are
 'universal' packages that work across many different Linux systems,
 enabling secure distribution of the latest apps and utilities for
 cloud, servers, desktops and the internet of things.
 .
 This is the CLI for snapd, a background service that takes care of
 snaps on the system. Start with 'snap list' to see installed snaps.
Description-md5: ad5806e76513cff3a5382bff8123a97a
Built-Using: apparmor (= 2.10.95-0ubuntu2.6), golang-1.6 (= 1.6.2-0ubuntu5~16.04.3), golang-defaults (= 2:1.6-1ubuntu4), libcap2 (= 1:2.24-12), libseccomp (= 2.2.3-3ubuntu3)
Homepage: https://github.com/snapcore/snapd
Bugs: https://bugs.launchpad.net/ubuntu/+filebug
Origin: Ubuntu
Supported: 5y
Task: ubuntu-core, ubuntu-desktop, ubuntu-usb, cloud-image, server, kubuntu-desktop, ubuntu-core, edubuntu-desktop, edubuntu-usb, xubuntu-core, xubuntu-desktop, mythbuntu-desktop, lubuntu-core, ubuntustudio-desktop-core, ubuntustudio-desktop, ubuntu-gnome-desktop, ubuntukylin-desktop, ubuntu-mate-core, ubuntu-mate-desktop, ubuntu-mate-cloudtop

Package: snapd
Priority: optional
Section: devel
Installed-Size: 60468
Maintainer: Ubuntu Developers <ubuntu-devel-discuss@lists.ubuntu.com>
Architecture: amd64
Version: 2.26.10
Replaces: snap-confine (<< 2.23), ubuntu-core-launcher (<< 2.22), ubuntu-snappy (<< 1.9), ubuntu-snappy-cli (<< 1.9)
Depends: adduser, apparmor (>= 2.10.95-0ubuntu2.2), ca-certificates, gnupg1 | gnupg, openssh-client, squashfs-tools, systemd, init-system-helpers (>= 1.18~), libc6 (>= 2.17), libudev1 (>= 183)
Conflicts: snap (<< 2013-11-29-1ubuntu1)
Breaks: snap-confine (<< 2.23), ubuntu-core-launcher (<< 2.22), ubuntu-snappy (<< 1.9), ubuntu-snappy-cli (<< 1.9)
Filename: pool/main/s/snapd/snapd_2.26.10_amd64.deb
Size: 10113204
MD5sum: 4a634f7769c934a36e93982af89de93b
SHA1: 5417986cabb9aadd4fd25f07308d421141bc7839
SHA256: 0f23b823f5cd70418b4e64d01a2042ff6cc138649d274281b5033f0e6de3ffb1
Description-en: Tool to interact with Ubuntu Core Snappy.
 Install, configure, refresh and remove snap packages. Snaps are
 'universal' packages that work across many different Linux systems,
 enabling secure distribution of the latest apps and utilities for
 cloud, servers, desktops and the internet of things.
 .
 This is the CLI for snapd, a background service that takes care of
 snaps on the system. Start with 'snap list' to see installed snaps.
Description-md5: ad5806e76513cff3a5382bff8123a97a
Built-Using: apparmor (= 2.10.95-0ubuntu2.6), golang-1.6 (= 1.6.2-0ubuntu5~16.04.3), golang-defaults (= 2:1.6-1ubuntu4), libcap2 (= 1:2.24-12), libseccomp (= 2.2.3-3ubuntu3)
Homepage: https://github.com/snapcore/snapd
Bugs: https://bugs.launchpad.net/ubuntu/+filebug
Origin: Ubuntu
Supported: 5y
Task: ubuntu-core, ubuntu-desktop, ubuntu-usb, cloud-image, server, kubuntu-desktop, ubuntu-core, edubuntu-desktop, edubuntu-usb, xubuntu-core, xubuntu-desktop, mythbuntu-desktop, lubuntu-core, ubuntustudio-desktop-core, ubuntustudio-desktop, ubuntu-gnome-desktop, ubuntukylin-desktop, ubuntu-mate-core, ubuntu-mate-desktop, ubuntu-mate-cloudtop

Package: snapd
Priority: optional
Section: devel
Installed-Size: 18536
Maintainer: Ubuntu Developers <ubuntu-devel-discuss@lists.ubuntu.com>
Architecture: amd64
Version: 2.0.2
Replaces: ubuntu-snappy (<< 1.9), ubuntu-snappy-cli (<< 1.9)
Depends: init-system-helpers (>= 1.18~), libc6 (>= 2.4), adduser, lsb-release, squashfs-tools, ubuntu-core-launcher (>= 1.0.23)
Conflicts: snap (<< 2013-11-29-1ubuntu1), snappy
Breaks: ubuntu-snappy (<< 1.9), ubuntu-snappy-cli (<< 1.9)
Filename: pool/main/s/snapd/snapd_2.0.2_amd64.deb
Size: 4010516
MD5sum: 45b58056b9107a47e185f4a9069e5044
SHA1: 003a857233ebd9315c4d5e86efea8015f1d0f28a
SHA256: 27507f566e314d3f1f65b609c7007b69b69249d82233bbfbd1d8a507eeda9d24
Description-en: Tool to interact with Ubuntu Core Snappy.
 Manage an Ubuntu system with snappy.
Description-md5: 364ba9499ea9442fb2a40f0fe7925d19
Built-Using: golang-1.6 (= 1.6.1-0ubuntu1), golang-check.v1 (= 0.0+git20150729.11d3bc7-2), golang-defaults (= 2:1.6-1ubuntu4), golang-github-coreos-go-systemd (= 3-2), golang-github-gorilla-mux (= 0.0~git20150814.0.f7b6aaa-1), golang-github-gosexy-gettext (= 0~git20130221-0ubuntu6), golang-github-mvo5-goconfigparser (= 0.2.1-0ubuntu1), golang-github-mvo5-uboot-go (= 0~3.git69978a3-0ubuntu5), golang-github-peterh-liner (= 0.0~git20151118.0.4d47685-1), golang-go-flags (= 0.0~git20160302-0ubuntu1), golang-go.crypto (= 1:0.0~git20151201.0.7b85b09-2), golang-gopkg-tomb.v2 (= 0.0~git20140626.14b3d72-1), golang-pb (= 0.0~git20131219-1), golang-pty (= 0.0~git20150511.1.5cf931e-1ubuntu1), golang-websocket (= 0.0~git20150811.0.b6ab76f-1), golang-yaml.v2 (= 0.0+git20160301.0.a83829b-1)
Homepage: https://github.com/ubuntu-core/snappy
Bugs: https://bugs.launchpad.net/ubuntu/+filebug
Origin: Ubuntu
Supported: 5y
Task: ubuntu-core, ubuntu-desktop, ubuntu-usb, cloud-image, server, kubuntu-desktop, ubuntu-core, edubuntu-desktop, edubuntu-usb, xubuntu-core, xubuntu-desktop, mythbuntu-desktop, lubuntu-core, ubuntustudio-desktop-core, ubuntustudio-desktop, ubuntu-gnome-desktop, ubuntukylin-desktop, ubuntu-mate-core, ubuntu-mate-desktop, ubuntu-mate-cloudtop
$ snap info core
name:      core
summary:   "snapd runtime environment"
publisher: canonical
contact:   snappy-canonical-storeaccount@canonical.com
description: |
  The core runtime environment for snapd
type:        core
snap-id:     99T7MUlRhtI3U0QFgl5mXXESAiSwt776
tracking:    stable
installed:   16-2.26.14 (2462) 84MB core
refreshed:   2017-07-20 14:45:34 +0200 CEST
channels:                                    
  stable:    16-2.26.14               (2462) 84MB -
  candidate: 16-2.27.2                (2677) 85MB -
  beta:      16-2.27.2                (2677) 85MB -
  edge:      16-2.27.3+git329.f905257 (2720) 86MB -

If somebody wants access to the whole journal log, please ping me.

I didn’t tried to see what happens on next system reboot.

regards,
Simon

I tried to reproduce this in an up-to-date VM with:

# install hello-world and core from stable
$ sudo snap install hello-world
hello-world 6.3 from 'canonical' installed

# start with snapd from xenial-updates
$ apt-cache policy snapd
snapd:
  Installed: 2.27.3
  Candidate: 2.27.3
  Version table:
     2.27.3 500
        500 http://us.archive.ubuntu.com/ubuntu xenial-proposed/main amd64 Packages
        100 /var/lib/dpkg/status
 *** 2.26.10 500
        500 http://us.archive.ubuntu.com/ubuntu xenial-updates/main amd64 Packages
     2.0.2 500
        500 http://us.archive.ubuntu.com/ubuntu xenial/main amd64 Packages

# upgrade to snapd in xenial-proposed
$ sudo apt-get install snapd

The following packages will be upgraded:
  snapd
1 upgraded, 0 newly installed, 0 to remove and 61 not upgraded.
Need to get 10.9 MB of archives.
After this operation, 4,456 kB of additional disk space will be used.
Get:1 http://us.archive.ubuntu.com/ubuntu xenial-proposed/main amd64 snapd amd64 2.27.3 [10.9 MB]
Fetched 10.9 MB in 2s (5,293 kB/s)
(Reading database ... 213617 files and directories currently installed.)
Preparing to unpack .../snapd_2.27.3_amd64.deb ...
Warning: Stopping snapd.service, but it can still be activated by:
  snapd.socket
Unpacking snapd (2.27.3) over (2.26.10) ...
Processing triggers for man-db (2.7.5-1) ...
Setting up snapd (2.27.3) ...
Installing new version of config file /etc/apparmor.d/usr.lib.snapd.snap-confine.real ...

# verify the profile on disk was updated with the nsswitch.conf rule
$ grep nsswitch.conf /etc/apparmor.d/usr.lib.snapd.snap-confine.real |grep bind
    mount options=(rw bind) /snap/{,ubuntu-}core/*/etc/nsswitch.conf -> /tmp/snap.rootfs_*/etc/nsswitch.conf,

# verify the profile as loaded
$ grep profile_replace /var/log/syslog
Aug 23 06:55:19 sec-xenial-amd64 kernel: [  122.881809] audit: type=1400 audit(1503489319.220:38): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/snap/core/2462/usr/lib/snapd/snap-confine" pid=2458 comm="apparmor_parser"
Aug 23 06:55:19 sec-xenial-amd64 kernel: [  122.882055] audit: type=1400 audit(1503489319.220:39): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/snap/core/2462/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=2458 comm="apparmor_parser"
Aug 23 06:55:19 sec-xenial-amd64 kernel: [  123.062991] audit: type=1400 audit(1503489319.400:40): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.core.hook.configure" pid=2460 comm="apparmor_parser"
Aug 23 06:55:19 sec-xenial-amd64 kernel: [  123.433509] audit: type=1400 audit(1503489319.772:41): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.hello-world.env" pid=2465 comm="apparmor_parser"
Aug 23 06:55:19 sec-xenial-amd64 kernel: [  123.501987] audit: type=1400 audit(1503489319.840:42): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.hello-world.evil" pid=2467 comm="apparmor_parser"
Aug 23 06:55:19 sec-xenial-amd64 kernel: [  123.588710] audit: type=1400 audit(1503489319.928:43): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.hello-world.hello-world" pid=2469 comm="apparmor_parser"
Aug 23 06:55:20 sec-xenial-amd64 kernel: [  123.669787] audit: type=1400 audit(1503489320.008:44): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.hello-world.sh" pid=2471 comm="apparmor_parser"
Aug 23 06:55:20 sec-xenial-amd64 kernel: [  124.545800] audit: type=1400 audit(1503489320.885:45): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/snapd/snap-confine" pid=2530 comm="apparmor_parser"
Aug 23 06:55:20 sec-xenial-amd64 kernel: [  124.545988] audit: type=1400 audit(1503489320.885:46): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=2530 comm="apparmor_parser"

# verify the cache was updated
$ stat /etc/apparmor.d/usr.lib.snapd.snap-confine.real /etc/apparmor.d/cache/usr.lib.snapd.snap-confine.real 
  File: '/etc/apparmor.d/usr.lib.snapd.snap-confine.real'
  Size: 15854     	Blocks: 32         IO Block: 4096   regular file
Device: fd01h/64769d	Inode: 267215      Links: 1
Access: (0644/-rw-r--r--)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2017-08-23 06:55:20.777424973 -0500
Modify: 2017-08-18 09:43:14.000000000 -0500
Change: 2017-08-23 06:55:17.671006986 -0500
 Birth: -
  File: '/etc/apparmor.d/cache/usr.lib.snapd.snap-confine.real'
  Size: 52914     	Blocks: 104        IO Block: 4096   regular file
Device: fd01h/64769d	Inode: 267146      Links: 1
Access: (0600/-rw-------)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2017-08-23 06:55:20.777424973 -0500
Modify: 2017-08-18 09:43:14.000000000 -0500
Change: 2017-08-23 06:55:20.885504139 -0500
 Birth: -

# verify snaps launch
$ hello-world
Hello World!

# reboot and verify snaps launch
$ hello-world
Hello World!

$ snap list
Name         Version     Rev   Developer  Notes
core         16-2.26.14  2462  canonical  core
hello-world  6.3         27    canonical  -

$ snap --version
snap    2.27.3
snapd   2.27.3
series  16
ubuntu  16.04
kernel  4.4.0-92-generic

I then reverted the VM and tried to reproduce this in an up-to-date VM with a core from edge:

$ sudo snap install core --edge
core (edge) 16-2.27.3+git329.f905257 from 'canonical' installed
$ sudo snap install hello-world
hello-world 6.3 from 'canonical' installed

# start with snapd from xenial-updates
$ apt-cache policy snapd
snapd:
  Installed: 2.26.10
  Candidate: 2.27.3
  Version table:
     2.27.3 500
        500 http://us.archive.ubuntu.com/ubuntu xenial-proposed/main amd64 Packages
 *** 2.26.10 500
        500 http://us.archive.ubuntu.com/ubuntu xenial-updates/main amd64 Packages
        100 /var/lib/dpkg/status
     2.0.2 500
        500 http://us.archive.ubuntu.com/ubuntu xenial/main amd64 Package

# upgrade to snapd in xenial-proposed
$ sudo apt-get install snapd
Reading package lists... Done
Building dependency tree       
Reading state information... Done
The following packages will be upgraded:
  snapd
1 upgraded, 0 newly installed, 0 to remove and 61 not upgraded.
Need to get 10.9 MB of archives.
After this operation, 4,456 kB of additional disk space will be used.
Get:1 http://us.archive.ubuntu.com/ubuntu xenial-proposed/main amd64 snapd amd64 2.27.3 [10.9 MB]
Fetched 10.9 MB in 1s (9,420 kB/s)
(Reading database ... 213617 files and directories currently installed.)
Preparing to unpack .../snapd_2.27.3_amd64.deb ...
Warning: Stopping snapd.service, but it can still be activated by:
  snapd.socket
Unpacking snapd (2.27.3) over (2.26.10) ...
Processing triggers for man-db (2.7.5-1) ...
Setting up snapd (2.27.3) ...
Installing new version of config file /etc/apparmor.d/usr.lib.snapd.snap-confine.real ...

# verify the profile on disk was updated with the nsswitch.conf rule
$ grep nsswitch.conf /etc/apparmor.d/usr.lib.snapd.snap-confine.real |grep bind
    mount options=(rw bind) /snap/{,ubuntu-}core/*/etc/nsswitch.conf -> /tmp/snap.rootfs_*/etc/nsswitch.conf,

# verify the profile as loaded
$ grep profile_replace /var/log/syslog
Aug 23 07:11:36 sec-xenial-amd64 kernel: [  257.292380] audit: type=1400 audit(1503490296.695:37): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/snap/core/2720/usr/lib/snapd/snap-confine" pid=2436 comm="apparmor_parser"
Aug 23 07:11:36 sec-xenial-amd64 kernel: [  257.292570] audit: type=1400 audit(1503490296.695:38): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/snap/core/2720/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=2436 comm="apparmor_parser"
Aug 23 07:11:36 sec-xenial-amd64 kernel: [  257.295438] audit: type=1400 audit(1503490296.699:39): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.core.hook.configure" pid=2438 comm="apparmor_parser"
Aug 23 07:11:37 sec-xenial-amd64 kernel: [  257.729643] audit: type=1400 audit(1503490297.131:40): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.hello-world.env" pid=2443 comm="apparmor_parser"
Aug 23 07:11:37 sec-xenial-amd64 kernel: [  257.738669] audit: type=1400 audit(1503490297.143:41): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.hello-world.evil" pid=2445 comm="apparmor_parser"
Aug 23 07:11:37 sec-xenial-amd64 kernel: [  257.744511] audit: type=1400 audit(1503490297.147:42): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.hello-world.hello-world" pid=2447 comm="apparmor_parser"
Aug 23 07:11:37 sec-xenial-amd64 kernel: [  257.748764] audit: type=1400 audit(1503490297.151:43): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.hello-world.sh" pid=2449 comm="apparmor_parser"
Aug 23 07:11:37 sec-xenial-amd64 kernel: [  258.548409] audit: type=1400 audit(1503490297.951:44): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/snapd/snap-confine" pid=2509 comm="apparmor_parser"
Aug 23 07:11:37 sec-xenial-amd64 kernel: [  258.548606] audit: type=1400 audit(1503490297.951:45): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=2509 comm="apparmor_parser"

# verify the cache was updated
$ stat /etc/apparmor.d/usr.lib.snapd.snap-confine.real /etc/apparmor.d/cache/usr.lib.snapd.snap-confine.real 
  File: '/etc/apparmor.d/usr.lib.snapd.snap-confine.real'
  Size: 15854     	Blocks: 32         IO Block: 4096   regular file
Device: fd01h/64769d	Inode: 267215      Links: 1
Access: (0644/-rw-r--r--)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2017-08-23 07:11:37.847328533 -0500
Modify: 2017-08-18 09:43:14.000000000 -0500
Change: 2017-08-23 07:11:34.907305449 -0500
 Birth: -
  File: '/etc/apparmor.d/cache/usr.lib.snapd.snap-confine.real'
  Size: 52914     	Blocks: 104        IO Block: 4096   regular file
Device: fd01h/64769d	Inode: 267146      Links: 1
Access: (0600/-rw-------)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2017-08-23 07:11:37.847328533 -0500
Modify: 2017-08-18 09:43:14.000000000 -0500
Change: 2017-08-23 07:11:37.951329327 -0500
 Birth: -

# verify snaps launch
$ hello-world
Hello World!

# reboot and verify snaps launch
$ hello-world
Hello World!

$ snap list
Name         Version                   Rev   Developer  Notes
core         16-2.27.3+git329.f905257  2720  canonical  core
hello-world  6.3                       27    canonical  -
$ snap --version
snap    2.27.3+git329.f905257~ubuntu16.04.1
snapd   2.27.3+git329.f905257~ubuntu16.04.1
series  16
ubuntu  16.04
kernel  4.4.0-92-generic

At this point I am not able to reproduce. We can see that when upgrading from 2.26.10, things work correctly. We see that the reexec profile from /snap/core is being loaded (name="/snap/core/2462/usr/lib/snapd/snap-confine"), the app profiles loaded (these are from snapd restart) and that the /etc/apparmor.d/usr.lib.snapd.snap-confine.real profile is being loaded (name="/usr/lib/snapd/snap-confine").

We also see from the reported denial:

Aug 23 11:58:56 nirvana audit[21476]: AVC apparmor="DENIED" operation="mount" info="failed srcname match" error=-13 profile="/usr/lib/snapd/snap-confine" name="/tmp/snap.rootfs_jxIslj/etc/nsswitch.conf" pid=21476 comm="snap-confine" srcname="/snap/core/2462/etc/nsswitch.conf" flags="rw, bind"

that profile="/usr/lib/snapd/snap-confine" which means that /usr/lib/snapd/snap-confine was used, not the SNAP_REEXEC’d snap-confine from core.

What is the output of stat /etc/apparmor.d/usr.lib.snapd.snap-confine.real /etc/apparmor.d/cache/usr.lib.snapd.snap-confine.real?

This is a non-standard kernel. Where did you get it? What is the output of ls -1R /sys/kernel/security/apparmor/features/? It should match:

$ ls -1R /sys/kernel/security/apparmor/features/
/sys/kernel/security/apparmor/features/:
capability
caps
dbus
domain
file
mount
namespaces
network
policy
ptrace
rlimit
signal

/sys/kernel/security/apparmor/features/caps:
mask

/sys/kernel/security/apparmor/features/dbus:
mask

/sys/kernel/security/apparmor/features/domain:
change_hat
change_hatv
change_onexec
change_profile
stack
version

/sys/kernel/security/apparmor/features/file:
mask

/sys/kernel/security/apparmor/features/mount:
mask

/sys/kernel/security/apparmor/features/namespaces:
pivot_root
profile

/sys/kernel/security/apparmor/features/network:
af_mask
af_unix

/sys/kernel/security/apparmor/features/policy:
set_load
versions

/sys/kernel/security/apparmor/features/policy/versions:
v5
v6
v7

/sys/kernel/security/apparmor/features/ptrace:
mask

/sys/kernel/security/apparmor/features/rlimit:
mask

/sys/kernel/security/apparmor/features/signal:
mask

This is the HWE kernel from the xenial archive:

$ apt-cache show linux-image-4.10.0-30-generic
Package: linux-image-4.10.0-30-generic
Priority: optional
Section: kernel
Installed-Size: 68419
Maintainer: Ubuntu Kernel Team <kernel-team@lists.ubuntu.com>
Architecture: amd64
Source: linux-hwe
Version: 4.10.0-30.34~16.04.1
Provides: fuse-module, ivtv-modules, kvm-api-4, linux-image, redhat-cluster-modules, spl-dkms, spl-modules, virtualbox-guest-modules, zfs-dkms, zfs-modules
Depends: initramfs-tools | linux-initramfs-tool, kmod
Recommends: grub-pc | grub-efi-amd64 | grub-efi-ia32 | grub | lilo
Suggests: fdutils, linux-tools, linux-headers-4.10.0-30-generic
Filename: pool/main/l/linux-hwe/linux-image-4.10.0-30-generic_4.10.0-30.34~16.04.1_amd64.deb
Size: 20159210
MD5sum: d5e3b4986146e4531894e36b8a45f456
SHA1: 660b24090a5d7ef221035667d6ead128513e9fa7
SHA256: c41a5d149586546fd051f1d396da699036424d5ddb623134f3e863ed598f9341
Description-en: Linux kernel image for version 4.10.0 on 64 bit x86 SMP
 This package contains the Linux kernel image for version 4.10.0 on
 64 bit x86 SMP.
 .
 Also includes the corresponding System.map file, the modules built by the
 packager, and scripts that try to ensure that the system is not left in an
 unbootable state after an update.
 .
 Supports Generic processors.
 .
 Geared toward desktop and server systems.
 .
 You likely do not want to install this package directly. Instead, install
 the linux-generic meta-package, which will ensure that upgrades work
 correctly, and that supporting packages are also installed.
Description-md5: 714888c26c02c3dcd7938f6495920e2f
Bugs: https://bugs.launchpad.net/ubuntu/+filebug
Origin: Ubuntu
Supported: 5y

Installed with apt install linux-image-generic-hwe-16.04

Output from ls -1R /sys/kernel/security/apparmor/features:

/sys/kernel/security/apparmor/features/:
capability
caps
dbus
domain
file
mount
namespaces
network
policy
ptrace
query
rlimit
signal

/sys/kernel/security/apparmor/features/caps:
mask

/sys/kernel/security/apparmor/features/dbus:
mask

/sys/kernel/security/apparmor/features/domain:
change_hat
change_hatv
change_onexec
change_profile
fix_binfmt_elf_mmap
stack
version

/sys/kernel/security/apparmor/features/file:
mask

/sys/kernel/security/apparmor/features/mount:
mask

/sys/kernel/security/apparmor/features/namespaces:
pivot_root
profile

/sys/kernel/security/apparmor/features/network:
af_mask
af_unix

/sys/kernel/security/apparmor/features/policy:
set_load
versions

/sys/kernel/security/apparmor/features/policy/versions:
v5
v6
v7

/sys/kernel/security/apparmor/features/ptrace:
mask

/sys/kernel/security/apparmor/features/query:
label

/sys/kernel/security/apparmor/features/query/label:
data
perms

/sys/kernel/security/apparmor/features/rlimit:
mask

/sys/kernel/security/apparmor/features/signal:
mask
# This is AFTER I did apparmor_parser -r /etc/apparmor.d/usr.lib.snapd.snap-confine.real
$ stat /etc/apparmor.d/usr.lib.snapd.snap-confine.real /etc/apparmor.d/cache/usr.lib.snapd.snap-confine.real                                                                                                           
  File: '/etc/apparmor.d/usr.lib.snapd.snap-confine.real'
  Size: 15854     	Blocks: 32         IO Block: 4096   regular file
Device: fd01h/64769d	Inode: 33077730    Links: 1
Access: (0644/-rw-r--r--)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2017-08-23 09:29:53.583297634 +0200
Modify: 2017-08-18 16:43:14.000000000 +0200
Change: 2017-08-23 09:29:40.971287583 +0200
 Birth: -
  File: '/etc/apparmor.d/cache/usr.lib.snapd.snap-confine.real'
  Size: 52914     	Blocks: 104        IO Block: 4096   regular file
Device: fd01h/64769d	Inode: 33035741    Links: 1
Access: (0600/-rw-------)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2017-08-23 10:57:21.315748439 +0200
Modify: 2017-08-18 16:43:14.000000000 +0200
Change: 2017-08-23 09:29:53.791297800 +0200
 Birth: -

The apparmor_parser -r won’t update the cache file-- you need -W for that. The reboot would’ve caused the apparmor cache to be updated though. The stat looks fine right now (the mtimes are correctly the same, which indicates that the parser used /etc/apparmor.d/usr.lib.snapd.snap-confine.real to create /etc/apparmor.d/cache/usr.lib.snapd.snap-confine.real (apparmor_parser copies the mtime of the profile it loaded when -W is specified).

Also, this mtime on your device matches the mtime on my VM where it worked correctly: 2017-08-18 09:43:14.000000000 -0500 which indicates that .real and the cache files are correct.

I did notice in /var/lib/dpkg/info/snapd.postinst that the apparmor_parser command is run after the snapd systemd start. Reading setupSnapConfineReexec() in interfaces/apparmor/backend.go, snapd will not load /etc/apparmor.d/usr.lib.snapd.snap-confine.real or update /etc/apparmor.d/cache/usr.lib.snapd.snap-confine.real under any circumstances (it deals only with loading /etc/apparmor.d/snap.core.*.usr.lib.snapd.snap-confine). This means that between when the deb is unpacked and when the updated profile is loaded and cache is updated, there is a window where if a snap is started (or refreshed) the new snap-confine on disk will run under the currently loaded profile in the kernel instead of the new one.

I suspect if we change debian/rules to call dh_apparmor before dh_installinit, this will order the postinst correctly so that the updated snap-confine profile will always be loaded before snapd is started, therefore a snap can’t refresh or start with the old profile, because snaps can’t refresh or start without snapd running.

Looking at debian/rules, we have overrides for override_dh_installinit and override_dh_install and based on the current postinst, it appears that dh_installinit is added before dh_install scripts, so moving the contents of override_dh_install into override_dh_installinit before the call to dh_installinit should fix the ordering. This can be verified by examining /var/lib/dpkg/info/snapd.postinst.