ZFS shmounts issues

[tomposmiko]

Required information

• Distribution: Ubuntu
• Distribution version: Focal
• The output of "lxc info" or if that fails:

  config: {}
  api_extensions:
  - storage_zfs_remove_snapshots
  - container_host_shutdown_timeout
  - container_stop_priority
  - container_syscall_filtering
  - auth_pki
  - container_last_used_at
  - etag
  - patch
  - usb_devices
  - https_allowed_credentials
  - image_compression_algorithm
  - directory_manipulation
  - container_cpu_time
  - storage_zfs_use_refquota
  - storage_lvm_mount_options
  - network
  - profile_usedby
  - container_push
  - container_exec_recording
  - certificate_update
  - container_exec_signal_handling
  - gpu_devices
  - container_image_properties
  - migration_progress
  - id_map
  - network_firewall_filtering
  - network_routes
  - storage
  - file_delete
  - file_append
  - network_dhcp_expiry
  - storage_lvm_vg_rename
  - storage_lvm_thinpool_rename
  - network_vlan
  - image_create_aliases
  - container_stateless_copy
  - container_only_migration
  - storage_zfs_clone_copy
  - unix_device_rename
  - storage_lvm_use_thinpool
  - storage_rsync_bwlimit
  - network_vxlan_interface
  - storage_btrfs_mount_options
  - entity_description
  - image_force_refresh
  - storage_lvm_lv_resizing
  - id_map_base
  - file_symlinks
  - container_push_target
  - network_vlan_physical
  - storage_images_delete
  - container_edit_metadata
  - container_snapshot_stateful_migration
  - storage_driver_ceph
  - storage_ceph_user_name
  - resource_limits
  - storage_volatile_initial_source
  - storage_ceph_force_osd_reuse
  - storage_block_filesystem_btrfs
  - resources
  - kernel_limits
  - storage_api_volume_rename
  - macaroon_authentication
  - network_sriov
  - console
  - restrict_devlxd
  - migration_pre_copy
  - infiniband
  - maas_network
  - devlxd_events
  - proxy
  - network_dhcp_gateway
  - file_get_symlink
  - network_leases
  - unix_device_hotplug
  - storage_api_local_volume_handling
  - operation_description
  - clustering
  - event_lifecycle
  - storage_api_remote_volume_handling
  - nvidia_runtime
  - container_mount_propagation
  - container_backup
  - devlxd_images
  - container_local_cross_pool_handling
  - proxy_unix
  - proxy_udp
  - clustering_join
  - proxy_tcp_udp_multi_port_handling
  - network_state
  - proxy_unix_dac_properties
  - container_protection_delete
  - unix_priv_drop
  - pprof_http
  - proxy_haproxy_protocol
  - network_hwaddr
  - proxy_nat
  - network_nat_order
  - container_full
  - candid_authentication
  - backup_compression
  - candid_config
  - nvidia_runtime_config
  - storage_api_volume_snapshots
  - storage_unmapped
  - projects
  - candid_config_key
  - network_vxlan_ttl
  - container_incremental_copy
  - usb_optional_vendorid
  - snapshot_scheduling
  - container_copy_project
  - clustering_server_address
  - clustering_image_replication
  - container_protection_shift
  - snapshot_expiry
  - container_backup_override_pool
  - snapshot_expiry_creation
  - network_leases_location
  - resources_cpu_socket
  - resources_gpu
  - resources_numa
  - kernel_features
  - id_map_current
  - event_location
  - storage_api_remote_volume_snapshots
  - network_nat_address
  - container_nic_routes
  - rbac
  - cluster_internal_copy
  - seccomp_notify
  - lxc_features
  - container_nic_ipvlan
  - network_vlan_sriov
  - storage_cephfs
  - container_nic_ipfilter
  - resources_v2
  - container_exec_user_group_cwd
  - container_syscall_intercept
  - container_disk_shift
  - storage_shifted
  - resources_infiniband
  - daemon_storage
  - instances
  - image_types
  - resources_disk_sata
  - clustering_roles
  - images_expiry
  - resources_network_firmware
  - backup_compression_algorithm
  - ceph_data_pool_name
  - container_syscall_intercept_mount
  - compression_squashfs
  - container_raw_mount
  - container_nic_routed
  - container_syscall_intercept_mount_fuse
  - container_disk_ceph
  - virtual-machines
  - image_profiles
  - clustering_architecture
  - resources_disk_id
  - storage_lvm_stripes
  - vm_boot_priority
  - unix_hotplug_devices
  - api_filtering
  - instance_nic_network
  - clustering_sizing
  - firewall_driver
  - projects_limits
  - container_syscall_intercept_hugetlbfs
  - limits_hugepages
  - container_nic_routed_gateway
  - projects_restrictions
  - custom_volume_snapshot_expiry
  - volume_snapshot_scheduling
  - trust_ca_certificates
  - snapshot_disk_usage
  - clustering_edit_roles
  - container_nic_routed_host_address
  - container_nic_ipvlan_gateway
  - resources_usb_pci
  - resources_cpu_threads_numa
  - resources_cpu_core_die
  - api_os
  - resources_system
  - usedby_consistency
  api_status: stable
  api_version: "1.0"
  auth: trusted
  public: false
  auth_methods:
  - tls
  environment:
  addresses: []
  architectures:
  - x86_64
  - i686
  certificate: |
  -----BEGIN CERTIFICATE-----
  MIIFPjCCAyagAwIBAgIRAO0feJeGdoQakUfi0zaZEqAwDQYJKoZIhvcNAQELBQAw
  MzEcMBoGA1UEChMTbGludXhjb250YWluZXJzLm9yZzETMBEGA1UEAwwKcm9vdEB0
  dW1teTAeFw0xOTA0MjcxNDQ4MzJaFw0yOTA0MjQxNDQ4MzJaMDMxHDAaBgNVBAoT
  E2xpbnV4Y29udGFpbmVycy5vcmcxEzARBgNVBAMMCnJvb3RAdHVtbXkwggIiMA0G
  CSqGSIb3DQEBAQUAA4ICDwAwggIKAoICAQC11IOxuOtOzsGjz2jn8cDnTBZ3xrsF
  N6CS5jIZQA6S101Hj+TsyNvAOn3Lp5wFzq2+v79VbbKpnKjCZkOpY+sLkZoHphl5
  GPOBaGZgEK3ySlRIuSiaQH+yZl6ExYgLctyo8BtoxsZyJJrSt+YNHql2rQoDxdBG
  7MlvmJ6v5pJfLQc2QDHP2k/UJLVpdqFFw0D3f+t6yjh8vjXm9tBUuAs/RJHGwwca
  ex1dcEdkIDISsO5GenvOm5L04GIh+x3nAOdVY2NLaxOPXvpEhX13b4Rp4nKokld6
  0VD7uKP5e0Q2soztGBhNPHetEMSs34zR4V7GOxIOz4UsQ2+bifo7nSnBuED1uHNc
  Mjb0m7QmMLFQjhvF+BG0Ja4cB5gP/3fVF41NgDJqhyDoKeW3rDNziD+Bz3MJcDFu
  ISe5kFMBotDqas8IWGpGUJsM9iKcQFk76rSkExTRA6EHmEiBCxF6K8wRg0dLfg3f
  96E++8hOyaptb7kRxNzCl3sjXet4A24V4th+d3IQzVZ/BvvnWWUiTbkMzoU90ZDg
  cssmCoAPZ8FBfXd48AyOaJ+YxqakdoqiJGyedEwQjWFfTlMwSpva1C7Bj7LHyR2+
  vbmFwc4iJEVX3tniWKk6sWcoHBIxCq1kxf0jNssavjDKZjbOa0KgTygcpCtMU3GW
  oUeIX8fkQyXgJQIDAQABo00wSzAOBgNVHQ8BAf8EBAMCBaAwEwYDVR0lBAwwCgYI
  KwYBBQUHAwEwDAYDVR0TAQH/BAIwADAWBgNVHREEDzANggV0dW1teYcEwKigTDAN
  BgkqhkiG9w0BAQsFAAOCAgEAZlewGkZBaEGumo4teqNg/Z981ey5ZqmXmiznAAIl
  Fnv0Mlbg73wnqeIKeAOz+9eJiQ9vmXzbag3KLuuWR6DWL9EnST8VkOqeIh78NQIX
  bSag2QpSlT5RaOHhDrHHSwlFBuzycJCVvMU9TuUvA/sSzgP/lIuu/T/v0gdwriCt
  ofSLz7YyqpDIOUbCgqWOMFXMkhZqLJPo2Se609qHcqhS1tUATW62nhF4Ly9GXTu7
  HlrPqw1a2/BGyrGSRSn6AWcVV+6nCJfdekv0Ed2nc6QVPaK2lAMmDofc289MGrAa
  BGlttdRzS0zuNg3GKySS6+xbryGvAXDBL39iZMMAog9T55t2fB8RM1BeYcyhJVM5
  WORk1IQlzBx0bXz0Xtkr6nYLfg/IDswyyDbkT1yGLHZjcz70u2MU5tbChmOyAbVu
  tCE3QVCLj/+KHIlE+Z5YIZ17LKcUTI6jiViESOSRm6Qvi0XkQcaK06JRaH6neXi0
  ACq5NJ2UjSOhk60TQj18I493/ooFR3nN5M8OPyVLEXruEOsjw5E6BBqBt70H4/9V
  F2PqMhhCvrzdd9faC4PKPcHRKMzhMyd3+0NffT2Z8l3dElSmN5dyv4Ig3sLD3uTj
  4vRTMt8lrfmfeIXlwk+i9RslYsYmGGETi8R85FrTbMLv6SpDbRLQ74rarbU4nnFi
  ZpA=
  -----END CERTIFICATE-----
  certificate_fingerprint: ae0ef773c385ab2d7e14642aea1ec8aae8728be9b5862240b045de9b45b740b4
  driver: lxc
  driver_version: 4.0.3
  firewall: xtables
  kernel: Linux
  kernel_architecture: x86_64
  kernel_features:
  netnsid_getifaddrs: "true"
  seccomp_listener: "true"
  seccomp_listener_continue: "true"
  shiftfs: "false"
  uevent_injection: "true"
  unpriv_fscaps: "true"
  kernel_version: 5.4.0-40-generic
  lxc_features:
  cgroup2: "true"
  mount_injection_file: "true"
  network_gateway_device_route: "true"
  network_ipvlan: "true"
  network_l2proxy: "true"
  network_phys_macvlan_mtu: "true"
  network_veth_router: "true"
  pidfd: "true"
  seccomp_allow_deny_syntax: "true"
  seccomp_notify: "true"
  os_name: Ubuntu
  os_version: "20.04"
  project: default
  server: lxd
  server_clustered: false
  server_name: tummy
  server_pid: 1215389
  server_version: 4.0.2
  storage: zfs
  storage_version: 0.8.3-1ubuntu12

Issue description

This issue already happened a couple of months ago. At that time restarting the server fixed it. No it's back.

Steps to reproduce

I have no reproducer, just the failing environment.

# lxc snapshot feb sssss
Error: Create instance snapshot (mount source): Failed to run: zfs mount tank/lxd/containers/feb: cannot mount 'tank/lxd/containers/feb': filesystem already mounted

Information to attach

I see no more relevant information. It just started to happen. Let me know if I can help more.

[stgraber]

Can you show:

• nsenter --mount=/run/snapd/ns/lxd.mnt cat /proc/self/mountinfo
• journalctl -u snap.lxd.daemon -n 300

[tomposmiko]

