5.4-3 Can't start Containter: Failed to mount rootfs

Jan 21, 2016
83
7
28
41
Germany
www.pug.org
hi,

I have a cluster with and I have a container, which does not start on a 5.4. node:

Code:
lxc-start: 133: conf.c: lxc_mount_rootfs: 1343 Failed to mount rootfs "/var/lib/lxc/133/rootfs" onto "/usr/lib/x86_64-linux-gnu/lxc/rootfs" with options "(null)"

On a host with PVE 5.3 the same container starts, without problems. The container OS is a Debian Stretch.

Code:
# pct mount 133
mounted CT 133 in '/var/lib/lxc/133/rootfs'
root@node-04:[~]: ls /var/lib/lxc/133/rootfs
bin  boot  dev    etc  fastboot  home  lib  lib64  media    mnt  nonexistent  opt  proc  root  run    sbin  srv  sys    tmp  usr  var

works, also the unmount. FS is ZFS. Also other container works too.

I have no idea, what the problem could be.

Update:

I migrated the container to other node, also with pve 5.4-3 and I was able to start the container. So, question is, why I can't start it on the other node ...
 
Last edited:
Jan 21, 2016
83
7
28
41
Germany
www.pug.org
hi,

Code:
# pveversion -v
proxmox-ve: 5.4-1 (running kernel: 4.15.18-12-pve)
pve-manager: 5.4-3 (running version: 5.4-3/0a6eaa62)
pve-kernel-4.15: 5.3-3
pve-kernel-4.15.18-12-pve: 4.15.18-35
pve-kernel-4.15.18-11-pve: 4.15.18-34
pve-kernel-4.15.18-10-pve: 4.15.18-32
pve-kernel-4.15.18-9-pve: 4.15.18-30
corosync: 2.4.4-pve1
criu: 2.11.1-1~bpo90
glusterfs-client: 3.8.8-1
ksm-control-daemon: 1.2-2
libjs-extjs: 6.0.1-2
libpve-access-control: 5.1-8
libpve-apiclient-perl: 2.0-5
libpve-common-perl: 5.0-50
libpve-guest-common-perl: 2.0-20
libpve-http-server-perl: 2.0-13
libpve-storage-perl: 5.0-41
libqb0: 1.0.3-1~bpo9
lvm2: 2.02.168-pve6
lxc-pve: 3.1.0-3
lxcfs: 3.0.3-pve1
novnc-pve: 1.0.0-3
proxmox-widget-toolkit: 1.0-25
pve-cluster: 5.0-36
pve-container: 2.0-37
pve-docs: 5.4-2
pve-edk2-firmware: 1.20190312-1
pve-firewall: 3.0-19
pve-firmware: 2.0-6
pve-ha-manager: 2.0-9
pve-i18n: 1.1-4
pve-libspice-server1: 0.14.1-2
pve-qemu-kvm: 2.12.1-3
pve-xtermjs: 3.12.0-1
qemu-server: 5.0-50
smartmontools: 6.5+svn4324-1
spiceterm: 3.0-5
vncterm: 1.5-3
zfsutils-linux: 0.7.13-pve1~bpo2

Code:
# pct config  133
arch: amd64
cores: 2
cpulimit: 1
cpuunits: 1024
hostname: fra-corp-proxy-02
memory: 2048
nameserver: 192.168.1.25
net0: name=eth0,bridge=vmbr100,gw=192.168.1.100,hwaddr=:EE:AA:BB:CC:DD,ip=192.168.1.2/24,type=veth
ostype: debian
rootfs: pve-container:subvol-133-disk-0,size=8G
searchdomain: netz.local
swap: 512
unprivileged: 1


I replaced the MAC ...

I've an older debug log, before I moved to the other node:

