Unpriviliged container wont start - Failed to allocate manager object

When I try to start my unprivileged lxc I get the following:

lxc-start vpn1 -F
systemd 245.5-2-arch running in system mode. (+PAM +AUDIT -SELINUX -IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=hybrid)
Detected virtualization lxc.
Detected architecture x86-64.

Welcome to Arch Linux!

Failed to create /init.scope control group: Permission denied
Failed to allocate manager object: Permission denied
[!!!!!!] Failed to allocate manager object.
Exiting PID 1...

Config:

#sysctl kernel.unprivileged_userns_clone
1

$ grep lxcuser /etc/sub* 2>/dev/null
/etc/subgid:lxcuser:100000:65536
/etc/subuid:lxcuser:100000:65536

$ cat ~/.config/lxc/lxc-usernet
lxcuser veth lxcbr0 10

$ cat ~/.config/lxc/default.conf
lxc.idmap = u 0 100000 65536
lxc.idmap = g 0 100000 65536

lxc.net.0.type = veth
lxc.net.0.link = lxcbr0
lxc.net.0.flags = up
lxc.net.0.hwaddr = 00:16:3e:xx:xx:xx

$ lxc-checkconfig
--- Namespaces ---
Namespaces: enabled
Utsname namespace: enabled
Ipc namespace: enabled
Pid namespace: enabled
User namespace: enabled
Network namespace: enabled

--- Control groups ---
Cgroups: enabled

Cgroup v1 mount points: 
/sys/fs/cgroup/systemd
/sys/fs/cgroup/memory
/sys/fs/cgroup/cpu,cpuacct
/sys/fs/cgroup/net_cls,net_prio
/sys/fs/cgroup/rdma
/sys/fs/cgroup/cpuset
/sys/fs/cgroup/blkio
/sys/fs/cgroup/freezer
/sys/fs/cgroup/perf_event
/sys/fs/cgroup/pids
/sys/fs/cgroup/devices
/sys/fs/cgroup/hugetlb

Cgroup v2 mount points: 
/sys/fs/cgroup/unified

Cgroup v1 clone_children flag: enabled
Cgroup device: enabled
Cgroup sched: enabled
Cgroup cpu account: enabled
Cgroup memory controller: enabled
Cgroup cpuset: enabled

--- Misc ---
Veth pair device: enabled, loaded
Macvlan: enabled, not loaded
Vlan: enabled, not loaded
Bridges: enabled, loaded
Advanced netfilter: enabled, not loaded
CONFIG_NF_NAT_IPV4: missing
CONFIG_NF_NAT_IPV6: missing
CONFIG_IP_NF_TARGET_MASQUERADE: enabled, not loaded
CONFIG_IP6_NF_TARGET_MASQUERADE: enabled, not loaded
CONFIG_NETFILTER_XT_TARGET_CHECKSUM: enabled, loaded
CONFIG_NETFILTER_XT_MATCH_COMMENT: enabled, not loaded
FUSE (for use with lxcfs): enabled, loaded

--- Checkpoint/Restore ---
checkpoint restore: enabled
CONFIG_FHANDLE: enabled
CONFIG_EVENTFD: enabled
CONFIG_EPOLL: enabled
CONFIG_UNIX_DIAG: enabled
CONFIG_INET_DIAG: enabled
CONFIG_PACKET_DIAG: enabled
CONFIG_NETLINK_DIAG: enabled
File capabilities: 

Note : Before booting a new kernel, you can check its configuration
usage : CONFIG=/path/to/config /usr/bin/lxc-checkconfig

Debug:

