Autostart of container during boot on debian buster not working

zerocool · January 21, 2020, 10:14pm

Hi everybody,

I used the Debian LXC information to setup LXC containers on Debian 10 buster. I could successfully generate unpriviledged container with root account, but failed to autostart those containers during boot.

I did the following steps on a clean virtual machine to install and run LXC:

LXC installation

root@test # apt-get update
root@test # apt-get install lxc libvirt0 libpam-cgfs bridge-utils libvirt-clients libvirt-daemon-system iptables ebtables dnsmasq-base

Default container configuration

root@test # nano /etc/lxc/default.conf
  lxc.net.0.type = veth
  lxc.net.0.link = virbr0
  lxc.net.0.flags = up

  # Apparmor configuration
  lxc.apparmor.profile = generated
  lxc.apparmor.allow_nesting = 1

  # automatically start containers on boot
  lxc.start.auto = 1

  # Subuids and subgids mapping
  lxc.idmap = u 0 100000 65536
  lxc.idmap = g 0 100000 65536

  # "Secure" mounting
  lxc.mount.auto = proc:mixed sys:ro cgroup:mixed

Prepare for unpriviledged root containers

root@test # nano /etc/subuid
  root:100000:65536
root@test # nano /etc/subgid
  root:100000:65536

Starting virtual network bridge

root@test # virsh net-start default
root@test # virsh net-autostart default

Create new unprivileded container

root@test # lxc-create -n debian -t download -- -d debian -r buster -a amd64

Start container and stop it after some time

root@test # lxc-start -n debian --logfile /tmp/debian.log --logpriority DEBUG
root@test # lxc-stop -n debian

/tmp/debian.log