Code:
lxc-start 133 20190429140928.857 INFO     confile - confile.c:set_config_idmaps:1673 - Read uid map: type u nsid 0 hostid 100000 range 65536
lxc-start 133 20190429140928.857 INFO     confile - confile.c:set_config_idmaps:1673 - Read uid map: type g nsid 0 hostid 100000 range 65536
lxc-start 133 20190429140928.858 INFO     lsm - lsm/lsm.c:lsm_init:50 - LSM security driver AppArmor
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "reject_force_umount  # comment this to allow umount -f;  not recommended"
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:do_resolve_add_rule:505 - Set seccomp rule to reject force umounts
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:937 - Added native rule for arch 0 for reject_force_umount action 0(kill)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:do_resolve_add_rule:505 - Set seccomp rule to reject force umounts
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for reject_force_umount action 0(kill)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:do_resolve_add_rule:505 - Set seccomp rule to reject force umounts
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for reject_force_umount action 0(kill)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:do_resolve_add_rule:505 - Set seccomp rule to reject force umounts
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for reject_force_umount action 0(kill)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "[all]"
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "kexec_load errno 1"
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:937 - Added native rule for arch 0 for kexec_load action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for kexec_load action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for kexec_load action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for kexec_load action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "open_by_handle_at errno 1"
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:937 - Added native rule for arch 0 for open_by_handle_at action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for open_by_handle_at action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for open_by_handle_at action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for open_by_handle_at action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "init_module errno 1"
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:937 - Added native rule for arch 0 for init_module action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for init_module action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for init_module action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for init_module action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "finit_module errno 1"
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:937 - Added native rule for arch 0 for finit_module action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for finit_module action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for finit_module action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for finit_module action 327681(errno)
lxc-start 133 20190429140928.858 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "delete_module errno 1"
lxc-start 133 20190429140928.859 INFO     seccomp - seccomp.c:parse_config_v2:937 - Added native rule for arch 0 for delete_module action 327681(errno)
lxc-start 133 20190429140928.859 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for delete_module action 327681(errno)
lxc-start 133 20190429140928.859 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for delete_module action 327681(errno)
lxc-start 133 20190429140928.859 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for delete_module action 327681(errno)
lxc-start 133 20190429140928.859 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "keyctl errno 38"
lxc-start 133 20190429140928.859 INFO     seccomp - seccomp.c:parse_config_v2:937 - Added native rule for arch 0 for keyctl action 327718(errno)
lxc-start 133 20190429140928.859 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for keyctl action 327718(errno)
lxc-start 133 20190429140928.859 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for keyctl action 327718(errno)
lxc-start 133 20190429140928.859 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for keyctl action 327718(errno)
lxc-start 133 20190429140928.859 INFO     seccomp - seccomp.c:parse_config_v2:970 - Merging compat seccomp contexts into main context
lxc-start 133 20190429140928.859 INFO     conf - conf.c:run_script_argv:356 - Executing script "/usr/share/lxc/hooks/lxc-pve-prestart-hook" for container "133", config section "lxc"
lxc-start 133 20190429140929.548 DEBUG    terminal - terminal.c:lxc_terminal_peer_default:714 - Using terminal "/dev/tty" as proxy
lxc-start 133 20190429140929.549 DEBUG    terminal - terminal.c:lxc_terminal_signal_init:192 - Created signal fd 9
lxc-start 133 20190429140929.549 DEBUG    terminal - terminal.c:lxc_terminal_winsz:90 - Set window size to 238 columns and 65 rows
lxc-start 133 20190429140929.666 INFO     start - start.c:lxc_init:906 - Container "133" is initialized
lxc-start 133 20190429140929.667 DEBUG    storage - storage/storage.c:storage_query:253 - Detected rootfs type "dir"
lxc-start 133 20190429140929.668 INFO     conf - conf.c:run_script:495 - Executing script "/usr/share/lxc/lxcnetaddbr" for container "133", config section "net"
lxc-start 133 20190429140930.292 DEBUG    network - network.c:instantiate_veth:206 - Instantiated veth "veth133i0/vethWVO1KC", index is "50"
lxc-start 133 20190429140930.293 DEBUG    cgfsng - cgroups/cgfsng.c:cg_legacy_handle_cpuset_hierarchy:619 - "cgroup.clone_children" was already set to "1"
lxc-start 133 20190429140930.293 INFO     cgfsng - cgroups/cgfsng.c:cgfsng_payload_create:1537 - The container uses "lxc/133" as cgroup
lxc-start 133 20190429140930.293 INFO     start - start.c:lxc_spawn:1707 - Cloned CLONE_NEWUSER
lxc-start 133 20190429140930.293 INFO     start - start.c:lxc_spawn:1707 - Cloned CLONE_NEWNS
lxc-start 133 20190429140930.293 INFO     start - start.c:lxc_spawn:1707 - Cloned CLONE_NEWPID
lxc-start 133 20190429140930.293 INFO     start - start.c:lxc_spawn:1707 - Cloned CLONE_NEWUTS
lxc-start 133 20190429140930.293 INFO     start - start.c:lxc_spawn:1707 - Cloned CLONE_NEWIPC
lxc-start 133 20190429140930.293 DEBUG    start - start.c:lxc_try_preserve_namespaces:196 - Preserved user namespace via fd 14
lxc-start 133 20190429140930.293 DEBUG    start - start.c:lxc_try_preserve_namespaces:196 - Preserved mnt namespace via fd 15
lxc-start 133 20190429140930.293 DEBUG    start - start.c:lxc_try_preserve_namespaces:196 - Preserved pid namespace via fd 16
lxc-start 133 20190429140930.293 DEBUG    start - start.c:lxc_try_preserve_namespaces:196 - Preserved uts namespace via fd 17
lxc-start 133 20190429140930.294 DEBUG    start - start.c:lxc_try_preserve_namespaces:196 - Preserved ipc namespace via fd 18
lxc-start 133 20190429140930.294 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newuidmap" does have the setuid bit set
lxc-start 133 20190429140930.294 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newgidmap" does have the setuid bit set
lxc-start 133 20190429140930.294 DEBUG    conf - conf.c:lxc_map_ids:2982 - Functional newuidmap and newgidmap binary found
lxc-start 133 20190429140930.301 INFO     start - start.c:do_start:1152 - Unshared CLONE_NEWNET
lxc-start 133 20190429140930.301 DEBUG    cgfsng - cgroups/cgfsng.c:__cg_legacy_setup_limits:2476 - Set controller "memory.limit_in_bytes" set to "2147483648"
lxc-start 133 20190429140930.301 DEBUG    cgfsng - cgroups/cgfsng.c:__cg_legacy_setup_limits:2476 - Set controller "memory.memsw.limit_in_bytes" set to "2684354560"
lxc-start 133 20190429140930.301 DEBUG    cgfsng - cgroups/cgfsng.c:__cg_legacy_setup_limits:2476 - Set controller "cpu.shares" set to "1024"
lxc-start 133 20190429140930.301 DEBUG    cgfsng - cgroups/cgfsng.c:__cg_legacy_setup_limits:2476 - Set controller "cpuset.cpus" set to "13,21"
lxc-start 133 20190429140930.301 INFO     cgfsng - cgroups/cgfsng.c:__cg_legacy_setup_limits:2481 - Limits for the legacy cgroup hierarchies have been setup
lxc-start 133 20190429140930.302 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newuidmap" does have the setuid bit set
lxc-start 133 20190429140930.302 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newgidmap" does have the setuid bit set
lxc-start 133 20190429140930.302 DEBUG    conf - conf.c:lxc_map_ids:2982 - Functional newuidmap and newgidmap binary found
lxc-start 133 20190429140930.309 DEBUG    start - start.c:lxc_spawn:1761 - Preserved net namespace via fd 10
lxc-start 133 20190429140930.336 DEBUG    network - network.c:lxc_network_move_created_netdev_priv:2505 - Moved network device "vethWVO1KC"/"eth0" to network namespace of 9697
lxc-start 133 20190429140930.336 NOTICE   utils - utils.c:lxc_switch_uid_gid:1386 - Switched to gid 0
lxc-start 133 20190429140930.336 NOTICE   utils - utils.c:lxc_switch_uid_gid:1395 - Switched to uid 0
lxc-start 133 20190429140930.336 NOTICE   utils - utils.c:lxc_setgroups:1408 - Dropped additional groups
lxc-start 133 20190429140930.336 INFO     cgfsng - cgroups/cgfsng.c:__cg_legacy_setup_limits:2481 - Limits for the legacy cgroup hierarchies have been setup
lxc-start 133 20190429140930.337 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newuidmap" does have the setuid bit set
lxc-start 133 20190429140930.337 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newgidmap" does have the setuid bit set
lxc-start 133 20190429140930.337 DEBUG    conf - conf.c:lxc_map_ids:2982 - Functional newuidmap and newgidmap binary found
lxc-start 133 20190429140930.344 INFO     start - start.c:do_start:1258 - Unshared CLONE_NEWCGROUP
lxc-start 133 20190429140930.357 ERROR    conf - conf.c:lxc_mount_rootfs:1343 - Failed to mount rootfs "/var/lib/lxc/133/rootfs" onto "/usr/lib/x86_64-linux-gnu/lxc/rootfs" with options "(null)"
lxc-start 133 20190429140930.357 ERROR    conf - conf.c:lxc_setup_rootfs_prepare_root:3499 - Failed to setup rootfs for
lxc-start 133 20190429140930.357 ERROR    conf - conf.c:lxc_setup:3552 - Failed to setup rootfs
lxc-start 133 20190429140930.358 ERROR    start - start.c:do_start:1279 - Failed to setup container "133"
lxc-start 133 20190429140930.358 ERROR    sync - sync.c:__sync_wait:62 - An error occurred in another process (expected sequence number 5)
lxc-start 133 20190429140930.358 WARN     network - network.c:lxc_delete_network_priv:2594 - Operation not permitted - Failed to remove interface "eth0" with index 50
lxc-start 133 20190429140930.358 DEBUG    network - network.c:lxc_delete_network:3185 - Deleted network devices
lxc-start 133 20190429140930.358 ERROR    start - start.c:__lxc_start:1989 - Failed to spawn container "133"
lxc-start 133 20190429140930.469 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newuidmap" does have the setuid bit set
lxc-start 133 20190429140930.470 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newgidmap" does have the setuid bit set
lxc-start 133 20190429140930.470 DEBUG    conf - conf.c:lxc_map_ids:2982 - Functional newuidmap and newgidmap binary found
lxc-start 133 20190429140930.479 INFO     conf - conf.c:run_script_argv:356 - Executing script "/usr/share/lxc/hooks/lxc-pve-poststop-hook" for container "133", config section "lxc"
lxc-start 133 20190429140931.187 INFO     conf - conf.c:run_script_argv:356 - Executing script "/usr/share/lxcfs/lxc.reboot.hook" for container "133", config section "lxc"
lxc-start 133 20190429140931.736 ERROR    lxc_start - tools/lxc_start.c:main:330 - The container failed to start
lxc-start 133 20190429140931.736 ERROR    lxc_start - tools/lxc_start.c:main:336 - Additional information can be obtained by setting the --logfile and --logpriority options