lxc-start vpn1 20200501170749.810 INFO     utils - utils.c:get_rundir:258 - XDG_RUNTIME_DIR isn't set in the environment
lxc-start vpn1 20200501170749.810 INFO     confile - confile.c:set_config_idmaps:2008 - Read uid map: type u nsid 0 hostid 100000 range 65536
lxc-start vpn1 20200501170749.810 INFO     confile - confile.c:set_config_idmaps:2008 - Read uid map: type g nsid 0 hostid 100000 range 65536
lxc-start vpn1 20200501170749.810 INFO     lsm - lsm/lsm.c:lsm_init:29 - LSM security driver nop
lxc-start vpn1 20200501170749.810 INFO     utils - utils.c:get_rundir:258 - XDG_RUNTIME_DIR isn't set in the environment
lxc-start vpn1 20200501170749.811 DEBUG    terminal - terminal.c:lxc_terminal_peer_default:662 - Using terminal "/dev/tty" as proxy
lxc-start vpn1 20200501170749.811 DEBUG    terminal - terminal.c:lxc_terminal_winsz:60 - Set window size to 140 columns and 45 rows
lxc-start vpn1 20200501170749.811 DEBUG    conf - conf.c:chown_mapped_root:2932 - trying to chown "/dev/pts/2" to 1001
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:770 - Processing "reject_force_umount  # comment this to allow umount -f;  not recommended"
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:do_resolve_add_rule:516 - Set seccomp rule to reject force umounts
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:965 - Added native rule for arch 0 for reject_force_umount action 0(kill)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:do_resolve_add_rule:516 - Set seccomp rule to reject force umounts
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:974 - Added compat rule for arch 1073741827 for reject_force_umount action 0(kill)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:do_resolve_add_rule:516 - Set seccomp rule to reject force umounts
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:984 - Added compat rule for arch 1073741886 for reject_force_umount action 0(kill)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:do_resolve_add_rule:516 - Set seccomp rule to reject force umounts
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:994 - Added native rule for arch -1073741762 for reject_force_umount action 0(kill)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:770 - Processing "[all]"
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:770 - Processing "kexec_load errno 1"
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:965 - Added native rule for arch 0 for kexec_load action 327681(errno)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:974 - Added compat rule for arch 1073741827 for kexec_load action 327681(errno)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:984 - Added compat rule for arch 1073741886 for kexec_load action 327681(errno)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:994 - Added native rule for arch -1073741762 for kexec_load action 327681(errno)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:770 - Processing "open_by_handle_at errno 1"
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:965 - Added native rule for arch 0 for open_by_handle_at action 327681(errno)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:974 - Added compat rule for arch 1073741827 for open_by_handle_at action 327681(errno)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:984 - Added compat rule for arch 1073741886 for open_by_handle_at action 327681(errno)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:994 - Added native rule for arch -1073741762 for open_by_handle_at action 327681(errno)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:770 - Processing "init_module errno 1"
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:965 - Added native rule for arch 0 for init_module action 327681(errno)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:974 - Added compat rule for arch 1073741827 for init_module action 327681(errno)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:984 - Added compat rule for arch 1073741886 for init_module action 327681(errno)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:994 - Added native rule for arch -1073741762 for init_module action 327681(errno)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:770 - Processing "finit_module errno 1"
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:965 - Added native rule for arch 0 for finit_module action 327681(errno)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:974 - Added compat rule for arch 1073741827 for finit_module action 327681(errno)
lxc-start vpn1 20200501170749.828 INFO     seccomp - seccomp.c:parse_config_v2:984 - Added compat rule for arch 1073741886 for finit_module action 327681(errno)
lxc-start vpn1 20200501170749.829 INFO     seccomp - seccomp.c:parse_config_v2:994 - Added native rule for arch -1073741762 for finit_module action 327681(errno)
lxc-start vpn1 20200501170749.829 INFO     seccomp - seccomp.c:parse_config_v2:770 - Processing "delete_module errno 1"
lxc-start vpn1 20200501170749.829 INFO     seccomp - seccomp.c:parse_config_v2:965 - Added native rule for arch 0 for delete_module action 327681(errno)
lxc-start vpn1 20200501170749.829 INFO     seccomp - seccomp.c:parse_config_v2:974 - Added compat rule for arch 1073741827 for delete_module action 327681(errno)
lxc-start vpn1 20200501170749.829 INFO     seccomp - seccomp.c:parse_config_v2:984 - Added compat rule for arch 1073741886 for delete_module action 327681(errno)
lxc-start vpn1 20200501170749.829 INFO     seccomp - seccomp.c:parse_config_v2:994 - Added native rule for arch -1073741762 for delete_module action 327681(errno)
lxc-start vpn1 20200501170749.829 INFO     seccomp - seccomp.c:parse_config_v2:1000 - Merging compat seccomp contexts into main context
lxc-start vpn1 20200501170749.829 INFO     start - start.c:lxc_init:850 - Container "vpn1" is initialized
lxc-start vpn1 20200501170749.829 INFO     start - start.c:lxc_spawn:1664 - Cloned CLONE_NEWUSER
lxc-start vpn1 20200501170749.829 INFO     start - start.c:lxc_spawn:1664 - Cloned CLONE_NEWNS
lxc-start vpn1 20200501170749.829 INFO     start - start.c:lxc_spawn:1664 - Cloned CLONE_NEWPID
lxc-start vpn1 20200501170749.829 INFO     start - start.c:lxc_spawn:1664 - Cloned CLONE_NEWUTS
lxc-start vpn1 20200501170749.829 INFO     start - start.c:lxc_spawn:1664 - Cloned CLONE_NEWIPC
lxc-start vpn1 20200501170749.829 DEBUG    start - start.c:lxc_try_preserve_namespaces:165 - Preserved user namespace via fd 16
lxc-start vpn1 20200501170749.829 DEBUG    start - start.c:lxc_try_preserve_namespaces:165 - Preserved mnt namespace via fd 17
lxc-start vpn1 20200501170749.829 DEBUG    start - start.c:lxc_try_preserve_namespaces:165 - Preserved pid namespace via fd 18
lxc-start vpn1 20200501170749.829 DEBUG    start - start.c:lxc_try_preserve_namespaces:165 - Preserved uts namespace via fd 19
lxc-start vpn1 20200501170749.829 DEBUG    start - start.c:lxc_try_preserve_namespaces:165 - Preserved ipc namespace via fd 20
lxc-start vpn1 20200501170749.829 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2642 - The binary "/usr/bin/newuidmap" does have the setuid bit set
lxc-start vpn1 20200501170749.829 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2642 - The binary "/usr/bin/newgidmap" does have the setuid bit set
lxc-start vpn1 20200501170749.829 DEBUG    conf - conf.c:lxc_map_ids:2710 - Functional newuidmap and newgidmap binary found
lxc-start vpn1 20200501170749.841 INFO     start - start.c:do_start:1098 - Unshared CLONE_NEWNET
lxc-start vpn1 20200501170749.841 DEBUG    start - start.c:lxc_spawn:1737 - Preserved net namespace via fd 5
lxc-start vpn1 20200501170749.841 WARN     start - start.c:lxc_spawn:1742 - Operation not permitted - Failed to allocate new network namespace id
lxc-start vpn1 20200501170749.842 INFO     network - network.c:lxc_create_network_unpriv_exec:2628 - Execing lxc-user-nic create /home/lxcuser/.local/share/lxc vpn1 1622 veth br0 (null)
lxc-start vpn1 20200501170749.868 NOTICE   utils - utils.c:lxc_setgroups:1366 - Dropped additional groups
lxc-start vpn1 20200501170749.868 NOTICE   utils - utils.c:lxc_switch_uid_gid:1344 - Switched to gid 0
lxc-start vpn1 20200501170749.868 NOTICE   utils - utils.c:lxc_switch_uid_gid:1353 - Switched to uid 0
lxc-start vpn1 20200501170749.868 INFO     start - start.c:do_start:1211 - Unshared CLONE_NEWCGROUP
lxc-start vpn1 20200501170749.869 DEBUG    storage - storage/storage.c:get_storage_by_name:211 - Detected rootfs type "dir"
lxc-start vpn1 20200501170749.869 DEBUG    conf - conf.c:lxc_mount_rootfs:1258 - Mounted rootfs "/home/lxcuser/.local/share/lxc/vpn1/rootfs" onto "/usr/lib/lxc/rootfs" with options "(null)"
lxc-start vpn1 20200501170749.871 INFO     conf - conf.c:setup_utsname:751 - Set hostname to "vpn1"
lxc-start vpn1 20200501170749.871 DEBUG    network - network.c:setup_hw_addr:3388 - Mac address "00:16:3e:20:90:11" on "eth0" has been setup
lxc-start vpn1 20200501170749.872 DEBUG    network - network.c:lxc_network_setup_in_child_namespaces_common:3538 - Network device "eth0" has been setup
lxc-start vpn1 20200501170749.872 INFO     network - network.c:lxc_setup_network_in_child_namespaces:3560 - Network has been setup
lxc-start vpn1 20200501170749.872 INFO     conf - conf.c:mount_autodev:1059 - Preparing "/dev"
lxc-start vpn1 20200501170749.872 DEBUG    conf - conf.c:mount_autodev:1065 - Using mount options: size=500000,mode=755
lxc-start vpn1 20200501170749.872 INFO     conf - conf.c:mount_autodev:1108 - Prepared "/dev"
lxc-start vpn1 20200501170749.872 INFO     conf - conf.c:mount_entry:1851 - No such file or directory - Failed to mount "/sys/fs/fuse/connections" on "/usr/lib/lxc/rootfs/sys/fs/fuse/connections" (optional)
lxc-start vpn1 20200501170749.873 INFO     conf - conf.c:run_script_argv:339 - Executing script "/usr/share/lxcfs/lxc.mount.hook" for container "vpn1", config section "lxc"
lxc-start vpn1 20200501170749.886 INFO     conf - conf.c:lxc_fill_autodev:1152 - Populating "/dev"
lxc-start vpn1 20200501170749.886 DEBUG    conf - conf.c:lxc_fill_autodev:1218 - Bind mounted host device node "/dev/full" onto "/usr/lib/lxc/rootfs/dev/full"
lxc-start vpn1 20200501170749.886 DEBUG    conf - conf.c:lxc_fill_autodev:1218 - Bind mounted host device node "/dev/null" onto "/usr/lib/lxc/rootfs/dev/null"
lxc-start vpn1 20200501170749.886 DEBUG    conf - conf.c:lxc_fill_autodev:1218 - Bind mounted host device node "/dev/random" onto "/usr/lib/lxc/rootfs/dev/random"
lxc-start vpn1 20200501170749.886 DEBUG    conf - conf.c:lxc_fill_autodev:1218 - Bind mounted host device node "/dev/tty" onto "/usr/lib/lxc/rootfs/dev/tty"
lxc-start vpn1 20200501170749.886 DEBUG    conf - conf.c:lxc_fill_autodev:1218 - Bind mounted host device node "/dev/urandom" onto "/usr/lib/lxc/rootfs/dev/urandom"
lxc-start vpn1 20200501170749.886 DEBUG    conf - conf.c:lxc_fill_autodev:1218 - Bind mounted host device node "/dev/zero" onto "/usr/lib/lxc/rootfs/dev/zero"
lxc-start vpn1 20200501170749.886 INFO     conf - conf.c:lxc_fill_autodev:1222 - Populated "/dev"
lxc-start vpn1 20200501170749.886 DEBUG    conf - conf.c:lxc_setup_dev_console:1618 - Mounted pts device "/dev/pts/2" onto "/usr/lib/lxc/rootfs/dev/console"
lxc-start vpn1 20200501170749.886 INFO     utils - utils.c:lxc_mount_proc_if_needed:1200 - I am 1, /proc/self points to "1"
lxc-start vpn1 20200501170749.886 DEBUG    conf - conf.c:lxc_setup_devpts:1521 - Mount new devpts instance with options "gid=5,newinstance,ptmxmode=0666,mode=0620,max=1024"
lxc-start vpn1 20200501170749.886 DEBUG    conf - conf.c:lxc_setup_devpts:1536 - Created dummy "/dev/ptmx" file as bind mount target
lxc-start vpn1 20200501170749.886 DEBUG    conf - conf.c:lxc_setup_devpts:1541 - Bind mounted "/dev/pts/ptmx" to "/dev/ptmx"
lxc-start vpn1 20200501170749.887 DEBUG    conf - conf.c:lxc_allocate_ttys:938 - Created tty "/dev/pts/0" with master fd 15 and slave fd 16
lxc-start vpn1 20200501170749.887 DEBUG    conf - conf.c:lxc_allocate_ttys:938 - Created tty "/dev/pts/1" with master fd 17 and slave fd 18
lxc-start vpn1 20200501170749.887 DEBUG    conf - conf.c:lxc_allocate_ttys:938 - Created tty "/dev/pts/2" with master fd 19 and slave fd 20
lxc-start vpn1 20200501170749.887 DEBUG    conf - conf.c:lxc_allocate_ttys:938 - Created tty "/dev/pts/3" with master fd 21 and slave fd 22
lxc-start vpn1 20200501170749.887 INFO     conf - conf.c:lxc_allocate_ttys:955 - Finished creating 4 tty devices
lxc-start vpn1 20200501170749.887 DEBUG    conf - conf.c:lxc_setup_ttys:893 - Bind mounted "/dev/pts/0" onto "/dev/tty1"
lxc-start vpn1 20200501170749.887 DEBUG    conf - conf.c:lxc_setup_ttys:893 - Bind mounted "/dev/pts/1" onto "/dev/tty2"
lxc-start vpn1 20200501170749.887 DEBUG    conf - conf.c:lxc_setup_ttys:893 - Bind mounted "/dev/pts/2" onto "/dev/tty3"
lxc-start vpn1 20200501170749.887 DEBUG    conf - conf.c:lxc_setup_ttys:893 - Bind mounted "/dev/pts/3" onto "/dev/tty4"
lxc-start vpn1 20200501170749.887 INFO     conf - conf.c:lxc_setup_ttys:900 - Finished setting up 4 /dev/tty<N> device(s)
lxc-start vpn1 20200501170749.887 INFO     conf - conf.c:setup_personality:1572 - Set personality to "0x0"
lxc-start vpn1 20200501170749.887 DEBUG    conf - conf.c:setup_caps:2338 - Capabilities have been setup
lxc-start vpn1 20200501170749.887 NOTICE   conf - conf.c:lxc_setup:3433 - The container "vpn1" is set up
lxc-start vpn1 20200501170749.888 DEBUG    start - start.c:lxc_spawn:1808 - Preserved cgroup namespace via fd 11
lxc-start vpn1 20200501170749.888 NOTICE   start - start.c:start:2041 - Exec'ing "/sbin/init"
lxc-start vpn1 20200501170749.888 NOTICE   start - start.c:post_start:2052 - Started "/sbin/init" with pid "1622"
lxc-start vpn1 20200501170749.888 INFO     utils - utils.c:get_rundir:258 - XDG_RUNTIME_DIR isn't set in the environment
lxc-start vpn1 20200501170749.888 NOTICE   start - start.c:signal_handler:393 - Received 17 from pid 1618 instead of container init 1622
lxc-start vpn1 20200501170749.915 DEBUG    start - start.c:signal_handler:411 - Container init process 1622 exited
lxc-start vpn1 20200501170749.915 INFO     utils - utils.c:get_rundir:258 - XDG_RUNTIME_DIR isn't set in the environment
lxc-start vpn1 20200501170749.915 INFO     error - error.c:lxc_error_set_and_log:28 - Child <1622> ended on error (255)
lxc-start vpn1 20200501170749.915 DEBUG    network - network.c:lxc_delete_network:3693 - Deleted network devices
lxc-start vpn1 20200501170749.915 INFO     utils - utils.c:get_rundir:258 - XDG_RUNTIME_DIR isn't set in the environment
lxc-start vpn1 20200501170749.915 INFO     utils - utils.c:get_rundir:258 - XDG_RUNTIME_DIR isn't set in the environment
lxc-start vpn1 20200501170749.967 INFO     conf - conf.c:run_script_argv:339 - Executing script "/usr/share/lxcfs/lxc.reboot.hook" for container "vpn1", config section "lxc"

