apparmor logs filled when ubuntu store launches

[Sam]

When I launch the Ubuntu snap store from my favorites, the following lines appear in dmesg.

[38514.879381] audit: type=1400 audit(1588562964.269:5985): apparmor="DENIED" operation="open" profile="snap.snap-store.ubuntu-software" name="/var/lib/snapd/hostfs/usr/share/mime/mime.cache" pid=17441 comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
[38514.879402] audit: type=1400 audit(1588562964.269:5986): apparmor="DENIED" operation="open" profile="snap.snap-store.ubuntu-software" name="/var/lib/snapd/hostfs/usr/share/mime/globs2" pid=17441 comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
[38514.879426] audit: type=1400 audit(1588562964.269:5987): apparmor="DENIED" operation="open" profile="snap.snap-store.ubuntu-software" name="/var/lib/snapd/hostfs/usr/share/mime/magic" pid=17441 comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
[38514.879443] audit: type=1400 audit(1588562964.269:5988): apparmor="DENIED" operation="open" profile="snap.snap-store.ubuntu-software" name="/var/lib/snapd/hostfs/usr/share/mime/aliases" pid=17441 comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
[38514.879459] audit: type=1400 audit(1588562964.269:5989): apparmor="DENIED" operation="open" profile="snap.snap-store.ubuntu-software" name="/var/lib/snapd/hostfs/usr/share/mime/subclasses" pid=17441 comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
[38514.879474] audit: type=1400 audit(1588562964.269:5990): apparmor="DENIED" operation="open" profile="snap.snap-store.ubuntu-software" name="/var/lib/snapd/hostfs/usr/share/mime/icons" pid=17441 comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
[38514.879488] audit: type=1400 audit(1588562964.269:5991): apparmor="DENIED" operation="open" profile="snap.snap-store.ubuntu-software" name="/var/lib/snapd/hostfs/usr/share/mime/generic-icons" pid=17441 comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
[38514.880255] audit: type=1400 audit(1588562964.269:5992): apparmor="DENIED" operation="open" profile="snap.snap-store.ubuntu-software" name="/etc/gnome/defaults.list" pid=17441 comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
[38514.961031] audit: type=1400 audit(1588562964.349:5993): apparmor="DENIED" operation="open" profile="snap.snap-store.ubuntu-software" name="/var/lib/snapd/hostfs/usr/share/mime/mime.cache" pid=2467 comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
[38514.961038] audit: type=1400 audit(1588562964.349:5994): apparmor="DENIED" operation="open" profile="snap.snap-store.ubuntu-software" name="/var/lib/snapd/hostfs/usr/share/mime/globs2" pid=2467 comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0

