Can't start ephemeral containers after migrating to snap

LXD
1

I migrated my laptop to the lxd snap this morning after using the deb for many years. I previously had version 3.0.3-0ubuntu1~18.04.1 installed, and now have 3.18 from the stable channel. I ran sudo lxd.migrate and it seems to have correctly migrated all my existing containers (they’re in a ZFS pool, so it just rewrote the mountpoint property of the datasets rather than actually moving any data around).

Most things seem to work fine, but I use ephemeral copies of containers quite heavily to run Launchpad tests, and that no longer seems to work. I have a base container with the following configuration:

$ lxc config show --expanded xenial-lptest-base
architecture: i686
config:
  raw.lxc: |
    lxc.idmap = u 400000 1000 1
    lxc.idmap = g 400000 1000 1
  user.user-data: |
    #cloud-config
    runcmd:
      - "groupadd cjwatson --gid 400000"
      - "useradd cjwatson --uid 400000 --gid cjwatson --groups adm,sudo --shell /bin/bash"
      - "mkdir -p /etc/sudoers.d"
      - "echo 'cjwatson ALL=(ALL) NOPASSWD:ALL' >/etc/sudoers.d/90-cloud-init-users"
      - "chmod 0440 /etc/sudoers.d/90-cloud-init-users"
  volatile.base_image: 658d08cdd3225fbe5586a86543db8835f068880c55a8b19b078a23c367e005ea
  volatile.eth0.host_name: veth1ba64fee
  volatile.eth0.hwaddr: 00:16:3e:c5:2b:d7
  volatile.idmap.base: "0"
  volatile.idmap.current: '[{"Isuid":true,"Isgid":false,"Hostid":100000,"Nsid":0,"Maprange":65536},{"Isuid":false,"Isgid":true,"Hostid":100000,"Nsid":0,"Maprange":65536}]'
  volatile.idmap.next: '[{"Isuid":true,"Isgid":false,"Hostid":100000,"Nsid":0,"Maprange":65536},{"Isuid":false,"Isgid":true,"Hostid":100000,"Nsid":0,"Maprange":65536}]'
  volatile.last_state.idmap: '[{"Isuid":true,"Isgid":false,"Hostid":100000,"Nsid":0,"Maprange":65536},{"Isuid":false,"Isgid":true,"Hostid":100000,"Nsid":0,"Maprange":65536}]'
  volatile.last_state.power: RUNNING
  volatile.virbr0.host_name: veth16c021a9
  volatile.virbr0.hwaddr: 00:16:3e:f2:f9:e5
devices:
  eth0:
    name: eth0
    nictype: bridged
    parent: lxdbr0
    type: nic
  home:
    path: /home/cjwatson
    source: /home/cjwatson
    type: disk
  root:
    path: /
    pool: lxd
    type: disk
  virbr0:
    name: virbr0
    nictype: bridged
    parent: virbr0
    type: nic
ephemeral: false
profiles:
- default
- cjwatson
stateful: false
description: ""

If I then run lxc copy --ephemeral xenial-lptest-base xenial-lptest-45902a9a-7cb0-4ef3-bdc8-0f6ed3e758bf (the name is just from uuidgen) and then lxc start xenial-lptest-45902a9a-7cb0-4ef3-bdc8-0f6ed3e758bf, the container ostensibly starts, but then I see this in /var/snap/lxd/common/lxd/logs/lxd.log:

t=2019-12-06T13:09:58+0000 lvl=info msg="Creating container" ephemeral=true name=xenial-lptest-45902a9a-7cb0-4ef3-bdc8-0f6ed3e758bf project=default
t=2019-12-06T13:09:58+0000 lvl=info msg="Created container" ephemeral=true name=xenial-lptest-45902a9a-7cb0-4ef3-bdc8-0f6ed3e758bf project=default
t=2019-12-06T13:11:30+0000 lvl=info msg="Starting container" action=start created=2019-12-06T13:09:58+0000 ephemeral=true name=xenial-lptest-45902a9a-7cb0-4ef3-bdc8-0f6ed3e758bf project=default stateful=false used=1970-01-01T01:00:00+0100
t=2019-12-06T13:11:46+0000 lvl=info msg="Started container" action=start created=2019-12-06T13:09:58+0000 ephemeral=true name=xenial-lptest-45902a9a-7cb0-4ef3-bdc8-0f6ed3e758bf project=default stateful=false used=1970-01-01T01:00:00+0100
t=2019-12-06T13:12:01+0000 lvl=eror msg="balance: Unable to set cpuset" err="Failed to set cgroup cpuset.cpus=\"0,1,2,3\": setting cgroup item for the container failed" name=xenial-lptest-45902a9a-7cb0-4ef3-bdc8-0f6ed3e758bf value=0,1,2,3
t=2019-12-06T13:12:01+0000 lvl=eror msg="Failed to stop device 'home': Error unmounting the device path inside container: Can't remove mount from stopped container"
t=2019-12-06T13:12:02+0000 lvl=info msg="Container initiated stop" action=stop created=2019-12-06T13:09:58+0000 ephemeral=true name=xenial-lptest-45902a9a-7cb0-4ef3-bdc8-0f6ed3e758bf project=default stateful=false used=2019-12-06T13:11:31+0000
t=2019-12-06T13:12:02+0000 lvl=info msg="Deleting container" created=2019-12-06T13:09:58+0000 ephemeral=true name=xenial-lptest-45902a9a-7cb0-4ef3-bdc8-0f6ed3e758bf project=default used=2019-12-06T13:11:31+0000
t=2019-12-06T13:12:02+0000 lvl=info msg="Deleted container" created=2019-12-06T13:09:58+0000 ephemeral=true name=xenial-lptest-45902a9a-7cb0-4ef3-bdc8-0f6ed3e758bf project=default used=2019-12-06T13:11:31+0000