lxc-start debian 20200121215234.710 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for finit_module action 327681(errno)
lxc-start debian 20200121215234.710 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for finit_module action 327681(errno)
lxc-start debian 20200121215234.710 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for finit_module action 327681(errno)
lxc-start debian 20200121215234.710 INFO     seccomp - seccomp.c:parse_config_v2:759 - Processing "delete_module errno 1"
lxc-start debian 20200121215234.710 INFO     seccomp - seccomp.c:parse_config_v2:937 - Added native rule for arch 0 for delete_module action 327681(errno)
lxc-start debian 20200121215234.710 INFO     seccomp - seccomp.c:parse_config_v2:946 - Added compat rule for arch 1073741827 for delete_module action 327681(errno)
lxc-start debian 20200121215234.710 INFO     seccomp - seccomp.c:parse_config_v2:956 - Added compat rule for arch 1073741886 for delete_module action 327681(errno)
lxc-start debian 20200121215234.710 INFO     seccomp - seccomp.c:parse_config_v2:966 - Added native rule for arch -1073741762 for delete_module action 327681(errno)
lxc-start debian 20200121215234.710 INFO     seccomp - seccomp.c:parse_config_v2:970 - Merging compat seccomp contexts into main context
lxc-start debian 20200121215234.710 DEBUG    terminal - terminal.c:lxc_terminal_peer_default:707 - No such device - The process does not have a controlling terminal
lxc-start debian 20200121215234.781 INFO     start - start.c:lxc_init:904 - Container "debian" is initialized
lxc-start debian 20200121215234.781 DEBUG    storage - storage/storage.c:get_storage_by_name:231 - Detected rootfs type "dir"
lxc-start debian 20200121215234.784 INFO     network - network.c:instantiate_veth:147 - Retrieved mtu 1500 from virbr0
lxc-start debian 20200121215234.785 INFO     network - network.c:instantiate_veth:175 - Attached "veth87MON3" to bridge "virbr0"
lxc-start debian 20200121215234.785 DEBUG    network - network.c:instantiate_veth:201 - Instantiated veth "veth87MON3/vethB94AAA", index is "9"
lxc-start debian 20200121215234.785 DEBUG    cgfsng - cgroups/cgfsng.c:cg_legacy_handle_cpuset_hierarchy:620 - "cgroup.clone_children" was already set to "1"
lxc-start debian 20200121215234.786 INFO     start - start.c:lxc_spawn:1700 - Cloned CLONE_NEWUSER
lxc-start debian 20200121215234.786 INFO     start - start.c:lxc_spawn:1700 - Cloned CLONE_NEWNS
lxc-start debian 20200121215234.786 INFO     start - start.c:lxc_spawn:1700 - Cloned CLONE_NEWPID
lxc-start debian 20200121215234.786 INFO     start - start.c:lxc_spawn:1700 - Cloned CLONE_NEWUTS
lxc-start debian 20200121215234.786 INFO     start - start.c:lxc_spawn:1700 - Cloned CLONE_NEWIPC
lxc-start debian 20200121215234.786 DEBUG    start - start.c:lxc_try_preserve_namespaces:196 - Preserved user namespace via fd 14
lxc-start debian 20200121215234.786 DEBUG    start - start.c:lxc_try_preserve_namespaces:196 - Preserved mnt namespace via fd 15
lxc-start debian 20200121215234.786 DEBUG    start - start.c:lxc_try_preserve_namespaces:196 - Preserved pid namespace via fd 16
lxc-start debian 20200121215234.786 DEBUG    start - start.c:lxc_try_preserve_namespaces:196 - Preserved uts namespace via fd 17
lxc-start debian 20200121215234.786 DEBUG    start - start.c:lxc_try_preserve_namespaces:196 - Preserved ipc namespace via fd 18
lxc-start debian 20200121215234.786 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2860 - The binary "/usr/bin/newuidmap" does have the setuid bit set
lxc-start debian 20200121215234.786 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2860 - The binary "/usr/bin/newgidmap" does have the setuid bit set
lxc-start debian 20200121215234.786 DEBUG    conf - conf.c:lxc_map_ids:2952 - Functional newuidmap and newgidmap binary found
lxc-start debian 20200121215234.803 INFO     start - start.c:do_start:1148 - Unshared CLONE_NEWNET
lxc-start debian 20200121215234.803 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2860 - The binary "/usr/bin/newuidmap" does have the setuid bit set
lxc-start debian 20200121215234.803 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2860 - The binary "/usr/bin/newgidmap" does have the setuid bit set
lxc-start debian 20200121215234.803 DEBUG    conf - conf.c:lxc_map_ids:2952 - Functional newuidmap and newgidmap binary found
lxc-start debian 20200121215234.810 DEBUG    start - start.c:lxc_spawn:1754 - Preserved net namespace via fd 10
lxc-start debian 20200121215234.818 DEBUG    network - network.c:lxc_network_move_created_netdev_priv:2500 - Moved network device "vethB94AAA"/"(null)" to network namespace of 808
lxc-start debian 20200121215234.818 NOTICE   utils - utils.c:lxc_switch_uid_gid:1378 - Switched to gid 0
lxc-start debian 20200121215234.818 NOTICE   utils - utils.c:lxc_switch_uid_gid:1387 - Switched to uid 0
lxc-start debian 20200121215234.818 NOTICE   utils - utils.c:lxc_setgroups:1400 - Dropped additional groups
lxc-start debian 20200121215234.818 INFO     start - start.c:do_start:1254 - Unshared CLONE_NEWCGROUP
lxc-start debian 20200121215234.818 DEBUG    storage - storage/storage.c:get_storage_by_name:231 - Detected rootfs type "dir"
lxc-start debian 20200121215234.818 DEBUG    conf - conf.c:lxc_mount_rootfs:1332 - Mounted rootfs "/var/lib/lxc/debian/rootfs" onto "/usr/lib/x86_64-linux-gnu/lxc/rootfs" with options "(null)"
lxc-start debian 20200121215234.818 INFO     conf - conf.c:setup_utsname:791 - Set hostname to "debian"
lxc-start debian 20200121215234.818 DEBUG    network - network.c:setup_hw_addr:2767 - Mac address "52:54:00:00:00:02" on "eth0" has been setup
lxc-start debian 20200121215234.819 DEBUG    network - network.c:lxc_setup_netdev_in_child_namespaces:3032 - Network device "eth0" has been setup
lxc-start debian 20200121215234.819 INFO     network - network.c:lxc_setup_network_in_child_namespaces:3053 - network has been setup
lxc-start debian 20200121215234.819 INFO     conf - conf.c:mount_autodev:1118 - Preparing "/dev"
lxc-start debian 20200121215234.819 INFO     conf - conf.c:mount_autodev:1165 - Prepared "/dev"
lxc-start debian 20200121215234.819 INFO     conf - conf.c:run_script_argv:356 - Executing script "/usr/share/lxcfs/lxc.mount.hook" for container "debian", config section "lxc"
lxc-start debian 20200121215234.861 INFO     conf - conf.c:lxc_fill_autodev:1209 - Populating "/dev"
lxc-start debian 20200121215234.861 DEBUG    conf - conf.c:lxc_fill_autodev:1282 - Bind mounted host device node "/dev/full" onto "/usr/lib/x86_64-linux-gnu/lxc/rootfs/dev/full"
lxc-start debian 20200121215234.861 DEBUG    conf - conf.c:lxc_fill_autodev:1282 - Bind mounted host device node "/dev/null" onto "/usr/lib/x86_64-linux-gnu/lxc/rootfs/dev/null"
lxc-start debian 20200121215234.861 DEBUG    conf - conf.c:lxc_fill_autodev:1282 - Bind mounted host device node "/dev/random" onto "/usr/lib/x86_64-linux-gnu/lxc/rootfs/dev/random"
lxc-start debian 20200121215234.861 DEBUG    conf - conf.c:lxc_fill_autodev:1282 - Bind mounted host device node "/dev/tty" onto "/usr/lib/x86_64-linux-gnu/lxc/rootfs/dev/tty"
lxc-start debian 20200121215234.861 DEBUG    conf - conf.c:lxc_fill_autodev:1282 - Bind mounted host device node "/dev/urandom" onto "/usr/lib/x86_64-linux-gnu/lxc/rootfs/dev/urandom"
lxc-start debian 20200121215234.861 DEBUG    conf - conf.c:lxc_fill_autodev:1282 - Bind mounted host device node "/dev/zero" onto "/usr/lib/x86_64-linux-gnu/lxc/rootfs/dev/zero"
lxc-start debian 20200121215234.861 INFO     conf - conf.c:lxc_fill_autodev:1286 - Populated "/dev"
lxc-start debian 20200121215234.861 DEBUG    conf - conf.c:mount_entry:2027 - Remounting "/sys/fs/fuse/connections" on "/usr/lib/x86_64-linux-gnu/lxc/rootfs/sys/fs/fuse/connections" to respect bind or remount options
lxc-start debian 20200121215234.861 DEBUG    conf - conf.c:mount_entry:2048 - Flags for "/sys/fs/fuse/connections" were 4096, required extra flags are 0
lxc-start debian 20200121215234.861 DEBUG    conf - conf.c:mount_entry:2058 - Mountflags already were 4096, skipping remount
lxc-start debian 20200121215234.861 DEBUG    conf - conf.c:mount_entry:2102 - Mounted "/sys/fs/fuse/connections" on "/usr/lib/x86_64-linux-gnu/lxc/rootfs/sys/fs/fuse/connections" with filesystem type "none"
lxc-start debian 20200121215234.861 DEBUG    conf - conf.c:mount_entry:2102 - Mounted "proc" on "/usr/lib/x86_64-linux-gnu/lxc/rootfs/dev/.lxc/proc" with filesystem type "proc"
lxc-start debian 20200121215234.861 DEBUG    conf - conf.c:mount_entry:2102 - Mounted "sys" on "/usr/lib/x86_64-linux-gnu/lxc/rootfs/dev/.lxc/sys" with filesystem type "sysfs"
lxc-start debian 20200121215234.861 INFO     conf - conf.c:mount_file_entries:2333 - Finished setting up mounts
lxc-start debian 20200121215234.861 DEBUG    conf - conf.c:lxc_setup_dev_console:1771 - Mounted pts device "/dev/pts/1" onto "/usr/lib/x86_64-linux-gnu/lxc/rootfs/dev/console"
lxc-start debian 20200121215234.861 INFO     utils - utils.c:lxc_mount_proc_if_needed:1231 - I am 1, /proc/self points to "1"
lxc-start debian 20200121215234.862 WARN     conf - conf.c:lxc_setup_devpts:1616 - Invalid argument - Failed to unmount old devpts instance
lxc-start debian 20200121215234.862 DEBUG    conf - conf.c:lxc_setup_devpts:1653 - Mount new devpts instance with options "gid=5,newinstance,ptmxmode=0666,mode=0620,max=1024"
lxc-start debian 20200121215234.862 DEBUG    conf - conf.c:lxc_setup_devpts:1672 - Created dummy "/dev/ptmx" file as bind mount target
lxc-start debian 20200121215234.862 DEBUG    conf - conf.c:lxc_setup_devpts:1677 - Bind mounted "/dev/pts/ptmx" to "/dev/ptmx"
lxc-start debian 20200121215234.862 DEBUG    conf - conf.c:lxc_allocate_ttys:989 - Created tty "/dev/pts/0" with master fd 11 and slave fd 14
lxc-start debian 20200121215234.862 DEBUG    conf - conf.c:lxc_allocate_ttys:989 - Created tty "/dev/pts/1" with master fd 15 and slave fd 16
lxc-start debian 20200121215234.862 DEBUG    conf - conf.c:lxc_allocate_ttys:989 - Created tty "/dev/pts/2" with master fd 17 and slave fd 18
lxc-start debian 20200121215234.862 DEBUG    conf - conf.c:lxc_allocate_ttys:989 - Created tty "/dev/pts/3" with master fd 19 and slave fd 20
lxc-start debian 20200121215234.862 INFO     conf - conf.c:lxc_allocate_ttys:1005 - Finished creating 4 tty devices
lxc-start debian 20200121215234.862 DEBUG    conf - conf.c:lxc_setup_ttys:940 - Bind mounted "/dev/pts/0" onto "/dev/tty1"
lxc-start debian 20200121215234.862 DEBUG    conf - conf.c:lxc_setup_ttys:940 - Bind mounted "/dev/pts/1" onto "/dev/tty2"
lxc-start debian 20200121215234.862 DEBUG    conf - conf.c:lxc_setup_ttys:940 - Bind mounted "/dev/pts/2" onto "/dev/tty3"
lxc-start debian 20200121215234.862 DEBUG    conf - conf.c:lxc_setup_ttys:940 - Bind mounted "/dev/pts/3" onto "/dev/tty4"
lxc-start debian 20200121215234.862 INFO     conf - conf.c:lxc_setup_ttys:949 - Finished setting up 4 /dev/tty<N> device(s)
lxc-start debian 20200121215234.862 INFO     conf - conf.c:setup_personality:1716 - Set personality to "0x0"
lxc-start debian 20200121215234.862 DEBUG    conf - conf.c:setup_caps:2529 - Capabilities have been setup
lxc-start debian 20200121215234.862 NOTICE   conf - conf.c:lxc_setup:3716 - The container "debian" is set up
lxc-start debian 20200121215234.862 INFO     lsm - lsm/lsm.c:lsm_process_label_set_at:178 - Set AppArmor label to "lxc-debian_</var/lib/lxc>//&:lxc-debian_<-var-lib-lxc>:"
lxc-start debian 20200121215234.862 INFO     apparmor - lsm/apparmor.c:apparmor_process_label_set:1101 - Changed AppArmor profile to lxc-debian_</var/lib/lxc>//&:lxc-debian_<-var-lib-lxc>:
lxc-start debian 20200121215234.862 DEBUG    start - start.c:lxc_spawn:1829 - Preserved cgroup namespace via fd 19
lxc-start debian 20200121215234.862 NOTICE   start - start.c:start:2037 - Exec'ing "/sbin/init"
lxc-start debian 20200121215234.862 NOTICE   start - start.c:post_start:2048 - Started "/sbin/init" with pid "808"
lxc-start debian 20200121215234.863 NOTICE   start - start.c:signal_handler:430 - Received 17 from pid 803 instead of container init 808
lxc-start debian 20200121215234.863 DEBUG    lxccontainer - lxccontainer.c:wait_on_daemonized_start:830 - First child 801 exited

