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

Alexandre DERUMIER aderumier at odiso.com
Mon Mar 11 20:17:27 CET 2019


>>hm - could be related to multicast mac-addresses? - see [0] 
>>the first octet of the prefix AF has the least-significant bit set and 
>>if I read [1] correctly this implies multicast mac-addresses. 


It seem that it don't work, with I have a "F" in second character

don't work with "1F:...", "CF:...", "4F:.....", ...

Need to read the mac address rfc ;)



>>But definitely an issue that is hard to find/unexpected (I had luck 
>>in choosing the correct logline to search for). 

yes ;)


>>We could consider checking for this when the prefix is set in 
>>datacenter.cfg?

At least, test it and throw an explicit error at lxc start.


----- Mail original -----
De: "Stoiko Ivanov" <s.ivanov at proxmox.com>
À: "aderumier" <aderumier at odiso.com>
Cc: "pve-devel" <pve-devel at pve.proxmox.com>
Envoyé: Lundi 11 Mars 2019 20:02:24
Objet: Re: [pve-devel] proxmox training week : error starting lxc with network interface

Hi, 

hm - could be related to multicast mac-addresses? - see [0] 
the first octet of the prefix AF has the least-significant bit set and 
if I read [1] correctly this implies multicast mac-addresses. 

But definitely an issue that is hard to find/unexpected (I had luck 
in choosing the correct logline to search for). 

We could consider checking for this when the prefix is set in 
datacenter.cfg? 

Thanks for reporting! 

[0]https://lists.linuxcontainers.org/pipermail/lxc-users/2010-August/000783.html 
[1]https://en.wikipedia.org/wiki/MAC_address 

On Mon, 11 Mar 2019 19:18:41 +0100 (CET) Alexandre DERUMIER 
<aderumier at odiso.com> wrote: 

> Ok found the problem, 
> 
> I had setup a mac address prefix in datacenter: 
> 
> AF:BB 
> 
> and it seem to not work with lxc (qemu is fine) 
> 
> 
> 
> ----- Mail original ----- 
> De: "aderumier" <aderumier at odiso.com> 
> À: "pve-devel" <pve-devel at pve.proxmox.com> 
> Envoyé: Lundi 11 Mars 2019 17:36:03 
> Objet: [pve-devel] proxmox training week : error starting lxc with 
> network interface 
> 
> 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 ? 
> 
> _______________________________________________ 
> pve-devel mailing list 
> pve-devel at pve.proxmox.com 
> https://pve.proxmox.com/cgi-bin/mailman/listinfo/pve-devel 
> 
> _______________________________________________ 
> pve-devel mailing list 
> pve-devel at pve.proxmox.com 
> https://pve.proxmox.com/cgi-bin/mailman/listinfo/pve-devel 



More information about the pve-devel mailing list