Adding these lines:

  /var/lib/snapd/hostfs/usr/share/mime/* r,
  /etc/gnome/defaults.list r,

to /var/lib/snapd/apparmor/profiles/snap.snap-store.ubuntu-software

made the messages go away.

Further notes. https://ubuntuforums.org/showthread.php?t=2442426

[Sam (source-decays)]

Sent patch here.
https://bazaar.launchpad.net/~sklein/snapd/snapd/revision/4829

[Ian Johnson (anonymouse67)]

Hi, we use GitHub for snapd source control, could you submit your patch to
github.com/snapcore/snapd instead?

Thanks,
Ian

On Mon, May 4, 2020, 16:15 Launchpad Bug Tracker <email address hidden>
wrote:

> ** Branch linked: lp:~sklein/snapd/snapd
>
> --
> You received this bug notification because you are subscribed to snapd.
> Matching subscriptions: snapd-all-bugs
> https://bugs.launchpad.net/bugs/1876804
>
> Title:
> apparmor logs filled when ubuntu store launches
>
> Status in snapd:
> New
>
> Bug description:
> When I launch the Ubuntu snap store from my favorites, the following
> lines appear in dmesg.
>
> [38514.879381] audit: type=1400 audit(1588562964.269:5985):
> apparmor="DENIED" operation="open"
> profile="snap.snap-store.ubuntu-software"
> name="/var/lib/snapd/hostfs/usr/share/mime/mime.cache" pid=17441
> comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
> [38514.879402] audit: type=1400 audit(1588562964.269:5986):
> apparmor="DENIED" operation="open"
> profile="snap.snap-store.ubuntu-software"
> name="/var/lib/snapd/hostfs/usr/share/mime/globs2" pid=17441
> comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
> [38514.879426] audit: type=1400 audit(1588562964.269:5987):
> apparmor="DENIED" operation="open"
> profile="snap.snap-store.ubuntu-software"
> name="/var/lib/snapd/hostfs/usr/share/mime/magic" pid=17441
> comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
> [38514.879443] audit: type=1400 audit(1588562964.269:5988):
> apparmor="DENIED" operation="open"
> profile="snap.snap-store.ubuntu-software"
> name="/var/lib/snapd/hostfs/usr/share/mime/aliases" pid=17441
> comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
> [38514.879459] audit: type=1400 audit(1588562964.269:5989):
> apparmor="DENIED" operation="open"
> profile="snap.snap-store.ubuntu-software"
> name="/var/lib/snapd/hostfs/usr/share/mime/subclasses" pid=17441
> comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
> [38514.879474] audit: type=1400 audit(1588562964.269:5990):
> apparmor="DENIED" operation="open"
> profile="snap.snap-store.ubuntu-software"
> name="/var/lib/snapd/hostfs/usr/share/mime/icons" pid=17441
> comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
> [38514.879488] audit: type=1400 audit(1588562964.269:5991):
> apparmor="DENIED" operation="open"
> profile="snap.snap-store.ubuntu-software"
> name="/var/lib/snapd/hostfs/usr/share/mime/generic-icons" pid=17441
> comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
> [38514.880255] audit: type=1400 audit(1588562964.269:5992):
> apparmor="DENIED" operation="open"
> profile="snap.snap-store.ubuntu-software" name="/etc/gnome/defaults.list"
> pid=17441 comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000
> ouid=0
> [38514.961031] audit: type=1400 audit(1588562964.349:5993):
> apparmor="DENIED" operation="open"
> profile="snap.snap-store.ubuntu-software"
> name="/var/lib/snapd/hostfs/usr/share/mime/mime.cache" pid=2467
> comm="snap-store" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
> [38514.961038] audit: type=1400 audi...

[Sam (source-decays)]

Hi Ian,

I sent this pull request. https://github.com/snapcore/snapd/pull/8601

Thanks,
Sam

[Jamie Strandboge (jdstrand)]

Ken, I've added a new snap-store task and tentatively assigned it to you based on https://github.com/snapcore/snapd/pull/8609#pullrequestreview-419262316. Please adjust as needed.

I also marked the snapd task as Won't Fix for now, but we can reopen if necessary.

[Vasili Pupkin (vasilipupkin765)]

Will the snap-store be fixed or should I apply the patch and grant it access to those directories? Half a year have passed already and it still spoil the blog with thousands of warnings.

[Hannu E K N (hannu-n)]

Updated my Ubuntu to
 Ubuntu 20.04.1 LTS (Focal Fossa) / Linux wkbx 5.8.0-34-generic #37~20.04.2-Ubuntu SMP Thu Dec 17 14:53:00 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
from 5.4 today.

On reboot the login screen appears with 10-15 seconds, after entering the password,
I have a delay of up to 60 seconds before the desktop appears.
This 60 second delaywas created as I updated.

Attached you find a *.tgz file with dmesg:s for four reboots.

This appears as an issue with some config that got reset as the kernel was updated.
Going back to 5.4 does not solve the issue.
apt --reinstall of apparmor and snapd did not resolve it.

[Hannu E K N (hannu-n)]

One more reboot, decent timing, dmesg attached.
A race condition?

[Hannu E K N (hannu-n)]

dmesg still filled with "apparmor"-items, tgz file attached.

Extract in a temp-dir, then do

for file in dmesg* ; do echo -e "\n\n--- $file --- "; if [ "${file##*.}" == "gz" ] ; then zcat $file | grep 'type=1400' ;else cat $file | grep 'type=1400' ;fi ;done

All of these indicate a startup time <10s, but it still takes approx 60 seconds before the desktop appears. I suspect the apparmor-stuff to be the culprit.

[Hannu E K N (hannu-n)]

Ubuntu 20.04.1 LTS,
Linux wkbx 5.8.0-40-generic #45~20.04.1-Ubuntu SMP Fri Jan 15 11:35:04 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

More of the same as above.

[Hannu E K N (hannu-n)]

/var/log $ for file in dmesg* ; do echo -e "\n\n--- $file --- "; if [ "${file##*.}" == "gz" ] ; then zcat $file | grep 'type=1400' ;else cat $file | grep 'type=1400' ;fi ;done

--- dmesg ---
[ 6.251986] kernel: audit: type=1400 audit(1611934870.347:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="libreoffice-senddoc" pid=1220 comm="apparmor_parser"
[ 6.252398] kernel: audit: type=1400 audit(1611934870.347:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe" pid=1223 comm="apparmor_parser"
[ 6.252402] kernel: audit: type=1400 audit(1611934870.347:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe//kmod" pid=1223 comm="apparmor_parser"
[ 6.252826] kernel: audit: type=1400 audit(1611934870.347:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/man" pid=1219 comm="apparmor_parser"
[ 6.252829] kernel: audit: type=1400 audit(1611934870.347:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_filter" pid=1219 comm="apparmor_parser"
[ 6.252831] kernel: audit: type=1400 audit(1611934870.347:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_groff" pid=1219 comm="apparmor_parser"
[ 6.252991] kernel: audit: type=1400 audit(1611934870.347:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="libreoffice-oopslash" pid=1226 comm="apparmor_parser"
[ 6.254322] kernel: audit: type=1400 audit(1611934870.351:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/cups-browsed" pid=1225 comm="apparmor_parser"
[ 6.254777] kernel: audit: type=1400 audit(1611934870.351:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="ippusbxd" pid=1227 comm="apparmor_parser"
[ 6.255903] kernel: audit: type=1400 audit(1611934870.351:11): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/tcpdump" pid=1221 comm="apparmor_parser"

--- dmesg.0 ---
[ 6.340707] kernel: audit: type=1400 audit(1611693630.431:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="libreoffice-senddoc" pid=1152 comm="apparmor_parser"
[ 6.341402] kernel: audit: type=1400 audit(1611693630.431:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe" pid=1155 comm="apparmor_parser"
[ 6.341404] kernel: audit: type=1400 audit(1611693630.431:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe//kmod" pid=1155 comm="apparmor_parser"
[ 6.341828] kernel: audit: type=1400 audit(1611693630.435:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/man" pid=1151 comm="apparmor_parser"
[ 6.341831] kernel: audit: type=1400 audit(1611693630.435:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_filter" pid=1151 comm="apparmor_parser"
[ 6.341833] kernel: audit: type=1400 audit(1611693630.435:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_groff" pid=1151 comm="apparmor_parser"
[ 6.342673] kernel: audit: type=1400 aud...