[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