LXC not starting because permission denied?

Airw0lf

Active Member
Apr 11, 2021
83
5
28
it-visibility.net
Team,

See below the output of an attempt starting a LXC container with pct start 107 --debug.
Until a few days this container was starting and running as expected.

Anyone an idea what is happening? And how to fix this?

I have tried a search on this forum with the phrase:
ERROR start - ../src/lxc/start.c:start:2204 - Permission denied - Failed to exec "/sbin/init"

I hhave searched this forum and tried ChatGPT but didn't find any fixes - at least not recognized as such.

The link to systemd exists and has the right owner rights. And also the right read & execution flags set.

If fixing is not possible I could mount the container with pct mount 107 and copy the relevant config and data to a newly created LXC container (mounted in the same way). In an attempt re-create the original LXC.

Does this make sense? Any other suggestions?

Thank you - Will

=====

Code:
# pct start 107 --debug
sync_wait: 34 An error occurred in another process (expected sequence number 7)
__lxc_start: 2114 Failed to spawn container "107"
- ../src/lxc/confile.c:set_config_idmaps:2273 - Read uid map: type g nsid 0 hostid 100000 range 65536
INFO     lsm - ../src/lxc/lsm/lsm.c:lsm_init_static:38 - Initialized LSM security driver AppArmor
INFO     utils - ../src/lxc/utils.c:run_script_argv:587 - Executing script "/usr/share/lxc/hooks/lxc-pve-prestart-hook" for container "107", config section "lxc"
INFO     cgfsng - ../src/lxc/cgroups/cgfsng.c:unpriv_systemd_create_scope:1498 - Running privileged, not using a systemd unit
DEBUG    seccomp - ../src/lxc/seccomp.c:parse_config_v2:664 - Host native arch is [3221225534]
INFO     seccomp - ../src/lxc/seccomp.c:parse_config_v2:815 - Processing "reject_force_umount  # comment this to allow umount -f;  not recommended"
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:532 - Set seccomp rule to reject force umounts
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:532 - Set seccomp rule to reject force umounts
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:532 - Set seccomp rule to reject force umounts
INFO     seccomp - ../src/lxc/seccomp.c:parse_config_v2:815 - Processing "[all]"
INFO     seccomp - ../src/lxc/seccomp.c:parse_config_v2:815 - Processing "kexec_load errno 1"
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding native rule for syscall[246:kexec_load] action[327681:errno] arch[0]
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding compat rule for syscall[246:kexec_load] action[327681:errno] arch[1073741827]
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding compat rule for syscall[246:kexec_load] action[327681:errno] arch[1073741886]
INFO     seccomp - ../src/lxc/seccomp.c:parse_config_v2:815 - Processing "open_by_handle_at errno 1"
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding native rule for syscall[304:open_by_handle_at] action[327681:errno] arch[0]
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding compat rule for syscall[304:open_by_handle_at] action[327681:errno] arch[1073741827]
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding compat rule for syscall[304:open_by_handle_at] action[327681:errno] arch[1073741886]
INFO     seccomp - ../src/lxc/seccomp.c:parse_config_v2:815 - Processing "init_module errno 1"
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding native rule for syscall[175:init_module] action[327681:errno] arch[0]
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding compat rule for syscall[175:init_module] action[327681:errno] arch[1073741827]
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding compat rule for syscall[175:init_module] action[327681:errno] arch[1073741886]
INFO     seccomp - ../src/lxc/seccomp.c:parse_config_v2:815 - Processing "finit_module errno 1"
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding native rule for syscall[313:finit_module] action[327681:errno] arch[0]
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding compat rule for syscall[313:finit_module] action[327681:errno] arch[1073741827]
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding compat rule for syscall[313:finit_module] action[327681:errno] arch[1073741886]
INFO     seccomp - ../src/lxc/seccomp.c:parse_config_v2:815 - Processing "delete_module errno 1"
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding native rule for syscall[176:delete_module] action[327681:errno] arch[0]
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding compat rule for syscall[176:delete_module] action[327681:errno] arch[1073741827]
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding compat rule for syscall[176:delete_module] action[327681:errno] arch[1073741886]
INFO     seccomp - ../src/lxc/seccomp.c:parse_config_v2:815 - Processing "ioctl errno 1 [1,0x9400,SCMP_CMP_MASKED_EQ,0xff00]"
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:555 - arg_cmp[0]: SCMP_CMP(1, 7, 65280, 37888)
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding native rule for syscall[16:ioctl] action[327681:errno] arch[0]
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:555 - arg_cmp[0]: SCMP_CMP(1, 7, 65280, 37888)
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding compat rule for syscall[16:ioctl] action[327681:errno] arch[1073741827]
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:555 - arg_cmp[0]: SCMP_CMP(1, 7, 65280, 37888)
INFO     seccomp - ../src/lxc/seccomp.c:do_resolve_add_rule:572 - Adding compat rule for syscall[16:ioctl] action[327681:errno] arch[1073741886]
INFO     seccomp - ../src/lxc/seccomp.c:parse_config_v2:1036 - Merging compat seccomp contexts into main context
INFO     start - ../src/lxc/start.c:lxc_init:882 - Container "107" is initialized
INFO     cgfsng - ../src/lxc/cgroups/cgfsng.c:cgfsng_monitor_create:1669 - The monitor process uses "lxc.monitor/107" as cgroup
DEBUG    storage - ../src/lxc/storage/storage.c:storage_query:231 - Detected rootfs type "dir"
DEBUG    storage - ../src/lxc/storage/storage.c:storage_query:231 - Detected rootfs type "dir"
INFO     cgfsng - ../src/lxc/cgroups/cgfsng.c:cgfsng_payload_create:1777 - The container process uses "lxc/107/ns" as inner and "lxc/107" as limit cgroup
INFO     start - ../src/lxc/start.c:lxc_spawn:1769 - Cloned CLONE_NEWUSER
INFO     start - ../src/lxc/start.c:lxc_spawn:1769 - Cloned CLONE_NEWNS
INFO     start - ../src/lxc/start.c:lxc_spawn:1769 - Cloned CLONE_NEWPID
INFO     start - ../src/lxc/start.c:lxc_spawn:1769 - Cloned CLONE_NEWUTS
INFO     start - ../src/lxc/start.c:lxc_spawn:1769 - Cloned CLONE_NEWIPC
INFO     start - ../src/lxc/start.c:lxc_spawn:1769 - Cloned CLONE_NEWCGROUP
DEBUG    start - ../src/lxc/start.c:lxc_try_preserve_namespace:140 - Preserved user namespace via fd 17 and stashed path as user:/proc/50729/fd/17
DEBUG    start - ../src/lxc/start.c:lxc_try_preserve_namespace:140 - Preserved mnt namespace via fd 18 and stashed path as mnt:/proc/50729/fd/18
DEBUG    start - ../src/lxc/start.c:lxc_try_preserve_namespace:140 - Preserved pid namespace via fd 19 and stashed path as pid:/proc/50729/fd/19
DEBUG    start - ../src/lxc/start.c:lxc_try_preserve_namespace:140 - Preserved uts namespace via fd 20 and stashed path as uts:/proc/50729/fd/20
DEBUG    start - ../src/lxc/start.c:lxc_try_preserve_namespace:140 - Preserved ipc namespace via fd 21 and stashed path as ipc:/proc/50729/fd/21
DEBUG    start - ../src/lxc/start.c:lxc_try_preserve_namespace:140 - Preserved cgroup namespace via fd 22 and stashed path as cgroup:/proc/50729/fd/22
DEBUG    idmap_utils - ../src/lxc/idmap_utils.c:idmaptool_on_path_and_privileged:93 - The binary "/usr/bin/newuidmap" does have the setuid bit set
DEBUG    idmap_utils - ../src/lxc/idmap_utils.c:idmaptool_on_path_and_privileged:93 - The binary "/usr/bin/newgidmap" does have the setuid bit set
DEBUG    idmap_utils - ../src/lxc/idmap_utils.c:lxc_map_ids:178 - Functional newuidmap and newgidmap binary found
INFO     cgfsng - ../src/lxc/cgroups/cgfsng.c:cgfsng_setup_limits:3528 - Limits for the unified cgroup hierarchy have been setup
DEBUG    idmap_utils - ../src/lxc/idmap_utils.c:idmaptool_on_path_and_privileged:93 - The binary "/usr/bin/newuidmap" does have the setuid bit set
DEBUG    idmap_utils - ../src/lxc/idmap_utils.c:idmaptool_on_path_and_privileged:93 - The binary "/usr/bin/newgidmap" does have the setuid bit set
INFO     idmap_utils - ../src/lxc/idmap_utils.c:lxc_map_ids:176 - Caller maps host root. Writing mapping directly
NOTICE   utils - ../src/lxc/utils.c:lxc_drop_groups:1572 - Dropped supplimentary groups
INFO     start - ../src/lxc/start.c:do_start:1105 - Unshared CLONE_NEWNET
NOTICE   utils - ../src/lxc/utils.c:lxc_drop_groups:1572 - Dropped supplimentary groups
NOTICE   utils - ../src/lxc/utils.c:lxc_switch_uid_gid:1548 - Switched to gid 0
NOTICE   utils - ../src/lxc/utils.c:lxc_switch_uid_gid:1557 - Switched to uid 0
DEBUG    start - ../src/lxc/start.c:lxc_try_preserve_namespace:140 - Preserved net namespace via fd 5 and stashed path as net:/proc/50729/fd/5
INFO     utils - ../src/lxc/utils.c:run_script_argv:587 - Executing script "/usr/share/lxc/lxcnetaddbr" for container "107", config section "net"
DEBUG    network - ../src/lxc/network.c:netdev_configure_server_veth:876 - Instantiated veth tunnel "veth107i0 <--> vethF8hVIQ"
DEBUG    conf - ../src/lxc/conf.c:lxc_mount_rootfs:1240 - Mounted rootfs "/var/lib/lxc/107/rootfs" onto "/usr/lib/x86_64-linux-gnu/lxc/rootfs" with options "(null)"
INFO     conf - ../src/lxc/conf.c:setup_utsname:679 - Set hostname to "mouse-zie-notes"
DEBUG    network - ../src/lxc/network.c:setup_hw_addr:3863 - Mac address "BC:24:11:59:3F:7D" on "eth0" has been setup
DEBUG    network - ../src/lxc/network.c:lxc_network_setup_in_child_namespaces_common:4004 - Network device "eth0" has been setup
INFO     network - ../src/lxc/network.c:lxc_setup_network_in_child_namespaces:4061 - Finished setting up network devices with caller assigned names
INFO     conf - ../src/lxc/conf.c:mount_autodev:1023 - Preparing "/dev"
INFO     conf - ../src/lxc/conf.c:mount_autodev:1084 - Prepared "/dev"
DEBUG    conf - ../src/lxc/conf.c:lxc_mount_auto_mounts:539 - Invalid argument - Tried to ensure procfs is unmounted
DEBUG    conf - ../src/lxc/conf.c:lxc_mount_auto_mounts:562 - Invalid argument - Tried to ensure sysfs is unmounted
DEBUG    conf - ../src/lxc/conf.c:mount_entry:2219 - Remounting "/sys/fs/fuse/connections" on "/usr/lib/x86_64-linux-gnu/lxc/rootfs/sys/fs/fuse/connections" to respect bind or remount options
DEBUG    conf - ../src/lxc/conf.c:mount_entry:2238 - Flags for "/sys/fs/fuse/connections" were 4110, required extra flags are 14
DEBUG    conf - ../src/lxc/conf.c:mount_entry:2282 - Mounted "/sys/fs/fuse/connections" on "/usr/lib/x86_64-linux-gnu/lxc/rootfs/sys/fs/fuse/connections" with filesystem type "none"
DEBUG    conf - ../src/lxc/conf.c:mount_entry:2219 - Remounting "/dev/fuse" on "/usr/lib/x86_64-linux-gnu/lxc/rootfs/dev/fuse" to respect bind or remount options
DEBUG    conf - ../src/lxc/conf.c:mount_entry:2238 - Flags for "/dev/fuse" were 4098, required extra flags are 2
DEBUG    conf - ../src/lxc/conf.c:mount_entry:2282 - Mounted "/dev/fuse" on "/usr/lib/x86_64-linux-gnu/lxc/rootfs/dev/fuse" with filesystem type "none"
DEBUG    conf - ../src/lxc/conf.c:mount_entry:2282 - Mounted "proc" on "/usr/lib/x86_64-linux-gnu/lxc/rootfs/dev/.lxc/proc" with filesystem type "proc"
DEBUG    conf - ../src/lxc/conf.c:mount_entry:2282 - Mounted "sys" on "/usr/lib/x86_64-linux-gnu/lxc/rootfs/dev/.lxc/sys" with filesystem type "sysfs"
DEBUG    cgfsng - ../src/lxc/cgroups/cgfsng.c:__cgroupfs_mount:2187 - Mounted cgroup filesystem cgroup2 onto 19((null))
INFO     utils - ../src/lxc/utils.c:run_script_argv:587 - Executing script "/usr/share/lxcfs/lxc.mount.hook" for container "107", config section "lxc"
INFO     utils - ../src/lxc/utils.c:run_script_argv:587 - Executing script "/usr/share/lxc/hooks/lxc-pve-autodev-hook" for container "107", config section "lxc"
INFO     conf - ../src/lxc/conf.c:lxc_fill_autodev:1121 - Populating "/dev"
DEBUG    conf - ../src/lxc/conf.c:lxc_fill_autodev:1205 - Bind mounted host device 16(dev/full) to 18(full)
DEBUG    conf - ../src/lxc/conf.c:lxc_fill_autodev:1205 - Bind mounted host device 16(dev/null) to 18(null)
DEBUG    conf - ../src/lxc/conf.c:lxc_fill_autodev:1205 - Bind mounted host device 16(dev/random) to 18(random)
DEBUG    conf - ../src/lxc/conf.c:lxc_fill_autodev:1205 - Bind mounted host device 16(dev/tty) to 18(tty)
DEBUG    conf - ../src/lxc/conf.c:lxc_fill_autodev:1205 - Bind mounted host device 16(dev/urandom) to 18(urandom)
DEBUG    conf - ../src/lxc/conf.c:lxc_fill_autodev:1205 - Bind mounted host device 16(dev/zero) to 18(zero)
INFO     conf - ../src/lxc/conf.c:lxc_fill_autodev:1209 - Populated "/dev"
INFO     conf - ../src/lxc/conf.c:lxc_transient_proc:3307 - Caller's PID is 1; /proc/self points to 1
DEBUG    conf - ../src/lxc/conf.c:lxc_setup_devpts_child:1554 - Attached detached devpts mount 20 to 18/pts
DEBUG    conf - ../src/lxc/conf.c:lxc_setup_devpts_child:1640 - Created "/dev/ptmx" file as bind mount target
DEBUG    conf - ../src/lxc/conf.c:lxc_setup_devpts_child:1647 - Bind mounted "/dev/pts/ptmx" to "/dev/ptmx"
DEBUG    conf - ../src/lxc/conf.c:lxc_allocate_ttys:908 - Created tty with ptx fd 22 and pty fd 23 and index 1
DEBUG    conf - ../src/lxc/conf.c:lxc_allocate_ttys:908 - Created tty with ptx fd 24 and pty fd 25 and index 2
INFO     conf - ../src/lxc/conf.c:lxc_allocate_ttys:913 - Finished creating 2 tty devices
DEBUG    conf - ../src/lxc/conf.c:lxc_setup_ttys:869 - Bind mounted "pts/1" onto "tty1"
DEBUG    conf - ../src/lxc/conf.c:lxc_setup_ttys:869 - Bind mounted "pts/2" onto "tty2"
INFO     conf - ../src/lxc/conf.c:lxc_setup_ttys:876 - Finished setting up 2 /dev/tty<N> device(s)
INFO     conf - ../src/lxc/conf.c:setup_personality:1720 - Set personality to "0lx0"
DEBUG    conf - ../src/lxc/conf.c:capabilities_deny:3006 - Capabilities have been setup
NOTICE   conf - ../src/lxc/conf.c:lxc_setup:4014 - The container "107" is set up
INFO     apparmor - ../src/lxc/lsm/apparmor.c:apparmor_process_label_set_at:1189 - Set AppArmor label to "lxc-107_</var/lib/lxc>//&:lxc-107_<-var-lib-lxc>:"
INFO     apparmor - ../src/lxc/lsm/apparmor.c:apparmor_process_label_set:1234 - Changed AppArmor profile to lxc-107_</var/lib/lxc>//&:lxc-107_<-var-lib-lxc>:
DEBUG    terminal - ../src/lxc/terminal.c:lxc_terminal_peer_default:709 - No such device - The process does not have a controlling terminal
NOTICE   start - ../src/lxc/start.c:start:2201 - Exec'ing "/sbin/init"
ERROR    start - ../src/lxc/start.c:start:2204 - Permission denied - Failed to exec "/sbin/init"
ERROR    sync - ../src/lxc/sync.c:sync_wait:34 - An error occurred in another process (expected sequence number 7)
INFO     network - ../src/lxc/network.c:lxc_delete_network_priv:3720 - Removed interface "veth107i0" from ""
DEBUG    network - ../src/lxc/network.c:lxc_delete_network:4217 - Deleted network devices
ERROR    start - ../src/lxc/start.c:__lxc_start:2114 - Failed to spawn container "107"
WARN     start - ../src/lxc/start.c:lxc_abort:1037 - No such process - Failed to send SIGKILL via pidfd 16 for process 50761
startup for container '107' failed
 