Checking if the container was stopped indeed

root@test # lxc-ls --fancy
NAME   STATE   AUTOSTART GROUPS IPV4 IPV6 UNPRIVILEGED
debian STOPPED 1         -      -    -    true

Trying to autostart containers on command-line

root@test # lxc-autostart
root@test # lxc-ls --fancy
NAME   STATE   AUTOSTART GROUPS IPV4 IPV6 UNPRIVILEGED
debian RUNNING 1         -      -    -    true

Rebooting the machine …

root@test # lxc-ls --fancy
NAME   STATE   AUTOSTART GROUPS IPV4 IPV6 UNPRIVILEGED
debian STOPPED 1         -      -    -    true

root@test # systemctl status lxc
● lxc.service - LXC Container Initialization and Autoboot Code
   Loaded: loaded (/lib/systemd/system/lxc.service; enabled; vendor preset: enabled)
   Active: active (exited) since Tue 2020-01-21 22:58:46 CET; 50s ago
     Docs: man:lxc-autostart
           man:lxc
  Process: 351 ExecStartPre=/usr/lib/x86_64-linux-gnu/lxc/lxc-apparmor-load (code=exited, status=0/SUCCESS)
  Process: 363 ExecStart=/usr/lib/x86_64-linux-gnu/lxc/lxc-containers start (code=exited, status=0/SUCCESS)
 Main PID: 363 (code=exited, status=0/SUCCESS)
    Tasks: 0 (limit: 4668)
   Memory: 3.0M
   CGroup: /system.slice/lxc.service