Thank you

This suggests permission issues on your cgroups.

That’s what I’m thinking I’ve been reading arch support - any commands I can reference?

Tried it with a trace, looks like networking and such are setup…still reading it…

lxc-start vpn1 20200501172901.970 INFO     confile - confile.c:set_config_idmaps:2008 - Read uid map: type u nsid 0 hostid 100000 range 65536
lxc-start vpn1 20200501172901.970 INFO     confile - confile.c:set_config_idmaps:2008 - Read uid map: type g nsid 0 hostid 100000 range 65536
lxc-start vpn1 20200501172901.971 TRACE    commands - commands.c:lxc_cmd:285 - Connection refused - Command "get_init_pid" failed to connect command socket
lxc-start vpn1 20200501172901.971 TRACE    commands - commands.c:lxc_cmd:285 - Connection refused - Command "get_state" failed to connect command socket
lxc-start vpn1 20200501172901.971 TRACE    start - start.c:lxc_init_handler:701 - Created anonymous pair {4,5} of unix sockets
lxc-start vpn1 20200501172901.971 TRACE    commands - commands.c:lxc_cmd_init:1582 - Created abstract unix socket "/home/lxcuser/.local/share/lxc/vpn1/command"
lxc-start vpn1 20200501172901.971 TRACE    start - start.c:lxc_init_handler:714 - Unix domain socket 6 for command server is ready
lxc-start vpn1 20200501172901.971 INFO     lxccontainer - lxccontainer.c:do_lxcapi_start:972 - Set process title to [lxc monitor] /home/lxcuser/.local/share/lxc vpn1
lxc-start vpn1 20200501172901.972 DEBUG    lxccontainer - lxccontainer.c:wait_on_daemonized_start:830 - First child 1823 exited
lxc-start vpn1 20200501172901.972 TRACE    start - start.c:lxc_start:2068 - Doing lxc_start
lxc-start vpn1 20200501172901.972 INFO     lsm - lsm/lsm.c:lsm_init:29 - LSM security driver nop
lxc-start vpn1 20200501172901.972 TRACE    start - start.c:lxc_init:738 - Initialized LSM
lxc-start vpn1 20200501172901.972 TRACE    start - start.c:lxc_serve_state_clients:427 - Set container state to STARTING
lxc-start vpn1 20200501172901.972 TRACE    start - start.c:lxc_serve_state_clients:430 - No state clients registered
lxc-start vpn1 20200501172901.972 TRACE    start - start.c:lxc_init:744 - Set container state to "STARTING"
lxc-start vpn1 20200501172901.972 TRACE    start - start.c:lxc_init:800 - Set environment variables
lxc-start vpn1 20200501172901.972 TRACE    start - start.c:lxc_init:805 - Ran pre-start hooks
lxc-start vpn1 20200501172901.972 TRACE    start - start.c:setup_signal_fd:320 - Created signal file descriptor 8
lxc-start vpn1 20200501172901.972 TRACE    start - start.c:lxc_init:814 - Set up signal fd
lxc-start vpn1 20200501172901.973 DEBUG    terminal - terminal.c:lxc_terminal_peer_default:655 - No such device - The process does not have a controlling terminal
lxc-start vpn1 20200501172901.973 TRACE    start - start.c:lxc_init:822 - Created console
lxc-start vpn1 20200501172901.973 DEBUG    conf - conf.c:chown_mapped_root:2932 - trying to chown "/dev/pts/1" to 1001
lxc-start vpn1 20200501172901.991 TRACE    terminal - terminal.c:lxc_terminal_map_ids:1176 - Chowned terminal "/dev/pts/1"
lxc-start vpn1 20200501172901.991 TRACE    start - start.c:lxc_init:829 - Chowned console
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:939 - basecginfo is:
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:940 - 12:freezer:/
11:blkio:/
10:memory:/user.slice/user-1001.slice/session-4.scope
9:cpuset:/
8:hugetlb:/
7:cpu,cpuacct:/
6:devices:/user.slice
5:perf_event:/
4:pids:/user.slice/user-1001.slice/session-4.scope
3:net_cls,net_prio:/
2:rdma:/
1:name=systemd:/user.slice/user-1001.slice/session-4.scope
0::/user.slice/user-1001.slice/session-4.scope

lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:943 - kernel subsystem 0: freezer
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:943 - kernel subsystem 1: blkio
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:943 - kernel subsystem 2: memory
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:943 - kernel subsystem 3: cpuset
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:943 - kernel subsystem 4: hugetlb
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:943 - kernel subsystem 5: cpu
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:943 - kernel subsystem 6: cpuacct
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:943 - kernel subsystem 7: devices
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:943 - kernel subsystem 8: perf_event
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:943 - kernel subsystem 9: pids
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:943 - kernel subsystem 10: net_cls
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:943 - kernel subsystem 11: net_prio
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:943 - kernel subsystem 12: rdma
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:943 - kernel subsystem 13: cgroup2
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_basecg_debuginfo:946 - named subsystem 0: name=systemd
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:cg_hybrid_init:3121 - The /user.slice/user-1001.slice/session-4.scope group is not writeable
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:cg_hybrid_init:3121 - The /user.slice/user-1001.slice/session-4.scope group is not writeable
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:cg_hybrid_init:3121 - The / group is not writeable
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:cg_hybrid_init:3121 - The / group is not writeable
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:cg_hybrid_init:3121 - The /user.slice/user-1001.slice/session-4.scope group is not writeable
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:cg_hybrid_init:3121 - The / group is not writeable
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:cg_hybrid_init:3121 - The /user.slice group is not writeable
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:cg_hybrid_init:3121 - The / group is not writeable
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:cg_hybrid_init:3121 - The / group is not writeable
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:cg_hybrid_init:3121 - The / group is not writeable
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:cg_hybrid_init:3121 - The /user.slice/user-1001.slice/session-4.scope group is not writeable
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:cg_hybrid_init:3121 - The / group is not writeable
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:cg_hybrid_init:3121 - The / group is not writeable
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:cg_hybrid_init:3155 - Writable cgroup hierarchies:
lxc-start vpn1 20200501172901.992 TRACE    cgfsng - cgroups/cgfsng.c:lxc_cgfsng_print_hierarchies:916 -   No hierarchies found
lxc-start vpn1 20200501172901.992 TRACE    cgroup - cgroups/cgroup.c:cgroup_init:40 - Initialized cgroup driver cgfsng
lxc-start vpn1 20200501172901.992 TRACE    cgroup - cgroups/cgroup.c:cgroup_init:45 - Running with hybrid cgroup layout
lxc-start vpn1 20200501172901.992 TRACE    start - start.c:lxc_init:836 - Initialized cgroup driver
lxc-start vpn1 20200501172901.992 TRACE    seccomp - seccomp.c:get_new_ctx:469 - Added arch 2 to main seccomp context
lxc-start vpn1 20200501172901.992 TRACE    seccomp - seccomp.c:get_new_ctx:477 - Removed native arch from main seccomp context
lxc-start vpn1 20200501172901.992 TRACE    seccomp - seccomp.c:get_new_ctx:469 - Added arch 3 to main seccomp context
lxc-start vpn1 20200501172901.992 TRACE    seccomp - seccomp.c:get_new_ctx:477 - Removed native arch from main seccomp context
lxc-start vpn1 20200501172901.992 TRACE    seccomp - seccomp.c:get_new_ctx:482 - Arch 4 already present in main seccomp context
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:770 - Processing "reject_force_umount  # comment this to allow umount -f;  not recommended"
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:do_resolve_add_rule:516 - Set seccomp rule to reject force umounts
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:965 - Added native rule for arch 0 for reject_force_umount action 0(kill)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:do_resolve_add_rule:516 - Set seccomp rule to reject force umounts
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:974 - Added compat rule for arch 1073741827 for reject_force_umount action 0(kill)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:do_resolve_add_rule:516 - Set seccomp rule to reject force umounts
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:984 - Added compat rule for arch 1073741886 for reject_force_umount action 0(kill)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:do_resolve_add_rule:516 - Set seccomp rule to reject force umounts
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:994 - Added native rule for arch -1073741762 for reject_force_umount action 0(kill)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:770 - Processing "[all]"
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:770 - Processing "kexec_load errno 1"
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:965 - Added native rule for arch 0 for kexec_load action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:974 - Added compat rule for arch 1073741827 for kexec_load action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:984 - Added compat rule for arch 1073741886 for kexec_load action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:994 - Added native rule for arch -1073741762 for kexec_load action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:770 - Processing "open_by_handle_at errno 1"
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:965 - Added native rule for arch 0 for open_by_handle_at action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:974 - Added compat rule for arch 1073741827 for open_by_handle_at action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:984 - Added compat rule for arch 1073741886 for open_by_handle_at action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:994 - Added native rule for arch -1073741762 for open_by_handle_at action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:770 - Processing "init_module errno 1"
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:965 - Added native rule for arch 0 for init_module action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:974 - Added compat rule for arch 1073741827 for init_module action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:984 - Added compat rule for arch 1073741886 for init_module action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:994 - Added native rule for arch -1073741762 for init_module action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:770 - Processing "finit_module errno 1"
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:965 - Added native rule for arch 0 for finit_module action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:974 - Added compat rule for arch 1073741827 for finit_module action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:984 - Added compat rule for arch 1073741886 for finit_module action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:994 - Added native rule for arch -1073741762 for finit_module action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:770 - Processing "delete_module errno 1"
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:965 - Added native rule for arch 0 for delete_module action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:974 - Added compat rule for arch 1073741827 for delete_module action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:984 - Added compat rule for arch 1073741886 for delete_module action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:994 - Added native rule for arch -1073741762 for delete_module action 327681(errno)
lxc-start vpn1 20200501172901.992 INFO     seccomp - seccomp.c:parse_config_v2:1000 - Merging compat seccomp contexts into main context
lxc-start vpn1 20200501172901.992 TRACE    seccomp - seccomp.c:parse_config_v2:1010 - Merged first compat seccomp context into main context
lxc-start vpn1 20200501172901.992 TRACE    seccomp - seccomp.c:parse_config_v2:1026 - Merged second compat seccomp context into main context
lxc-start vpn1 20200501172901.992 TRACE    start - start.c:lxc_init:841 - Read seccomp policy
lxc-start vpn1 20200501172901.992 TRACE    start - start.c:lxc_init:848 - Initialized LSM
lxc-start vpn1 20200501172901.992 INFO     start - start.c:lxc_init:850 - Container "vpn1" is initialized
lxc-start vpn1 20200501172901.993 TRACE    start - start.c:lxc_spawn:1648 - Cloned child process 1829
lxc-start vpn1 20200501172901.993 TRACE    utils - utils.c:lxc_can_use_pidfd:1861 - Kernel supports pidfds
lxc-start vpn1 20200501172901.993 INFO     start - start.c:lxc_spawn:1664 - Cloned CLONE_NEWUSER
lxc-start vpn1 20200501172901.993 INFO     start - start.c:lxc_spawn:1664 - Cloned CLONE_NEWNS
lxc-start vpn1 20200501172901.993 INFO     start - start.c:lxc_spawn:1664 - Cloned CLONE_NEWPID
lxc-start vpn1 20200501172901.993 INFO     start - start.c:lxc_spawn:1664 - Cloned CLONE_NEWUTS
lxc-start vpn1 20200501172901.993 INFO     start - start.c:lxc_spawn:1664 - Cloned CLONE_NEWIPC
lxc-start vpn1 20200501172901.993 DEBUG    start - start.c:lxc_try_preserve_namespaces:165 - Preserved user namespace via fd 16
lxc-start vpn1 20200501172901.993 DEBUG    start - start.c:lxc_try_preserve_namespaces:165 - Preserved mnt namespace via fd 17
lxc-start vpn1 20200501172901.993 DEBUG    start - start.c:lxc_try_preserve_namespaces:165 - Preserved pid namespace via fd 18
lxc-start vpn1 20200501172901.993 DEBUG    start - start.c:lxc_try_preserve_namespaces:165 - Preserved uts namespace via fd 19
lxc-start vpn1 20200501172901.993 DEBUG    start - start.c:lxc_try_preserve_namespaces:165 - Preserved ipc namespace via fd 20
lxc-start vpn1 20200501172901.993 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2642 - The binary "/usr/bin/newuidmap" does have the setuid bit set
lxc-start vpn1 20200501172901.993 DEBUG    conf - conf.c:idmaptool_on_path_and_privileged:2642 - The binary "/usr/bin/newgidmap" does have the setuid bit set
lxc-start vpn1 20200501172901.993 DEBUG    conf - conf.c:lxc_map_ids:2710 - Functional newuidmap and newgidmap binary found
lxc-start vpn1 20200501172901.998 TRACE    conf - conf.c:lxc_map_ids:2780 - newuidmap wrote mapping "newuidmap 1829 0 100000 65536"
lxc-start vpn1 20200501172902.417 TRACE    conf - conf.c:lxc_map_ids:2780 - newgidmap wrote mapping "newgidmap 1829 0 100000 65536"
lxc-start vpn1 20200501172902.546 INFO     start - start.c:do_start:1098 - Unshared CLONE_NEWNET
lxc-start vpn1 20200501172902.554 DEBUG    start - start.c:lxc_spawn:1737 - Preserved net namespace via fd 7
lxc-start vpn1 20200501172902.558 WARN     start - start.c:lxc_spawn:1742 - Operation not permitted - Failed to allocate new network namespace id
lxc-start vpn1 20200501172902.595 INFO     network - network.c:lxc_create_network_unpriv_exec:2628 - Execing lxc-user-nic create /home/lxcuser/.local/share/lxc vpn1 1829 veth br0 (null)
lxc-start vpn1 20200501172902.447 TRACE    network - network.c:lxc_create_network_unpriv_exec:2658 - Received output "eth0:2:veth1001_9Aiq:14" from lxc-user-nic
lxc-start vpn1 20200501172902.447 TRACE    network - network.c:lxc_network_send_to_child:3586 - Sent network device name "eth0" to child
lxc-start vpn1 20200501172902.448 TRACE    network - network.c:lxc_network_recv_from_parent:3613 - Received network device name "eth0" from parent
lxc-start vpn1 20200501172902.448 NOTICE   utils - utils.c:lxc_setgroups:1366 - Dropped additional groups
lxc-start vpn1 20200501172902.449 NOTICE   utils - utils.c:lxc_switch_uid_gid:1344 - Switched to gid 0
lxc-start vpn1 20200501172902.449 NOTICE   utils - utils.c:lxc_switch_uid_gid:1353 - Switched to uid 0
lxc-start vpn1 20200501172902.449 INFO     start - start.c:do_start:1211 - Unshared CLONE_NEWCGROUP
lxc-start vpn1 20200501172902.452 TRACE    conf - conf.c:remount_all_slave:3094 - Remounted all mount table entries as MS_SLAVE
lxc-start vpn1 20200501172902.452 DEBUG    storage - storage/storage.c:get_storage_by_name:211 - Detected rootfs type "dir"
lxc-start vpn1 20200501172902.452 TRACE    dir - storage/dir.c:dir_mount:165 - Mounted "/home/lxcuser/.local/share/lxc/vpn1/rootfs" on "/usr/lib/lxc/rootfs" with options "(null)", mount flags "0", and propagation flags "0"
lxc-start vpn1 20200501172902.452 DEBUG    conf - conf.c:lxc_mount_rootfs:1258 - Mounted rootfs "/home/lxcuser/.local/share/lxc/vpn1/rootfs" onto "/usr/lib/lxc/rootfs" with options "(null)"
lxc-start vpn1 20200501172902.453 INFO     conf - conf.c:setup_utsname:751 - Set hostname to "vpn1"
lxc-start vpn1 20200501172902.454 DEBUG    network - network.c:setup_hw_addr:3388 - Mac address "00:16:3e:20:90:11" on "eth0" has been setup
lxc-start vpn1 20200501172902.460 DEBUG    network - network.c:lxc_network_setup_in_child_namespaces_common:3538 - Network device "eth0" has been setup
lxc-start vpn1 20200501172902.461 INFO     network - network.c:lxc_setup_network_in_child_namespaces:3560 - Network has been setup
lxc-start vpn1 20200501172902.461 INFO     conf - conf.c:mount_autodev:1059 - Preparing "/dev"
lxc-start vpn1 20200501172902.461 DEBUG    conf - conf.c:mount_autodev:1065 - Using mount options: size=500000,mode=755
lxc-start vpn1 20200501172902.462 TRACE    conf - conf.c:mount_autodev:1085 - Mounted tmpfs on "/usr/lib/lxc/rootfs/dev"
lxc-start vpn1 20200501172902.462 INFO     conf - conf.c:mount_autodev:1108 - Prepared "/dev"
lxc-start vpn1 20200501172902.466 INFO     conf - conf.c:mount_entry:1851 - No such file or directory - Failed to mount "/sys/fs/fuse/connections" on "/usr/lib/lxc/rootfs/sys/fs/fuse/connections" (optional)
lxc-start vpn1 20200501172902.466 INFO     conf - conf.c:run_script_argv:339 - Executing script "/usr/share/lxcfs/lxc.mount.hook" for container "vpn1", config section "lxc"
lxc-start vpn1 20200501172902.599 INFO     conf - conf.c:lxc_fill_autodev:1152 - Populating "/dev"
lxc-start vpn1 20200501172902.601 DEBUG    conf - conf.c:lxc_fill_autodev:1218 - Bind mounted host device node "/dev/full" onto "/usr/lib/lxc/rootfs/dev/full"
lxc-start vpn1 20200501172902.602 DEBUG    conf - conf.c:lxc_fill_autodev:1218 - Bind mounted host device node "/dev/null" onto "/usr/lib/lxc/rootfs/dev/null"
lxc-start vpn1 20200501172902.602 DEBUG    conf - conf.c:lxc_fill_autodev:1218 - Bind mounted host device node "/dev/random" onto "/usr/lib/lxc/rootfs/dev/random"
lxc-start vpn1 20200501172902.602 DEBUG    conf - conf.c:lxc_fill_autodev:1218 - Bind mounted host device node "/dev/tty" onto "/usr/lib/lxc/rootfs/dev/tty"
lxc-start vpn1 20200501172902.603 DEBUG    conf - conf.c:lxc_fill_autodev:1218 - Bind mounted host device node "/dev/urandom" onto "/usr/lib/lxc/rootfs/dev/urandom"
lxc-start vpn1 20200501172902.603 DEBUG    conf - conf.c:lxc_fill_autodev:1218 - Bind mounted host device node "/dev/zero" onto "/usr/lib/lxc/rootfs/dev/zero"
lxc-start vpn1 20200501172902.603 INFO     conf - conf.c:lxc_fill_autodev:1222 - Populated "/dev"
lxc-start vpn1 20200501172902.603 DEBUG    conf - conf.c:lxc_setup_dev_console:1618 - Mounted pts device "/dev/pts/1" onto "/usr/lib/lxc/rootfs/dev/console"
lxc-start vpn1 20200501172902.604 INFO     utils - utils.c:lxc_mount_proc_if_needed:1200 - I am 1, /proc/self points to "1"
lxc-start vpn1 20200501172902.608 TRACE    conf - conf.c:lxc_pivot_root:1427 - pivot_root("/usr/lib/lxc/rootfs") successful
lxc-start vpn1 20200501172902.610 DEBUG    conf - conf.c:lxc_setup_devpts:1521 - Mount new devpts instance with options "gid=5,newinstance,ptmxmode=0666,mode=0620,max=1024"
lxc-start vpn1 20200501172902.610 DEBUG    conf - conf.c:lxc_setup_devpts:1536 - Created dummy "/dev/ptmx" file as bind mount target
lxc-start vpn1 20200501172902.610 DEBUG    conf - conf.c:lxc_setup_devpts:1541 - Bind mounted "/dev/pts/ptmx" to "/dev/ptmx"
lxc-start vpn1 20200501172902.611 DEBUG    conf - conf.c:lxc_allocate_ttys:938 - Created tty "/dev/pts/0" with master fd 15 and slave fd 16
lxc-start vpn1 20200501172902.612 DEBUG    conf - conf.c:lxc_allocate_ttys:938 - Created tty "/dev/pts/1" with master fd 17 and slave fd 18
lxc-start vpn1 20200501172902.613 DEBUG    conf - conf.c:lxc_allocate_ttys:938 - Created tty "/dev/pts/2" with master fd 19 and slave fd 20
lxc-start vpn1 20200501172902.614 DEBUG    conf - conf.c:lxc_allocate_ttys:938 - Created tty "/dev/pts/3" with master fd 21 and slave fd 22
lxc-start vpn1 20200501172902.614 INFO     conf - conf.c:lxc_allocate_ttys:955 - Finished creating 4 tty devices
lxc-start vpn1 20200501172902.614 TRACE    conf - conf.c:lxc_send_ttys_to_parent:996 - Sent tty "/dev/pts/0" with master fd 15 and slave fd 16 to parent
lxc-start vpn1 20200501172902.614 TRACE    conf - conf.c:lxc_send_ttys_to_parent:996 - Sent tty "/dev/pts/1" with master fd 17 and slave fd 18 to parent
lxc-start vpn1 20200501172902.614 TRACE    conf - conf.c:lxc_send_ttys_to_parent:996 - Sent tty "/dev/pts/2" with master fd 19 and slave fd 20 to parent
lxc-start vpn1 20200501172902.614 TRACE    conf - conf.c:lxc_send_ttys_to_parent:996 - Sent tty "/dev/pts/3" with master fd 21 and slave fd 22 to parent
lxc-start vpn1 20200501172902.614 TRACE    conf - conf.c:lxc_send_ttys_to_parent:1003 - Sent 4 ttys to parent
lxc-start vpn1 20200501172902.614 DEBUG    conf - conf.c:lxc_setup_ttys:893 - Bind mounted "/dev/pts/0" onto "/dev/tty1"
lxc-start vpn1 20200501172902.614 DEBUG    conf - conf.c:lxc_setup_ttys:893 - Bind mounted "/dev/pts/1" onto "/dev/tty2"
lxc-start vpn1 20200501172902.615 DEBUG    conf - conf.c:lxc_setup_ttys:893 - Bind mounted "/dev/pts/2" onto "/dev/tty3"
lxc-start vpn1 20200501172902.615 DEBUG    conf - conf.c:lxc_setup_ttys:893 - Bind mounted "/dev/pts/3" onto "/dev/tty4"
lxc-start vpn1 20200501172902.615 INFO     conf - conf.c:lxc_setup_ttys:900 - Finished setting up 4 /dev/tty<N> device(s)
lxc-start vpn1 20200501172902.615 INFO     conf - conf.c:setup_personality:1572 - Set personality to "0x0"
lxc-start vpn1 20200501172902.615 DEBUG    conf - conf.c:setup_caps:2338 - Capabilities have been setup
lxc-start vpn1 20200501172902.615 NOTICE   conf - conf.c:lxc_setup:3433 - The container "vpn1" is set up
#
# pseudo filter code start
#
# filter for arch x86_64 (3221225534)
if ($arch == 3221225534)
  # filter for syscall "finit_module" (313) [priority: 65535]
  if ($syscall == 313)
    action ERRNO(1);
  # filter for syscall "open_by_handle_at" (304) [priority: 65535]
  if ($syscall == 304)
    action ERRNO(1);
  # filter for syscall "kexec_load" (246) [priority: 65535]
  if ($syscall == 246)
    action ERRNO(1);
  # filter for syscall "delete_module" (176) [priority: 65535]
  if ($syscall == 176)
    action ERRNO(1);
  # filter for syscall "init_module" (175) [priority: 65535]
  if ($syscall == 175)
    action ERRNO(1);
  # filter for syscall "umount2" (166) [priority: 65533]
  if ($syscall == 166)
    if ($a1.hi32 & 0x00000000 == 0)
      if ($a1.lo32 & 0x00000001 == 1)
        action ERRNO(13);
  # default action
  action ALLOW;
