[pve-devel] proxmox training week : error starting lxc with network interface

Alexandre DERUMIER aderumier at odiso.com
Mon Mar 11 17:36:03 CET 2019


Hi,

We are doing some tests in this training week,

and I have a bug never seen before with lxc container, when a network interface is present in ct


root at kvmformation1:~# pveversion -v
proxmox-ve: 5.3-1 (running kernel: 4.15.18-11-pve)
pve-manager: 5.3-11 (running version: 5.3-11/d4907f84)
pve-kernel-4.15: 5.3-2
pve-kernel-4.15.18-11-pve: 4.15.18-34
pve-kernel-4.15.18-10-pve: 4.15.18-32
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-3
libpve-apiclient-perl: 2.0-5
libpve-common-perl: 5.0-47
libpve-guest-common-perl: 2.0-20
libpve-http-server-perl: 2.0-12
libpve-storage-perl: 5.0-38
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-23
pve-cluster: 5.0-33
pve-container: 2.0-34
pve-docs: 5.3-3
pve-edk2-firmware: 1.20181023-1
pve-firewall: 3.0-18
pve-firmware: 2.0-6
pve-ha-manager: 2.0-6
pve-i18n: 1.0-9
pve-libspice-server1: 0.14.1-2
pve-qemu-kvm: 2.12.1-2
pve-xtermjs: 3.10.1-2
qemu-server: 5.0-47
smartmontools: 6.5+svn4324-1
spiceterm: 3.0-5
vncterm: 1.5-3
zfsutils-linux: 0.7.12-pve1~bpo1


