I then lxc exec into that container to do:
$ snap refresh juju-db --channel 4.0/candidate
to move from 4.0.9 to 4.0.23
This still leaves me with a juju apiserver that doesn't respond, so I run
$ systemctl restart jujud-machine-0
Even with the 4.0.23 snap, I still see the same syslog DENIED messages. So it is consistent with even a rebuilt snap.
I don't think it is safe to switch to the 4.4.5 snap (since that would corrupt the DB), but just to see if it makes the errors go away:
root@juju-97ff2b-0:~# snap refresh juju-db --channel 4.4
error: cannot perform the following tasks:
- Mount snap "juju-db" (71) (cannot validate license "SSPL-1.0": unknown license: SSPL-1.0)
well, that means my snapd is also out of date:
root@juju-97ff2b-0:~# snap refresh snapd
2021-06-04T14:49:30Z INFO Waiting for automatic snapd restart...
snapd 2.50.1 from Canonical✓ refreshed
the errors are still happening, back to candidate?
Jun 4 10:52:30 focal kernel: [1156807.047474] audit: type=1400 audit(1622818350.139:1838962): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-juju-97ff2b-0_</var/snap/lxd/common/lxd>//&:lxd-juju-97ff2b-0_<var-snap-lxd-common-lxd>:unconfined" name="/snap/snapd/12057/usr/lib/snapd/snap-confine" pid=3427374 comm="apparmor_parser"
Jun 4 10:52:30 focal kernel: [1156807.047480] audit: type=1400 audit(1622818350.139:1838963): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-juju-97ff2b-0_</var/snap/lxd/common/lxd>//&:lxd-juju-97ff2b-0_<var-snap-lxd-common-lxd>:unconfined" name="/snap/snapd/12057/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=3427374 comm="apparmor_parser"
Jun 4 10:52:30 focal kernel: [1156807.156300] audit: type=1400 audit(1622818350.247:1838964): apparmor="STATUS" operation="profile_replace" label="lxd-juju-97ff2b-0_</var/snap/lxd/common/lxd>//&:lxd-juju-97ff2b-0_<var-snap-lxd-common-lxd>:unconfined" name="snap.juju-db.hook.configure" pid=3427377 comm="apparmor_parser"
Jun 4 10:52:30 focal kernel: [1156807.158750] audit: type=1400 audit(1622818350.251:1838965): apparmor="STATUS" operation="profile_replace" label="lxd-juju-97ff2b-0_</var/snap/lxd/common/lxd>//&:lxd-juju-97ff2b-0_<var-snap-lxd-common-lxd>:unconfined" name="snap.juju-db.hook.install" pid=3427378 comm="apparmor_parser"
It does seem to consider a new apparmor profile, but it seems to say there is no actual difference.
Jun 4 10:52:30 focal kernel: [1156807.204794] audit: type=1400 audit(1622818350.299:1838969): apparmor="STATUS" operation="profile_replace" label="lxd-juju-97ff2b-0_</var/snap/lxd/common/lxd>//&:lxd-juju-97ff2b-0_<var-snap-lxd-common-lxd>:unconfined" name="snap.juju-db.mongod" pid=3427380 comm="apparmor_parser"
Note that the error do stop until I restart jujud-machine-0
Right at the beginning after restart I see some other things that are denied:
Jun 4 10:54:31 focal kernel: [1156928.177399] audit: type=1400 audit(1622818471.275:1838976): apparmor="DENIED" operation="file_inherit" namespace="root//lxd-juju-97ff2b-0_<var-snap-lxd-common-lxd>" profile="/snap/snapd/12057/usr/lib/snapd/snap-confine" pid=3428342 comm="snap-confine" family="netlink" sock_type="raw" protocol=15 requested_mask="send receive" denied_mask="send receive"
Jun 4 10:54:31 focal kernel: [1156928.182426] audit: type=1400 audit(1622818471.279:1838977): apparmor="DENIED" operation="file_inherit" namespace="root//lxd-juju-97ff2b-0_<var-snap-lxd-common-lxd>" profile="snap.juju-db.hook.configure" name="/apparmor/.null" pid=3428342 comm="snap-exec" requested_mask="wr" denied_mask="wr" fsuid=1000000 ouid=0
Jun 4 10:54:33 focal kernel: [1156930.069462] audit: type=1400 audit(1622818473.167:1838978): apparmor="DENIED" operation="open" namespace="root//lxd-juju-97ff2b-0_<var-snap-lxd-common-lxd>" profile="snap.juju-db.daemon" name="/sys/block/" pid=3428428 comm="mongod" requested_mask="r" denied_mask="r" fsuid=1000000 ouid=0
Jun 4 10:54:34 focal kernel: [1156930.916199] audit: type=1400 audit(1622818474.011:1838979): apparmor="DENIED" operation="open" namespace="root//lxd-juju-97ff2b-0_<var-snap-lxd-common-lxd>" profile="snap.juju-db.daemon" name="/proc/6443/net/netstat" pid=3428428 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=1000000 ouid=1000000
Jun 4 10:54:34 focal kernel: [1156930.916211] audit: type=1400 audit(1622818474.011:1838980): apparmor="DENIED" operation="open" namespace="root//lxd-juju-97ff2b-0_<var-snap-lxd-common-lxd>" profile="snap.juju-db.daemon" name="/proc/6443/net/snmp" pid=3428428 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=1000000 ouid=1000000
Jun 4 10:54:34 focal kernel: [1156930.916217] audit: type=1400 audit(1622818474.011:1838981): apparmor="DENIED" operation="open" namespace="root//lxd-juju-97ff2b-0_<var-snap-lxd-common-lxd>" profile="snap.juju-db.daemon" name="/proc/vmstat" pid=3428428 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=1000000 ouid=0
But those aren't triggered approximately every second.
I do see the ongoing net/stat issues, and I did confirm (again) that
# pgrep mongod
6443
matches
Jun 4 10:55:32 focal kernel: [1156988.903111] audit: type=1400 audit(1622818531.998:1839153): apparmor="DENIED" operation="open" namespace="root//lxd-juju-97ff2b-0_<var-snap-lxd-common-lxd>" profile="snap.juju-db.daemon" name="/proc/6443/net/netstat" pid=3428428 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=1000000 ouid=1000000
And outside the container:
$ pgrep mongod
3428428
so the log line says it is denying 'pid=3428428' from reading '/proc/6443' which very much matches the pid inside and outside of the container.
And now to try 4.4
root@juju-97ff2b-0:~# snap refresh juju-db --channel 4.4
I then lxc exec into that container to do:
$ snap refresh juju-db --channel 4.0/candidate
to move from 4.0.9 to 4.0.23
This still leaves me with a juju apiserver that doesn't respond, so I run
$ systemctl restart jujud-machine-0
Even with the 4.0.23 snap, I still see the same syslog DENIED messages. So it is consistent with even a rebuilt snap.
I don't think it is safe to switch to the 4.4.5 snap (since that would corrupt the DB), but just to see if it makes the errors go away: 97ff2b- 0:~# snap refresh juju-db --channel 4.4
root@juju-
error: cannot perform the following tasks:
- Mount snap "juju-db" (71) (cannot validate license "SSPL-1.0": unknown license: SSPL-1.0)
well, that means my snapd is also out of date: 97ff2b- 0:~# snap refresh snapd 04T14:49: 30Z INFO Waiting for automatic snapd restart...
root@juju-
2021-06-
snapd 2.50.1 from Canonical✓ refreshed
that, in itself, did not fix the apparmor issues
root@juju- 97ff2b- 0:~# snap refresh juju-db --channel 4.0/stable
juju-db (4.0/stable) 4.0.9 from Canonical Juju QA Bot (juju-qa) refreshed
$ systemctl restart jujud-machine-0
the errors are still happening, back to candidate?
Jun 4 10:52:30 focal kernel: [1156807.047474] audit: type=1400 audit(162281835 0.139:1838962) : apparmor="STATUS" operation= "profile_ replace" info="same as current profile, skipping" label=" lxd-juju- 97ff2b- 0_</var/ snap/lxd/ common/ lxd>//& :lxd-juju- 97ff2b- 0_<var- snap-lxd- common- lxd>:unconfined " name="/ snap/snapd/ 12057/usr/ lib/snapd/ snap-confine" pid=3427374 comm="apparmor_ parser" 0.139:1838963) : apparmor="STATUS" operation= "profile_ replace" info="same as current profile, skipping" label=" lxd-juju- 97ff2b- 0_</var/ snap/lxd/ common/ lxd>//& :lxd-juju- 97ff2b- 0_<var- snap-lxd- common- lxd>:unconfined " name="/ snap/snapd/ 12057/usr/ lib/snapd/ snap-confine/ /mount- namespace- capture- helper" pid=3427374 comm="apparmor_ parser" 0.247:1838964) : apparmor="STATUS" operation= "profile_ replace" label=" lxd-juju- 97ff2b- 0_</var/ snap/lxd/ common/ lxd>//& :lxd-juju- 97ff2b- 0_<var- snap-lxd- common- lxd>:unconfined " name="snap. juju-db. hook.configure" pid=3427377 comm="apparmor_ parser" 0.251:1838965) : apparmor="STATUS" operation= "profile_ replace" label=" lxd-juju- 97ff2b- 0_</var/ snap/lxd/ common/ lxd>//& :lxd-juju- 97ff2b- 0_<var- snap-lxd- common- lxd>:unconfined " name="snap. juju-db. hook.install" pid=3427378 comm="apparmor_ parser"
Jun 4 10:52:30 focal kernel: [1156807.047480] audit: type=1400 audit(162281835
Jun 4 10:52:30 focal kernel: [1156807.156300] audit: type=1400 audit(162281835
Jun 4 10:52:30 focal kernel: [1156807.158750] audit: type=1400 audit(162281835
It does seem to consider a new apparmor profile, but it seems to say there is no actual difference. 0.299:1838969) : apparmor="STATUS" operation= "profile_ replace" label=" lxd-juju- 97ff2b- 0_</var/ snap/lxd/ common/ lxd>//& :lxd-juju- 97ff2b- 0_<var- snap-lxd- common- lxd>:unconfined " name="snap. juju-db. mongod" pid=3427380 comm="apparmor_ parser"
Jun 4 10:52:30 focal kernel: [1156807.204794] audit: type=1400 audit(162281835
Note that the error do stop until I restart jujud-machine-0
Right at the beginning after restart I see some other things that are denied: 1.275:1838976) : apparmor="DENIED" operation= "file_inherit" namespace= "root// lxd-juju- 97ff2b- 0_<var- snap-lxd- common- lxd>" profile= "/snap/ snapd/12057/ usr/lib/ snapd/snap- confine" pid=3428342 comm="snap-confine" family="netlink" sock_type="raw" protocol=15 requested_ mask="send receive" denied_mask="send receive" 1.279:1838977) : apparmor="DENIED" operation= "file_inherit" namespace= "root// lxd-juju- 97ff2b- 0_<var- snap-lxd- common- lxd>" profile= "snap.juju- db.hook. configure" name="/ apparmor/ .null" pid=3428342 comm="snap-exec" requested_mask="wr" denied_mask="wr" fsuid=1000000 ouid=0 3.167:1838978) : apparmor="DENIED" operation="open" namespace= "root// lxd-juju- 97ff2b- 0_<var- snap-lxd- common- lxd>" profile= "snap.juju- db.daemon" name="/sys/block/" pid=3428428 comm="mongod" requested_mask="r" denied_mask="r" fsuid=1000000 ouid=0 4.011:1838979) : apparmor="DENIED" operation="open" namespace= "root// lxd-juju- 97ff2b- 0_<var- snap-lxd- common- lxd>" profile= "snap.juju- db.daemon" name="/ proc/6443/ net/netstat" pid=3428428 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=1000000 ouid=1000000 4.011:1838980) : apparmor="DENIED" operation="open" namespace= "root// lxd-juju- 97ff2b- 0_<var- snap-lxd- common- lxd>" profile= "snap.juju- db.daemon" name="/ proc/6443/ net/snmp" pid=3428428 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=1000000 ouid=1000000 4.011:1838981) : apparmor="DENIED" operation="open" namespace= "root// lxd-juju- 97ff2b- 0_<var- snap-lxd- common- lxd>" profile= "snap.juju- db.daemon" name="/proc/vmstat" pid=3428428 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=1000000 ouid=0
Jun 4 10:54:31 focal kernel: [1156928.177399] audit: type=1400 audit(162281847
Jun 4 10:54:31 focal kernel: [1156928.182426] audit: type=1400 audit(162281847
Jun 4 10:54:33 focal kernel: [1156930.069462] audit: type=1400 audit(162281847
Jun 4 10:54:34 focal kernel: [1156930.916199] audit: type=1400 audit(162281847
Jun 4 10:54:34 focal kernel: [1156930.916211] audit: type=1400 audit(162281847
Jun 4 10:54:34 focal kernel: [1156930.916217] audit: type=1400 audit(162281847
But those aren't triggered approximately every second.
I do see the ongoing net/stat issues, and I did confirm (again) that 1.998:1839153) : apparmor="DENIED" operation="open" namespace= "root// lxd-juju- 97ff2b- 0_<var- snap-lxd- common- lxd>" profile= "snap.juju- db.daemon" name="/ proc/6443/ net/netstat" pid=3428428 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=1000000 ouid=1000000
# pgrep mongod
6443
matches
Jun 4 10:55:32 focal kernel: [1156988.903111] audit: type=1400 audit(162281853
And outside the container:
$ pgrep mongod
3428428
so the log line says it is denying 'pid=3428428' from reading '/proc/6443' which very much matches the pid inside and outside of the container.
And now to try 4.4 97ff2b- 0:~# snap refresh juju-db --channel 4.4
root@juju-
root@juju- 97ff2b- 0:~# systemctl restart jujud-machine-0
At this point 'pgrep mongod' shows nothing running, so as expected, it isn't a fair test.