Last edited:
Could you please post the container config. It can be obtained with pct config 107
 
  • Like
Reactions: Airw0lf
Could you please post the container config. It can be obtained with pct config 107

Thank you for having a look at this

See below: this is the current config.

Code:
root@vigilant:/home/will# pct config 107
arch: amd64
cores: 2
description: wmo - 2025jan12%3A de nieuwe mouse - klaar om in gebruik te nemen.%0Awmo - 2025jan29%3A alle gegevens gecopieerd en Synology uitgezet.%0Awmo - 2025feb7%3A andere inzichten door complexiteit omv met (Docker) containers%0A%0Amp0 - nas-volume - voor alle nas-achtige opslag waaronder smb en nextcloud%0A
features: fuse=1,keyctl=1,nesting=1
hostname: mouse
memory: 4096
mp0: usb-bu:107/vm-107-disk-0.raw,mp=/mnt/nas-volume,size=14500G
nameserver: 127.0.0.53
net0: name=eth0,bridge=vmbr0,hwaddr=BC:24:11:59:3F:7D,ip=dhcp,type=veth
onboot: 0
ostype: debian
rootfs: all-PVE-volumes:vm-107-disk-0,mountoptions=lazytime,size=100G
searchdomain: tech.lan
startup: order=9
swap: 4096
unprivileged: 1
root@vigilant:/home/will#
 