# nsenter --mount=/run/snapd/ns/lxd.mnt cat /proc/self/mountinfo
5546 5786 0:25 /@ /var/lib/snapd/hostfs rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@
5647 5546 0:24 / /var/lib/snapd/hostfs/run rw,nosuid,nodev,noexec,relatime master:5 - tmpfs tmpfs rw,size=3275204k,mode=755
5648 5647 0:29 / /var/lib/snapd/hostfs/run/lock rw,nosuid,nodev,noexec,relatime master:6 - tmpfs tmpfs rw,size=5120k
5649 5647 0:24 /snapd/ns /var/lib/snapd/hostfs/run/snapd/ns rw,nosuid,nodev,noexec,relatime - tmpfs tmpfs rw,size=3275204k,mode=755
5679 5546 7:2 / /var/lib/snapd/hostfs/snap/lxd/16099 ro,nodev,relatime master:69 - squashfs /dev/loop2 ro
5680 5546 7:5 / /var/lib/snapd/hostfs/snap/snapd/8140 ro,nodev,relatime master:77 - squashfs /dev/loop5 ro
5681 5546 0:25 /@home /var/lib/snapd/hostfs/home rw,relatime master:79 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=258,subvol=/@home
5682 5546 0:53 / /var/lib/snapd/hostfs/tank rw,noatime master:81 - zfs tank rw,xattr,noacl
5683 5682 0:54 / /var/lib/snapd/hostfs/tank/lxc rw,noatime master:83 - zfs tank/lxc rw,xattr,noacl
5684 5683 0:55 / /var/lib/snapd/hostfs/tank/lxc/jolokia rw,noatime master:85 - zfs tank/lxc/jolokia rw,xattr,noacl
5685 5546 0:60 / /var/lib/snapd/hostfs/var/lib/lxcfs rw,nosuid,nodev,relatime master:208 - fuse.lxcfs lxcfs rw,user_id=0,group_id=0,allow_other
5686 5546 0:63 / /var/lib/snapd/hostfs/var/snap/lxd/common/ns rw,relatime master:1174 - tmpfs tmpfs rw,size=1024k,mode=700
5687 5546 7:6 / /var/lib/snapd/hostfs/snap/core18/1880 ro,nodev,relatime master:1159 - squashfs /dev/loop6 ro
5688 5546 7:0 / /var/lib/snapd/hostfs/snap/snapd/8542 ro,nodev,relatime master:73 - squashfs /dev/loop0 ro
5689 5546 7:3 / /var/lib/snapd/hostfs/snap/lxd/16558 ro,nodev,relatime master:1172 - squashfs /dev/loop3 ro
5690 5546 7:4 / /var/lib/snapd/hostfs/snap/core18/1885 ro,nodev,relatime master:613 - squashfs /dev/loop4 ro
5708 5515 7:4 / / ro,nodev,relatime master:613 - squashfs /dev/loop4 ro
5709 5708 0:6 / /dev rw,nosuid,noexec,relatime master:2 - devtmpfs udev rw,size=16345716k,nr_inodes=4086429,mode=755
5710 5709 0:23 / /dev/pts rw,nosuid,noexec,relatime master:3 - devpts devpts rw,gid=5,mode=620,ptmxmode=000
5711 5709 0:28 / /dev/shm rw,nosuid,nodev master:4 - tmpfs tmpfs rw
5712 5709 0:47 / /dev/hugepages rw,relatime master:27 - hugetlbfs hugetlbfs rw,pagesize=2M
5713 5709 0:20 / /dev/mqueue rw,nosuid,nodev,noexec,relatime master:28 - mqueue mqueue rw
5714 5708 0:25 /@/etc /etc rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/etc
5715 5708 0:25 /@home /home rw,relatime master:79 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=258,subvol=/@home
5716 5708 0:25 /@/root /root rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/root
5717 5708 0:5 / /proc rw,nosuid,nodev,noexec,relatime master:14 - proc proc rw
5718 5717 0:46 / /proc/sys/fs/binfmt_misc rw,relatime master:26 - autofs systemd-1 rw,fd=28,pgrp=1,timeout=0,minproto=5,maxproto=5,direct,pipe_ino=2806
5719 5718 0:77 / /proc/sys/fs/binfmt_misc rw,nosuid,nodev,noexec,relatime master:267 - binfmt_misc binfmt_misc rw
5720 5708 0:22 / /sys rw,nosuid,nodev,noexec,relatime master:7 - sysfs sysfs rw
5721 5720 0:7 / /sys/kernel/security rw,nosuid,nodev,noexec,relatime master:8 - securityfs securityfs rw
5722 5720 0:30 / /sys/fs/cgroup ro,nosuid,nodev,noexec master:9 - tmpfs tmpfs ro,mode=755
5723 5722 0:31 / /sys/fs/cgroup/unified rw,nosuid,nodev,noexec,relatime master:10 - cgroup2 cgroup2 rw
5724 5722 0:32 / /sys/fs/cgroup/systemd rw,nosuid,nodev,noexec,relatime master:11 - cgroup cgroup rw,xattr,name=systemd
5742 5722 0:35 / /sys/fs/cgroup/freezer rw,nosuid,nodev,noexec,relatime master:15 - cgroup cgroup rw,freezer
5743 5722 0:36 / /sys/fs/cgroup/hugetlb rw,nosuid,nodev,noexec,relatime master:16 - cgroup cgroup rw,hugetlb
5744 5722 0:37 / /sys/fs/cgroup/devices rw,nosuid,nodev,noexec,relatime master:17 - cgroup cgroup rw,devices
5745 5722 0:38 / /sys/fs/cgroup/cpu,cpuacct rw,nosuid,nodev,noexec,relatime master:18 - cgroup cgroup rw,cpu,cpuacct
5746 5722 0:39 / /sys/fs/cgroup/memory rw,nosuid,nodev,noexec,relatime master:19 - cgroup cgroup rw,memory
5747 5722 0:40 / /sys/fs/cgroup/pids rw,nosuid,nodev,noexec,relatime master:20 - cgroup cgroup rw,pids
5748 5722 0:41 / /sys/fs/cgroup/net_cls,net_prio rw,nosuid,nodev,noexec,relatime master:21 - cgroup cgroup rw,net_cls,net_prio
5749 5722 0:42 / /sys/fs/cgroup/blkio rw,nosuid,nodev,noexec,relatime master:22 - cgroup cgroup rw,blkio
5750 5722 0:43 / /sys/fs/cgroup/perf_event rw,nosuid,nodev,noexec,relatime master:23 - cgroup cgroup rw,perf_event
5751 5722 0:44 / /sys/fs/cgroup/cpuset rw,nosuid,nodev,noexec,relatime master:24 - cgroup cgroup rw,cpuset,clone_children
5752 5722 0:45 / /sys/fs/cgroup/rdma rw,nosuid,nodev,noexec,relatime master:25 - cgroup cgroup rw,rdma
5753 5720 0:33 / /sys/fs/pstore rw,nosuid,nodev,noexec,relatime master:12 - pstore pstore rw
5754 5720 0:34 / /sys/fs/bpf rw,nosuid,nodev,noexec,relatime master:13 - bpf none rw,mode=700
5755 5720 0:8 / /sys/kernel/debug rw,nosuid,nodev,noexec,relatime master:29 - debugfs debugfs rw
5756 5720 0:12 / /sys/kernel/tracing rw,nosuid,nodev,noexec,relatime master:30 - tracefs tracefs rw
5757 5720 0:48 / /sys/fs/fuse/connections rw,nosuid,nodev,noexec,relatime master:31 - fusectl fusectl rw
5758 5720 0:21 / /sys/kernel/config rw,nosuid,nodev,noexec,relatime master:32 - configfs configfs rw
5759 5708 0:25 /@/tmp /tmp rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/tmp
5760 5708 0:25 /@/var/snap /var/snap rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/var/snap
5761 5760 0:63 / /var/snap/lxd/common/ns rw,relatime master:1174 - tmpfs tmpfs rw,size=1024k,mode=700
5762 5708 0:25 /@/var/lib/dhcp /var/lib/dhcp rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/var/lib/dhcp
5763 5708 0:25 /@/var/lib/snapd /var/lib/snapd rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/var/lib/snapd
5764 5708 0:25 /@/var/tmp /var/tmp rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/var/tmp
5765 5708 0:24 / /run rw,nosuid,nodev,noexec,relatime master:5 - tmpfs tmpfs rw,size=3275204k,mode=755
5766 5765 0:29 / /run/lock rw,nosuid,nodev,noexec,relatime master:6 - tmpfs tmpfs rw,size=5120k
5767 5765 0:24 /snapd/ns /run/snapd/ns rw,nosuid,nodev,noexec,relatime - tmpfs tmpfs rw,size=3275204k,mode=755
5769 5708 0:25 /@/lib/modules /lib/modules rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/lib/modules
5770 5708 0:25 /@/lib/firmware /lib/firmware rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/lib/firmware
5771 5708 0:25 /@/usr/src /usr/src rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/usr/src
5772 5708 0:25 /@/var/log /var/log rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/var/log
5773 5708 0:25 /@/media /media rw,relatime shared:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/media
5774 5765 0:24 /netns /run/netns rw,nosuid,nodev,noexec,relatime shared:5 - tmpfs tmpfs rw,size=3275204k,mode=755
5775 5708 0:25 /@/mnt /mnt rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/mnt
5776 5714 7:4 /etc/ssl /etc/ssl ro,nodev,relatime master:613 - squashfs /dev/loop4 ro
5777 5714 7:4 /etc/nsswitch.conf /etc/nsswitch.conf ro,nodev,relatime master:613 - squashfs /dev/loop4 ro
5778 5708 7:0 /usr/lib/snapd /usr/lib/snapd ro,nodev,relatime master:73 - squashfs /dev/loop0 ro
5779 5708 0:25 /@/snap /snap rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/snap
5780 5779 7:2 / /snap/lxd/16099 ro,nodev,relatime master:69 - squashfs /dev/loop2 ro
5781 5779 7:5 / /snap/snapd/8140 ro,nodev,relatime master:77 - squashfs /dev/loop5 ro
5782 5779 7:6 / /snap/core18/1880 ro,nodev,relatime master:1159 - squashfs /dev/loop6 ro
5783 5779 7:0 / /snap/snapd/8542 ro,nodev,relatime master:73 - squashfs /dev/loop0 ro
5784 5779 7:3 / /snap/lxd/16558 ro,nodev,relatime master:1172 - squashfs /dev/loop3 ro
5785 5779 7:4 / /snap/core18/1885 ro,nodev,relatime master:613 - squashfs /dev/loop4 ro
5786 5763 0:25 /@/var/lib/snapd/hostfs /var/lib/snapd/hostfs rw,relatime - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/var/lib/snapd/hostfs
5628 5759 0:25 /@/tmp/snap.lxd/tmp /tmp rw,relatime - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/tmp/snap.lxd/tmp
5643 5710 0:200 / /dev/pts rw,relatime - devpts devpts rw,gid=5,mode=620,ptmxmode=666
5644 5709 0:200 /ptmx /dev/ptmx rw,relatime - devpts devpts rw,gid=5,mode=620,ptmxmode=666
430 5765 0:199 / /run/user/1000 rw,nosuid,nodev,relatime master:67 - tmpfs tmpfs rw,size=3275200k,mode=700,uid=1000,gid=1000
408 5647 0:199 / /var/lib/snapd/hostfs/run/user/1000 rw,nosuid,nodev,relatime master:67 - tmpfs tmpfs rw,size=3275200k,mode=700,uid=1000,gid=1000

# journalctl -u snap.lxd.daemon -n 300
-- Logs begin at Wed 2020-07-01 22:00:02 CEST, end at Thu 2020-08-06 22:34:01 CEST. --
Jul 06 23:44:00 tummy lxd.daemon[2914]: mount namespace: 5
Jul 06 23:44:00 tummy lxd.daemon[2914]: hierarchies:
Jul 06 23:44:00 tummy lxd.daemon[2914]:   0: fd:   6:
Jul 06 23:44:00 tummy lxd.daemon[2914]:   1: fd:   7: name=systemd
Jul 06 23:44:00 tummy lxd.daemon[2914]:   2: fd:   8: rdma
Jul 06 23:44:00 tummy lxd.daemon[2914]:   3: fd:   9: blkio
Jul 06 23:44:00 tummy lxd.daemon[2914]:   4: fd:  10: memory
Jul 06 23:44:00 tummy lxd.daemon[2914]:   5: fd:  11: freezer
Jul 06 23:44:00 tummy lxd.daemon[2914]:   6: fd:  12: cpu,cpuacct
Jul 06 23:44:00 tummy lxd.daemon[2914]:   7: fd:  13: net_cls,net_prio
Jul 06 23:44:00 tummy lxd.daemon[2914]:   8: fd:  14: perf_event
Jul 06 23:44:00 tummy lxd.daemon[2914]:   9: fd:  15: cpuset
Jul 06 23:44:00 tummy lxd.daemon[2914]:  10: fd:  16: devices
Jul 06 23:44:00 tummy lxd.daemon[2914]:  11: fd:  17: hugetlb
Jul 06 23:44:00 tummy lxd.daemon[2914]:  12: fd:  19: pids
Jul 06 23:44:00 tummy lxd.daemon[2914]: Kernel supports pidfds
Jul 06 23:44:00 tummy lxd.daemon[2914]: Kernel does not support swap accounting
Jul 06 23:44:00 tummy lxd.daemon[2914]: api_extensions:
Jul 06 23:44:00 tummy lxd.daemon[2914]: - cgroups
Jul 06 23:44:00 tummy lxd.daemon[2914]: - sys_cpu_online
Jul 06 23:44:00 tummy lxd.daemon[2914]: - proc_cpuinfo
Jul 06 23:44:00 tummy lxd.daemon[2914]: - proc_diskstats
Jul 06 23:44:00 tummy lxd.daemon[2914]: - proc_loadavg
Jul 06 23:44:00 tummy lxd.daemon[2914]: - proc_meminfo
Jul 06 23:44:00 tummy lxd.daemon[2914]: - proc_stat
Jul 06 23:44:00 tummy lxd.daemon[2914]: - proc_swaps
Jul 06 23:44:00 tummy lxd.daemon[2914]: - proc_uptime
Jul 06 23:44:00 tummy lxd.daemon[2914]: - shared_pidns
Jul 06 23:44:00 tummy lxd.daemon[2914]: - cpuview_daemon
Jul 06 23:44:00 tummy lxd.daemon[2914]: - loadavg_daemon
Jul 06 23:44:00 tummy lxd.daemon[2914]: - pidfds
Jul 06 23:44:00 tummy lxd.daemon[2914]: Reloaded LXCFS
Jul 06 23:44:07 tummy lxd.daemon[1307522]: t=2020-07-06T23:44:07+0200 lvl=eror msg="The stop hook failed" container=gaia err="Failed to unmount '/var/snap/lxd/common/lxd/storage-pools/default/containers/gaia': >
Jul 10 00:57:04 tummy systemd[1]: Stopping Service for snap application lxd.daemon...
Jul 10 00:57:04 tummy lxd.daemon[3925179]: => Stop reason is: snap refresh
Jul 10 00:57:04 tummy lxd.daemon[3925179]: => Stopping LXD
Jul 10 00:57:05 tummy lxd.daemon[1307136]: => LXD exited cleanly
Jul 10 00:57:06 tummy systemd[1]: snap.lxd.daemon.service: Succeeded.
Jul 10 00:57:06 tummy systemd[1]: Stopped Service for snap application lxd.daemon.
Jul 10 00:57:20 tummy systemd[1]: Started Service for snap application lxd.daemon.
Jul 10 00:57:20 tummy lxd.daemon[3926635]: => Preparing the system (16099)
Jul 10 00:57:20 tummy lxd.daemon[3926635]: ==> Loading snap configuration
Jul 10 00:57:20 tummy lxd.daemon[3926635]: ==> Setting up mntns symlink (mnt:[4026532316])
Jul 10 00:57:20 tummy lxd.daemon[3926635]: ==> Setting up kmod wrapper
Jul 10 00:57:20 tummy lxd.daemon[3926635]: ==> Preparing /boot
Jul 10 00:57:20 tummy lxd.daemon[3926635]: ==> Preparing a clean copy of /run
Jul 10 00:57:20 tummy lxd.daemon[3926635]: ==> Preparing a clean copy of /etc
Jul 10 00:57:21 tummy lxd.daemon[3926635]: ==> Preparing a clean copy of /usr/share/misc
Jul 10 00:57:21 tummy lxd.daemon[3926635]: ==> Setting up ceph configuration
Jul 10 00:57:21 tummy lxd.daemon[3926635]: ==> Setting up LVM configuration
Jul 10 00:57:21 tummy lxd.daemon[3926635]: ==> Rotating logs
Jul 10 00:57:21 tummy lxd.daemon[3926635]: ==> Setting up ZFS (0.8)
Jul 10 00:57:21 tummy lxd.daemon[3926635]: ==> Escaping the systemd cgroups

What you see above with gaia, it's a different story, it does not work for a very long time. Though the error was very similar and server reboot fixed it.

[stgraber]

The journal output looks truncated, we should have quite a few more lines there leading to LXD getting ready.

[tomposmiko]

Do you want me to restart the lxd daemon? Where can we make this more interactive? IRC?

[stgraber]

journalctl -u snap.lxd.daemon -n 300 | cat so it doesn't paginate the output and we can see the whole 300 lines.

[tomposmiko]