root at kvmformation1:~# cat /tmp/lxc-ID.log
lxc-start 106 20190311163245.796 INFO     confile - confile.c:set_config_idmaps:1673 - Read uid map: type u nsid 0 hostid 100000 range 65536
lxc-start 106 20190311163245.796 INFO     confile - confile.c:set_config_idmaps:1673 - Read uid map: type g nsid 0 hostid 100000 range 65536
lxc-start 106 20190311163245.797 INFO     lsm - lsm/lsm.c:lsm_init:50 - LSM security driver AppArmor
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "reject_force_umount  # comment this to allow umount -f;  not recommended"
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:do_resolve_add_rule:505 - Set seccomp rule to reject force umounts
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:937 - Added native rule for arch 0 for reject_force_umount action 0(kill)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:do_resolve_add_rule:505 - Set seccomp rule to reject force umounts
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for reject_force_umount action 0(kill)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:do_resolve_add_rule:505 - Set seccomp rule to reject force umounts
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for reject_force_umount action 0(kill)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:do_resolve_add_rule:505 - Set seccomp rule to reject force umounts
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for reject_force_umount action 0(kill)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "[all]"
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "kexec_load errno 1"
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:937 - Added native rule for arch 0 for kexec_load action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for kexec_load action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for kexec_load action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for kexec_load action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "open_by_handle_at errno 1"
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:937 - Added native rule for arch 0 for open_by_handle_at action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for open_by_handle_at action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for open_by_handle_at action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for open_by_handle_at action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "init_module errno 1"
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:937 - Added native rule for arch 0 for init_module action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for init_module action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for init_module action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for init_module action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "finit_module errno 1"
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:937 - Added native rule for arch 0 for finit_module action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for finit_module action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for finit_module action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for finit_module action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "delete_module errno 1"
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:937 - Added native rule for arch 0 for delete_module action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for delete_module action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for delete_module action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for delete_module action 327681(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "keyctl errno 38"
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:937 - Added native rule for arch 0 for keyctl action 327718(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for keyctl action 327718(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for keyctl action 327718(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for keyctl action 327718(errno)
lxc-start 106 20190311163245.797 INFO     seccomp - seccomp.c:parse_config_v2:970 - Merging compat seccomp contexts into main context
lxc-start 106 20190311163245.797 INFO     conf - conf.c:run_script_argv:356 - Executing script "/usr/share/lxc/hooks/lxc-pve-prestart-hook" for container "106", config section "lxc"
lxc-start 106 20190311163246.749 DEBUG    terminal - terminal.c:lxc_terminal_peer_default:714 - Using terminal "/dev/tty" as proxy
lxc-start 106 20190311163246.749 DEBUG    terminal - terminal.c:lxc_terminal_signal_init:192 - Created signal fd 9
lxc-start 106 20190311163246.749 DEBUG    terminal - terminal.c:lxc_terminal_winsz:90 - Set window size to 136 columns and 35 rows
lxc-start 106 20190311163246.906 INFO     start - start.c:lxc_init:906 - Container "106" is initialized
lxc-start 106 20190311163246.906 DEBUG    storage - storage/storage.c:storage_query:253 - Detected rootfs type "dir"
lxc-start 106 20190311163246.908 INFO     conf - conf.c:run_script:495 - Executing script "/usr/share/lxc/lxcnetaddbr" for container "106", config section "net"
lxc-start 106 20190311163247.766 DEBUG    network - network.c:instantiate_veth:206 - Instantiated veth "veth106i0/vethEEIO1G", index is "21"
lxc-start 106 20190311163247.766 ERROR    cgfsng - cgroups/cgfsng.c:mkdir_eexist_on_last:1301 - File exists - Failed to create directory "/sys/fs/cgroup/systemd//lxc/106"
lxc-start 106 20190311163247.766 ERROR    cgfsng - cgroups/cgfsng.c:container_create_path_for_hierarchy:1353 - Failed to create cgroup "/sys/fs/cgroup/systemd//lxc/106"
lxc-start 106 20190311163247.766 ERROR    cgfsng - cgroups/cgfsng.c:cgfsng_payload_create:1526 - Failed to create cgroup "/sys/fs/cgroup/systemd//lxc/106"
lxc-start 106 20190311163247.766 ERROR    cgfsng - cgroups/cgfsng.c:mkdir_eexist_on_last:1301 - File exists - Failed to create directory "/sys/fs/cgroup/systemd//lxc/106-1"
lxc-start 106 20190311163247.766 ERROR    cgfsng - cgroups/cgfsng.c:container_create_path_for_hierarchy:1353 - Failed to create cgroup "/sys/fs/cgroup/systemd//lxc/106-1"
lxc-start 106 20190311163247.766 ERROR    cgfsng - cgroups/cgfsng.c:cgfsng_payload_create:1526 - Failed to create cgroup "/sys/fs/cgroup/systemd//lxc/106-1"
lxc-start 106 20190311163247.767 DEBUG    cgfsng - cgroups/cgfsng.c:cg_legacy_handle_cpuset_hierarchy:619 - "cgroup.clone_children" was already set to "1"
lxc-start 106 20190311163247.767 INFO     cgfsng - cgroups/cgfsng.c:cgfsng_payload_create:1537 - The container uses "lxc/106-2" as cgroup
lxc-start 106 20190311163247.768 INFO     start - start.c:lxc_spawn:1707 - Cloned CLONE_NEWUSER
lxc-start 106 20190311163247.768 INFO     start - start.c:lxc_spawn:1707 - Cloned CLONE_NEWNS
lxc-start 106 20190311163247.768 INFO     start - start.c:lxc_spawn:1707 - Cloned CLONE_NEWPID
lxc-start 106 20190311163247.768 INFO     start - start.c:lxc_spawn:1707 - Cloned CLONE_NEWUTS
lxc-start 106 20190311163247.768 INFO     start - start.c:lxc_spawn:1707 - Cloned CLONE_NEWIPC
lxc-start 106 20190311163247.768 DEBUG    start - start.c:lxc_try_preserve_namespaces:196 - Preserved user namespace via fd 14
lxc-start 106 20190311163247.768 DEBUG    start - start.c:lxc_try_preserve_namespaces:196 - Preserved mnt namespace via fd 15
lxc-start 106 20190311163247.768 DEBUG    start - start.c:lxc_try_preserve_namespaces:196 - Preserved pid namespace via fd 16
lxc-start 106 20190311163247.768 DEBUG    start - start.c:lxc_try_preserve_namespaces:196 - Preserved uts namespace via fd 17
lxc-start 106 20190311163247.768 DEBUG    start - start.c:lxc_try_preserve_namespaces:196 - Preserved ipc namespace via fd 18
lxc-start 106 20190311163247.768 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newuidmap" does have the setuid bit set
lxc-start 106 20190311163247.768 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newgidmap" does have the setuid bit set
lxc-start 106 20190311163247.768 DEBUG    conf - conf.c:lxc_map_ids:2982 - Functional newuidmap and newgidmap binary found
lxc-start 106 20190311163247.776 INFO     start - start.c:do_start:1152 - Unshared CLONE_NEWNET
lxc-start 106 20190311163247.776 DEBUG    cgfsng - cgroups/cgfsng.c:__cg_legacy_setup_limits:2476 - Set controller "memory.limit_in_bytes" set to "2147483648"
lxc-start 106 20190311163247.776 DEBUG    cgfsng - cgroups/cgfsng.c:__cg_legacy_setup_limits:2476 - Set controller "memory.memsw.limit_in_bytes" set to "2684354560"
lxc-start 106 20190311163247.776 DEBUG    cgfsng - cgroups/cgfsng.c:__cg_legacy_setup_limits:2476 - Set controller "cpu.shares" set to "1024"
lxc-start 106 20190311163247.776 DEBUG    cgfsng - cgroups/cgfsng.c:__cg_legacy_setup_limits:2476 - Set controller "cpuset.cpus" set to "1-2"
lxc-start 106 20190311163247.776 INFO     cgfsng - cgroups/cgfsng.c:__cg_legacy_setup_limits:2481 - Limits for the legacy cgroup hierarchies have been setup
lxc-start 106 20190311163247.777 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newuidmap" does have the setuid bit set
lxc-start 106 20190311163247.777 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newgidmap" does have the setuid bit set
lxc-start 106 20190311163247.777 DEBUG    conf - conf.c:lxc_map_ids:2982 - Functional newuidmap and newgidmap binary found
lxc-start 106 20190311163247.784 DEBUG    start - start.c:lxc_spawn:1761 - Preserved net namespace via fd 10
lxc-start 106 20190311163247.828 DEBUG    network - network.c:lxc_network_move_created_netdev_priv:2505 - Moved network device "vethEEIO1G"/"eth0" to network namespace of 7706
lxc-start 106 20190311163247.828 NOTICE   utils - utils.c:lxc_switch_uid_gid:1386 - Switched to gid 0
lxc-start 106 20190311163247.828 NOTICE   utils - utils.c:lxc_switch_uid_gid:1395 - Switched to uid 0
lxc-start 106 20190311163247.828 NOTICE   utils - utils.c:lxc_setgroups:1408 - Dropped additional groups
lxc-start 106 20190311163247.828 INFO     cgfsng - cgroups/cgfsng.c:__cg_legacy_setup_limits:2481 - Limits for the legacy cgroup hierarchies have been setup
lxc-start 106 20190311163247.830 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newuidmap" does have the setuid bit set
lxc-start 106 20190311163247.830 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newgidmap" does have the setuid bit set
lxc-start 106 20190311163247.830 DEBUG    conf - conf.c:lxc_map_ids:2982 - Functional newuidmap and newgidmap binary found
lxc-start 106 20190311163247.836 INFO     start - start.c:do_start:1258 - Unshared CLONE_NEWCGROUP
lxc-start 106 20190311163247.837 DEBUG    storage - storage/storage.c:storage_query:253 - Detected rootfs type "dir"
lxc-start 106 20190311163247.837 DEBUG    conf - conf.c:lxc_mount_rootfs:1358 - Mounted rootfs "/var/lib/lxc/106/rootfs" onto "/usr/lib/x86_64-linux-gnu/lxc/rootfs" with options "(null)"
lxc-start 106 20190311163247.837 INFO     conf - conf.c:setup_utsname:817 - Set hostname to "ctdebian"
lxc-start 106 20190311163247.872 ERROR    network - network.c:setup_hw_addr:2767 - Cannot assign requested address - Failed to perform ioctl
lxc-start 106 20190311163247.872 DEBUG    network - network.c:setup_hw_addr:2772 - Mac address "AF:BB:33:CD:A4:78" on "eth0" has been setup
lxc-start 106 20190311163247.872 ERROR    network - network.c:lxc_setup_netdev_in_child_namespaces:2912 - Failed to setup hw address for network device "eth0"
lxc-start 106 20190311163247.872 ERROR    network - network.c:lxc_setup_network_in_child_namespaces:3052 - failed to setup netdev
lxc-start 106 20190311163247.872 ERROR    conf - conf.c:lxc_setup:3570 - Failed to setup network
lxc-start 106 20190311163247.872 ERROR    start - start.c:do_start:1279 - Failed to setup container "106"
lxc-start 106 20190311163247.872 ERROR    sync - sync.c:__sync_wait:62 - An error occurred in another process (expected sequence number 5)
lxc-start 106 20190311163247.872 WARN     network - network.c:lxc_delete_network_priv:2594 - Operation not permitted - Failed to remove interface "eth0" with index 21
lxc-start 106 20190311163247.872 DEBUG    network - network.c:lxc_delete_network:3185 - Deleted network devices
lxc-start 106 20190311163247.872 ERROR    start - start.c:__lxc_start:1989 - Failed to spawn container "106"
lxc-start 106 20190311163248.288 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newuidmap" does have the setuid bit set
lxc-start 106 20190311163248.289 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2890 - The binary "/usr/bin/newgidmap" does have the setuid bit set
lxc-start 106 20190311163248.289 DEBUG    conf - conf.c:lxc_map_ids:2982 - Functional newuidmap and newgidmap binary found
lxc-start 106 20190311163248.382 INFO     conf - conf.c:run_script_argv:356 - Executing script "/usr/share/lxcfs/lxc.reboot.hook" for container "106", config section "lxc"
lxc-start 106 20190311163248.541 INFO     conf - conf.c:run_script_argv:356 - Executing script "/usr/share/lxc/hooks/lxc-pve-poststop-hook" for container "106", config section "lxc"
lxc-start 106 20190311163249.520 ERROR    lxc_start - tools/lxc_start.c:main:330 - The container failed to start
lxc-start 106 20190311163249.520 ERROR    lxc_start - tools/lxc_start.c:main:336 - Additional information can be obtained by setting the --logfile and --logpriority options




Any idea ?



More information about the pve-devel mailing list