Last edited:
I don't know exactly what is wrong, but just a stab in the dark:

Have you tried to start that LXC without that usb-bu mountpoint?


Is there a special reason you are applying the lazytime option?

No - never tried that. How would that make a difference?
I have serveral lxc containers with and without such mountpoints.
All others are working as expected.

The lazytime option prevents immediate update of timestamps when accessing files.
And therefor reduces I/O overhead and ssd wearout.
 
I know what mountoptions=lazytime does, my question was whether you had suffered some I/O issue/latency etc. & that is why you added it.

No - never tried that. How would that make a difference?
My thinking - it would appear you have a permissions issue, the first attempt would be to isolate the exact data causing it (for testing). I don't know what that defined storage (backend) that usb-bu is - but something tells me it is external.

Trying can't harm.
 
I know what mountoptions=lazytime does, my question was whether you had suffered some I/O issue/latency etc. & that is why you added it.


My thinking - it would appear you have a permissions issue, the first attempt would be to isolate the exact data causing it (for testing). I don't know what that defined storage (backend) that usb-bu is - but something tells me it is external.

Trying can't harm.

The option lazytime is more like a pro-active measure for minimizing io latency and ssd wearout. I don't have any I/O issues.

The premission error points to a folder in the boot volume (i.e. rootfs).
I can mount the container and have access to all folders and files for rootfs and mp0.

Testing without mp0 shows the same result.

I'm tuning the PVE setup to maximize performance and predictability. Meaning no lvm-thin, snapshots, etc - if the setup as a whole needs 2-TBytes, the used storage should show 2-TBytes - even if not really used.

The mp0 called usb-bu is a temp situation (referencing an external usb disk). This is done for the migration from lvn-thin to lvm of the real data volume. Using this external usb allowed me te free the data volume for changing it from lvm-thin to lvm.

Does this make sense? Any (other) suggestion?
 
Last edited: