I looked at it for my 18.04 LTS and all I found is a PPA. It’s not exactly ‘out of the box’ IMO. According to this there may be some hope for August 2019.
Linux 5.0 is currently available in Ubuntu 19.04 or newer. Indeed, it will reach the latest LTS at Ubuntu 18.04.3 (1st Aug).
Here are some benchmarks, on Ubuntu 19.10 (latest daily).
Before enabling shiftfs
myusername@myusername-desktop:~$ time lxc launch ubuntu:18.04 mycontainer
Creating mycontainer
Starting mycontainer
real 0m2,551s
user 0m0,074s
sys 0m0,033s
myusername@myusername-desktop:~$ time lxc launch ubuntu:18.04 mycontainer2
Creating mycontainer2
Starting mycontainer2
real 0m2,550s
user 0m0,071s
sys 0m0,034s
myusername@myusername-desktop:~$ time lxc launch ubuntu:18.04 mycontainer3
Creating mycontainer3
Starting mycontainer3
real 0m2,718s
user 0m0,069s
sys 0m0,036s
myusername@myusername-desktop:~$
After enabling shiftfs
myusername@myusername-desktop:~$ time lxc launch ubuntu:18.04 mycontainer
Creating mycontainer
Starting mycontainer
real 0m0,513s
user 0m0,070s
sys 0m0,041s
myusername@myusername-desktop:~$ time lxc launch ubuntu:18.04 mycontainer2
Creating mycontainer2
Starting mycontainer2
real 0m0,473s
user 0m0,066s
sys 0m0,031s
myusername@myusername-desktop:~$ time lxc launch ubuntu:18.04 mycontainer3
Creating mycontainer3
Starting mycontainer3
real 0m0,550s
user 0m0,072s
sys 0m0,027s
myusername@myusername-desktop:~$
This shows that the creation speed went from 2.5s down to 500s (SSD disk, using ZFS over a loop file).
Using lxd-benchmark
but no shiftfs
$ lxd.benchmark launch --count 10 --parallel 10 ubuntu:18.04
Test environment:
Server backend: lxd
Server version: 3.14
Kernel: Linux
Kernel architecture: x86_64
Kernel version: 5.0.0-17-generic
Storage backend: zfs
Storage version: 0.7.12-1ubuntu5
Container backend: lxc
Container version: 3.1.0
Test variables:
Container count: 10
Container mode: unprivileged
Startup mode: normal startup
Image: ubuntu:18.04
Batches: 1
Batch size: 10
Remainder: 0
[Jul 2 12:41:37.107] Found image in local store: 6ae1c6e92017402f1aee655fa8d785ee9d2337a3369d76115cecad5e7a303e07
[Jul 2 12:41:37.107] Batch processing start
[Jul 2 12:41:46.664] Processed 10 containers in 9.557s (1.046/s)
[Jul 2 12:41:46.664] Batch processing completed in 9.557s
Using lxd-benchmark
and shiftfs
$ lxd.benchmark launch --count 10 --parallel 10 ubuntu:18.04
Test environment:
Server backend: lxd
Server version: 3.14
Kernel: Linux
Kernel architecture: x86_64
Kernel version: 5.0.0-17-generic
Storage backend: zfs
Storage version: 0.7.12-1ubuntu5
Container backend: lxc
Container version: 3.1.0
Test variables:
Container count: 10
Container mode: unprivileged
Startup mode: normal startup
Image: ubuntu:18.04
Batches: 1
Batch size: 10
Remainder: 0
[Jul 2 12:38:16.553] Found image in local store: 6ae1c6e92017402f1aee655fa8d785ee9d2337a3369d76115cecad5e7a303e07
[Jul 2 12:38:16.553] Batch processing start
[Jul 2 12:38:18.353] Processed 10 containers in 1.800s (5.557/s)
[Jul 2 12:38:18.353] Batch processing completed in 1.800s
This was launching 10 Ubuntu containers in parallel. The time spent, when from 9.5s way down to 1.8s.
The 5.0 kernel is available for Ubuntu 18.04 users as linux-generic-hwe-18.04-edge
.
That edge
kernel will then get promoted to just linux-generic-hwe-18.04
with the next point release of Ubuntu 18.04.
After the Bionic 5.0 HWE kernel was released I recreated my Disco container to use shiftfs. After running fine for several days, this morning I found that processes running as part of a manual apt update
(like gpgv
) were hanging in D state. I was able to kill them with ^C. Stopping the container took a long time as well. This is with LXD 3.15 (11437).
So I deleted the container and created it without shiftfs and will watch for the problem to recur. I had no problems running this Disco container with the previous Bionic 4.18 HWE kernel. I use a “real” ZFS for container storage and a “real” bridge with its own network interface. The only unusual part of the configuration is that the container is on a WireGuard VPN using the kernel module from the host.
Can you show uname -a
and the output of dmesg
?
Normally such hangs are indicative of a kernel issue and should be accompanied by a kernel trace in dmesg
.
Linux kif 5.0.0-23-generic #24~18.04.1-Ubuntu SMP Mon Jul 29 16:12:28 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux
The dmesg -T
output below starts from when I first logged in after first booting into 5.0. After enabling shiftfs as specified earlier in this thread, I deleted and relaunched the container disco
and it ran fine for several days. df -T
inside the container confirmed that shiftfs was in use.
Based on reviewing journalctl
messages, here’s what I think I did (all times local):
Jul 31 19:12:14
: First boot into HWE 5.0.0
Jul 31 19:12:31
: Login; container disco
remains stopped from before reboot
Jul 31 19:14:31
: Ran lxc list
; lxd
starts
Jul 31 19:16:53
: Enable shiftfs; delete and launch container disco
Jul 31 19:32:49
: Container disco
starts with shiftfs (after new image downloads)
Jul 31 19:33:10
: Run scripts to configure container and set up WireGuard
Aug 04 07:??:??
: Processes in container disco
hang during apt update
Aug 04 07:44:02
: Stop container disco
; this took longer than usual
Aug 04 07:52:58
: Delete container disco
Aug 04 07:53:05
: Disable shiftfs and launch container disco
[Wed Jul 31 19:14:32 2019] new mount options do not match the existing superblock, will be ignored
[Wed Jul 31 19:16:52 2019] kauditd_printk_skb: 32 callbacks suppressed
[Wed Jul 31 19:16:52 2019] audit: type=1400 audit(1564615013.130:44): apparmor="DENIED" operation="open" profile="snap.lxd.hook.configure" name="/var/lib/snapd/hostfs/usr/lib/os-release" pid=2190 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[Wed Jul 31 19:16:53 2019] audit: type=1400 audit(1564615013.390:45): apparmor="DENIED" operation="open" profile="snap.lxd.hook.configure" name="/var/lib/snapd/hostfs/usr/lib/os-release" pid=2211 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[Wed Jul 31 19:16:53 2019] audit: type=1400 audit(1564615013.454:46): apparmor="DENIED" operation="open" profile="snap.lxd.hook.configure" name="/var/lib/snapd/hostfs/usr/lib/os-release" pid=2219 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[Wed Jul 31 19:16:53 2019] audit: type=1400 audit(1564615013.462:47): apparmor="DENIED" operation="open" profile="snap.lxd.hook.configure" name="/var/lib/snapd/hostfs/usr/lib/os-release" pid=2225 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[Wed Jul 31 19:16:53 2019] audit: type=1400 audit(1564615013.474:48): apparmor="DENIED" operation="open" profile="snap.lxd.hook.configure" name="/var/lib/snapd/hostfs/usr/lib/os-release" pid=2234 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[Wed Jul 31 19:16:53 2019] audit: type=1400 audit(1564615013.482:49): apparmor="DENIED" operation="open" profile="snap.lxd.hook.configure" name="/var/lib/snapd/hostfs/usr/lib/os-release" pid=2243 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[Wed Jul 31 19:16:53 2019] audit: type=1400 audit(1564615013.494:50): apparmor="DENIED" operation="open" profile="snap.lxd.hook.configure" name="/var/lib/snapd/hostfs/usr/lib/os-release" pid=2253 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[Wed Jul 31 19:32:49 2019] audit: type=1400 audit(1564615969.722:51): apparmor="STATUS" operation="profile_load" profile="unconfined" name="lxd-disco_</var/snap/lxd/common/lxd>" pid=10556 comm="apparmor_parser"
[Wed Jul 31 19:32:49 2019] br0: port 2(veth31XCZZ) entered blocking state
[Wed Jul 31 19:32:49 2019] br0: port 2(veth31XCZZ) entered disabled state
[Wed Jul 31 19:32:49 2019] device veth31XCZZ entered promiscuous mode
[Wed Jul 31 19:32:49 2019] br0: port 2(veth31XCZZ) entered blocking state
[Wed Jul 31 19:32:49 2019] br0: port 2(veth31XCZZ) entered forwarding state
[Wed Jul 31 19:32:49 2019] br0: port 2(veth31XCZZ) entered disabled state
[Wed Jul 31 19:32:49 2019] eth0: renamed from vethEAGWGM
[Wed Jul 31 19:32:49 2019] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[Wed Jul 31 19:32:49 2019] IPv6: ADDRCONF(NETDEV_CHANGE): veth31XCZZ: link becomes ready
[Wed Jul 31 19:32:49 2019] br0: port 2(veth31XCZZ) entered blocking state
[Wed Jul 31 19:32:49 2019] br0: port 2(veth31XCZZ) entered forwarding state
[Wed Jul 31 19:32:49 2019] new mount options do not match the existing superblock, will be ignored
[Wed Jul 31 19:32:50 2019] audit: type=1400 audit(1564615970.754:52): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="nvidia_modprobe" pid=10840 comm="apparmor_parser"
[Wed Jul 31 19:32:50 2019] audit: type=1400 audit(1564615970.754:53): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="nvidia_modprobe//kmod" pid=10840 comm="apparmor_parser"
[Wed Jul 31 19:32:50 2019] audit: type=1400 audit(1564615970.882:54): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/usr/sbin/tcpdump" pid=10841 comm="apparmor_parser"
[Wed Jul 31 19:32:50 2019] audit: type=1400 audit(1564615970.954:55): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/usr/bin/man" pid=10842 comm="apparmor_parser"
[Wed Jul 31 19:32:50 2019] audit: type=1400 audit(1564615970.954:56): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="man_filter" pid=10842 comm="apparmor_parser"
[Wed Jul 31 19:32:50 2019] audit: type=1400 audit(1564615970.954:57): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="man_groff" pid=10842 comm="apparmor_parser"
[Wed Jul 31 19:32:50 2019] audit: type=1400 audit(1564615971.082:58): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/sbin/dhclient" pid=10837 comm="apparmor_parser"
[Wed Jul 31 19:32:50 2019] audit: type=1400 audit(1564615971.086:59): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=10837 comm="apparmor_parser"
[Wed Jul 31 19:32:50 2019] audit: type=1400 audit(1564615971.086:60): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=10837 comm="apparmor_parser"
[Wed Jul 31 19:33:07 2019] kauditd_printk_skb: 3 callbacks suppressed
[Wed Jul 31 19:33:07 2019] audit: type=1400 audit(1564615987.503:64): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/snap/core/7270/usr/lib/snapd/snap-confine" pid=11724 comm="apparmor_parser"
[Wed Jul 31 19:33:07 2019] audit: type=1400 audit(1564615987.503:65): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/snap/core/7270/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=11724 comm="apparmor_parser"
[Wed Jul 31 19:33:07 2019] audit: type=1400 audit(1564615987.543:66): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap-update-ns.core" pid=11727 comm="apparmor_parser"
[Wed Jul 31 19:33:07 2019] audit: type=1400 audit(1564615987.671:67): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.core.hook.configure" pid=11728 comm="apparmor_parser"
[Wed Jul 31 19:33:10 2019] audit: type=1400 audit(1564615990.971:68): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/snap/core/7270/usr/lib/snapd/snap-confine" pid=11801 comm="apparmor_parser"
[Wed Jul 31 19:33:10 2019] audit: type=1400 audit(1564615990.975:69): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/snap/core/7270/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=11801 comm="apparmor_parser"
[Wed Jul 31 19:33:10 2019] audit: type=1400 audit(1564615991.003:70): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap-update-ns.core" pid=11946 comm="apparmor_parser"
[Wed Jul 31 19:33:10 2019] audit: type=1400 audit(1564615991.143:71): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.core.hook.configure" pid=11947 comm="apparmor_parser"
[Wed Jul 31 19:33:10 2019] PKCS#7 signature not signed with a trusted key
[Wed Jul 31 19:33:10 2019] wireguard: module verification failed: signature and/or required key missing - tainting kernel
[Wed Jul 31 19:33:10 2019] wireguard: WireGuard 0.0.20190702 loaded. See www.wireguard.com for information.
[Wed Jul 31 19:33:10 2019] wireguard: Copyright (C) 2015-2019 Jason A. Donenfeld <Jason@zx2c4.com>. All Rights Reserved.
[Wed Jul 31 19:33:14 2019] audit: type=1400 audit(1564615994.899:72): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap-update-ns.lxd" pid=12516 comm="apparmor_parser"
[Wed Jul 31 19:33:14 2019] audit: type=1400 audit(1564615995.059:73): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.benchmark" pid=12518 comm="apparmor_parser"
[Wed Jul 31 19:33:14 2019] audit: type=1400 audit(1564615995.091:74): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.buginfo" pid=12519 comm="apparmor_parser"
[Wed Jul 31 19:33:14 2019] audit: type=1400 audit(1564615995.099:75): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.check-kernel" pid=12520 comm="apparmor_parser"
[Wed Jul 31 19:33:14 2019] audit: type=1400 audit(1564615995.099:76): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.activate" pid=12517 comm="apparmor_parser"
[Wed Jul 31 19:33:14 2019] audit: type=1400 audit(1564615995.239:77): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.daemon" pid=12521 comm="apparmor_parser"
[Wed Jul 31 19:33:14 2019] audit: type=1400 audit(1564615995.271:78): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.hook.configure" pid=12522 comm="apparmor_parser"
[Wed Jul 31 19:33:14 2019] audit: type=1400 audit(1564615995.279:79): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.hook.install" pid=12523 comm="apparmor_parser"
[Wed Jul 31 19:33:14 2019] audit: type=1400 audit(1564615995.279:80): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.lxc" pid=12524 comm="apparmor_parser"
[Wed Jul 31 19:33:15 2019] audit: type=1400 audit(1564615995.391:81): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.lxd" pid=12525 comm="apparmor_parser"
[Wed Jul 31 19:33:19 2019] kauditd_printk_skb: 34 callbacks suppressed
[Wed Jul 31 19:33:19 2019] audit: type=1400 audit(1564615999.911:116): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.core.hook.configure" pid=12736 comm="apparmor_parser"
[Wed Jul 31 19:33:19 2019] audit: type=1400 audit(1564616000.295:117): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.activate" pid=12786 comm="apparmor_parser"
[Wed Jul 31 19:33:19 2019] audit: type=1400 audit(1564616000.299:118): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.check-kernel" pid=12789 comm="apparmor_parser"
[Wed Jul 31 19:33:19 2019] audit: type=1400 audit(1564616000.299:119): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.buginfo" pid=12788 comm="apparmor_parser"
[Wed Jul 31 19:33:19 2019] audit: type=1400 audit(1564616000.299:120): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.benchmark" pid=12787 comm="apparmor_parser"
[Wed Jul 31 19:33:20 2019] audit: type=1400 audit(1564616000.471:121): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.hook.install" pid=12792 comm="apparmor_parser"
[Wed Jul 31 19:33:20 2019] audit: type=1400 audit(1564616000.479:122): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.hook.configure" pid=12791 comm="apparmor_parser"
[Wed Jul 31 19:33:20 2019] audit: type=1400 audit(1564616000.499:123): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.lxc" pid=12793 comm="apparmor_parser"
[Wed Jul 31 19:33:20 2019] audit: type=1400 audit(1564616000.575:124): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.daemon" pid=12790 comm="apparmor_parser"
[Wed Jul 31 19:33:20 2019] audit: type=1400 audit(1564616000.655:125): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.lxd" pid=12794 comm="apparmor_parser"
[Wed Jul 31 19:33:25 2019] kauditd_printk_skb: 20 callbacks suppressed
[Wed Jul 31 19:33:25 2019] audit: type=1400 audit(1564616005.575:146): apparmor="DENIED" operation="file_inherit" namespace="root//lxd-disco_<var-snap-lxd-common-lxd>" profile="/snap/core/7270/usr/lib/snapd/snap-confine" pid=13002 comm="snap-confine" family="netlink" sock_type="raw" protocol=15 requested_mask="send receive" denied_mask="send receive"
[Wed Jul 31 19:33:25 2019] audit: type=1400 audit(1564616005.587:147): apparmor="DENIED" operation="file_inherit" namespace="root//lxd-disco_<var-snap-lxd-common-lxd>" profile="snap.lxd.hook.configure" name="/apparmor/.null" pid=13002 comm="snap-exec" requested_mask="wr" denied_mask="wr" fsuid=1000000 ouid=0
[Wed Jul 31 19:34:18 2019] audit: type=1400 audit(1564616059.211:148): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="nvidia_modprobe" pid=13885 comm="apparmor_parser"
[Wed Jul 31 19:34:18 2019] audit: type=1400 audit(1564616059.211:149): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="nvidia_modprobe//kmod" pid=13885 comm="apparmor_parser"
[Wed Jul 31 19:34:19 2019] audit: type=1400 audit(1564616059.859:150): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="nvidia_modprobe" pid=13940 comm="apparmor_parser"
[Wed Jul 31 19:34:19 2019] audit: type=1400 audit(1564616059.887:151): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="nvidia_modprobe//kmod" pid=13940 comm="apparmor_parser"
[Wed Jul 31 19:34:19 2019] audit: type=1400 audit(1564616059.979:152): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/usr/bin/man" pid=13942 comm="apparmor_parser"
[Wed Jul 31 19:34:19 2019] audit: type=1400 audit(1564616059.979:153): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="man_filter" pid=13942 comm="apparmor_parser"
[Wed Jul 31 19:34:19 2019] audit: type=1400 audit(1564616059.979:154): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="man_groff" pid=13942 comm="apparmor_parser"
[Wed Jul 31 19:34:19 2019] audit: type=1400 audit(1564616060.003:155): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/usr/sbin/tcpdump" pid=13941 comm="apparmor_parser"
[Wed Jul 31 19:34:19 2019] audit: type=1400 audit(1564616060.035:156): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/sbin/dhclient" pid=13937 comm="apparmor_parser"
[Wed Jul 31 19:34:19 2019] audit: type=1400 audit(1564616060.035:157): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=13937 comm="apparmor_parser"
[Wed Jul 31 19:34:34 2019] kauditd_printk_skb: 19 callbacks suppressed
[Wed Jul 31 19:34:34 2019] audit: type=1400 audit(1564616074.744:177): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.activate" pid=14601 comm="apparmor_parser"
[Wed Jul 31 19:34:34 2019] audit: type=1400 audit(1564616074.748:178): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.check-kernel" pid=14604 comm="apparmor_parser"
[Wed Jul 31 19:34:34 2019] audit: type=1400 audit(1564616074.752:179): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.benchmark" pid=14602 comm="apparmor_parser"
[Wed Jul 31 19:34:34 2019] audit: type=1400 audit(1564616074.752:180): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.buginfo" pid=14603 comm="apparmor_parser"
[Wed Jul 31 19:34:34 2019] audit: type=1400 audit(1564616074.948:181): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.lxc" pid=14608 comm="apparmor_parser"
[Wed Jul 31 19:34:34 2019] audit: type=1400 audit(1564616074.952:182): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.migrate" pid=14610 comm="apparmor_parser"
[Wed Jul 31 19:34:34 2019] audit: type=1400 audit(1564616074.952:183): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.lxd" pid=14609 comm="apparmor_parser"
[Wed Jul 31 19:34:34 2019] audit: type=1400 audit(1564616075.004:184): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.daemon" pid=14607 comm="apparmor_parser"
[Wed Jul 31 19:34:34 2019] audit: type=1400 audit(1564616075.012:185): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap-update-ns.lxd" pid=14612 comm="apparmor_parser"
[Wed Jul 31 19:34:34 2019] audit: type=1400 audit(1564616075.016:186): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.hook.install" pid=14614 comm="apparmor_parser"
[Wed Jul 31 19:35:28 2019] nf_conntrack: default automatic helper assignment has been turned off for security reasons and CT-based firewall rule not found. Use the iptables CT target to attach helpers instead.
[Thu Aug 1 10:27:27 2019] kauditd_printk_skb: 50 callbacks suppressed
[Thu Aug 1 10:27:27 2019] audit: type=1400 audit(1564669648.540:237): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.lxd.benchmark" pid=31639 comm="apparmor_parser"
[Thu Aug 1 10:27:27 2019] audit: type=1400 audit(1564669648.540:238): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.lxd.check-kernel" pid=31641 comm="apparmor_parser"
[Thu Aug 1 10:27:27 2019] audit: type=1400 audit(1564669648.544:239): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.lxd.activate" pid=31638 comm="apparmor_parser"
[Thu Aug 1 10:27:27 2019] audit: type=1400 audit(1564669648.548:240): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.lxd.buginfo" pid=31640 comm="apparmor_parser"
[Thu Aug 1 10:27:27 2019] audit: type=1400 audit(1564669648.728:241): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.lxd.hook.install" pid=31644 comm="apparmor_parser"
[Thu Aug 1 10:27:27 2019] audit: type=1400 audit(1564669648.748:242): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.lxd.lxc" pid=31645 comm="apparmor_parser"
[Thu Aug 1 10:27:27 2019] audit: type=1400 audit(1564669648.792:243): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.lxd.hook.configure" pid=31643 comm="apparmor_parser"
[Thu Aug 1 10:27:27 2019] audit: type=1400 audit(1564669648.804:244): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.lxd.daemon" pid=31642 comm="apparmor_parser"
[Thu Aug 1 10:27:27 2019] audit: type=1400 audit(1564669648.912:245): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.lxd.lxd" pid=31646 comm="apparmor_parser"
[Thu Aug 1 10:27:28 2019] audit: type=1400 audit(1564669648.928:246): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.lxd.migrate" pid=31647 comm="apparmor_parser"
[Thu Aug 1 12:43:48 2019] perf: interrupt took too long (2512 > 2500), lowering kernel.perf_event_max_sample_rate to 79500
[Thu Aug 1 12:47:38 2019] new mount options do not match the existing superblock, will be ignored
[Fri Aug 2 00:59:33 2019] perf: interrupt took too long (3166 > 3140), lowering kernel.perf_event_max_sample_rate to 63000
[Fri Aug 2 16:43:04 2019] perf: interrupt took too long (3979 > 3957), lowering kernel.perf_event_max_sample_rate to 50250
[Sat Aug 3 08:53:34 2019] [UFW BLOCK] IN=enp1s0 OUT= MAC=00:22:4d:1f:5a:2b:00:0d:b9:47:24:05:08:00 SRC=157.240.14.19 DST=10.167.10.8 LEN=91 TOS=0x00 PREC=0x00 TTL=83 ID=49842 DF PROTO=TCP SPT=443 DPT=50151 WINDOW=113 RES=0x00 ACK PSH URGP=0
[Sat Aug 3 08:55:32 2019] [UFW BLOCK] IN=enp1s0 OUT= MAC=00:22:4d:1f:5a:2b:00:0d:b9:47:24:05:08:00 SRC=31.13.67.35 DST=10.167.10.8 LEN=91 TOS=0x00 PREC=0x00 TTL=83 ID=13193 DF PROTO=TCP SPT=443 DPT=50347 WINDOW=113 RES=0x00 ACK PSH URGP=0
[Sat Aug 3 08:55:38 2019] [UFW BLOCK] IN=enp1s0 OUT= MAC=00:22:4d:1f:5a:2b:00:0d:b9:47:24:05:08:00 SRC=31.13.67.35 DST=10.167.10.8 LEN=91 TOS=0x00 PREC=0x00 TTL=83 ID=13200 DF PROTO=TCP SPT=443 DPT=50347 WINDOW=113 RES=0x00 ACK PSH FIN URGP=0
[Sat Aug 3 08:55:44 2019] [UFW BLOCK] IN=enp1s0 OUT= MAC=00:22:4d:1f:5a:2b:00:0d:b9:47:24:05:08:00 SRC=31.13.67.35 DST=10.167.10.8 LEN=91 TOS=0x00 PREC=0x00 TTL=83 ID=13201 DF PROTO=TCP SPT=443 DPT=50347 WINDOW=113 RES=0x00 ACK PSH FIN URGP=0
[Sat Aug 3 11:11:15 2019] perf: interrupt took too long (4982 > 4973), lowering kernel.perf_event_max_sample_rate to 40000
[Sun Aug 4 07:43:58 2019] kauditd_printk_skb: 12 callbacks suppressed
[Sun Aug 4 07:43:58 2019] audit: type=1400 audit(1564919042.385:259): apparmor="DENIED" operation="mount" info="failed flags match" error=-13 profile="lxd-disco_</var/snap/lxd/common/lxd>" name="/run/" pid=18838 comm="mount" flags="rw, nosuid, nodev, remount"
[Sun Aug 4 07:44:43 2019] br0: port 2(veth31XCZZ) entered disabled state
[Sun Aug 4 07:44:43 2019] device veth31XCZZ left promiscuous mode
[Sun Aug 4 07:44:43 2019] br0: port 2(veth31XCZZ) entered disabled state
[Sun Aug 4 07:45:31 2019] audit: type=1400 audit(1564919135.225:260): apparmor="STATUS" operation="profile_remove" profile="unconfined" name="lxd-disco_</var/snap/lxd/common/lxd>" pid=29094 comm="apparmor_parser"
[Sun Aug 4 07:53:02 2019] audit: type=1400 audit(1564919585.682:261): apparmor="DENIED" operation="open" profile="snap.lxd.hook.configure" name="/var/lib/snapd/hostfs/usr/lib/os-release" pid=29812 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[Sun Aug 4 07:53:02 2019] audit: type=1400 audit(1564919585.690:262): apparmor="DENIED" operation="open" profile="snap.lxd.hook.configure" name="/var/lib/snapd/hostfs/usr/lib/os-release" pid=29833 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[Sun Aug 4 07:53:02 2019] audit: type=1400 audit(1564919585.698:263): apparmor="DENIED" operation="open" profile="snap.lxd.hook.configure" name="/var/lib/snapd/hostfs/usr/lib/os-release" pid=29841 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[Sun Aug 4 07:53:02 2019] audit: type=1400 audit(1564919585.706:264): apparmor="DENIED" operation="open" profile="snap.lxd.hook.configure" name="/var/lib/snapd/hostfs/usr/lib/os-release" pid=29847 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[Sun Aug 4 07:53:02 2019] audit: type=1400 audit(1564919585.718:265): apparmor="DENIED" operation="open" profile="snap.lxd.hook.configure" name="/var/lib/snapd/hostfs/usr/lib/os-release" pid=29856 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[Sun Aug 4 07:53:02 2019] audit: type=1400 audit(1564919585.730:266): apparmor="DENIED" operation="open" profile="snap.lxd.hook.configure" name="/var/lib/snapd/hostfs/usr/lib/os-release" pid=29866 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[Sun Aug 4 07:53:02 2019] audit: type=1400 audit(1564919585.738:267): apparmor="DENIED" operation="open" profile="snap.lxd.hook.configure" name="/var/lib/snapd/hostfs/usr/lib/os-release" pid=29875 comm="snapctl" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[Sun Aug 4 07:53:24 2019] audit: type=1400 audit(1564919607.554:268): apparmor="STATUS" operation="profile_load" profile="unconfined" name="lxd-disco_</var/snap/lxd/common/lxd>" pid=30192 comm="apparmor_parser"
[Sun Aug 4 07:53:24 2019] br0: port 2(veth4VINYO) entered blocking state
[Sun Aug 4 07:53:24 2019] br0: port 2(veth4VINYO) entered disabled state
[Sun Aug 4 07:53:24 2019] device veth4VINYO entered promiscuous mode
[Sun Aug 4 07:53:24 2019] eth0: renamed from veth99YIUV
[Sun Aug 4 07:53:24 2019] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[Sun Aug 4 07:53:24 2019] IPv6: ADDRCONF(NETDEV_CHANGE): veth4VINYO: link becomes ready
[Sun Aug 4 07:53:24 2019] br0: port 2(veth4VINYO) entered blocking state
[Sun Aug 4 07:53:24 2019] br0: port 2(veth4VINYO) entered forwarding state
[Sun Aug 4 07:53:24 2019] new mount options do not match the existing superblock, will be ignored
[Sun Aug 4 07:53:25 2019] audit: type=1400 audit(1564919608.478:269): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="nvidia_modprobe" pid=30821 comm="apparmor_parser"
[Sun Aug 4 07:53:25 2019] audit: type=1400 audit(1564919608.494:270): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="nvidia_modprobe//kmod" pid=30821 comm="apparmor_parser"
[Sun Aug 4 07:53:25 2019] audit: type=1400 audit(1564919608.494:271): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/usr/bin/man" pid=30824 comm="apparmor_parser"
[Sun Aug 4 07:53:25 2019] audit: type=1400 audit(1564919608.498:272): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="man_filter" pid=30824 comm="apparmor_parser"
[Sun Aug 4 07:53:25 2019] audit: type=1400 audit(1564919608.498:273): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="man_groff" pid=30824 comm="apparmor_parser"
[Sun Aug 4 07:53:25 2019] audit: type=1400 audit(1564919608.550:274): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/sbin/dhclient" pid=30823 comm="apparmor_parser"
[Sun Aug 4 07:53:25 2019] audit: type=1400 audit(1564919608.554:275): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=30823 comm="apparmor_parser"
[Sun Aug 4 07:53:25 2019] audit: type=1400 audit(1564919608.554:276): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=30823 comm="apparmor_parser"
[Sun Aug 4 07:53:25 2019] audit: type=1400 audit(1564919608.554:277): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=30823 comm="apparmor_parser"
[Sun Aug 4 07:53:45 2019] kauditd_printk_skb: 3 callbacks suppressed
[Sun Aug 4 07:53:45 2019] audit: type=1400 audit(1564919629.183:281): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/snap/core/7270/usr/lib/snapd/snap-confine" pid=32183 comm="apparmor_parser"
[Sun Aug 4 07:53:45 2019] audit: type=1400 audit(1564919629.183:282): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/snap/core/7270/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=32183 comm="apparmor_parser"
[Sun Aug 4 07:53:45 2019] audit: type=1400 audit(1564919629.231:283): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap-update-ns.core" pid=32185 comm="apparmor_parser"
[Sun Aug 4 07:53:45 2019] audit: type=1400 audit(1564919629.367:284): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.core.hook.configure" pid=32186 comm="apparmor_parser"
[Sun Aug 4 07:53:49 2019] audit: type=1400 audit(1564919633.031:285): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/snap/core/7270/usr/lib/snapd/snap-confine" pid=32296 comm="apparmor_parser"
[Sun Aug 4 07:53:49 2019] audit: type=1400 audit(1564919633.055:286): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="/snap/core/7270/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=32296 comm="apparmor_parser"
[Sun Aug 4 07:53:49 2019] audit: type=1400 audit(1564919633.067:287): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap-update-ns.core" pid=32298 comm="apparmor_parser"
[Sun Aug 4 07:53:49 2019] audit: type=1400 audit(1564919633.067:288): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.core.hook.configure" pid=32299 comm="apparmor_parser"
[Sun Aug 4 07:53:59 2019] audit: type=1400 audit(1564919642.475:289): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap-update-ns.lxd" pid=32541 comm="apparmor_parser"
[Sun Aug 4 07:53:59 2019] audit: type=1400 audit(1564919642.631:290): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.benchmark" pid=32543 comm="apparmor_parser"
[Sun Aug 4 07:53:59 2019] audit: type=1400 audit(1564919642.651:291): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.buginfo" pid=32544 comm="apparmor_parser"
[Sun Aug 4 07:53:59 2019] audit: type=1400 audit(1564919642.667:292): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.activate" pid=32542 comm="apparmor_parser"
[Sun Aug 4 07:53:59 2019] audit: type=1400 audit(1564919642.735:293): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.check-kernel" pid=32545 comm="apparmor_parser"
[Sun Aug 4 07:53:59 2019] audit: type=1400 audit(1564919642.803:294): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.daemon" pid=32546 comm="apparmor_parser"
[Sun Aug 4 07:53:59 2019] audit: type=1400 audit(1564919642.871:295): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.hook.configure" pid=32547 comm="apparmor_parser"
[Sun Aug 4 07:53:59 2019] audit: type=1400 audit(1564919642.895:296): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.hook.install" pid=32548 comm="apparmor_parser"
[Sun Aug 4 07:53:59 2019] audit: type=1400 audit(1564919642.963:297): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.lxc" pid=32549 comm="apparmor_parser"
[Sun Aug 4 07:53:59 2019] audit: type=1400 audit(1564919642.975:298): apparmor="STATUS" operation="profile_load" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.lxd" pid=32550 comm="apparmor_parser"
[Sun Aug 4 07:54:04 2019] kauditd_printk_skb: 61 callbacks suppressed
[Sun Aug 4 07:54:04 2019] audit: type=1400 audit(1564919647.739:360): apparmor="DENIED" operation="file_inherit" namespace="root//lxd-disco_<var-snap-lxd-common-lxd>" profile="/snap/core/7270/usr/lib/snapd/snap-confine" pid=363 comm="snap-confine" family="netlink" sock_type="raw" protocol=15 requested_mask="send receive" denied_mask="send receive"
[Sun Aug 4 07:54:04 2019] audit: type=1400 audit(1564919647.763:361): apparmor="DENIED" operation="file_inherit" namespace="root//lxd-disco_<var-snap-lxd-common-lxd>" profile="snap-update-ns.lxd" name="/apparmor/.null" pid=379 comm="6" requested_mask="wr" denied_mask="wr" fsuid=1000000 ouid=0
[Sun Aug 4 07:54:04 2019] audit: type=1400 audit(1564919648.087:362): apparmor="DENIED" operation="file_inherit" namespace="root//lxd-disco_<var-snap-lxd-common-lxd>" profile="snap.lxd.hook.install" name="/apparmor/.null" pid=363 comm="snap-exec" requested_mask="wr" denied_mask="wr" fsuid=1000000 ouid=0
[Sun Aug 4 07:54:06 2019] audit: type=1400 audit(1564919649.819:363): apparmor="DENIED" operation="file_inherit" namespace="root//lxd-disco_<var-snap-lxd-common-lxd>" profile="/snap/core/7270/usr/lib/snapd/snap-confine" pid=557 comm="snap-confine" family="netlink" sock_type="raw" protocol=15 requested_mask="send receive" denied_mask="send receive"
[Sun Aug 4 07:54:06 2019] audit: type=1400 audit(1564919649.831:364): apparmor="DENIED" operation="file_inherit" namespace="root//lxd-disco_<var-snap-lxd-common-lxd>" profile="snap.lxd.hook.configure" name="/apparmor/.null" pid=557 comm="snap-exec" requested_mask="wr" denied_mask="wr" fsuid=1000000 ouid=0
[Sun Aug 4 07:54:36 2019] audit: type=1400 audit(1564919679.479:365): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.hook.configure" pid=1490 comm="apparmor_parser"
[Sun Aug 4 07:54:36 2019] audit: type=1400 audit(1564919679.487:366): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap-update-ns.lxd" pid=1492 comm="apparmor_parser"
[Sun Aug 4 07:54:36 2019] audit: type=1400 audit(1564919679.491:367): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.activate" pid=1493 comm="apparmor_parser"
[Sun Aug 4 07:54:36 2019] audit: type=1400 audit(1564919679.491:368): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.benchmark" pid=1494 comm="apparmor_parser"
[Sun Aug 4 07:54:36 2019] audit: type=1400 audit(1564919679.491:369): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.check-kernel" pid=1496 comm="apparmor_parser"
[Sun Aug 4 07:54:36 2019] audit: type=1400 audit(1564919679.495:370): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.buginfo" pid=1495 comm="apparmor_parser"
[Sun Aug 4 07:54:36 2019] audit: type=1400 audit(1564919679.495:371): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.hook.install" pid=1498 comm="apparmor_parser"
[Sun Aug 4 07:54:36 2019] audit: type=1400 audit(1564919679.495:372): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.daemon" pid=1497 comm="apparmor_parser"
[Sun Aug 4 07:54:36 2019] audit: type=1400 audit(1564919679.499:373): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.lxd" pid=1500 comm="apparmor_parser"
[Sun Aug 4 07:54:36 2019] audit: type=1400 audit(1564919679.499:374): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.lxc" pid=1499 comm="apparmor_parser"
[Sun Aug 4 07:54:41 2019] kauditd_printk_skb: 20 callbacks suppressed
[Sun Aug 4 07:54:41 2019] audit: type=1400 audit(1564919684.999:395): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.activate" pid=1709 comm="apparmor_parser"
[Sun Aug 4 07:54:41 2019] audit: type=1400 audit(1564919684.999:396): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.benchmark" pid=1710 comm="apparmor_parser"
[Sun Aug 4 07:54:41 2019] audit: type=1400 audit(1564919685.003:397): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.buginfo" pid=1711 comm="apparmor_parser"
[Sun Aug 4 07:54:41 2019] audit: type=1400 audit(1564919685.003:398): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.check-kernel" pid=1712 comm="apparmor_parser"
[Sun Aug 4 07:54:41 2019] audit: type=1400 audit(1564919685.183:399): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.hook.install" pid=1715 comm="apparmor_parser"
[Sun Aug 4 07:54:41 2019] audit: type=1400 audit(1564919685.183:400): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.lxc" pid=1716 comm="apparmor_parser"
[Sun Aug 4 07:54:41 2019] audit: type=1400 audit(1564919685.183:401): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.hook.configure" pid=1714 comm="apparmor_parser"
[Sun Aug 4 07:54:41 2019] audit: type=1400 audit(1564919685.247:402): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.daemon" pid=1713 comm="apparmor_parser"
[Sun Aug 4 07:54:41 2019] audit: type=1400 audit(1564919685.335:403): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.migrate" pid=1718 comm="apparmor_parser"
[Sun Aug 4 07:54:41 2019] audit: type=1400 audit(1564919685.339:404): apparmor="STATUS" operation="profile_replace" label="lxd-disco_</var/snap/lxd/common/lxd>//&:lxd-disco_<var-snap-lxd-common-lxd>:unconfined" name="snap.lxd.lxd" pid=1717 comm="apparmor_parser"
[Sun Aug 4 07:55:34 2019] nf_conntrack: default automatic helper assignment has been turned off for security reasons and CT-based firewall rule not found. Use the iptables CT target to attach helpers instead.
[Sun Aug 4 18:21:19 2019] perf: interrupt took too long (6254 > 6227), lowering kernel.perf_event_max_sample_rate to 31750
Odd, so you’re not hitting any obvious kernel bug at least.
It may be interesting to reproduce your issue, then when you get the stuck process, do cat /proc/PID/stack
which should show where exactly the process is stuck.
I’m running a shiftfs and non-shiftfs container side-by-side to see if the problem recurs. Below is output from zfs list
edited to remove some very long lines. Both container datasets are clones of the same image snapshot but the space used by the shiftfs container is much higher. This pool uses lz4
compression.
I know that figuring out ZFS disk usage can be confusing, but this looks like using shiftfs causes the entire image to be more than duplicated.
NAME USED AVAIL REFER
pool/lxd/containers/disco 87.3M 26.0G 558M
pool/lxd/containers/disco-shiftfs 822M 26.0G 1.27G
pool/lxd/images/<removed> 483M 26.0G 483M
That’s quite a bit larger than the image too, can you run du -sch -x /
inside both containers?
Both produced identical output:
571M /
571M total
That’s odd. With both containers started, can you run the same du
but this time against /var/snap/lxd/common/mntns/var/snap/lxd/common/lxd/storage-pools/default/containers/NAME
?
Both commands return 571M
.
Here’s something else odd. After some routine package updates the shiftfs container appears to be consuming pool space at a faster rate:
NAME USED AVAIL REFER
pool/lxd/containers/disco 105M 25.6G 562M
pool/lxd/containers/disco-shiftfs 1.24G 25.6G 1.69G
/var/log/apt/history.log
shows the updates to each container were identical. The only snap installed is core
.
That’s very weird because the du
output for the storage-pool volume entry should have been an identical match to filesystem usage… So I wonder exactly what zfs is tracking here.
I’m assuming that disco-shiftfs
doesn’t have any snapshots right?
Might also be interesting to see zfs get all pool/lxd/containers/disco
and pool/lxd/containers/disco-shiftfs
NAME PROPERTY VALUE SOURCE
pool/lxd/containers/disco type filesystem -
pool/lxd/containers/disco creation Sun Aug 4 7:53 2019 -
pool/lxd/containers/disco used 105M -
pool/lxd/containers/disco available 25.6G -
pool/lxd/containers/disco referenced 562M -
pool/lxd/containers/disco compressratio 2.18x -
pool/lxd/containers/disco mounted no -
pool/lxd/containers/disco origin pool/lxd/images/4b6301a6704253ff5e1a12c8521b55d8dcafad30f218b65edcb78ee3e110bf74@readonly -
pool/lxd/containers/disco quota none local
pool/lxd/containers/disco reservation none default
pool/lxd/containers/disco recordsize 128K default
pool/lxd/containers/disco mountpoint /var/snap/lxd/common/lxd/storage-pools/default/containers/disco local
pool/lxd/containers/disco sharenfs off default
pool/lxd/containers/disco checksum on default
pool/lxd/containers/disco compression lz4 inherited from pool
pool/lxd/containers/disco atime on default
pool/lxd/containers/disco devices on inherited from pool/lxd
pool/lxd/containers/disco exec on inherited from pool/lxd
pool/lxd/containers/disco setuid on inherited from pool/lxd
pool/lxd/containers/disco readonly off default
pool/lxd/containers/disco zoned off default
pool/lxd/containers/disco snapdir hidden default
pool/lxd/containers/disco aclinherit restricted default
pool/lxd/containers/disco createtxg 8033064 -
pool/lxd/containers/disco canmount noauto local
pool/lxd/containers/disco xattr sa inherited from pool/lxd
pool/lxd/containers/disco copies 1 default
pool/lxd/containers/disco version 5 -
pool/lxd/containers/disco utf8only off -
pool/lxd/containers/disco normalization none -
pool/lxd/containers/disco casesensitivity sensitive -
pool/lxd/containers/disco vscan off default
pool/lxd/containers/disco nbmand off default
pool/lxd/containers/disco sharesmb off default
pool/lxd/containers/disco refquota none default
pool/lxd/containers/disco refreservation none default
pool/lxd/containers/disco guid 5458112912204137206 -
pool/lxd/containers/disco primarycache all default
pool/lxd/containers/disco secondarycache all default
pool/lxd/containers/disco usedbysnapshots 0B -
pool/lxd/containers/disco usedbydataset 105M -
pool/lxd/containers/disco usedbychildren 0B -
pool/lxd/containers/disco usedbyrefreservation 0B -
pool/lxd/containers/disco logbias latency default
pool/lxd/containers/disco dedup off default
pool/lxd/containers/disco mlslabel none default
pool/lxd/containers/disco sync standard default
pool/lxd/containers/disco dnodesize legacy default
pool/lxd/containers/disco refcompressratio 1.74x -
pool/lxd/containers/disco written 105M -
pool/lxd/containers/disco logicalused 222M -
pool/lxd/containers/disco logicalreferenced 971M -
pool/lxd/containers/disco volmode default default
pool/lxd/containers/disco filesystem_limit none default
pool/lxd/containers/disco snapshot_limit none default
pool/lxd/containers/disco filesystem_count none default
pool/lxd/containers/disco snapshot_count none default
pool/lxd/containers/disco snapdev hidden default
pool/lxd/containers/disco acltype posixacl inherited from pool/lxd
pool/lxd/containers/disco context none default
pool/lxd/containers/disco fscontext none default
pool/lxd/containers/disco defcontext none default
pool/lxd/containers/disco rootcontext none default
pool/lxd/containers/disco relatime off default
pool/lxd/containers/disco redundant_metadata all default
pool/lxd/containers/disco overlay off default
pool/lxd/containers/disco com.sun:auto-snapshot false inherited from pool
NAME PROPERTY VALUE SOURCE
pool/lxd/containers/disco-shiftfs type filesystem -
pool/lxd/containers/disco-shiftfs creation Mon Aug 5 11:07 2019 -
pool/lxd/containers/disco-shiftfs used 1.24G -
pool/lxd/containers/disco-shiftfs available 25.6G -
pool/lxd/containers/disco-shiftfs referenced 1.70G -
pool/lxd/containers/disco-shiftfs compressratio 1.67x -
pool/lxd/containers/disco-shiftfs mounted no -
pool/lxd/containers/disco-shiftfs origin pool/lxd/images/4b6301a6704253ff5e1a12c8521b55d8dcafad30f218b65edcb78ee3e110bf74@readonly -
pool/lxd/containers/disco-shiftfs quota none local
pool/lxd/containers/disco-shiftfs reservation none default
pool/lxd/containers/disco-shiftfs recordsize 128K default
pool/lxd/containers/disco-shiftfs mountpoint /var/snap/lxd/common/lxd/storage-pools/default/containers/disco-shiftfs local
pool/lxd/containers/disco-shiftfs sharenfs off default
pool/lxd/containers/disco-shiftfs checksum on default
pool/lxd/containers/disco-shiftfs compression lz4 inherited from pool
pool/lxd/containers/disco-shiftfs atime on default
pool/lxd/containers/disco-shiftfs devices on inherited from pool/lxd
pool/lxd/containers/disco-shiftfs exec on inherited from pool/lxd
pool/lxd/containers/disco-shiftfs setuid on inherited from pool/lxd
pool/lxd/containers/disco-shiftfs readonly off default
pool/lxd/containers/disco-shiftfs zoned off default
pool/lxd/containers/disco-shiftfs snapdir hidden default
pool/lxd/containers/disco-shiftfs aclinherit restricted default
pool/lxd/containers/disco-shiftfs createtxg 8052330 -
pool/lxd/containers/disco-shiftfs canmount noauto local
pool/lxd/containers/disco-shiftfs xattr sa inherited from pool/lxd
pool/lxd/containers/disco-shiftfs copies 1 default
pool/lxd/containers/disco-shiftfs version 5 -
pool/lxd/containers/disco-shiftfs utf8only off -
pool/lxd/containers/disco-shiftfs normalization none -
pool/lxd/containers/disco-shiftfs casesensitivity sensitive -
pool/lxd/containers/disco-shiftfs vscan off default
pool/lxd/containers/disco-shiftfs nbmand off default
pool/lxd/containers/disco-shiftfs sharesmb off default
pool/lxd/containers/disco-shiftfs refquota none default
pool/lxd/containers/disco-shiftfs refreservation none default
pool/lxd/containers/disco-shiftfs guid 5217981688024002070 -
pool/lxd/containers/disco-shiftfs primarycache all default
pool/lxd/containers/disco-shiftfs secondarycache all default
pool/lxd/containers/disco-shiftfs usedbysnapshots 0B -
pool/lxd/containers/disco-shiftfs usedbydataset 1.24G -
pool/lxd/containers/disco-shiftfs usedbychildren 0B -
pool/lxd/containers/disco-shiftfs usedbyrefreservation 0B -
pool/lxd/containers/disco-shiftfs logbias latency default
pool/lxd/containers/disco-shiftfs dedup off default
pool/lxd/containers/disco-shiftfs mlslabel none default
pool/lxd/containers/disco-shiftfs sync standard default
pool/lxd/containers/disco-shiftfs dnodesize legacy default
pool/lxd/containers/disco-shiftfs refcompressratio 1.67x -
pool/lxd/containers/disco-shiftfs written 1.24G -
pool/lxd/containers/disco-shiftfs logicalused 2.08G -
pool/lxd/containers/disco-shiftfs logicalreferenced 2.84G -
pool/lxd/containers/disco-shiftfs volmode default default
pool/lxd/containers/disco-shiftfs filesystem_limit none default
pool/lxd/containers/disco-shiftfs snapshot_limit none default
pool/lxd/containers/disco-shiftfs filesystem_count none default
pool/lxd/containers/disco-shiftfs snapshot_count none default
pool/lxd/containers/disco-shiftfs snapdev hidden default
pool/lxd/containers/disco-shiftfs acltype posixacl inherited from pool/lxd
pool/lxd/containers/disco-shiftfs context none default
pool/lxd/containers/disco-shiftfs fscontext none default
pool/lxd/containers/disco-shiftfs defcontext none default
pool/lxd/containers/disco-shiftfs rootcontext none default
pool/lxd/containers/disco-shiftfs relatime off default
pool/lxd/containers/disco-shiftfs redundant_metadata all default
pool/lxd/containers/disco-shiftfs overlay off default
pool/lxd/containers/disco-shiftfs com.sun:auto-snapshot false inherited from pool
My observations of shiftfs storage use so far have been on an existing physical server. I thought I would try to recreate the behavior on a newly created virtual system. Here’s what I did:
- Install Bionic Server in VirtualBox (on a Mac) with 2 virtual disks
- Upgrade to HWE kernel
- Initialize ZFS on 2nd virtual disk (using
lz4
) - Migrate to LXD snap
- Initialize LXD to use ZFS dataset and default bridge
- Launch container
disco
- Enable shiftfs
- Launch container
disco-shiftfs
Immediately after launch:
NAME USED AVAIL REFER
pool/lxd/containers/disco 8.07M 3.36G 484M
pool/lxd/containers/disco-shiftfs 5.64M 3.36G 487M
After updating the few outdated packages:
NAME USED AVAIL REFER
pool/lxd/containers/disco 104M 3.04G 560M
pool/lxd/containers/disco-shiftfs 233M 3.04G 712M
After installing build-essential
:
NAME USED AVAIL REFER
pool/lxd/containers/disco 191M 2.80G 648M
pool/lxd/containers/disco-shiftfs 393M 2.80G 872M
At this point du -sch -x /
still matches from inside each container at 660M
.
Hopefully this helps with recreating the issue.
Hm, not really atm.
How exactly are the zfs tools calculating disk usage. Because du seems to be working just fine, so that doesn’t look like a bug in shiftfs.