root@tummy:~# journalctl -u snap.lxd.daemon -n 300 |cat
-- Logs begin at Mon 2020-07-06 22:00:01 CEST, end at Tue 2020-08-11 06:03:38 CEST. --
Jul 10 00:57:04 tummy systemd[1]: Stopping Service for snap application lxd.daemon...
Jul 10 00:57:04 tummy lxd.daemon[3925179]: => Stop reason is: snap refresh
Jul 10 00:57:04 tummy lxd.daemon[3925179]: => Stopping LXD
Jul 10 00:57:05 tummy lxd.daemon[1307136]: => LXD exited cleanly
Jul 10 00:57:06 tummy systemd[1]: snap.lxd.daemon.service: Succeeded.
Jul 10 00:57:06 tummy systemd[1]: Stopped Service for snap application lxd.daemon.
Jul 10 00:57:20 tummy systemd[1]: Started Service for snap application lxd.daemon.
Jul 10 00:57:20 tummy lxd.daemon[3926635]: => Preparing the system (16099)
Jul 10 00:57:20 tummy lxd.daemon[3926635]: ==> Loading snap configuration
Jul 10 00:57:20 tummy lxd.daemon[3926635]: ==> Setting up mntns symlink (mnt:[4026532316])
Jul 10 00:57:20 tummy lxd.daemon[3926635]: ==> Setting up kmod wrapper
Jul 10 00:57:20 tummy lxd.daemon[3926635]: ==> Preparing /boot
Jul 10 00:57:20 tummy lxd.daemon[3926635]: ==> Preparing a clean copy of /run
Jul 10 00:57:20 tummy lxd.daemon[3926635]: ==> Preparing a clean copy of /etc
Jul 10 00:57:21 tummy lxd.daemon[3926635]: ==> Preparing a clean copy of /usr/share/misc
Jul 10 00:57:21 tummy lxd.daemon[3926635]: ==> Setting up ceph configuration
Jul 10 00:57:21 tummy lxd.daemon[3926635]: ==> Setting up LVM configuration
Jul 10 00:57:21 tummy lxd.daemon[3926635]: ==> Rotating logs
Jul 10 00:57:21 tummy lxd.daemon[3926635]: ==> Setting up ZFS (0.8)
Jul 10 00:57:21 tummy lxd.daemon[3926635]: ==> Escaping the systemd cgroups
Jul 10 00:57:21 tummy lxd.daemon[3926635]: ====> Detected cgroup V1
Jul 10 00:57:21 tummy lxd.daemon[3926635]: ==> Escaping the systemd process resource limits
Jul 10 00:57:21 tummy lxd.daemon[3926635]: ==> Disabling shiftfs on this kernel (auto)
Jul 10 00:57:21 tummy lxd.daemon[3926635]: => Re-using existing LXCFS
Jul 10 00:57:21 tummy lxd.daemon[3926635]: => Starting LXD
Jul 10 00:57:21 tummy lxd.daemon[3926781]: t=2020-07-10T00:57:21+0200 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, I/O weight limits will be ignored"
Jul 10 00:57:21 tummy lxd.daemon[3926781]: t=2020-07-10T00:57:21+0200 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored"
Jul 10 00:57:23 tummy lxd.daemon[3926781]: t=2020-07-10T00:57:23+0200 lvl=eror msg="Failed starting container" action=start created=2020-05-31T23:16:06+0200 ephemeral=false name=gaia project=default stateful=false used=2020-07-06T23:43:56+0200
Jul 10 00:57:23 tummy lxd.daemon[3926781]: t=2020-07-10T00:57:23+0200 lvl=eror msg="Failed to start instance 'gaia': Failed to run: /snap/lxd/current/bin/lxd forkstart gaia /var/snap/lxd/common/lxd/containers /var/snap/lxd/common/lxd/logs/gaia/lxc.conf: "
Jul 10 00:57:23 tummy lxd.daemon[3926635]: => LXD is ready
Jul 10 00:57:30 tummy lxd.daemon[2914]: Closed liblxcfs.so
Jul 10 00:57:30 tummy lxd.daemon[2914]: Running destructor lxcfs_exit
Jul 10 00:57:30 tummy lxd.daemon[2914]: Running constructor lxcfs_init to reload liblxcfs
Jul 10 00:57:30 tummy lxd.daemon[2914]: mount namespace: 5
Jul 10 00:57:30 tummy lxd.daemon[2914]: hierarchies:
Jul 10 00:57:30 tummy lxd.daemon[2914]:   0: fd:   6:
Jul 10 00:57:30 tummy lxd.daemon[2914]:   1: fd:   7: name=systemd
Jul 10 00:57:30 tummy lxd.daemon[2914]:   2: fd:   8: rdma
Jul 10 00:57:30 tummy lxd.daemon[2914]:   3: fd:   9: blkio
Jul 10 00:57:30 tummy lxd.daemon[2914]:   4: fd:  10: memory
Jul 10 00:57:30 tummy lxd.daemon[2914]:   5: fd:  11: freezer
Jul 10 00:57:30 tummy lxd.daemon[2914]:   6: fd:  12: cpu,cpuacct
Jul 10 00:57:30 tummy lxd.daemon[2914]:   7: fd:  13: net_cls,net_prio
Jul 10 00:57:30 tummy lxd.daemon[2914]:   8: fd:  14: perf_event
Jul 10 00:57:30 tummy lxd.daemon[2914]:   9: fd:  15: cpuset
Jul 10 00:57:30 tummy lxd.daemon[2914]:  10: fd:  16: devices
Jul 10 00:57:30 tummy lxd.daemon[2914]:  11: fd:  17: hugetlb
Jul 10 00:57:30 tummy lxd.daemon[2914]:  12: fd:  19: pids
Jul 10 00:57:30 tummy lxd.daemon[2914]: Kernel supports pidfds
Jul 10 00:57:30 tummy lxd.daemon[2914]: Kernel does not support swap accounting
Jul 10 00:57:30 tummy lxd.daemon[2914]: api_extensions:
Jul 10 00:57:30 tummy lxd.daemon[2914]: - cgroups
Jul 10 00:57:30 tummy lxd.daemon[2914]: - sys_cpu_online
Jul 10 00:57:30 tummy lxd.daemon[2914]: - proc_cpuinfo
Jul 10 00:57:30 tummy lxd.daemon[2914]: - proc_diskstats
Jul 10 00:57:30 tummy lxd.daemon[2914]: - proc_loadavg
Jul 10 00:57:30 tummy lxd.daemon[2914]: - proc_meminfo
Jul 10 00:57:30 tummy lxd.daemon[2914]: - proc_stat
Jul 10 00:57:30 tummy lxd.daemon[2914]: - proc_swaps
Jul 10 00:57:30 tummy lxd.daemon[2914]: - proc_uptime
Jul 10 00:57:30 tummy lxd.daemon[2914]: - shared_pidns
Jul 10 00:57:30 tummy lxd.daemon[2914]: - cpuview_daemon
Jul 10 00:57:30 tummy lxd.daemon[2914]: - loadavg_daemon
Jul 10 00:57:30 tummy lxd.daemon[2914]: - pidfds
Jul 10 00:57:30 tummy lxd.daemon[2914]: Reloaded LXCFS
Jul 10 00:57:33 tummy lxd.daemon[3926781]: t=2020-07-10T00:57:33+0200 lvl=eror msg="The stop hook failed" container=gaia err="Failed to unmount '/var/snap/lxd/common/lxd/storage-pools/default/containers/gaia': invalid argument"
-- Reboot --
Jul 12 13:54:03 tummy systemd[1]: Started Service for snap application lxd.daemon.
Jul 12 13:54:03 tummy lxd.daemon[2028]: => Preparing the system (16099)
Jul 12 13:54:03 tummy lxd.daemon[2070]: cmd_linux.go:160: cannot read /proc/self/exe: readlink /proc/self/exe: no such file or directory
Jul 12 13:54:03 tummy lxd.daemon[2028]: ==> Loading snap configuration
Jul 12 13:54:03 tummy lxd.daemon[2028]: ==> Setting up mntns symlink (mnt:[4026532315])
Jul 12 13:54:03 tummy lxd.daemon[2028]: ==> Setting up mount propagation on /var/snap/lxd/common/lxd/storage-pools
Jul 12 13:54:03 tummy lxd.daemon[2028]: ==> Setting up mount propagation on /var/snap/lxd/common/lxd/devices
Jul 12 13:54:03 tummy lxd.daemon[2028]: ==> Setting up persistent shmounts path
Jul 12 13:54:03 tummy lxd.daemon[2028]: ====> Making LXD shmounts use the persistent path
Jul 12 13:54:03 tummy lxd.daemon[2028]: ====> Making LXCFS use the persistent path
Jul 12 13:54:03 tummy lxd.daemon[2028]: ==> Setting up kmod wrapper
Jul 12 13:54:03 tummy lxd.daemon[2028]: ==> Preparing /boot
Jul 12 13:54:03 tummy lxd.daemon[2028]: ==> Preparing a clean copy of /run
Jul 12 13:54:03 tummy lxd.daemon[2028]: ==> Preparing a clean copy of /etc
Jul 12 13:54:04 tummy lxd.daemon[2028]: ==> Preparing a clean copy of /usr/share/misc
Jul 12 13:54:04 tummy lxd.daemon[2028]: ==> Setting up ceph configuration
Jul 12 13:54:04 tummy lxd.daemon[2028]: ==> Setting up LVM configuration
Jul 12 13:54:04 tummy lxd.daemon[2028]: ==> Rotating logs
Jul 12 13:54:04 tummy lxd.daemon[2028]: ==> Setting up ZFS (0.8)
Jul 12 13:54:04 tummy lxd.daemon[2028]: ==> Escaping the systemd cgroups
Jul 12 13:54:04 tummy lxd.daemon[2028]: ====> Detected cgroup V1
Jul 12 13:54:04 tummy lxd.daemon[2028]: ==> Escaping the systemd process resource limits
Jul 12 13:54:04 tummy lxd.daemon[2028]: ==> Increasing the number of inotify user instances
Jul 12 13:54:04 tummy lxd.daemon[2028]: ==> Disabling shiftfs on this kernel (auto)
Jul 12 13:54:04 tummy lxd.daemon[2028]: => Starting LXCFS
Jul 12 13:54:04 tummy lxd.daemon[2175]: Running constructor lxcfs_init to reload liblxcfs
Jul 12 13:54:04 tummy lxd.daemon[2175]: mount namespace: 4
Jul 12 13:54:04 tummy lxd.daemon[2175]: hierarchies:
Jul 12 13:54:04 tummy lxd.daemon[2175]:   0: fd:   5:
Jul 12 13:54:04 tummy lxd.daemon[2175]:   1: fd:   6: name=systemd
Jul 12 13:54:04 tummy lxd.daemon[2175]:   2: fd:   7: devices
Jul 12 13:54:04 tummy lxd.daemon[2175]:   3: fd:   8: rdma
Jul 12 13:54:04 tummy lxd.daemon[2175]:   4: fd:   9: cpu,cpuacct
Jul 12 13:54:04 tummy lxd.daemon[2175]:   5: fd:  10: hugetlb
Jul 12 13:54:04 tummy lxd.daemon[2175]:   6: fd:  11: memory
Jul 12 13:54:04 tummy lxd.daemon[2175]:   7: fd:  12: freezer
Jul 12 13:54:04 tummy lxd.daemon[2175]:   8: fd:  13: perf_event
Jul 12 13:54:04 tummy lxd.daemon[2175]:   9: fd:  14: cpuset
Jul 12 13:54:04 tummy lxd.daemon[2175]:  10: fd:  15: pids
Jul 12 13:54:04 tummy lxd.daemon[2175]:  11: fd:  16: blkio
Jul 12 13:54:04 tummy lxd.daemon[2175]:  12: fd:  17: net_cls,net_prio
Jul 12 13:54:04 tummy lxd.daemon[2175]: Kernel supports pidfds
Jul 12 13:54:04 tummy lxd.daemon[2175]: Kernel does not support swap accounting
Jul 12 13:54:04 tummy lxd.daemon[2175]: api_extensions:
Jul 12 13:54:04 tummy lxd.daemon[2175]: - cgroups
Jul 12 13:54:04 tummy lxd.daemon[2175]: - sys_cpu_online
Jul 12 13:54:04 tummy lxd.daemon[2175]: - proc_cpuinfo
Jul 12 13:54:04 tummy lxd.daemon[2175]: - proc_diskstats
Jul 12 13:54:04 tummy lxd.daemon[2175]: - proc_loadavg
Jul 12 13:54:04 tummy lxd.daemon[2175]: - proc_meminfo
Jul 12 13:54:04 tummy lxd.daemon[2175]: - proc_stat
Jul 12 13:54:04 tummy lxd.daemon[2175]: - proc_swaps
Jul 12 13:54:04 tummy lxd.daemon[2175]: - proc_uptime
Jul 12 13:54:04 tummy lxd.daemon[2175]: - shared_pidns
Jul 12 13:54:04 tummy lxd.daemon[2175]: - cpuview_daemon
Jul 12 13:54:04 tummy lxd.daemon[2175]: - loadavg_daemon
Jul 12 13:54:04 tummy lxd.daemon[2175]: - pidfds
Jul 12 13:54:05 tummy lxd.daemon[2028]: => Starting LXD
Jul 12 13:54:05 tummy lxd.daemon[2186]: t=2020-07-12T13:54:05+0200 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, I/O weight limits will be ignored"
Jul 12 13:54:05 tummy lxd.daemon[2186]: t=2020-07-12T13:54:05+0200 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored"
Jul 12 13:54:06 tummy lxd.daemon[2186]: t=2020-07-12T13:54:06+0200 lvl=warn msg="Failed getting list of tables from \"/proc/self/net/ip6_tables_names\", assuming all requested tables exist"
Jul 12 13:54:08 tummy lxd.daemon[2186]: t=2020-07-12T13:54:08+0200 lvl=eror msg="Failed to start instance 'gaia': Common start logic: Failed to run: zfs mount tank/lxd/containers/gaia: cannot mount '/var/snap/lxd/common/lxd/storage-pools/default/containers/gaia': directory is not empty"
Jul 12 13:54:11 tummy lxd.daemon[2028]: => LXD is ready
Jul 12 13:54:14 tummy lxd.daemon[2186]: t=2020-07-12T13:54:14+0200 lvl=warn msg="Failed to update instance types: Get \"https://images.linuxcontainers.org/meta/instance-types/.yaml\": lookup images.linuxcontainers.org: Temporary failure in name resolution"
Jul 13 09:21:10 tummy lxd.daemon[2186]: t=2020-07-13T09:21:10+0200 lvl=warn msg="Detected poll(POLLNVAL) event."
Jul 13 09:42:48 tummy lxd.daemon[2186]: t=2020-07-13T09:42:48+0200 lvl=warn msg="Detected poll(POLLNVAL) event."
-- Reboot --
Jul 13 10:47:27 tummy systemd[1]: Started Service for snap application lxd.daemon.
Jul 13 10:47:27 tummy lxd.daemon[2052]: => Preparing the system (16099)
Jul 13 10:47:27 tummy lxd.daemon[2094]: cmd_linux.go:160: cannot read /proc/self/exe: readlink /proc/self/exe: no such file or directory
Jul 13 10:47:27 tummy lxd.daemon[2052]: ==> Loading snap configuration
Jul 13 10:47:27 tummy lxd.daemon[2052]: ==> Setting up mntns symlink (mnt:[4026532315])
Jul 13 10:47:27 tummy lxd.daemon[2052]: ==> Setting up mount propagation on /var/snap/lxd/common/lxd/storage-pools
Jul 13 10:47:27 tummy lxd.daemon[2052]: ==> Setting up mount propagation on /var/snap/lxd/common/lxd/devices
Jul 13 10:47:27 tummy lxd.daemon[2052]: ==> Setting up persistent shmounts path
Jul 13 10:47:27 tummy lxd.daemon[2052]: ====> Making LXD shmounts use the persistent path
Jul 13 10:47:27 tummy lxd.daemon[2052]: ====> Making LXCFS use the persistent path
Jul 13 10:47:27 tummy lxd.daemon[2052]: ==> Setting up kmod wrapper
Jul 13 10:47:27 tummy lxd.daemon[2052]: ==> Preparing /boot
Jul 13 10:47:27 tummy lxd.daemon[2052]: ==> Preparing a clean copy of /run
Jul 13 10:47:27 tummy lxd.daemon[2052]: ==> Preparing a clean copy of /etc
Jul 13 10:47:27 tummy lxd.daemon[2052]: ==> Preparing a clean copy of /usr/share/misc
Jul 13 10:47:28 tummy lxd.daemon[2052]: ==> Setting up ceph configuration
Jul 13 10:47:28 tummy lxd.daemon[2052]: ==> Setting up LVM configuration
Jul 13 10:47:28 tummy lxd.daemon[2052]: ==> Rotating logs
Jul 13 10:47:28 tummy lxd.daemon[2052]: ==> Setting up ZFS (0.8)
Jul 13 10:47:28 tummy lxd.daemon[2052]: ==> Escaping the systemd cgroups
Jul 13 10:47:28 tummy lxd.daemon[2052]: ====> Detected cgroup V1
Jul 13 10:47:28 tummy lxd.daemon[2052]: ==> Escaping the systemd process resource limits
Jul 13 10:47:28 tummy lxd.daemon[2052]: ==> Increasing the number of inotify user instances
Jul 13 10:47:28 tummy lxd.daemon[2052]: ==> Disabling shiftfs on this kernel (auto)
Jul 13 10:47:28 tummy lxd.daemon[2052]: => Starting LXCFS
Jul 13 10:47:28 tummy lxd.daemon[2200]: Running constructor lxcfs_init to reload liblxcfs
Jul 13 10:47:28 tummy lxd.daemon[2200]: mount namespace: 4
Jul 13 10:47:28 tummy lxd.daemon[2200]: hierarchies:
Jul 13 10:47:28 tummy lxd.daemon[2200]:   0: fd:   5:
Jul 13 10:47:28 tummy lxd.daemon[2200]:   1: fd:   6: name=systemd
Jul 13 10:47:28 tummy lxd.daemon[2200]:   2: fd:   7: freezer
Jul 13 10:47:28 tummy lxd.daemon[2200]:   3: fd:   8: hugetlb
Jul 13 10:47:28 tummy lxd.daemon[2200]:   4: fd:   9: devices
Jul 13 10:47:28 tummy lxd.daemon[2200]:   5: fd:  10: cpu,cpuacct
Jul 13 10:47:28 tummy lxd.daemon[2200]:   6: fd:  11: memory
Jul 13 10:47:28 tummy lxd.daemon[2200]:   7: fd:  12: pids
Jul 13 10:47:28 tummy lxd.daemon[2200]:   8: fd:  13: net_cls,net_prio
Jul 13 10:47:28 tummy lxd.daemon[2200]:   9: fd:  14: blkio
Jul 13 10:47:28 tummy lxd.daemon[2200]:  10: fd:  15: perf_event
Jul 13 10:47:28 tummy lxd.daemon[2200]:  11: fd:  16: cpuset
Jul 13 10:47:28 tummy lxd.daemon[2200]:  12: fd:  17: rdma
Jul 13 10:47:28 tummy lxd.daemon[2200]: Kernel supports pidfds
Jul 13 10:47:28 tummy lxd.daemon[2200]: Kernel does not support swap accounting
Jul 13 10:47:28 tummy lxd.daemon[2200]: api_extensions:
Jul 13 10:47:28 tummy lxd.daemon[2200]: - cgroups
Jul 13 10:47:28 tummy lxd.daemon[2200]: - sys_cpu_online
Jul 13 10:47:28 tummy lxd.daemon[2200]: - proc_cpuinfo
Jul 13 10:47:28 tummy lxd.daemon[2200]: - proc_diskstats
Jul 13 10:47:28 tummy lxd.daemon[2200]: - proc_loadavg
Jul 13 10:47:28 tummy lxd.daemon[2200]: - proc_meminfo
Jul 13 10:47:28 tummy lxd.daemon[2200]: - proc_stat
Jul 13 10:47:28 tummy lxd.daemon[2200]: - proc_swaps
Jul 13 10:47:28 tummy lxd.daemon[2200]: - proc_uptime
Jul 13 10:47:28 tummy lxd.daemon[2200]: - shared_pidns
Jul 13 10:47:28 tummy lxd.daemon[2200]: - cpuview_daemon
Jul 13 10:47:28 tummy lxd.daemon[2200]: - loadavg_daemon
Jul 13 10:47:28 tummy lxd.daemon[2200]: - pidfds
Jul 13 10:47:29 tummy lxd.daemon[2052]: => Starting LXD
Jul 13 10:47:29 tummy lxd.daemon[2211]: t=2020-07-13T10:47:29+0200 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, I/O weight limits will be ignored"
Jul 13 10:47:29 tummy lxd.daemon[2211]: t=2020-07-13T10:47:29+0200 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored"
Jul 13 10:47:30 tummy lxd.daemon[2211]: t=2020-07-13T10:47:30+0200 lvl=warn msg="Failed getting list of tables from \"/proc/self/net/ip6_tables_names\", assuming all requested tables exist"
Jul 13 10:47:32 tummy lxd.daemon[2211]: t=2020-07-13T10:47:32+0200 lvl=eror msg="Failed to start instance 'gaia': Common start logic: Failed to run: zfs mount tank/lxd/containers/gaia: cannot mount '/var/snap/lxd/common/lxd/storage-pools/default/containers/gaia': directory is not empty"
Jul 13 10:47:44 tummy lxd.daemon[2052]: => LXD is ready
Jul 13 12:04:08 tummy lxd.daemon[2211]: t=2020-07-13T12:04:08+0200 lvl=warn msg="Detected poll(POLLNVAL) event."
Jul 21 05:59:57 tummy lxd.daemon[2211]: t=2020-07-21T05:59:57+0200 lvl=warn msg="Detected poll(POLLNVAL) event."
Jul 21 09:04:45 tummy lxd.daemon[2211]: t=2020-07-21T09:04:45+0200 lvl=warn msg="Detected poll(POLLNVAL) event: exiting."
Jul 21 09:04:45 tummy lxd.daemon[2211]: t=2020-07-21T09:04:45+0200 lvl=warn msg="Detected poll(POLLNVAL) event."
Aug 04 02:13:07 tummy systemd[1]: Stopping Service for snap application lxd.daemon...
Aug 04 02:13:07 tummy lxd.daemon[1213325]: => Stop reason is: snap refresh
Aug 04 02:13:07 tummy lxd.daemon[1213325]: => Stopping LXD
Aug 04 02:13:09 tummy systemd[1]: snap.lxd.daemon.service: Succeeded.
Aug 04 02:13:09 tummy systemd[1]: Stopped Service for snap application lxd.daemon.
Aug 04 02:13:32 tummy systemd[1]: Started Service for snap application lxd.daemon.
Aug 04 02:13:32 tummy lxd.daemon[1215079]: => Preparing the system (16558)
Aug 04 02:13:32 tummy lxd.daemon[1215110]: cmd_linux.go:160: cannot read /proc/self/exe: readlink /proc/self/exe: no such file or directory
Aug 04 02:13:32 tummy lxd.daemon[1215079]: ==> Loading snap configuration
Aug 04 02:13:32 tummy lxd.daemon[1215079]: ==> Setting up mntns symlink (mnt:[4026532995])
Aug 04 02:13:32 tummy lxd.daemon[1215079]: ==> Setting up mount propagation on /var/snap/lxd/common/lxd/storage-pools
Aug 04 02:13:32 tummy lxd.daemon[1215079]: ==> Setting up mount propagation on /var/snap/lxd/common/lxd/devices
Aug 04 02:13:32 tummy lxd.daemon[1215079]: ==> Setting up persistent shmounts path
Aug 04 02:13:32 tummy lxd.daemon[1215188]: Failed to mount new mntns: Invalid argument
Aug 04 02:13:32 tummy lxd.daemon[1215079]: ====> Failed to setup shmounts, continuing without
Aug 04 02:13:32 tummy lxd.daemon[1215079]: ====> Making LXD shmounts use the persistent path
Aug 04 02:13:32 tummy lxd.daemon[1215079]: ====> Making LXCFS use the persistent path
Aug 04 02:13:32 tummy lxd.daemon[1215079]: ==> Setting up kmod wrapper
Aug 04 02:13:32 tummy lxd.daemon[1215079]: ==> Preparing /boot
Aug 04 02:13:32 tummy lxd.daemon[1215079]: ==> Preparing a clean copy of /run
Aug 04 02:13:32 tummy lxd.daemon[1215079]: ==> Preparing /run/bin
Aug 04 02:13:32 tummy lxd.daemon[1215079]: ==> Preparing a clean copy of /etc
Aug 04 02:13:33 tummy lxd.daemon[1215079]: ==> Preparing a clean copy of /usr/share/misc
Aug 04 02:13:33 tummy lxd.daemon[1215079]: ==> Setting up ceph configuration
Aug 04 02:13:33 tummy lxd.daemon[1215079]: ==> Setting up LVM configuration
Aug 04 02:13:33 tummy lxd.daemon[1215079]: ==> Rotating logs
Aug 04 02:13:33 tummy lxd.daemon[1215079]: ==> Setting up ZFS (0.8)
Aug 04 02:13:33 tummy lxd.daemon[1215079]: ==> Escaping the systemd cgroups
Aug 04 02:13:33 tummy lxd.daemon[1215079]: ====> Detected cgroup V1
Aug 04 02:13:33 tummy lxd.daemon[1215079]: ==> Escaping the systemd process resource limits
Aug 04 02:13:33 tummy lxd.daemon[1215079]: ==> Disabling shiftfs on this kernel (auto)
Aug 04 02:13:33 tummy lxd.daemon[1215079]: => Starting LXCFS
Aug 04 02:13:33 tummy lxd.daemon[1215374]: Running constructor lxcfs_init to reload liblxcfs
Aug 04 02:13:33 tummy lxd.daemon[1215374]: mount namespace: 4
Aug 04 02:13:33 tummy lxd.daemon[1215374]: hierarchies:
Aug 04 02:13:33 tummy lxd.daemon[1215374]:   0: fd:   5:
Aug 04 02:13:33 tummy lxd.daemon[1215374]:   1: fd:   6: name=systemd
Aug 04 02:13:33 tummy lxd.daemon[1215374]:   2: fd:   7: freezer
Aug 04 02:13:33 tummy lxd.daemon[1215374]:   3: fd:   8: hugetlb
Aug 04 02:13:33 tummy lxd.daemon[1215374]:   4: fd:   9: devices
Aug 04 02:13:33 tummy lxd.daemon[1215374]:   5: fd:  10: cpu,cpuacct
Aug 04 02:13:33 tummy lxd.daemon[1215374]:   6: fd:  11: memory
Aug 04 02:13:33 tummy lxd.daemon[1215374]:   7: fd:  12: pids
Aug 04 02:13:33 tummy lxd.daemon[1215374]:   8: fd:  13: net_cls,net_prio
Aug 04 02:13:33 tummy lxd.daemon[1215374]:   9: fd:  14: blkio
Aug 04 02:13:33 tummy lxd.daemon[1215374]:  10: fd:  15: perf_event
Aug 04 02:13:33 tummy lxd.daemon[1215374]:  11: fd:  16: cpuset
Aug 04 02:13:33 tummy lxd.daemon[1215374]:  12: fd:  17: rdma
Aug 04 02:13:33 tummy lxd.daemon[1215374]: Kernel supports pidfds
Aug 04 02:13:33 tummy lxd.daemon[1215374]: Kernel does not support swap accounting
Aug 04 02:13:33 tummy lxd.daemon[1215374]: api_extensions:
Aug 04 02:13:33 tummy lxd.daemon[1215374]: - cgroups
Aug 04 02:13:33 tummy lxd.daemon[1215374]: - sys_cpu_online
Aug 04 02:13:33 tummy lxd.daemon[1215374]: - proc_cpuinfo
Aug 04 02:13:33 tummy lxd.daemon[1215374]: - proc_diskstats
Aug 04 02:13:33 tummy lxd.daemon[1215374]: - proc_loadavg
Aug 04 02:13:33 tummy lxd.daemon[1215374]: - proc_meminfo
Aug 04 02:13:33 tummy lxd.daemon[1215374]: - proc_stat
Aug 04 02:13:33 tummy lxd.daemon[1215374]: - proc_swaps
Aug 04 02:13:33 tummy lxd.daemon[1215374]: - proc_uptime
Aug 04 02:13:33 tummy lxd.daemon[1215374]: - shared_pidns
Aug 04 02:13:33 tummy lxd.daemon[1215374]: - cpuview_daemon
Aug 04 02:13:33 tummy lxd.daemon[1215374]: - loadavg_daemon
Aug 04 02:13:33 tummy lxd.daemon[1215374]: - pidfds
Aug 04 02:13:34 tummy lxd.daemon[1215079]: => Starting LXD
Aug 04 02:13:34 tummy lxd.daemon[1215389]: t=2020-08-04T02:13:34+0200 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, I/O weight limits will be ignored"
Aug 04 02:13:34 tummy lxd.daemon[1215389]: t=2020-08-04T02:13:34+0200 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored"
Aug 04 02:13:36 tummy lxd.daemon[1215079]: => LXD is ready

[tomposmiko]

@stgraber Is the above suitable and enough?

[stgraber]

Yeah, it shows an error here: Aug 04 02:13:32 tummy lxd.daemon[1215188]: Failed to mount new mntns: Invalid argument

Failure to run the shmounts code would certainly expect the later behavior, though that particular kernel error isn't very clear as to what happened...

[stgraber]

Moving over to the snap packaging for now. I'll do some validation around core18 snap refresh + lxd snap refresh as that's usually what causes that kind of issue, though it's still unclear whether this is an issue in the shmounts logic or an actual kernel error that got hit.

[stgraber]

As a temporary fix, looking for existing mounts with something like grep tank/lxd/containers/feb /proc/*/mountinfo should help track down what process still holds the mount and manually unmount it from there.

[tomposmiko]

# grep tank/lxd/containers/feb /proc/*/mountinfo
/proc/1215374/mountinfo:536 5662 0:104 / /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb rw,noatime shared:262 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/1302190/mountinfo:847 747 0:104 / /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb rw,noatime shared:262 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/1874326/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/2200/mountinfo:847 747 0:104 / /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb rw,noatime shared:262 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/22990/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/22996/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/23066/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/23116/mountinfo:5183 5132 0:104 /rootfs / rw,noatime shared:1000 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/23116/mountinfo:5234 5183 0:104 /rootfs/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-Rh8BVg/tmp /tmp rw,noatime shared:1051 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/23116/mountinfo:5235 5183 0:104 /rootfs/var/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-IXLSji/tmp /var/tmp rw,noatime shared:1052 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/23326/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/23332/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/2354/mountinfo:847 747 0:104 / /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb rw,noatime shared:262 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/2564/mountinfo:847 747 0:104 / /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb rw,noatime shared:262 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/2710/mountinfo:847 747 0:104 / /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb rw,noatime shared:262 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/2940/mountinfo:847 747 0:104 / /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb rw,noatime shared:262 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3029/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3346/mountinfo:847 747 0:104 / /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb rw,noatime shared:262 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3381033/mountinfo:5183 5132 0:104 /rootfs / rw,noatime shared:1000 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3381033/mountinfo:5234 5183 0:104 /rootfs/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-Rh8BVg/tmp /tmp rw,noatime shared:1051 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3381033/mountinfo:5235 5183 0:104 /rootfs/var/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-IXLSji/tmp /var/tmp rw,noatime shared:1052 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3381034/mountinfo:5183 5132 0:104 /rootfs / rw,noatime shared:1000 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3381034/mountinfo:5234 5183 0:104 /rootfs/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-Rh8BVg/tmp /tmp rw,noatime shared:1051 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3381034/mountinfo:5235 5183 0:104 /rootfs/var/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-IXLSji/tmp /var/tmp rw,noatime shared:1052 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3381035/mountinfo:5183 5132 0:104 /rootfs / rw,noatime shared:1000 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3381035/mountinfo:5234 5183 0:104 /rootfs/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-Rh8BVg/tmp /tmp rw,noatime shared:1051 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3381035/mountinfo:5235 5183 0:104 /rootfs/var/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-IXLSji/tmp /var/tmp rw,noatime shared:1052 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3381036/mountinfo:5183 5132 0:104 /rootfs / rw,noatime shared:1000 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3381036/mountinfo:5234 5183 0:104 /rootfs/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-Rh8BVg/tmp /tmp rw,noatime shared:1051 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3381036/mountinfo:5235 5183 0:104 /rootfs/var/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-IXLSji/tmp /var/tmp rw,noatime shared:1052 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3381037/mountinfo:5183 5132 0:104 /rootfs / rw,noatime shared:1000 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3381037/mountinfo:5234 5183 0:104 /rootfs/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-Rh8BVg/tmp /tmp rw,noatime shared:1051 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3381037/mountinfo:5235 5183 0:104 /rootfs/var/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-IXLSji/tmp /var/tmp rw,noatime shared:1052 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3403235/mountinfo:5183 5132 0:104 /rootfs / rw,noatime shared:1000 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3403235/mountinfo:5234 5183 0:104 /rootfs/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-Rh8BVg/tmp /tmp rw,noatime shared:1051 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3403235/mountinfo:5235 5183 0:104 /rootfs/var/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-IXLSji/tmp /var/tmp rw,noatime shared:1052 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3449023/mountinfo:5183 5132 0:104 /rootfs / rw,noatime shared:1000 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3449023/mountinfo:5234 5183 0:104 /rootfs/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-Rh8BVg/tmp /tmp rw,noatime shared:1051 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3449023/mountinfo:5235 5183 0:104 /rootfs/var/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-IXLSji/tmp /var/tmp rw,noatime shared:1052 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3582170/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3582172/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3582173/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3582174/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3582175/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3582176/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3582177/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3582/mountinfo:847 747 0:104 / /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb rw,noatime shared:262 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3818/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3819/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3852/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3853/mountinfo:2489 2488 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3853/mountinfo:2540 2538 0:104 /rootfs /run/systemd/unit-root rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3853/mountinfo:2591 2540 0:104 /rootfs/etc /run/systemd/unit-root/etc rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3853/mountinfo:2619 2540 0:104 /rootfs/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-systemd-logind.service-OriHwh/tmp /run/systemd/unit-root/tmp rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3853/mountinfo:2620 2540 0:104 /rootfs/var/lib/systemd/linger /run/systemd/unit-root/var/lib/systemd/linger rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3853/mountinfo:2621 2540 0:104 /rootfs/var/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-systemd-logind.service-KLtGBi/tmp /run/systemd/unit-root/var/tmp rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3856886/mountinfo:5183 5132 0:104 /rootfs / rw,noatime shared:1000 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3856886/mountinfo:5234 5183 0:104 /rootfs/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-Rh8BVg/tmp /tmp rw,noatime shared:1051 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3856886/mountinfo:5235 5183 0:104 /rootfs/var/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-IXLSji/tmp /var/tmp rw,noatime shared:1052 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3857126/mountinfo:5183 5132 0:104 /rootfs / rw,noatime shared:1000 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3857126/mountinfo:5234 5183 0:104 /rootfs/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-Rh8BVg/tmp /tmp rw,noatime shared:1051 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/3857126/mountinfo:5235 5183 0:104 /rootfs/var/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-apache2.service-IXLSji/tmp /var/tmp rw,noatime shared:1052 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/4051/mountinfo:847 747 0:104 / /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb rw,noatime shared:262 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/4404/mountinfo:847 747 0:104 / /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb rw,noatime shared:262 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/4734/mountinfo:847 747 0:104 / /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb rw,noatime shared:262 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/5304/mountinfo:847 747 0:104 / /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb rw,noatime shared:262 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/611607/mountinfo:2370 2369 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/611607/mountinfo:2421 2419 0:104 /rootfs /run/systemd/unit-root rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/611607/mountinfo:2485 2421 0:104 /rootfs/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-systemd-resolved.service-FJjjGf/tmp /run/systemd/unit-root/tmp rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/611607/mountinfo:2486 2421 0:104 /rootfs/var/tmp/systemd-private-6478681448e449e4a5554d68c3aed1eb-systemd-resolved.service-Ten5Ci/tmp /run/systemd/unit-root/var/tmp rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/611620/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/612639/mountinfo:1941 1890 0:104 /rootfs / rw,noatime shared:504 - zfs tank/lxd/containers/feb rw,xattr,posixacl
/proc/965660/mountinfo:1807 1712 0:104 /rootfs / rw,noatime - zfs tank/lxd/containers/feb rw,xattr,posixacl

[tomposmiko]

I hope, it helps. BTW there is one more container with the same error for a while.

[stgraber]

try: nsenter -t 1215374 -m umount /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb see if that clears it everywhere that matters and things behave again.

[tomposmiko]

I don't know nsenter. Are you sure this is the right command?

# nsenter -t 1215374 -m umount /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb
umount: /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb: no mount point specified.

[stgraber]

Yep, the command is correct but your mount table is likely a bit messed up and it's over-mounted :)

Can you show cat /proc/1215374/mountinfo?

[tomposmiko]

I was about to ask it, because the failure message suggested mean bad command syntax (something is not specified).

mountinfo:

# /proc/1215374/mountinfo
708 5634 0:25 /@ /var/lib/snapd/hostfs rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@
5517 708 0:24 / /var/lib/snapd/hostfs/run rw,nosuid,nodev,noexec,relatime master:5 - tmpfs tmpfs rw,size=3275204k,mode=755
5518 5517 0:29 / /var/lib/snapd/hostfs/run/lock rw,nosuid,nodev,noexec,relatime master:6 - tmpfs tmpfs rw,size=5120k
5519 5517 0:24 /snapd/ns /var/lib/snapd/hostfs/run/snapd/ns rw,nosuid,nodev,noexec,relatime - tmpfs tmpfs rw,size=3275204k,mode=755
5551 708 0:25 /@home /var/lib/snapd/hostfs/home rw,relatime master:79 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=258,subvol=/@home
5552 708 0:53 / /var/lib/snapd/hostfs/tank rw,noatime master:81 - zfs tank rw,xattr,noacl
5553 5552 0:54 / /var/lib/snapd/hostfs/tank/lxc rw,noatime master:83 - zfs tank/lxc rw,xattr,noacl
5554 5553 0:55 / /var/lib/snapd/hostfs/tank/lxc/jolokia rw,noatime master:85 - zfs tank/lxc/jolokia rw,xattr,noacl
5555 708 0:60 / /var/lib/snapd/hostfs/var/lib/lxcfs rw,nosuid,nodev,relatime master:208 - fuse.lxcfs lxcfs rw,user_id=0,group_id=0,allow_other
5556 708 0:63 / /var/lib/snapd/hostfs/var/snap/lxd/common/ns rw,relatime - tmpfs tmpfs rw,size=1024k,mode=700
5557 708 7:6 / /var/lib/snapd/hostfs/snap/core18/1880 ro,nodev,relatime master:1159 - squashfs /dev/loop6 ro
5573 379 7:6 / / ro,nodev,relatime master:1159 - squashfs /dev/loop6 ro
5574 5573 0:6 / /dev rw,nosuid,noexec,relatime master:2 - devtmpfs udev rw,size=16345716k,nr_inodes=4086429,mode=755
5575 5574 0:23 / /dev/pts rw,nosuid,noexec,relatime master:3 - devpts devpts rw,gid=5,mode=620,ptmxmode=000
5576 5574 0:28 / /dev/shm rw,nosuid,nodev master:4 - tmpfs tmpfs rw
5577 5574 0:47 / /dev/hugepages rw,relatime master:27 - hugetlbfs hugetlbfs rw,pagesize=2M
5578 5574 0:20 / /dev/mqueue rw,nosuid,nodev,noexec,relatime master:28 - mqueue mqueue rw
5580 5573 0:25 /@home /home rw,relatime master:79 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=258,subvol=/@home
5581 5573 0:25 /@/root /root rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/root
5582 5573 0:5 / /proc rw,nosuid,nodev,noexec,relatime master:14 - proc proc rw
5583 5582 0:46 / /proc/sys/fs/binfmt_misc rw,relatime master:26 - autofs systemd-1 rw,fd=28,pgrp=1,timeout=0,minproto=5,maxproto=5,direct,pipe_ino=2806
5584 5583 0:77 / /proc/sys/fs/binfmt_misc rw,nosuid,nodev,noexec,relatime master:267 - binfmt_misc binfmt_misc rw
5585 5573 0:22 / /sys rw,nosuid,nodev,noexec,relatime master:7 - sysfs sysfs rw
5586 5585 0:7 / /sys/kernel/security rw,nosuid,nodev,noexec,relatime master:8 - securityfs securityfs rw
5587 5585 0:30 / /sys/fs/cgroup ro,nosuid,nodev,noexec master:9 - tmpfs tmpfs ro,mode=755
5588 5587 0:31 / /sys/fs/cgroup/unified rw,nosuid,nodev,noexec,relatime master:10 - cgroup2 cgroup2 rw
5589 5587 0:32 / /sys/fs/cgroup/systemd rw,nosuid,nodev,noexec,relatime master:11 - cgroup cgroup rw,xattr,name=systemd
5590 5587 0:35 / /sys/fs/cgroup/freezer rw,nosuid,nodev,noexec,relatime master:15 - cgroup cgroup rw,freezer
5591 5587 0:36 / /sys/fs/cgroup/hugetlb rw,nosuid,nodev,noexec,relatime master:16 - cgroup cgroup rw,hugetlb
5592 5587 0:37 / /sys/fs/cgroup/devices rw,nosuid,nodev,noexec,relatime master:17 - cgroup cgroup rw,devices
5593 5587 0:38 / /sys/fs/cgroup/cpu,cpuacct rw,nosuid,nodev,noexec,relatime master:18 - cgroup cgroup rw,cpu,cpuacct
5594 5587 0:39 / /sys/fs/cgroup/memory rw,nosuid,nodev,noexec,relatime master:19 - cgroup cgroup rw,memory
5595 5587 0:40 / /sys/fs/cgroup/pids rw,nosuid,nodev,noexec,relatime master:20 - cgroup cgroup rw,pids
5596 5587 0:41 / /sys/fs/cgroup/net_cls,net_prio rw,nosuid,nodev,noexec,relatime master:21 - cgroup cgroup rw,net_cls,net_prio
5597 5587 0:42 / /sys/fs/cgroup/blkio rw,nosuid,nodev,noexec,relatime master:22 - cgroup cgroup rw,blkio
5598 5587 0:43 / /sys/fs/cgroup/perf_event rw,nosuid,nodev,noexec,relatime master:23 - cgroup cgroup rw,perf_event
5599 5587 0:44 / /sys/fs/cgroup/cpuset rw,nosuid,nodev,noexec,relatime master:24 - cgroup cgroup rw,cpuset,clone_children
5600 5587 0:45 / /sys/fs/cgroup/rdma rw,nosuid,nodev,noexec,relatime master:25 - cgroup cgroup rw,rdma
5601 5585 0:33 / /sys/fs/pstore rw,nosuid,nodev,noexec,relatime master:12 - pstore pstore rw
5602 5585 0:34 / /sys/fs/bpf rw,nosuid,nodev,noexec,relatime master:13 - bpf none rw,mode=700
5603 5585 0:8 / /sys/kernel/debug rw,nosuid,nodev,noexec,relatime master:29 - debugfs debugfs rw
5604 5585 0:12 / /sys/kernel/tracing rw,nosuid,nodev,noexec,relatime master:30 - tracefs tracefs rw
5605 5585 0:48 / /sys/fs/fuse/connections rw,nosuid,nodev,noexec,relatime master:31 - fusectl fusectl rw
5606 5585 0:21 / /sys/kernel/config rw,nosuid,nodev,noexec,relatime master:32 - configfs configfs rw
5607 5573 0:25 /@/tmp /tmp rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/tmp
5608 5573 0:25 /@/var/snap /var/snap rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/var/snap
5609 5608 0:63 / /var/snap/lxd/common/ns rw,relatime - tmpfs tmpfs rw,size=1024k,mode=700
5610 5573 0:25 /@/var/lib/dhcp /var/lib/dhcp rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/var/lib/dhcp
5611 5573 0:25 /@/var/lib/snapd /var/lib/snapd rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/var/lib/snapd
5612 5573 0:25 /@/var/tmp /var/tmp rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/var/tmp
5617 5573 0:25 /@/lib/modules /lib/modules rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/lib/modules
5618 5573 0:25 /@/lib/firmware /lib/firmware rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/lib/firmware
5619 5573 0:25 /@/usr/src /usr/src rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/usr/src
5620 5573 0:25 /@/var/log /var/log rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/var/log
5621 5573 0:25 /@/media /media rw,relatime shared:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/media
5623 5573 0:25 /@/mnt /mnt rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/mnt
5626 5573 0:25 /@/usr/lib/snapd /usr/lib/snapd rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/usr/lib/snapd
5627 5573 0:25 /@/snap /snap rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/snap
5633 5627 7:6 / /snap/core18/1880 ro,nodev,relatime master:1159 - squashfs /dev/loop6 ro
5634 5611 0:25 /@/var/lib/snapd/hostfs /var/lib/snapd/hostfs rw,relatime - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/var/lib/snapd/hostfs
5512 5607 0:25 /@/tmp/snap.lxd/tmp /tmp rw,relatime - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/tmp/snap.lxd/tmp
5513 5575 0:191 / /dev/pts rw,relatime - devpts devpts rw,gid=5,mode=620,ptmxmode=666
5514 5574 0:191 /ptmx /dev/ptmx rw,relatime - devpts devpts rw,gid=5,mode=620,ptmxmode=666
5520 708 7:0 / /var/lib/snapd/hostfs/snap/snapd/8542 ro,nodev,relatime master:73 - squashfs /dev/loop0 ro
5516 5627 7:0 / /snap/snapd/8542 ro,nodev,relatime master:73 - squashfs /dev/loop0 ro
5566 708 7:3 / /var/lib/snapd/hostfs/snap/lxd/16558 ro,nodev,relatime master:1172 - squashfs /dev/loop3 ro
5559 5627 7:3 / /snap/lxd/16558 ro,nodev,relatime master:1172 - squashfs /dev/loop3 ro
93 5608 0:25 /@/var/snap/lxd/common/lxd/storage-pools /var/snap/lxd/common/lxd/storage-pools rw,relatime shared:75 master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/var/snap/lxd/common/lxd/storage-pools
135 5608 0:25 /@/var/snap/lxd/common/lxd/devices /var/snap/lxd/common/lxd/devices rw,relatime shared:80 master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/var/snap/lxd/common/lxd/devices
5662 5608 0:62 / /var/snap/lxd/common/shmounts rw,relatime shared:275 - tmpfs tmpfs rw,size=1024k,mode=711
5663 5662 0:69 / /var/snap/lxd/common/shmounts/lxcfs rw,nosuid,nodev,relatime shared:264 - fuse.lxcfs lxcfs rw,user_id=0,group_id=0,allow_other
5664 5662 0:70 / /var/snap/lxd/common/shmounts/containers rw,relatime shared:265 - tmpfs tmpfs rw,size=100k,mode=711
536 5662 0:104 / /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb rw,noatime shared:262 - zfs tank/lxd/containers/feb rw,xattr,posixacl
653 5662 0:114 / /var/snap/lxd/common/shmounts/storage-pools/default/containers/habanero rw,noatime shared:266 - zfs tank/lxd/containers/habanero rw,xattr,posixacl
5636 93 0:72 / /var/snap/lxd/common/lxd/storage-pools/default/containers/amkcs rw,noatime shared:135 - zfs tank/lxd/containers/amkcs rw,xattr,posixacl
192 93 0:79 / /var/snap/lxd/common/lxd/storage-pools/default/containers/core01-c14 rw,noatime shared:194 - zfs tank/lxd/containers/core01-c14 rw,xattr,posixacl
272 93 0:89 / /var/snap/lxd/common/lxd/storage-pools/default/containers/efop rw,noatime shared:250 - zfs tank/lxd/containers/efop rw,xattr,posixacl
326 93 0:125 / /var/snap/lxd/common/lxd/storage-pools/default/containers/hegyeseros rw,noatime shared:282 - zfs tank/lxd/containers/hegyeseros rw,xattr,posixacl
333 93 0:132 / /var/snap/lxd/common/lxd/storage-pools/default/containers/jalapeno rw,noatime shared:356 - zfs tank/lxd/containers/jalapeno rw,xattr,posixacl
371 93 0:148 / /var/snap/lxd/common/lxd/storage-pools/default/containers/jumper rw,noatime shared:395 - zfs tank/lxd/containers/jumper rw,xattr,posixacl
412 93 0:158 / /var/snap/lxd/common/lxd/storage-pools/default/containers/moodle rw,noatime shared:449 - zfs tank/lxd/containers/moodle rw,xattr,posixacl
703 93 0:168 / /var/snap/lxd/common/lxd/storage-pools/default/containers/oktatas rw,noatime shared:503 - zfs tank/lxd/containers/oktatas rw,xattr,posixacl
709 93 0:138 / /var/snap/lxd/common/lxd/storage-pools/default/containers/tony rw,noatime shared:557 - zfs tank/lxd/containers/tony rw,xattr,posixacl
716 5662 0:190 / /var/snap/lxd/common/shmounts rw,relatime shared:611 - tmpfs tmpfs rw,size=1024k,mode=711
769 5573 7:3 /wrappers/kmod /bin/kmod ro,nodev,relatime master:1172 - squashfs /dev/loop3 ro
2015 5573 0:25 /@/boot /boot rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/boot
2276 5573 0:192 / /run rw,nosuid,nodev,relatime - tmpfs tmpfs rw,mode=755
2358 5573 0:193 / /etc rw,relatime - tmpfs tmpfs rw,mode=755
2730 5573 0:25 /@/usr/share/ca-certificates /usr/share/ca-certificates rw,relatime master:1 - btrfs /dev/md0 rw,ssd,space_cache,subvolid=257,subvol=/@/usr/share/ca-certificates
2940 5573 0:194 / /usr/share/misc rw,nosuid,nodev,relatime - tmpfs tmpfs rw,mode=755
3775 708 0:6 / /var/lib/snapd/hostfs/dev rw,nosuid,noexec,relatime master:2 - devtmpfs udev rw,size=16345716k,nr_inodes=4086429,mode=755
5549 708 0:5 / /var/lib/snapd/hostfs/proc rw,nosuid,nodev,noexec,relatime master:14 - proc proc rw
5568 708 0:22 / /var/lib/snapd/hostfs/sys rw,nosuid,nodev,noexec,relatime master:7 - sysfs sysfs rw
5570 716 0:197 / /var/snap/lxd/common/shmounts/lxcfs rw,nosuid,nodev,relatime shared:612 - fuse.lxcfs lxcfs rw,user_id=0,group_id=0,allow_other
5579 5608 0:198 / /var/snap/lxd/common/lxd/devlxd rw,relatime - tmpfs tmpfs rw,size=100k,mode=755
5641 708 7:4 / /var/lib/snapd/hostfs/snap/core18/1885 ro,nodev,relatime master:613 - squashfs /dev/loop4 ro
5630 5627 7:4 / /snap/core18/1885 ro,nodev,relatime master:613 - squashfs /dev/loop4 ro
5655 708 7:7 / /var/lib/snapd/hostfs/snap/snapd/8790 ro,nodev,relatime master:67 - squashfs /dev/loop7 ro
5023 5627 7:7 / /snap/snapd/8790 ro,nodev,relatime master:67 - squashfs /dev/loop7 ro
5657 708 7:5 / /var/lib/snapd/hostfs/snap/lxd/16740 ro,nodev,relatime master:77 - squashfs /dev/loop5 ro
495 5627 7:5 / /snap/lxd/16740 ro,nodev,relatime master:77 - squashfs /dev/loop5 ro
191 716 0:199 / /var/snap/lxd/common/shmounts rw,relatime shared:134 - tmpfs tmpfs rw,size=1024k,mode=711
5661 191 0:206 / /var/snap/lxd/common/shmounts/lxcfs rw,nosuid,nodev,relatime shared:193 - fuse.lxcfs lxcfs rw,user_id=0,group_id=0,allow_other
5668 191 0:207 / /var/snap/lxd/common/shmounts/instances rw,relatime shared:247 - tmpfs tmpfs rw,size=100k,mode=711
5698 5517 0:209 / /var/lib/snapd/hostfs/run/user/1000 rw,nosuid,nodev,relatime master:1158 - tmpfs tmpfs rw,size=3275200k,mode=700,uid=1000,gid=1000

[stgraber]

nsenter -t 1215374 -m followed by

• umount -l /var/snap/lxd/common/shmounts/instances
• umount -l /var/snap/lxd/common/shmounts/lxcfs
• umount -l /var/snap/lxd/common/shmounts
• umount -l /var/snap/lxd/common/shmounts/lxcfs
• umount -l /var/snap/lxd/common/shmounts
• umount -l /var/snap/lxd/common/shmounts/storage-pools/default/containers/habanero
• umount -l /var/snap/lxd/common/shmounts/storage-pools/default/containers/feb
• exit

[tomposmiko]

Something happened before executing these commands, because snapshot could be created for feb. After executing the above commands a snapshot for habanero also could be created. Thanks for it.

Do you have any clue, what could be the long term fix?

[tomposmiko]

@stgraber I am a bit worried to use LXD in production with such an issue. How can is sure it is safe?

[stgraber]

You can keep an eye on Failed to setup shmounts, continuing without in the journal. If it shows up as it did in this case, then something went wrong with mount handling and we should know about it so we can hopefully catch it early and figure out what conditions triggered it.

When something like that happens, running instances won't be affected nor would newly created/started ones, the only issue is trying to restart or delete running instances as ZFS may get upset in that case.

[tomposmiko]

The same machine, but not exactly the same issue, though very similar.

Now any container cannot be started:

Error: Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?

Upgrading to latest/stable (4.4) did not help. I am starting to desperate.

[tomposmiko]

# cat lxd.log
t=2020-09-14T22:33:34+0200 lvl=info msg="LXD 4.4 is starting in normal mode" path=/var/snap/lxd/common/lxd
t=2020-09-14T22:33:34+0200 lvl=info msg="Kernel uid/gid map:" 
t=2020-09-14T22:33:34+0200 lvl=info msg=" - u 0 0 4294967295" 
t=2020-09-14T22:33:34+0200 lvl=info msg=" - g 0 0 4294967295" 
t=2020-09-14T22:33:34+0200 lvl=info msg="Configured LXD uid/gid map:" 
t=2020-09-14T22:33:34+0200 lvl=info msg=" - u 0 1000000 1000000000" 
t=2020-09-14T22:33:34+0200 lvl=info msg=" - g 0 1000000 1000000000" 
t=2020-09-14T22:33:34+0200 lvl=info msg="Kernel features:" 
t=2020-09-14T22:33:34+0200 lvl=info msg=" - closing multiple file descriptros efficiently: no" 
t=2020-09-14T22:33:34+0200 lvl=info msg=" - netnsid-based network retrieval: yes" 
t=2020-09-14T22:33:34+0200 lvl=info msg=" - pidfds: yes" 
t=2020-09-14T22:33:34+0200 lvl=info msg=" - uevent injection: yes" 
t=2020-09-14T22:33:34+0200 lvl=info msg=" - seccomp listener: yes" 
t=2020-09-14T22:33:34+0200 lvl=info msg=" - seccomp listener continue syscalls: yes" 
t=2020-09-14T22:33:34+0200 lvl=info msg=" - seccomp listener add file descriptors: no" 
t=2020-09-14T22:33:34+0200 lvl=info msg=" - safe native terminal allocation : no" 
t=2020-09-14T22:33:34+0200 lvl=info msg=" - unprivileged file capabilities: yes" 
t=2020-09-14T22:33:34+0200 lvl=info msg=" - cgroup layout: hybrid" 
t=2020-09-14T22:33:34+0200 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, I/O weight limits will be ignored" 
t=2020-09-14T22:33:34+0200 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored" 
t=2020-09-14T22:33:34+0200 lvl=info msg=" - shiftfs support: disabled" 
t=2020-09-14T22:33:34+0200 lvl=info msg="Initializing local database" 
t=2020-09-14T22:33:35+0200 lvl=warn msg="Failed settting up shared mounts: no such file or directory" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Starting /dev/lxd handler:" 
t=2020-09-14T22:33:35+0200 lvl=info msg=" - binding devlxd socket" socket=/var/snap/lxd/common/lxd/devlxd/sock
t=2020-09-14T22:33:35+0200 lvl=info msg="REST API daemon:" 
t=2020-09-14T22:33:35+0200 lvl=info msg=" - binding Unix socket" inherited=true socket=/var/snap/lxd/common/lxd/unix.socket
t=2020-09-14T22:33:35+0200 lvl=info msg="Initializing global database" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Updating the LXD global schema. Backup made as \"global.bak\"" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Firewall loaded driver \"xtables\"" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Initializing storage pools" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Initializing daemon storage mounts" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Initializing networks" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Pruning leftover image files" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Done pruning leftover image files" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Loading daemon configuration" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Started seccomp handler" path=/var/snap/lxd/common/lxd/seccomp.socket
t=2020-09-14T22:33:35+0200 lvl=info msg="Pruning expired images" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Done pruning expired images" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Pruning expired instance backups" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Done pruning expired instance backups" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Updating images" 
t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'amkcs': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?" 
t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'core01-c14': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?" 
t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'efop': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?" 
t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'feb': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Updating instance types" 
t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'habanero': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?" 
t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'hegyeseros': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?" 
t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'jalapeno': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?" 
t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'jumper': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?" 
t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'oktatas': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?" 
t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'tony': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Done updating images" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Done updating instance types" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Expiring log files" 
t=2020-09-14T22:33:35+0200 lvl=info msg="Done expiring log files" 

Is this a different issue?

[tomposmiko]

So upgrading LXD and restarting the service did not help. Rebooting the machine fixed the problem.

I have a bad feeling. Did MS acquired Canonical?

[stgraber]

Can you show journalctl -u snap.lxd.daemon -n 500, that should cover a few recent startup so we can see if something weird happened there.

[tomposmiko]