Help? I don’t understand what’s going on with this cgroup complaint. I can file a bug if need be, but I’m not sure whether this is a bug rather than some kind of local configuration error.

2

Do you get the same behavior when using a normal copy without --ephemeral?
It would be a bit easier to debug this if the container wasn’t getting deleted in the process :slight_smile:

Assuming you can reproduce this with a normal copy, lxc info NAME --show-log may be quite helpful.

3

The log seems to indicate the container started and ran for about 15s before PID1 died inside the container, it’s hard to tell exactly why that would be though, hopefully the lxc log will help with that.

It would also be interesting to know if the container is accessible during those 15s or so.

4

Yes, a normal copy behaves the same way:

$ lxc info xenial-lptest-e8de071a-67d2-4c05-b404-9ea0b4958c33 --show-log
Name: xenial-lptest-e8de071a-67d2-4c05-b404-9ea0b4958c33
Location: none
Remote: unix://
Architecture: i686
Created: 2019/12/06 17:11 UTC
Status: Stopped
Type: persistent
Profiles: default, cjwatson

Log:

lxc xenial-lptest-e8de071a-67d2-4c05-b404-9ea0b4958c33 20191206171122.394 ERROR    conf - conf.c:write_id_mapping:2817 - Invalid argument - Failed to write uid mapping to "/proc/21169/uid_map"
lxc xenial-lptest-e8de071a-67d2-4c05-b404-9ea0b4958c33 20191206171122.394 ERROR    conf - conf.c:lxc_map_ids:3016 - Failed to write mapping: 0 1000000 1000000000
400000 1000 1

lxc xenial-lptest-e8de071a-67d2-4c05-b404-9ea0b4958c33 20191206171122.394 ERROR    start - start.c:lxc_spawn:1801 - Failed to set up id mapping.
lxc xenial-lptest-e8de071a-67d2-4c05-b404-9ea0b4958c33 20191206171122.394 ERROR    lxccontainer - lxccontainer.c:wait_on_daemonized_start:873 - Received container state "ABORTING" instead of "RUNNING"
lxc xenial-lptest-e8de071a-67d2-4c05-b404-9ea0b4958c33 20191206171122.395 ERROR    start - start.c:__lxc_start:2039 - Failed to spawn container "xenial-lptest-e8de071a-67d2-4c05-b404-9ea0b4958c33"
lxc xenial-lptest-e8de071a-67d2-4c05-b404-9ea0b4958c33 20191206171152.431 ERROR    conf - conf.c:run_buffer:352 - Script exited with status 1
lxc xenial-lptest-e8de071a-67d2-4c05-b404-9ea0b4958c33 20191206171152.431 ERROR    start - start.c:lxc_fini:1024 - Failed to run "lxc.hook.stop" hook
lxc 20191206171152.437 WARN     commands - commands.c:lxc_cmd_rsp_recv:135 - Connection reset by peer - Failed to receive response for command "get_state"
lxc 20191206171152.437 WARN     commands - commands.c:lxc_cmd_rsp_recv:135 - Connection reset by peer - Failed to receive response for command "get_state"
lxc 20191206171152.437 WARN     commands - commands.c:lxc_cmd_rsp_recv:135 - Connection reset by peer - Failed to receive response for command "get_state"
lxc 20191206171152.437 WARN     commands - commands.c:lxc_cmd_rsp_recv:135 - Connection reset by peer - Failed to receive response for command "get_state"
lxc 20191206171152.438 WARN     commands - commands.c:lxc_cmd_rsp_recv:135 - Connection reset by peer - Failed to receive response for command "get_init_pid"

The container isn’t accessible during that period, at least as far as I can tell.

5

Ok, so that means that your raw.lxc modifying lxc.idmap is the issue.

This is most likely because prior to the switch to the snap, each container was limited to 65536 uid/gid. The snap doesn’t use the host limits so containers have far more uid/gid to play with, making your mapping collide with the default one.

I’d suggest moving your passthrough over to raw.idmap instead which then has LXD be aware of what you’re trying to do and will properly re-shuffle the map into something the kernel will accept.

6

Thanks! I switched that profile to raw.idmap: both 1000 400000 and all is well now.