ZFS permission error: After node restart container can't be started anymore

[drflo]

Hi all,

I created a new ZFS pool "zfs1" and enabled encryption for "zfs1/encrypted_data" based not the documentation here: https://pve.proxmox.com/wiki/ZFS_on_Linux#zfs_encryption

All works fine with the mounted share "zfs1_encrypted" -> mount point "zfs1/encrypted_data" until I restarted the node. After that the lxc containers are not starting anymore. I have also mounted the storage manually by providing the passphrase.

The error log of the lxc says:
lxc-start 135 20201118153333.190 INFO confile - confile.c:set_config_idmaps:2055 - Read uid map: type u nsid 0 hostid 100000 range 65536 lxc-start 135 20201118153333.190 INFO confile - confile.c:set_config_idmaps:2055 - Read uid map: type g nsid 0 hostid 100000 range 65536 lxc-start 135 20201118153333.190 INFO lsm - lsm/lsm.c:lsm_init:29 - LSM security driver AppArmor lxc-start 135 20201118153333.190 INFO conf - conf.c:run_script_argv:340 - Executing script "/usr/share/lxc/hooks/lxc-pve-prestart-hook" for container "135", config section "lxc" lxc-start 135 20201118153333.642 DEBUG conf - conf.c:run_buffer:312 - Script exec /usr/share/lxc/hooks/lxc-pve-prestart-hook 135 lxc pre-start produced output: /etc/os-release file not found and autodetection failed, falling back to 'unmanaged' WARNING: /etc not present in CT, is the rootfs mounted? got unexpected ostype (unmanaged != ubuntu) lxc-start 135 20201118153333.649 DEBUG terminal - terminal.c:lxc_terminal_peer_default:662 - Using terminal "/dev/tty" as proxy lxc-start 135 20201118153333.649 DEBUG terminal - terminal.c:lxc_terminal_winsz:61 - Set window size to 183 columns and 56 rows lxc-start 135 20201118153333.649 INFO seccomp - seccomp.c:parse_config_v2:770 - Processing "reject_force_umount # comment this to allow umount -f; not recommended" lxc-start 135 20201118153333.649 INFO seccomp - seccomp.c:do_resolve_add_rule:516 - Set seccomp rule to reject force umounts lxc-start 135 20201118153333.649 INFO seccomp - seccomp.c:parse_config_v2:967 - Added native rule for arch 0 for reject_force_umount action 0(kill) lxc-start 135 20201118153333.649 INFO seccomp - seccomp.c:do_resolve_add_rule:516 - Set seccomp rule to reject force umounts lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:976 - Added compat rule for arch 1073741827 for reject_force_umount action 0(kill) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:do_resolve_add_rule:516 - Set seccomp rule to reject force umounts lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:986 - Added compat rule for arch 1073741886 for reject_force_umount action 0(kill) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:do_resolve_add_rule:516 - Set seccomp rule to reject force umounts lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:996 - Added native rule for arch -1073741762 for reject_force_umount action 0(kill) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:770 - Processing "[all]" lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:770 - Processing "kexec_load errno 1" lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:967 - Added native rule for arch 0 for kexec_load action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:976 - Added compat rule for arch 1073741827 for kexec_load action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:986 - Added compat rule for arch 1073741886 for kexec_load action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:996 - Added native rule for arch -1073741762 for kexec_load action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:770 - Processing "open_by_handle_at errno 1" lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:967 - Added native rule for arch 0 for open_by_handle_at action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:976 - Added compat rule for arch 1073741827 for open_by_handle_at action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:986 - Added compat rule for arch 1073741886 for open_by_handle_at action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:996 - Added native rule for arch -1073741762 for open_by_handle_at action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:770 - Processing "init_module errno 1" lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:967 - Added native rule for arch 0 for init_module action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:976 - Added compat rule for arch 1073741827 for init_module action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:986 - Added compat rule for arch 1073741886 for init_module action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:996 - Added native rule for arch -1073741762 for init_module action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:770 - Processing "finit_module errno 1" lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:967 - Added native rule for arch 0 for finit_module action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:976 - Added compat rule for arch 1073741827 for finit_module action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:986 - Added compat rule for arch 1073741886 for finit_module action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:996 - Added native rule for arch -1073741762 for finit_module action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:770 - Processing "delete_module errno 1" lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:967 - Added native rule for arch 0 for delete_module action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:976 - Added compat rule for arch 1073741827 for delete_module action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:986 - Added compat rule for arch 1073741886 for delete_module action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:996 - Added native rule for arch -1073741762 for delete_module action 327681(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:770 - Processing "keyctl errno 38" lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:967 - Added native rule for arch 0 for keyctl action 327718(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:976 - Added compat rule for arch 1073741827 for keyctl action 327718(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:986 - Added compat rule for arch 1073741886 for keyctl action 327718(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:996 - Added native rule for arch -1073741762 for keyctl action 327718(errno) lxc-start 135 20201118153333.650 INFO seccomp - seccomp.c:parse_config_v2:1000 - Merging compat seccomp contexts into main context lxc-start 135 20201118153333.890 INFO start - start.c:lxc_init:843 - Container "135" is initialized lxc-start 135 20201118153333.926 INFO cgfsng - cgroups/cgfsng.c:cgfsng_monitor_create:1368 - The monitor process uses "lxc.monitor/135" as cgroup lxc-start 135 20201118153333.926 DEBUG storage - storage/storage.c:storage_query:233 - Detected rootfs type "dir" lxc-start 135 20201118153333.926 INFO cgfsng - cgroups/cgfsng.c:cgfsng_setup_limits_legacy:2863 - Limits for the legacy cgroup hierarchies have been setup lxc-start 135 20201118153333.927 INFO cgfsng - cgroups/cgfsng.c:cgfsng_payload_create:1472 - The container process uses "lxc/135/ns" as cgroup lxc-start 135 20201118153333.927 INFO start - start.c:lxc_spawn:1657 - Cloned CLONE_NEWUSER lxc-start 135 20201118153333.927 INFO start - start.c:lxc_spawn:1657 - Cloned CLONE_NEWNS lxc-start 135 20201118153333.927 INFO start - start.c:lxc_spawn:1657 - Cloned CLONE_NEWPID lxc-start 135 20201118153333.927 INFO start - start.c:lxc_spawn:1657 - Cloned CLONE_NEWUTS lxc-start 135 20201118153333.927 INFO start - start.c:lxc_spawn:1657 - Cloned CLONE_NEWIPC lxc-start 135 20201118153333.927 DEBUG start - start.c:lxc_try_preserve_namespaces:166 - Preserved user namespace via fd 55 lxc-start 135 20201118153333.927 DEBUG start - start.c:lxc_try_preserve_namespaces:166 - Preserved mnt namespace via fd 56 lxc-start 135 20201118153333.927 DEBUG start - start.c:lxc_try_preserve_namespaces:166 - Preserved pid namespace via fd 57 lxc-start 135 20201118153333.927 DEBUG start - start.c:lxc_try_preserve_namespaces:166 - Preserved uts namespace via fd 58 lxc-start 135 20201118153333.927 DEBUG start - start.c:lxc_try_preserve_namespaces:166 - Preserved ipc namespace via fd 59 lxc-start 135 20201118153333.927 DEBUG conf - conf.c:idmaptool_on_path_and_privileged:2679 - The binary "/usr/bin/newuidmap" does have the setuid bit set lxc-start 135 20201118153333.927 DEBUG conf - conf.c:idmaptool_on_path_and_privileged:2679 - The binary "/usr/bin/newgidmap" does have the setuid bit set lxc-start 135 20201118153333.927 DEBUG conf - conf.c:lxc_map_ids:2747 - Functional newuidmap and newgidmap binary found lxc-start 135 20201118153333.930 INFO start - start.c:do_start:1091 - Unshared CLONE_NEWNET lxc-start 135 20201118153333.930 DEBUG cgfsng - cgroups/cgfsng.c:cgfsng_setup_limits_legacy:2858 - Set controller "memory.limit_in_bytes" set to "4294967296" lxc-start 135 20201118153333.930 DEBUG cgfsng - cgroups/cgfsng.c:cgfsng_setup_limits_legacy:2858 - Set controller "memory.memsw.limit_in_bytes" set to "6442450944" lxc-start 135 20201118153333.930 DEBUG cgfsng - cgroups/cgfsng.c:cgfsng_setup_limits_legacy:2858 - Set controller "cpu.shares" set to "1024" lxc-start 135 20201118153333.931 DEBUG cgfsng - cgroups/cgfsng.c:cgfsng_setup_limits_legacy:2858 - Set controller "cpuset.cpus" set to "2-3,6" lxc-start 135 20201118153333.931 INFO cgfsng - cgroups/cgfsng.c:cgfsng_setup_limits_legacy:2863 - Limits for the legacy cgroup hierarchies have been setup lxc-start 135 20201118153333.931 DEBUG conf - conf.c:idmaptool_on_path_and_privileged:2679 - The binary "/usr/bin/newuidmap" does have the setuid bit set lxc-start 135 20201118153333.931 DEBUG conf - conf.c:idmaptool_on_path_and_privileged:2679 - The binary "/usr/bin/newgidmap" does have the setuid bit set lxc-start 135 20201118153333.931 DEBUG conf - conf.c:lxc_map_ids:2747 - Functional newuidmap and newgidmap binary found lxc-start 135 20201118153333.934 NOTICE utils - utils.c:lxc_setgroups:1366 - Dropped additional groups lxc-start 135 20201118153333.934 WARN cgfsng - cgroups/cgfsng.c:fchowmodat:1571 - No such file or directory - Failed to fchownat(29, memory.oom.group, 65536, 0, AT_EMPTY_PATH | AT_SYMLINK_NOFOLLOW ) lxc-start 135 20201118153333.934 DEBUG start - start.c:lxc_spawn:1730 - Preserved net namespace via fd 5 lxc-start 135 20201118153333.935 INFO conf - conf.c:run_script_argv:340 - Executing script "/usr/share/lxc/lxcnetaddbr" for container "135", config section "net" lxc-start 135 20201118153334.406 DEBUG network - network.c:instantiate_veth:449 - Instantiated veth tunnel "veth135i0 <--> vethpcz6Cs" lxc-start 135 20201118153334.406 NOTICE utils - utils.c:lxc_setgroups:1366 - Dropped additional groups lxc-start 135 20201118153334.406 NOTICE utils - utils.c:lxc_switch_uid_gid:1344 - Switched to gid 0 lxc-start 135 20201118153334.406 NOTICE utils - utils.c:lxc_switch_uid_gid:1353 - Switched to uid 0 lxc-start 135 20201118153334.406 INFO start - start.c:do_start:1204 - Unshared CLONE_NEWCGROUP lxc-start 135 20201118153334.407 DEBUG storage - storage/storage.c:storage_query:233 - Detected rootfs type "dir" lxc-start 135 20201118153334.407 DEBUG conf - conf.c:lxc_mount_rootfs:1260 - Mounted rootfs "/var/lib/lxc/135/rootfs" onto "/usr/lib/x86_64-linux-gnu/lxc/rootfs" with options "(null)" lxc-start 135 20201118153334.407 INFO conf - conf.c:setup_utsname:751 - Set hostname to "removed" lxc-start 135 20201118153334.434 DEBUG network - network.c:setup_hw_addr:3378 - Mac address "removed" on "eth0" has been setup lxc-start 135 20201118153334.434 DEBUG network - network.c:lxc_network_setup_in_child_namespaces_common:3528 - Network device "eth0" has been setup lxc-start 135 20201118153334.434 INFO network - network.c:lxc_setup_network_in_child_namespaces:3550 - Network has been setup lxc-start 135 20201118153334.434 INFO conf - conf.c:mount_autodev:1059 - Preparing "/dev" lxc-start 135 20201118153334.434 DEBUG conf - conf.c:mount_autodev:1065 - Using mount options: size=500000,mode=755 lxc-start 135 20201118153334.434 ERROR conf - conf.c:mount_autodev:1074 - Permission denied - Failed to create "/dev" directory lxc-start 135 20201118153334.434 INFO conf - conf.c:mount_autodev:1108 - Prepared "/dev" lxc-start 135 20201118153334.434 ERROR conf - conf.c:lxc_setup:3238 - Failed to mount "/dev" lxc-start 135 20201118153334.434 ERROR start - start.c:do_start:1224 - Failed to setup container "135" lxc-start 135 20201118153334.434 ERROR sync - sync.c:__sync_wait:41 - An error occurred in another process (expected sequence number 5) lxc-start 135 20201118153334.434 DEBUG network - network.c:lxc_delete_network:3683 - Deleted network devices lxc-start 135 20201118153334.434 ERROR start - start.c:__lxc_start:1950 - Failed to spawn container "135" lxc-start 135 20201118153334.434 WARN start - start.c:lxc_abort:1018 - No such process - Failed to send SIGKILL via pidfd 54 for process 21455 lxc-start 135 20201118153334.674 DEBUG conf - conf.c:idmaptool_on_path_and_privileged:2679 - The binary "/usr/bin/newuidmap" does have the setuid bit set lxc-start 135 20201118153334.674 DEBUG conf - conf.c:idmaptool_on_path_and_privileged:2679 - The binary "/usr/bin/newgidmap" does have the setuid bit set REMOVED

I already tried to mount / unmount the drives but nothing helped. I can also reproduce the behavior with a new ZFS pool ... I tried already 3 times.

I appreciate any help! Thank you in advance.

 

[fiona]

Hi,
I tried to reproduce this here and it seems like you have to mount the containers dataset(s) zfs1/encrypted_data/subvol-<ID>-disk-<N> too. Best to use zfs mount -al instead, then it mounts all datasets (although the non-encrypted ones should have already been mounted at boot).