I tried also to reboot the node to get rid of any cgroups in /sys ... and started the container, but without success.
 

oguz

Proxmox Retired Staff
Retired Staff
Nov 19, 2018
5,207
695
118
Hi,

so these are the relevant bits:

Code:
lxc-start 133 20190429140930.357 ERROR    conf - conf.c:lxc_mount_rootfs:1343 - Failed to mount rootfs "/var/lib/lxc/133/rootfs" onto "/usr/lib/x86_64-linux-gnu/lxc/rootfs" with options "(null)"
lxc-start 133 20190429140930.357 ERROR    conf - conf.c:lxc_setup_rootfs_prepare_root:3499 - Failed to setup rootfs for
lxc-start 133 20190429140930.357 ERROR    conf - conf.c:lxc_setup:3552 - Failed to setup rootfs
lxc-start 133 20190429140930.358 ERROR    start - start.c:do_start:1279 - Failed to setup container "133"

We've looked in the LXC code to figure out why this could be happening, but the error messages are not very verbose as you may see yourself. The problem occurs in function `lxc_setup_rootfs_prepare_root`, `lxc_mount_rootfs`, but we will need to adapt the error messages to be able to identify the root cause of the problem. Will update here when we find something.
 
  • Like
Reactions: Denny Fuchs

oguz

Proxmox Retired Staff
Retired Staff
Nov 19, 2018
5,207
695
118
hi,

are you still having this problem?
 

About

The Proxmox community has been around for many years and offers help and support for Proxmox VE, Proxmox Backup Server, and Proxmox Mail Gateway.
We think our community is one of the best thanks to people like you!

Get your subscription!

The Proxmox team works very hard to make sure you are running the best software and getting stable updates and security enhancements, as well as quick enterprise support. Tens of thousands of happy customers have a Proxmox subscription. Get your own in 60 seconds.

Buy now!