# filter for arch x86 (1073741827)
if ($arch == 1073741827)
  # filter for syscall "finit_module" (350) [priority: 65535]
  if ($syscall == 350)
    action ERRNO(1);
  # filter for syscall "open_by_handle_at" (342) [priority: 65535]
  if ($syscall == 342)
    action ERRNO(1);
  # filter for syscall "kexec_load" (283) [priority: 65535]
  if ($syscall == 283)
    action ERRNO(1);
  # filter for syscall "delete_module" (129) [priority: 65535]
  if ($syscall == 129)
    action ERRNO(1);
  # filter for syscall "init_module" (128) [priority: 65535]
  if ($syscall == 128)
    action ERRNO(1);
  # filter for syscall "umount2" (52) [priority: 65534]
  if ($syscall == 52)
    if ($a1 & 0x00000001 == 1)
      action ERRNO(13);
  # default action
  action ALLOW;
# filter for arch x32 (3221225534)
if ($arch == 3221225534)
  # filter for syscall "kexec_load" (1073742352) [priority: 65535]
  if ($syscall == 1073742352)
    action ERRNO(1);
  # filter for syscall "finit_module" (1073742137) [priority: 65535]
  if ($syscall == 1073742137)
    action ERRNO(1);
  # filter for syscall "open_by_handle_at" (1073742128) [priority: 65535]
  if ($syscall == 1073742128)
    action ERRNO(1);
  # filter for syscall "delete_module" (1073742000) [priority: 65535]
  if ($syscall == 1073742000)
    action ERRNO(1);
  # filter for syscall "init_module" (1073741999) [priority: 65535]
  if ($syscall == 1073741999)
    action ERRNO(1);
  # filter for syscall "umount2" (1073741990) [priority: 65534]
  if ($syscall == 1073741990)
    if ($a1 & 0x00000001 == 1)
      action ERRNO(13);
  # default action
  action ALLOW;
# invalid architecture action
action KILL;
#
# pseudo filter code end
#
lxc-start vpn1 20200501172902.629 TRACE    start - start.c:lxc_spawn:1790 - Set up legacy device cgroup controller limits
lxc-start vpn1 20200501172902.629 TRACE    start - start.c:lxc_spawn:1796 - Set up cgroup2 device controller limits
lxc-start vpn1 20200501172902.629 DEBUG    start - start.c:lxc_spawn:1808 - Preserved cgroup namespace via fd 11
lxc-start vpn1 20200501172902.629 TRACE    start - start.c:lxc_spawn:1813 - Finished setting up cgroups
lxc-start vpn1 20200501172902.629 NOTICE   start - start.c:start:2041 - Exec'ing "/sbin/init"
lxc-start vpn1 20200501172902.635 TRACE    confile_utils - confile_utils.c:lxc_log_configured_netdevs:254 - index: 0
lxc-start vpn1 20200501172902.635 TRACE    confile_utils - confile_utils.c:lxc_log_configured_netdevs:255 - ifindex: 2
lxc-start vpn1 20200501172902.635 TRACE    confile_utils - confile_utils.c:lxc_log_configured_netdevs:259 - type: veth
lxc-start vpn1 20200501172902.635 TRACE    confile_utils - confile_utils.c:lxc_log_configured_netdevs:266 - veth1 : veth1001_9Aiq
lxc-start vpn1 20200501172902.635 TRACE    confile_utils - confile_utils.c:lxc_log_configured_netdevs:270 - host side ifindex for veth device: 14
lxc-start vpn1 20200501172902.635 TRACE    confile_utils - confile_utils.c:lxc_log_configured_netdevs:319 - flags: up
lxc-start vpn1 20200501172902.635 TRACE    confile_utils - confile_utils.c:lxc_log_configured_netdevs:323 - link: br0
lxc-start vpn1 20200501172902.635 TRACE    confile_utils - confile_utils.c:lxc_log_configured_netdevs:327 - l2proxy: false
lxc-start vpn1 20200501172902.635 TRACE    confile_utils - confile_utils.c:lxc_log_configured_netdevs:330 - name: eth0
lxc-start vpn1 20200501172902.635 TRACE    confile_utils - confile_utils.c:lxc_log_configured_netdevs:333 - hwaddr: 00:16:3e:20:90:11
lxc-start vpn1 20200501172902.635 TRACE    confile_utils - confile_utils.c:lxc_log_configured_netdevs:344 - ipv4 gateway auto: false
lxc-start vpn1 20200501172902.635 TRACE    confile_utils - confile_utils.c:lxc_log_configured_netdevs:347 - ipv4 gateway dev: false
lxc-start vpn1 20200501172902.636 TRACE    confile_utils - confile_utils.c:lxc_log_configured_netdevs:363 - ipv6 gateway auto: false
lxc-start vpn1 20200501172902.636 TRACE    confile_utils - confile_utils.c:lxc_log_configured_netdevs:366 - ipv6 gateway dev: false
lxc-start vpn1 20200501172902.636 TRACE    start - start.c:lxc_recv_ttys_from_child:1447 - Received pty with master fd 21 and slave fd 22 from child
lxc-start vpn1 20200501172902.636 TRACE    start - start.c:lxc_recv_ttys_from_child:1447 - Received pty with master fd 23 and slave fd 24 from child
lxc-start vpn1 20200501172902.637 TRACE    start - start.c:lxc_recv_ttys_from_child:1447 - Received pty with master fd 25 and slave fd 26 from child
lxc-start vpn1 20200501172902.637 TRACE    start - start.c:lxc_recv_ttys_from_child:1447 - Received pty with master fd 27 and slave fd 28 from child
lxc-start vpn1 20200501172902.637 TRACE    start - start.c:lxc_recv_ttys_from_child:1453 - Received 4 ttys from child
lxc-start vpn1 20200501172902.637 NOTICE   start - start.c:post_start:2052 - Started "/sbin/init" with pid "1829"
lxc-start vpn1 20200501172902.637 TRACE    lxccontainer - lxccontainer.c:wait_on_daemonized_start:856 - Container is in "RUNNING" state
lxc-start vpn1 20200501172902.640 TRACE    start - start.c:lxc_serve_state_socket_pair:491 - Sent container state "RUNNING" to 5
lxc-start vpn1 20200501172902.640 TRACE    start - start.c:lxc_serve_state_clients:427 - Set container state to RUNNING
lxc-start vpn1 20200501172902.640 TRACE    start - start.c:lxc_serve_state_clients:430 - No state clients registered
lxc-start vpn1 20200501172902.641 TRACE    start - start.c:lxc_poll:581 - Mainloop is ready
lxc-start vpn1 20200501172902.641 NOTICE   start - start.c:signal_handler:393 - Received 17 from pid 1825 instead of container init 1829
lxc-start vpn1 20200501172902.915 DEBUG    start - start.c:signal_handler:411 - Container init process 1829 exited
lxc-start vpn1 20200501172902.916 TRACE    start - start.c:lxc_poll:594 - Closed console mainloop
lxc-start vpn1 20200501172902.916 TRACE    start - start.c:lxc_poll:599 - Closed mainloop
lxc-start vpn1 20200501172902.916 TRACE    start - start.c:lxc_poll:602 - Closed signal file descriptor 8
lxc-start vpn1 20200501172902.917 INFO     error - error.c:lxc_error_set_and_log:28 - Child <1829> ended on error (255)
lxc-start vpn1 20200501172902.917 DEBUG    network - network.c:lxc_delete_network:3693 - Deleted network devices
lxc-start vpn1 20200501172902.917 TRACE    start - start.c:lxc_serve_state_clients:427 - Set container state to STOPPING
lxc-start vpn1 20200501172902.917 TRACE    start - start.c:lxc_serve_state_clients:430 - No state clients registered
lxc-start vpn1 20200501172902.918 TRACE    start - start.c:lxc_end:949 - Closed command socket
lxc-start vpn1 20200501172902.918 TRACE    start - start.c:lxc_end:960 - Set container state to "STOPPED"
lxc-start vpn1 20200501172902.127 INFO     conf - conf.c:run_script_argv:339 - Executing script "/usr/share/lxcfs/lxc.reboot.hook" for container "vpn1", config section "lxc"

You really should run with --logfile= option and post the debug log like the OP in the old thread as permission error is very generic and yes it can suggest something, but also be other things.

Think it’s something in the archlinux container. Tried pulling an ubuntu and it starts fine. :frowning: Sticking with ubuntu as my container image for now.

Anyway, your trace looks strange to me as I don’t see an user mapping (unless you launched lxc-start as root and not as ‘lxcuser’ ?)

I started it as lxcuser just a basic account… :man_shrugging:

I wonder if you actually logged-in as lxcuser or if you did sudo su lxcuser.
Because I see a # and then a $ as prompt in your posted output, that could be explained by a switching from root to a standard user in this way. This could explain the lack of user idmap in your trace.
In this case it could be interesting to try again the arch container but with logging in directly as the user.

OK - I figured it out after stepping away from it and trying fresh this morning. I had an issue in my /etc/pam.d/system-login file. I fixed the cgfs line to read like this:

session optional pam_cgfs.so -c freezer,memory,name=systemd,unified

If anyone is having the same issue on archlinux try that. I’m excited to get back to lxc things. Thanks for assistance @gpatel-fr & @stgraber have a great weekend.

1 Like