-- Logs begin at Tue 2020-08-11 22:00:01 CEST, end at Tue 2020-09-15 22:44:13 CEST. --
Aug 15 01:15:25 tummy lxd.daemon[2290521]: Running destructor lxcfs_exit
Aug 15 01:15:37 tummy lxd.daemon[1215374]: Running destructor lxcfs_exit
Aug 18 18:43:12 tummy systemd[1]: Stopping Service for snap application lxd.daemon...
Aug 18 18:43:13 tummy lxd.daemon[3935141]: => Stop reason is: snap refresh
Aug 18 18:43:13 tummy lxd.daemon[3935141]: => Stopping LXD
Aug 18 18:43:13 tummy lxd.daemon[2290227]: => LXD exited cleanly
Aug 18 18:43:14 tummy systemd[1]: snap.lxd.daemon.service: Succeeded.
Aug 18 18:43:14 tummy systemd[1]: Stopped Service for snap application lxd.daemon.
Aug 18 18:43:36 tummy systemd[1]: Started Service for snap application lxd.daemon.
Aug 18 18:43:36 tummy lxd.daemon[3937426]: => Preparing the system (16894)
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ==> Loading snap configuration
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ==> Setting up mntns symlink (mnt:[4026532997])
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ==> Setting up kmod wrapper
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ==> Preparing /boot
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ==> Preparing a clean copy of /run
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ==> Preparing /run/bin
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ==> Preparing a clean copy of /etc
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ==> Preparing a clean copy of /usr/share/misc
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ==> Setting up ceph configuration
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ==> Setting up LVM configuration
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ==> Rotating logs
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ==> Setting up ZFS (0.8)
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ==> Escaping the systemd cgroups
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ====> Detected cgroup V1
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ==> Escaping the systemd process resource limits
Aug 18 18:43:37 tummy lxd.daemon[3937426]: ==> Disabling shiftfs on this kernel (auto)
Aug 18 18:43:37 tummy lxd.daemon[3937426]: => Starting LXCFS
Aug 18 18:43:37 tummy lxd.daemon[3937597]: Running constructor lxcfs_init to reload liblxcfs
Aug 18 18:43:37 tummy lxd.daemon[3937597]: mount namespace: 4
Aug 18 18:43:37 tummy lxd.daemon[3937597]: hierarchies:
Aug 18 18:43:37 tummy lxd.daemon[3937597]:   0: fd:   5:
Aug 18 18:43:37 tummy lxd.daemon[3937597]:   1: fd:   6: name=systemd
Aug 18 18:43:37 tummy lxd.daemon[3937597]:   2: fd:   7: freezer
Aug 18 18:43:37 tummy lxd.daemon[3937597]:   3: fd:   8: hugetlb
Aug 18 18:43:37 tummy lxd.daemon[3937597]:   4: fd:   9: devices
Aug 18 18:43:37 tummy lxd.daemon[3937597]:   5: fd:  10: cpu,cpuacct
Aug 18 18:43:37 tummy lxd.daemon[3937597]:   6: fd:  11: memory
Aug 18 18:43:37 tummy lxd.daemon[3937597]:   7: fd:  12: pids
Aug 18 18:43:37 tummy lxd.daemon[3937597]:   8: fd:  13: net_cls,net_prio
Aug 18 18:43:37 tummy lxd.daemon[3937597]:   9: fd:  14: blkio
Aug 18 18:43:37 tummy lxd.daemon[3937597]:  10: fd:  15: perf_event
Aug 18 18:43:37 tummy lxd.daemon[3937597]:  11: fd:  16: cpuset
Aug 18 18:43:37 tummy lxd.daemon[3937597]:  12: fd:  17: rdma
Aug 18 18:43:37 tummy lxd.daemon[3937597]: Kernel supports pidfds
Aug 18 18:43:37 tummy lxd.daemon[3937597]: Kernel does not support swap accounting
Aug 18 18:43:37 tummy lxd.daemon[3937597]: api_extensions:
Aug 18 18:43:37 tummy lxd.daemon[3937597]: - cgroups
Aug 18 18:43:37 tummy lxd.daemon[3937597]: - sys_cpu_online
Aug 18 18:43:37 tummy lxd.daemon[3937597]: - proc_cpuinfo
Aug 18 18:43:37 tummy lxd.daemon[3937597]: - proc_diskstats
Aug 18 18:43:37 tummy lxd.daemon[3937597]: - proc_loadavg
Aug 18 18:43:37 tummy lxd.daemon[3937597]: - proc_meminfo
Aug 18 18:43:37 tummy lxd.daemon[3937597]: - proc_stat
Aug 18 18:43:37 tummy lxd.daemon[3937597]: - proc_swaps
Aug 18 18:43:37 tummy lxd.daemon[3937597]: - proc_uptime
Aug 18 18:43:37 tummy lxd.daemon[3937597]: - shared_pidns
Aug 18 18:43:37 tummy lxd.daemon[3937597]: - cpuview_daemon
Aug 18 18:43:37 tummy lxd.daemon[3937597]: - loadavg_daemon
Aug 18 18:43:37 tummy lxd.daemon[3937597]: - pidfds
Aug 18 18:43:38 tummy lxd.daemon[3937426]: => Starting LXD
Aug 18 18:43:38 tummy lxd.daemon[3937608]: t=2020-08-18T18:43:38+0200 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, I/O weight limits will be ignored"
Aug 18 18:43:38 tummy lxd.daemon[3937608]: t=2020-08-18T18:43:38+0200 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored"
Aug 18 18:43:39 tummy lxd.daemon[3937608]: t=2020-08-18T18:43:39+0200 lvl=warn msg="Failed settting up shared mounts: no such file or directory"
Aug 18 18:43:40 tummy lxd.daemon[3937426]: => LXD is ready
Aug 19 12:43:43 tummy lxd.daemon[3937608]: t=2020-08-19T12:43:43+0200 lvl=eror msg="Failed to update the image" err="Unable to fetch https://images.linuxcontainers.org/images/ubuntu/focal/amd64/default/20200816_07:42/lxd.tar.xz: 404 Not Found" fp=8ee92cbf00adae6e1c239351d768de1ae2ca066c2869e527de9c98b9f0e84341
Aug 20 00:28:11 tummy systemd[1]: Stopping Service for snap application lxd.daemon...
Aug 20 00:28:12 tummy lxd.daemon[2192501]: => Stop reason is: snap refresh
Aug 20 00:28:12 tummy lxd.daemon[2192501]: => Stopping LXD
Aug 20 00:28:12 tummy lxd.daemon[3937426]: => LXD exited cleanly
Aug 20 00:28:13 tummy systemd[1]: snap.lxd.daemon.service: Succeeded.
Aug 20 00:28:13 tummy systemd[1]: Stopped Service for snap application lxd.daemon.
Aug 20 00:28:32 tummy systemd[1]: Started Service for snap application lxd.daemon.
Aug 20 00:28:32 tummy lxd.daemon[2194496]: => Preparing the system (16922)
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ==> Loading snap configuration
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ==> Setting up mntns symlink (mnt:[4026532997])
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ==> Setting up kmod wrapper
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ==> Preparing /boot
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ==> Preparing a clean copy of /run
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ==> Preparing /run/bin
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ==> Preparing a clean copy of /etc
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ==> Preparing a clean copy of /usr/share/misc
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ==> Setting up ceph configuration
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ==> Setting up LVM configuration
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ==> Rotating logs
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ==> Setting up ZFS (0.8)
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ==> Escaping the systemd cgroups
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ====> Detected cgroup V1
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ==> Escaping the systemd process resource limits
Aug 20 00:28:33 tummy lxd.daemon[2194496]: ==> Disabling shiftfs on this kernel (auto)
Aug 20 00:28:33 tummy lxd.daemon[2194496]: => Re-using existing LXCFS
Aug 20 00:28:33 tummy lxd.daemon[2194496]: => Starting LXD
Aug 20 00:28:33 tummy lxd.daemon[2194796]: t=2020-08-20T00:28:33+0200 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, I/O weight limits will be ignored"
Aug 20 00:28:33 tummy lxd.daemon[2194796]: t=2020-08-20T00:28:33+0200 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored"
Aug 20 00:28:34 tummy lxd.daemon[2194796]: t=2020-08-20T00:28:34+0200 lvl=warn msg="Failed settting up shared mounts: no such file or directory"
Aug 20 00:28:35 tummy lxd.daemon[2194496]: => LXD is ready
Aug 26 07:02:48 tummy lxd.daemon[2194796]: t=2020-08-26T07:02:48+0200 lvl=warn msg="Detected poll(POLLNVAL) event."
Aug 31 12:14:31 tummy lxd.daemon[2194796]: t=2020-08-31T12:14:31+0200 lvl=warn msg="Detected poll(POLLNVAL) event."
Sep 04 09:22:19 tummy lxd.daemon[2194796]: t=2020-09-04T09:22:19+0200 lvl=warn msg="Detected poll(POLLNVAL) event."
Sep 14 22:04:35 tummy lxd.daemon[2194796]: t=2020-09-14T22:04:35+0200 lvl=warn msg="Detected poll(POLLNVAL) event."
Sep 14 22:16:29 tummy systemd[1]: Stopping Service for snap application lxd.daemon...
Sep 14 22:16:30 tummy lxd.daemon[658080]: => Stop reason is: host shutdown
Sep 14 22:16:30 tummy lxd.daemon[658080]: => Stopping LXD (with container shutdown)
Sep 14 22:16:52 tummy lxd.daemon[2194496]: => LXD exited cleanly
Sep 14 22:16:53 tummy lxd.daemon[658080]: ==> Stopped LXD
Sep 14 22:16:53 tummy lxd.daemon[658080]: => Stopping LXCFS
Sep 14 22:16:53 tummy lxd.daemon[3937597]: Running destructor lxcfs_exit
Sep 14 22:16:54 tummy lxd.daemon[658080]: ==> Stopped LXCFS
Sep 14 22:16:54 tummy lxd.daemon[658080]: => Cleaning up PID files
Sep 14 22:16:54 tummy lxd.daemon[658080]: => Cleaning up namespaces
Sep 14 22:16:54 tummy lxd.daemon[658080]: => All done
Sep 14 22:16:54 tummy systemd[1]: snap.lxd.daemon.service: Succeeded.
Sep 14 22:16:54 tummy systemd[1]: Stopped Service for snap application lxd.daemon.
Sep 14 22:16:54 tummy systemd[1]: Started Service for snap application lxd.daemon.
Sep 14 22:16:54 tummy lxd.daemon[662436]: => Preparing the system (16922)
Sep 14 22:16:54 tummy lxd.daemon[662436]: ==> Loading snap configuration
Sep 14 22:16:54 tummy lxd.daemon[662436]: ==> Setting up mntns symlink (mnt:[4026532997])
Sep 14 22:16:54 tummy lxd.daemon[662436]: ==> Setting up kmod wrapper
Sep 14 22:16:54 tummy lxd.daemon[662436]: ==> Preparing /boot
Sep 14 22:16:54 tummy lxd.daemon[662436]: ==> Preparing a clean copy of /run
Sep 14 22:16:54 tummy lxd.daemon[662436]: ==> Preparing /run/bin
Sep 14 22:16:54 tummy lxd.daemon[662436]: ==> Preparing a clean copy of /etc
Sep 14 22:16:54 tummy lxd.daemon[662436]: ==> Preparing a clean copy of /usr/share/misc
Sep 14 22:16:54 tummy lxd.daemon[662436]: ==> Setting up ceph configuration
Sep 14 22:16:54 tummy lxd.daemon[662436]: ==> Setting up LVM configuration
Sep 14 22:16:54 tummy lxd.daemon[662436]: ==> Rotating logs
Sep 14 22:16:54 tummy lxd.daemon[662436]: ==> Setting up ZFS (0.8)
Sep 14 22:16:54 tummy lxd.daemon[662436]: ==> Escaping the systemd cgroups
Sep 14 22:16:54 tummy lxd.daemon[662436]: ====> Detected cgroup V1
Sep 14 22:16:54 tummy lxd.daemon[662436]: ==> Escaping the systemd process resource limits
Sep 14 22:16:54 tummy lxd.daemon[662436]: ==> Disabling shiftfs on this kernel (auto)
Sep 14 22:16:54 tummy lxd.daemon[662436]: => Starting LXCFS
Sep 14 22:16:54 tummy lxd.daemon[662555]: Running constructor lxcfs_init to reload liblxcfs
Sep 14 22:16:54 tummy lxd.daemon[662555]: mount namespace: 4
Sep 14 22:16:54 tummy lxd.daemon[662555]: hierarchies:
Sep 14 22:16:54 tummy lxd.daemon[662555]:   0: fd:   5:
Sep 14 22:16:54 tummy lxd.daemon[662555]:   1: fd:   6: name=systemd
Sep 14 22:16:54 tummy lxd.daemon[662555]:   2: fd:   7: freezer
Sep 14 22:16:54 tummy lxd.daemon[662555]:   3: fd:   8: hugetlb
Sep 14 22:16:54 tummy lxd.daemon[662555]:   4: fd:   9: devices
Sep 14 22:16:54 tummy lxd.daemon[662555]:   5: fd:  10: cpu,cpuacct
Sep 14 22:16:54 tummy lxd.daemon[662555]:   6: fd:  11: memory
Sep 14 22:16:54 tummy lxd.daemon[662555]:   7: fd:  12: pids
Sep 14 22:16:54 tummy lxd.daemon[662555]:   8: fd:  13: net_cls,net_prio
Sep 14 22:16:54 tummy lxd.daemon[662555]:   9: fd:  14: blkio
Sep 14 22:16:54 tummy lxd.daemon[662555]:  10: fd:  15: perf_event
Sep 14 22:16:54 tummy lxd.daemon[662555]:  11: fd:  16: cpuset
Sep 14 22:16:54 tummy lxd.daemon[662555]:  12: fd:  17: rdma
Sep 14 22:16:54 tummy lxd.daemon[662555]: Kernel supports pidfds
Sep 14 22:16:54 tummy lxd.daemon[662555]: Kernel does not support swap accounting
Sep 14 22:16:54 tummy lxd.daemon[662555]: api_extensions:
Sep 14 22:16:54 tummy lxd.daemon[662555]: - cgroups
Sep 14 22:16:54 tummy lxd.daemon[662555]: - sys_cpu_online
Sep 14 22:16:54 tummy lxd.daemon[662555]: - proc_cpuinfo
Sep 14 22:16:54 tummy lxd.daemon[662555]: - proc_diskstats
Sep 14 22:16:54 tummy lxd.daemon[662555]: - proc_loadavg
Sep 14 22:16:54 tummy lxd.daemon[662555]: - proc_meminfo
Sep 14 22:16:54 tummy lxd.daemon[662555]: - proc_stat
Sep 14 22:16:54 tummy lxd.daemon[662555]: - proc_swaps
Sep 14 22:16:54 tummy lxd.daemon[662555]: - proc_uptime
Sep 14 22:16:54 tummy lxd.daemon[662555]: - shared_pidns
Sep 14 22:16:54 tummy lxd.daemon[662555]: - cpuview_daemon
Sep 14 22:16:54 tummy lxd.daemon[662555]: - loadavg_daemon
Sep 14 22:16:54 tummy lxd.daemon[662555]: - pidfds
Sep 14 22:16:55 tummy lxd.daemon[662436]: => Starting LXD
Sep 14 22:16:55 tummy lxd.daemon[662566]: t=2020-09-14T22:16:55+0200 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, I/O weight limits will be ignored"
Sep 14 22:16:55 tummy lxd.daemon[662566]: t=2020-09-14T22:16:55+0200 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored"
Sep 14 22:16:56 tummy lxd.daemon[662566]: t=2020-09-14T22:16:56+0200 lvl=warn msg="Failed settting up shared mounts: no such file or directory"
Sep 14 22:16:57 tummy lxd.daemon[662566]: t=2020-09-14T22:16:57+0200 lvl=eror msg="Failed to start instance 'amkcs': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:16:57 tummy lxd.daemon[662566]: t=2020-09-14T22:16:57+0200 lvl=eror msg="Failed to start instance 'core01-c14': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:16:57 tummy lxd.daemon[662566]: t=2020-09-14T22:16:57+0200 lvl=eror msg="Failed to start instance 'efop': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:16:57 tummy lxd.daemon[662566]: t=2020-09-14T22:16:57+0200 lvl=eror msg="Failed to start instance 'feb': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:16:57 tummy lxd.daemon[662566]: t=2020-09-14T22:16:57+0200 lvl=eror msg="Failed to start instance 'habanero': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:16:57 tummy lxd.daemon[662566]: t=2020-09-14T22:16:57+0200 lvl=eror msg="Failed to start instance 'hegyeseros': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:16:57 tummy lxd.daemon[662566]: t=2020-09-14T22:16:57+0200 lvl=eror msg="Failed to start instance 'jalapeno': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:16:57 tummy lxd.daemon[662566]: t=2020-09-14T22:16:57+0200 lvl=eror msg="Failed to start instance 'jumper': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:16:57 tummy lxd.daemon[662566]: t=2020-09-14T22:16:57+0200 lvl=eror msg="Failed to start instance 'oktatas': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:16:57 tummy lxd.daemon[662566]: t=2020-09-14T22:16:57+0200 lvl=eror msg="Failed to start instance 'tony': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:16:57 tummy lxd.daemon[662436]: => LXD is ready
Sep 14 22:33:27 tummy systemd[1]: Stopping Service for snap application lxd.daemon...
Sep 14 22:33:28 tummy lxd.daemon[664028]: => Stop reason is: snap refresh
Sep 14 22:33:28 tummy lxd.daemon[664028]: => Stopping LXD
Sep 14 22:33:28 tummy lxd.daemon[662436]: => LXD exited cleanly
Sep 14 22:33:29 tummy systemd[1]: snap.lxd.daemon.service: Succeeded.
Sep 14 22:33:29 tummy systemd[1]: Stopped Service for snap application lxd.daemon.
Sep 14 22:33:33 tummy systemd[1]: Started Service for snap application lxd.daemon.
Sep 14 22:33:33 tummy lxd.daemon[664235]: => Preparing the system (16926)
Sep 14 22:33:34 tummy lxd.daemon[664235]: ==> Loading snap configuration
Sep 14 22:33:34 tummy lxd.daemon[664235]: ==> Setting up mntns symlink (mnt:[4026532997])
Sep 14 22:33:34 tummy lxd.daemon[664235]: ==> Setting up kmod wrapper
Sep 14 22:33:34 tummy lxd.daemon[664235]: ==> Preparing /boot
Sep 14 22:33:34 tummy lxd.daemon[664235]: ==> Preparing a clean copy of /run
Sep 14 22:33:34 tummy lxd.daemon[664235]: ==> Preparing /run/bin
Sep 14 22:33:34 tummy lxd.daemon[664235]: ==> Preparing a clean copy of /etc
Sep 14 22:33:34 tummy lxd.daemon[664235]: ==> Preparing a clean copy of /usr/share/misc
Sep 14 22:33:34 tummy lxd.daemon[664235]: ==> Setting up ceph configuration
Sep 14 22:33:34 tummy lxd.daemon[664235]: ==> Setting up LVM configuration
Sep 14 22:33:34 tummy lxd.daemon[664235]: ==> Rotating logs
Sep 14 22:33:34 tummy lxd.daemon[664235]: ==> Setting up ZFS (0.8)
Sep 14 22:33:34 tummy lxd.daemon[664235]: ==> Escaping the systemd cgroups
Sep 14 22:33:34 tummy lxd.daemon[664235]: ====> Detected cgroup V1
Sep 14 22:33:34 tummy lxd.daemon[664235]: ==> Escaping the systemd process resource limits
Sep 14 22:33:34 tummy lxd.daemon[664235]: ==> Disabling shiftfs on this kernel (auto)
Sep 14 22:33:34 tummy lxd.daemon[664235]: => Re-using existing LXCFS
Sep 14 22:33:34 tummy lxd.daemon[664235]: => Starting LXD
Sep 14 22:33:34 tummy lxd.daemon[664409]: t=2020-09-14T22:33:34+0200 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, I/O weight limits will be ignored"
Sep 14 22:33:34 tummy lxd.daemon[664409]: t=2020-09-14T22:33:34+0200 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored"
Sep 14 22:33:35 tummy lxd.daemon[664409]: t=2020-09-14T22:33:35+0200 lvl=warn msg="Failed settting up shared mounts: no such file or directory"
Sep 14 22:33:35 tummy lxd.daemon[664409]: t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'amkcs': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:33:35 tummy lxd.daemon[664409]: t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'core01-c14': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:33:35 tummy lxd.daemon[664409]: t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'efop': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:33:35 tummy lxd.daemon[664409]: t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'feb': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:33:35 tummy lxd.daemon[664409]: t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'habanero': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:33:35 tummy lxd.daemon[664409]: t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'hegyeseros': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:33:35 tummy lxd.daemon[664409]: t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'jalapeno': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:33:35 tummy lxd.daemon[664409]: t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'jumper': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:33:35 tummy lxd.daemon[664409]: t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'oktatas': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:33:35 tummy lxd.daemon[664409]: t=2020-09-14T22:33:35+0200 lvl=eror msg="Failed to start instance 'tony': Daemon failed to setup shared mounts base: <nil>. Does security.nesting need to be turned on?"
Sep 14 22:33:36 tummy lxd.daemon[664235]: => LXD is ready
Sep 14 23:00:55 tummy systemd[1]: Stopping Service for snap application lxd.daemon...
Sep 14 23:00:55 tummy lxd.daemon[672869]: => Stop reason is: host shutdown
Sep 14 23:00:55 tummy lxd.daemon[672869]: => Stopping LXD (with container shutdown)
Sep 14 23:00:55 tummy lxd.daemon[664409]: t=2020-09-14T23:00:55+0200 lvl=warn msg="Failed to delete operation 6b5724a9-ab03-4ef1-a0ea-37e4f70c4417: failed to begin transaction: sql: database is closed"
Sep 14 23:00:56 tummy lxd.daemon[664235]: => LXD exited cleanly
Sep 14 23:00:56 tummy lxd.daemon[672869]: ==> Stopped LXD
Sep 14 23:00:56 tummy lxd.daemon[672869]: => Stopping LXCFS
Sep 14 23:00:56 tummy lxd.daemon[662555]: Running destructor lxcfs_exit
Sep 14 23:00:57 tummy lxd.daemon[672869]: ==> Stopped LXCFS
Sep 14 23:00:57 tummy lxd.daemon[672869]: => Cleaning up PID files
Sep 14 23:00:57 tummy lxd.daemon[672869]: => Cleaning up namespaces
Sep 14 23:00:57 tummy lxd.daemon[672869]: => All done
Sep 14 23:00:57 tummy systemd[1]: snap.lxd.daemon.service: Succeeded.
Sep 14 23:00:57 tummy systemd[1]: Stopped Service for snap application lxd.daemon.
Sep 14 23:01:02 tummy systemd[1]: Started Service for snap application lxd.daemon.
Sep 14 23:01:02 tummy lxd.daemon[673417]: => Preparing the system (16926)
Sep 14 23:01:02 tummy lxd.daemon[673417]: ==> Loading snap configuration
Sep 14 23:01:02 tummy lxd.daemon[673417]: ==> Setting up mntns symlink (mnt:[4026532997])
Sep 14 23:01:02 tummy lxd.daemon[673417]: ==> Setting up kmod wrapper
Sep 14 23:01:02 tummy lxd.daemon[673417]: ==> Preparing /boot
Sep 14 23:01:02 tummy lxd.daemon[673417]: ==> Preparing a clean copy of /run
Sep 14 23:01:02 tummy lxd.daemon[673417]: ==> Preparing /run/bin
Sep 14 23:01:02 tummy lxd.daemon[673417]: ==> Preparing a clean copy of /etc
Sep 14 23:01:02 tummy lxd.daemon[673417]: ==> Preparing a clean copy of /usr/share/misc
Sep 14 23:01:02 tummy lxd.daemon[673417]: ==> Setting up ceph configuration
Sep 14 23:01:02 tummy lxd.daemon[673417]: ==> Setting up LVM configuration
Sep 14 23:01:02 tummy lxd.daemon[673417]: ==> Rotating logs
Sep 14 23:01:02 tummy lxd.daemon[673417]: ==> Setting up ZFS (0.8)
Sep 14 23:01:02 tummy lxd.daemon[673417]: ==> Escaping the systemd cgroups
Sep 14 23:01:02 tummy lxd.daemon[673417]: ====> Detected cgroup V1
Sep 14 23:01:02 tummy lxd.daemon[673417]: ==> Escaping the systemd process resource limits
Sep 14 23:01:02 tummy lxd.daemon[673417]: ==> Disabling shiftfs on this kernel (auto)
Sep 14 23:01:02 tummy lxd.daemon[673417]: => Starting LXCFS
Sep 14 23:01:02 tummy lxd.daemon[673610]: Running constructor lxcfs_init to reload liblxcfs
Sep 14 23:01:02 tummy lxd.daemon[673610]: mount namespace: 4
Sep 14 23:01:02 tummy lxd.daemon[673610]: hierarchies:
Sep 14 23:01:02 tummy lxd.daemon[673610]:   0: fd:   5:
Sep 14 23:01:02 tummy lxd.daemon[673610]:   1: fd:   6: name=systemd
Sep 14 23:01:02 tummy lxd.daemon[673610]:   2: fd:   7: freezer
Sep 14 23:01:02 tummy lxd.daemon[673610]:   3: fd:   8: hugetlb
Sep 14 23:01:02 tummy lxd.daemon[673610]:   4: fd:   9: devices
Sep 14 23:01:02 tummy lxd.daemon[673610]:   5: fd:  10: cpu,cpuacct
Sep 14 23:01:02 tummy lxd.daemon[673610]:   6: fd:  11: memory
Sep 14 23:01:02 tummy lxd.daemon[673610]:   7: fd:  12: pids
Sep 14 23:01:02 tummy lxd.daemon[673610]:   8: fd:  13: net_cls,net_prio
Sep 14 23:01:02 tummy lxd.daemon[673610]:   9: fd:  14: blkio
Sep 14 23:01:02 tummy lxd.daemon[673610]:  10: fd:  15: perf_event
Sep 14 23:01:02 tummy lxd.daemon[673610]:  11: fd:  16: cpuset
Sep 14 23:01:02 tummy lxd.daemon[673610]:  12: fd:  17: rdma
Sep 14 23:01:02 tummy lxd.daemon[673610]: Kernel supports pidfds
Sep 14 23:01:02 tummy lxd.daemon[673610]: Kernel does not support swap accounting
Sep 14 23:01:02 tummy lxd.daemon[673610]: api_extensions:
Sep 14 23:01:02 tummy lxd.daemon[673610]: - cgroups
Sep 14 23:01:02 tummy lxd.daemon[673610]: - sys_cpu_online
Sep 14 23:01:02 tummy lxd.daemon[673610]: - proc_cpuinfo
Sep 14 23:01:02 tummy lxd.daemon[673610]: - proc_diskstats
Sep 14 23:01:02 tummy lxd.daemon[673610]: - proc_loadavg
Sep 14 23:01:02 tummy lxd.daemon[673610]: - proc_meminfo
Sep 14 23:01:02 tummy lxd.daemon[673610]: - proc_stat
Sep 14 23:01:02 tummy lxd.daemon[673610]: - proc_swaps
Sep 14 23:01:02 tummy lxd.daemon[673610]: - proc_uptime
Sep 14 23:01:02 tummy lxd.daemon[673610]: - shared_pidns
Sep 14 23:01:02 tummy lxd.daemon[673610]: - cpuview_daemon
Sep 14 23:01:02 tummy lxd.daemon[673610]: - loadavg_daemon
Sep 14 23:01:02 tummy lxd.daemon[673610]: - pidfds
Sep 14 23:01:03 tummy lxd.daemon[673417]: => Starting LXD
Sep 14 23:01:03 tummy lxd.daemon[673698]: t=2020-09-14T23:01:03+0200 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, I/O weight limits will be ignored"
Sep 14 23:01:03 tummy lxd.daemon[673698]: t=2020-09-14T23:01:03+0200 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored"
Sep 14 23:01:03 tummy lxd.daemon[673698]: t=2020-09-14T23:01:03+0200 lvl=warn msg="Failed settting up shared mounts: no such file or directory"
Sep 14 23:01:04 tummy lxd.daemon[673417]: => LXD is ready
Sep 14 23:03:11 tummy systemd[1]: Stopping Service for snap application lxd.daemon...
Sep 14 23:03:11 tummy lxd.daemon[677102]: => Stop reason is: host shutdown
Sep 14 23:03:11 tummy lxd.daemon[677102]: => Stopping LXD (with container shutdown)
Sep 14 23:03:12 tummy lxd.daemon[673417]: => LXD exited cleanly
Sep 14 23:03:12 tummy lxd.daemon[677102]: ==> Stopped LXD
Sep 14 23:03:12 tummy lxd.daemon[677102]: => Stopping LXCFS
Sep 14 23:03:12 tummy lxd.daemon[673610]: Running destructor lxcfs_exit
Sep 14 23:03:13 tummy lxd.daemon[677102]: ==> Stopped LXCFS
Sep 14 23:03:13 tummy lxd.daemon[677102]: => Cleaning up PID files
Sep 14 23:03:13 tummy lxd.daemon[677102]: => Cleaning up namespaces
Sep 14 23:03:13 tummy lxd.daemon[677102]: => All done
Sep 14 23:03:13 tummy systemd[1]: snap.lxd.daemon.service: Succeeded.
Sep 14 23:03:13 tummy systemd[1]: Stopped Service for snap application lxd.daemon.
-- Reboot --
Sep 14 23:03:51 tummy systemd[1]: Started Service for snap application lxd.daemon.
Sep 14 23:03:51 tummy lxd.daemon[2220]: => Preparing the system (16926)
Sep 14 23:03:51 tummy lxd.daemon[2268]: cmd_linux.go:160: cannot read /proc/self/exe: readlink /proc/self/exe: no such file or directory
Sep 14 23:03:51 tummy lxd.daemon[2220]: ==> Loading snap configuration
Sep 14 23:03:51 tummy lxd.daemon[2220]: ==> Setting up mntns symlink (mnt:[4026532315])
Sep 14 23:03:51 tummy lxd.daemon[2220]: ==> Setting up mount propagation on /var/snap/lxd/common/lxd/storage-pools
Sep 14 23:03:51 tummy lxd.daemon[2220]: ==> Setting up mount propagation on /var/snap/lxd/common/lxd/devices
Sep 14 23:03:51 tummy lxd.daemon[2220]: ==> Setting up persistent shmounts path
Sep 14 23:03:51 tummy lxd.daemon[2220]: ====> Making LXD shmounts use the persistent path
Sep 14 23:03:51 tummy lxd.daemon[2220]: ====> Making LXCFS use the persistent path
Sep 14 23:03:51 tummy lxd.daemon[2220]: ==> Setting up kmod wrapper
Sep 14 23:03:51 tummy lxd.daemon[2220]: ==> Preparing /boot
Sep 14 23:03:51 tummy lxd.daemon[2220]: ==> Preparing a clean copy of /run
Sep 14 23:03:51 tummy lxd.daemon[2220]: ==> Preparing /run/bin
Sep 14 23:03:51 tummy lxd.daemon[2220]: ==> Preparing a clean copy of /etc
Sep 14 23:03:51 tummy lxd.daemon[2220]: ==> Preparing a clean copy of /usr/share/misc
Sep 14 23:03:51 tummy lxd.daemon[2220]: ==> Setting up ceph configuration
Sep 14 23:03:51 tummy lxd.daemon[2220]: ==> Setting up LVM configuration
Sep 14 23:03:51 tummy lxd.daemon[2220]: ==> Rotating logs
Sep 14 23:03:52 tummy lxd.daemon[2220]: ==> Setting up ZFS (0.8)
Sep 14 23:03:52 tummy lxd.daemon[2220]: ==> Escaping the systemd cgroups
Sep 14 23:03:52 tummy lxd.daemon[2220]: ====> Detected cgroup V1
Sep 14 23:03:52 tummy lxd.daemon[2220]: ==> Escaping the systemd process resource limits
Sep 14 23:03:52 tummy lxd.daemon[2220]: ==> Increasing the number of inotify user instances
Sep 14 23:03:52 tummy lxd.daemon[2220]: ==> Disabling shiftfs on this kernel (auto)
Sep 14 23:03:52 tummy lxd.daemon[2220]: => Starting LXCFS
Sep 14 23:03:52 tummy lxd.daemon[2371]: Running constructor lxcfs_init to reload liblxcfs
Sep 14 23:03:52 tummy lxd.daemon[2371]: mount namespace: 4
Sep 14 23:03:52 tummy lxd.daemon[2371]: hierarchies:
Sep 14 23:03:52 tummy lxd.daemon[2371]:   0: fd:   5:
Sep 14 23:03:52 tummy lxd.daemon[2371]:   1: fd:   6: name=systemd
Sep 14 23:03:52 tummy lxd.daemon[2371]:   2: fd:   7: devices
Sep 14 23:03:52 tummy lxd.daemon[2371]:   3: fd:   8: cpu,cpuacct
Sep 14 23:03:52 tummy lxd.daemon[2371]:   4: fd:   9: freezer
Sep 14 23:03:52 tummy lxd.daemon[2371]:   5: fd:  10: rdma
Sep 14 23:03:52 tummy lxd.daemon[2371]:   6: fd:  11: pids
Sep 14 23:03:52 tummy lxd.daemon[2371]:   7: fd:  12: net_cls,net_prio
Sep 14 23:03:52 tummy lxd.daemon[2371]:   8: fd:  13: blkio
Sep 14 23:03:52 tummy lxd.daemon[2371]:   9: fd:  14: hugetlb
Sep 14 23:03:52 tummy lxd.daemon[2371]:  10: fd:  15: cpuset
Sep 14 23:03:52 tummy lxd.daemon[2371]:  11: fd:  16: perf_event
Sep 14 23:03:52 tummy lxd.daemon[2371]:  12: fd:  17: memory
Sep 14 23:03:52 tummy lxd.daemon[2371]: Kernel supports pidfds
Sep 14 23:03:52 tummy lxd.daemon[2371]: Kernel does not support swap accounting
Sep 14 23:03:52 tummy lxd.daemon[2371]: api_extensions:
Sep 14 23:03:52 tummy lxd.daemon[2371]: - cgroups
Sep 14 23:03:52 tummy lxd.daemon[2371]: - sys_cpu_online
Sep 14 23:03:52 tummy lxd.daemon[2371]: - proc_cpuinfo
Sep 14 23:03:52 tummy lxd.daemon[2371]: - proc_diskstats
Sep 14 23:03:52 tummy lxd.daemon[2371]: - proc_loadavg
Sep 14 23:03:52 tummy lxd.daemon[2371]: - proc_meminfo
Sep 14 23:03:52 tummy lxd.daemon[2371]: - proc_stat
Sep 14 23:03:52 tummy lxd.daemon[2371]: - proc_swaps
Sep 14 23:03:52 tummy lxd.daemon[2371]: - proc_uptime
Sep 14 23:03:52 tummy lxd.daemon[2371]: - shared_pidns
Sep 14 23:03:52 tummy lxd.daemon[2371]: - cpuview_daemon
Sep 14 23:03:52 tummy lxd.daemon[2371]: - loadavg_daemon
Sep 14 23:03:52 tummy lxd.daemon[2371]: - pidfds
Sep 14 23:03:53 tummy lxd.daemon[2220]: => Starting LXD
Sep 14 23:03:53 tummy lxd.daemon[2382]: t=2020-09-14T23:03:53+0200 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, I/O weight limits will be ignored"
Sep 14 23:03:53 tummy lxd.daemon[2382]: t=2020-09-14T23:03:53+0200 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored"
Sep 14 23:03:54 tummy lxd.daemon[2382]: t=2020-09-14T23:03:54+0200 lvl=warn msg="Failed getting list of tables from \"/proc/self/net/ip6_tables_names\", assuming all requested tables exist"
Sep 14 23:03:55 tummy lxd.daemon[2220]: => LXD is ready
Sep 14 23:43:12 tummy lxd.daemon[2382]: t=2020-09-14T23:43:12+0200 lvl=warn msg="Detected poll(POLLNVAL) event."
Sep 15 09:56:17 tummy lxd.daemon[2382]: t=2020-09-15T09:56:17+0200 lvl=warn msg="Detected poll(POLLNVAL) event."

[tomposmiko]

@stgraber I'm wondering, if this issue is still valid. I have not experienced it for a while.

I mean did you do anything intentionally of unintentionally to fix it?

[stgraber]

I've had a couple of reports of zfs mount issues in the past month or so, so I don't think it's fully sorted.

The triggering condition is very odd though, it looks like you need one or two updates of the core18 snap, followed by one or two updates of the lxd snap, on a system using zfs, at which point the containers that were running during those refreshes will exhibit this kind of issue on restart. All new containers are unaffected.

But it's still mostly a guess, I've not had much luck scripting a reliable reproducer for this issue which would then allow us to add suitable debugging and get to the bottom of it.

[tomposmiko]

@stgraber Is there any way to help your debugging efforts? I can even provide access to this machine for you. I'm not sure if it would help.

[stgraber]

Sadly having access to a system where the issue happened isn't of much help. I've had it happen to enough of mine already.

What we need is a sequence of snap refreshes of both core18 and the LXD snap which will consistently cause this issue to appear. Then we can track it down and fix it.

[tomposmiko]

Would removing/installing the snap get it fixed?

[stgraber]

The most common issue with this goes away with a system reboot, at least until the stars align again a few months later and it shows up again.

If you have a persistent issue (still happens after reboot), then it should be much easier to track down and solve.

[tomposmiko]

hi @stgraber ,

As far as I recall, you told me, this issue comes up on systems upgraded from earlier versions of Ubuntu or LXD. Do I recall correctly?

I recently face this issue on a system that was installed on Dec 16, 2020 with Ubuntu 20.04. Does it help any way?

[stgraber]

It happens on any system using LXD and ZFS with LXD delivered as a snap. The trigger seems to be updates of both the core/core18 snap and lxd snap, in some order, combined with some instance restarting, the bug is hit.

[stgraber]

Our suspect is an issue with the mount table reshuffling that we do, but because the bug only becomes visible the next time you attempt to delete or restart an existing instance, it can be days/weeks/months before you notice.

[tomposmiko]

Ahh, OK, than I didn't help:/

[tomposmiko]

hi @stgraber,

Is it possible, that you fixed something related to this issue? I have not seen this issue for a while on any of my servers.

[tomposmiko]

Nevermind, it's just come back:/

[stgraber]

Sorry to hear that. We've indeed not yet found a reliable reproducer for this issue. I know what piece of code is almost certainly at fault but I need a way to easily script the failure so we can progressively add debugging and sort out exactly what's causing this mess...

[helamonster]

@stgraber I am experiencing this issue in a test environment. The problem persists across reboots of a simple QEMU virtual machine. If it would be helpful, I could provide the virtual machine disk image for you (should be able to get it down to ~ 1GB).

[stgraber]

Sure, that'd be useful Though the fact that it survives a reboot means it's a different bug from the one we've been chasing as that one is caused by incorrect mount namespace entries and those will not survive a reboot.

[v3ss0n]

I am having the same error . After clean shutdown of the instances cannot restart anymore..

ep 06 21:32:23 E3-2276G lxd.daemon[841134]: t=2021-09-06T21:32:23-0400 lvl=eror msg="Failed to register device" device=root err="Failed to run: zfs mount default/containers/blockchain-peer-1: cannot mount 'defa│·········
ult/containers/blockchain-peer-1': filesystem already mounted" instance=blockchain-peer-1 instanceType=container project=default                                                                                   │·········
Sep 06 21:32:23 E3-2276G lxd.daemon[841134]: t=2021-09-06T21:32:23-0400 lvl=eror msg="Failed to register device" device=root err="Failed to run: zfs mount default/containers/chain-hub: cannot mount 'default/cont│·········
ainers/chain-hub': filesystem already mounted" instance=chain-hub instanceType=container project=default                                                                                                           │·········
Sep 06 21:32:24 E3-2276G lxd.daemon[841134]: t=2021-09-06T21:32:24-0400 lvl=eror msg="Failed to register device" device=root err="Failed to run: zfs mount default/containers/chain-peer-0: cannot mount 'default/$│·········
ontainers/chain-peer-0': filesystem already mounted" instance=chain-peer-0 instanceType=container project=default                                                                                                  │·········
Sep 06 21:32:24 E3-2276G lxd.daemon[841134]: t=2021-09-06T21:32:24-0400 lvl=eror msg="Failed to register device" device=root err="Failed to run: zfs mount default/containers/chain-peer-1: cannot mount 'default/c│·········
ontainers/chain-peer-1': filesystem already mounted" instance=chain-peer-1 instanceType=container project=default                                                                                                  │·········
Sep 06 21:32:24 E3-2276G lxd.daemon[841134]: t=2021-09-06T21:32:24-0400 lvl=eror msg="Failed to register device" device=root err="Failed to run: zfs mount default/containers/chain-peer-2: cannot mount 'default/c│·········
ontainers/chain-peer-2': filesystem already mounted" instance=chain-peer-2 instanceType=container project=default                                                                                                  │·········
Sep 06 21:32:24 E3-2276G lxd.daemon[841134]: t=2021-09-06T21:32:24-0400 lvl=eror msg="Failed to register device" device=root err="Failed to run: zfs mount default/containers/hexcode-development: cannot mount 'de│·········
fault/containers/hexcode-development': filesystem already mounted" instance=hexcode-development instanceType=container project=default                                                                             │·········
Sep 06 21:32:24 E3-2276G lxd.daemon[841134]: t=2021-09-06T21:32:24-0400 lvl=eror msg="Failed to register device" device=root err="Failed to run: zfs mount default/containers/hexcode-matrix-dark: cannot mount 'de│·········
fault/containers/hexcode-matrix-dark': filesystem already mounted" instance=hexcode-matrix-dark instanceType=container project=default                                                                             │·········
Sep 06 21:32:24 E3-2276G lxd.daemon[841134]: t=2021-09-06T21:32:24-0400 lvl=eror msg="Failed to register device" device=root err="Failed to run: zfs mount default/containers/hexgen: cannot mount 'default/contain│

[v3ss0n]

can you provide us atelast a work around Script that clear the mounts so we can remount ?

[xrobau]

Happened to me yet again. I can see the volumes mounted in /proc/mounts:

nsenter --mount=/run/snapd/ns/lxd.mnt
root@lxc-07:/# mount | grep gai
default/containers/gaics on /var/snap/lxd/common/shmounts/storage-pools/default/containers/gaics type zfs (rw,xattr,posixacl)
root@lxc-07:/#

I couldn't managed to remove that one at all. I tried to ask zfs to unmount it, but there's no zfs tools available, and even trying to use the host tools by setting LD_LIBRARY_PATH=/var/lib/snapd/hostfs/lib didn't work.

I ended up taking a snapshot of it, then using zfs send | zfs recv into a new volume, creating a new container, and then putting the snapshot into the new container.

However, to confirm, there were core18 images mounted.

root@lxc-07:/# grep \ /snap/core /proc/mounts
/dev/loop8 /snap/core20/1026 squashfs ro,nodev,relatime 0 0
/dev/loop10 /snap/core18/2074 squashfs ro,nodev,relatime 0 0
/dev/loop7 /snap/core20/1081 squashfs ro,nodev,relatime 0 0
/dev/loop11 /snap/core/11420 squashfs ro,nodev,relatime 0 0
/dev/loop0 /snap/core18/2128 squashfs ro,nodev,relatime 0 0
/dev/loop2 /snap/core/11606 squashfs ro,nodev,relatime 0 0
root@lxc-07:/#

Should you just be raising big alerts and warnings about having core18, and that the machine needs to be rebooted?

[tomposmiko]

I realized, you upgraded the snap to depend on core20. What do you think, does it affect this bug positively, is there any chance that it eliminates the problem? Maybe the case above was triggered by the snap upgrade to core20?

I am asking this, because I am trying to find a reproducer and I don't know if it still makes and if so, how to install the snap with core18 dependency.

[stgraber]

I don't think so. What we've noticed so far is that for this to trigger, you need a combination of LXD and core (core20 in this case) refreshes, when those happen in some specific sequence (which is what we haven't figured out yet), the mount table gets into a confusing state and our startup logic cannot reshuffle it, causing this bug.

My suspicion as to why we've seen it less recently is that core20 has seen less frequent updates than core18 used to have and LXD itself also get slightly less frequent updates of late (we do our monthly releases and maybe a couple of bugfix revisions but we used to do up to 3-4 updates a week).

That combined with the change in LXD which makes this bug entirely invisible unless you attempt to delete an affected container means that while it may still happen, most users won't actually notice it and as it resolves itself with a reboot, the kernel updates that are pushed every 2 weeks will cause most users to reboot and fix the issue without them ever noticing.

[hanskuhn]

That combined with the change in LXD which makes this bug entirely invisible unless you attempt to delete an affected container means that while it may still happen, most users won't actually notice it

I have an hourly snapshot policy with 24h retention on a ZFS pool and this bug also causes snapshots to fail once the condition is trigged. It might be invisible, but a very unwelcome event if you happen to need a snapshot and find that they've all expired.

We are now on a weekly reboot to avoid this problem, but this is a pretty significant bug for my org. I haven't found a reproducible test case, but will certainly share if I find something interesting.

[stgraber]

@hanskuhn what do you get in lxd.log when one of the scheduled snapshot fails?

[hanskuhn]

@stgraber I don't have an instance of snapshot failure in my current log set, but I'll see if I can disable weekly reboots so we can capture this event.

[hanskuhn]

OK. Reboots have been disabled so I'll share what I find (if anything) when I get a snapshot failure.

[stgraber]

Thanks!