Jan 21 22:58:45 test systemd[1]: Starting LXC Container Initialization and Autoboot Code...
Jan 21 22:58:46 test systemd[1]: Started LXC Container Initialization and Autoboot Code.

Installed version of LCX …

root@test # apt list --installed | grep lxc
...
lxc-templates/stable,now 3.0.3-1 amd64 [installed,automatic]
lxc/stable,now 1:3.1.0+really3.0.3-8 amd64 [installed]
lxcfs/stable,now 3.0.3-2 amd64 [installed,automatic]

Can anybody tell me what I did wrong or what I missed?
I have searched a lot of different other webpages but could not find a solution that worked.

Thanks a lot in advance,
Tim

zerocool · January 23, 2020, 7:13pm

When following the Debian LXC information, no /etc/default/lxc-net file is created and therefore the variable USE_LXC_BRIDGE=“false” from /etc/default/lxc is not overridden.

The log file pointed me into the right direction

...
lxc-autostart debian 20200123190820.249 INFO     start - start.c:lxc_init:904 - Container "debian" is initialized
lxc-autostart debian 20200123190820.254 DEBUG    storage - storage/storage.c:get_storage_by_name:231 - Detected rootfs type "dir"
lxc-autostart debian 20200123190820.316 INFO     network - network.c:instantiate_veth:150 - Retrieved mtu 1500 from vethJE114P
lxc-autostart debian 20200123190820.316 ERROR    utils - utils.c:run_command:1615 - Failed to exec command
lxc-autostart debian 20200123190820.316 ERROR    network - network.c:lxc_ovs_attach_bridge:1887 - Failed to attach "virbr0" to openvswitch bridge "vethYH6M3N": lxc-autostart: debian:
lxc-autostart debian 20200123190820.316 ERROR    network - network.c:instantiate_veth:172 - Operation not permitted - Failed to attach "vethYH6M3N" to bridge "virbr0"
lxc-autostart debian 20200123190820.321 ERROR    network - network.c:lxc_create_network_priv:2457 - Failed to create network device
lxc-autostart debian 20200123190820.321 ERROR    start - start.c:lxc_spawn:1638 - Failed to create the network
lxc-autostart debian 20200123190820.321 ERROR    start - start.c:__lxc_start:1951 - Failed to spawn container "debian"
lxc-autostart debian 20200123190820.321 DEBUG    lxccontainer - lxccontainer.c:wait_on_daemonized_start:830 - First child 408 exited
lxc-autostart debian 20200123190820.321 ERROR    lxccontainer - lxccontainer.c:wait_on_daemonized_start:842 - Received container state "STOPPING" instead of "RUNNING"
lxc-autostart 20200123190820.321 ERROR    lxc_autostart - tools/lxc_autostart.c:main:474 - Error starting container: debian
lxc-autostart debian 20200123190820.322 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2860 - The binary "/usr/bin/newuidmap" does have the setuid bit set
lxc-autostart debian 20200123190820.322 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2860 - The binary "/usr/bin/newgidmap" does have the setuid bit set
lxc-autostart debian 20200123190820.322 DEBUG    conf - conf.c:lxc_map_ids:2952 - Functional newuidmap and newgidmap binary found
lxc-autostart debian 20200123190820.345 INFO     conf - conf.c:run_script_argv:356 - Executing script "/usr/share/lxcfs/lxc.reboot.hook" for container "debian", config section "lxc"

network - network.c:lxc_ovs_attach_bridge:1887 - Failed to attach “virbr0” to openvswitch bridge “vethxxxxxx”: lxc-autostart: debian:

One possible solution is to disable the virbr0 bridge and enable lxcbr0 bridge:

root@test # virsh net-autostart --disable default
root@test # nano /etc/default/lxc-net
  # use the virbr0 device that is automatically started
  USE_LXC_BRIDGE="true"
  ....