{"action":"created","issue":{"url":"https://api.github.com/repos/lxc/lxd/issues/4433","repository_url":"https://api.github.com/repos/lxc/lxd","labels_url":"https://api.github.com/repos/lxc/lxd/issues/4433/labels{/name}","comments_url":"https://api.github.com/repos/lxc/lxd/issues/4433/comments","events_url":"https://api.github.com/repos/lxc/lxd/issues/4433/events","html_url":"https://github.com/lxc/lxd/issues/4433","id":312618351,"number":4433,"title":"Failed to mount rootfs (newuidmap|newgidmap binary is missing)","user":{"login":"ftwrobert","id":2131279,"avatar_url":"https://avatars3.githubusercontent.com/u/2131279?v=4","gravatar_id":"","url":"https://api.github.com/users/ftwrobert","html_url":"https://github.com/ftwrobert","followers_url":"https://api.github.com/users/ftwrobert/followers","following_url":"https://api.github.com/users/ftwrobert/following{/other_user}","gists_url":"https://api.github.com/users/ftwrobert/gists{/gist_id}","starred_url":"https://api.github.com/users/ftwrobert/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/ftwrobert/subscriptions","organizations_url":"https://api.github.com/users/ftwrobert/orgs","repos_url":"https://api.github.com/users/ftwrobert/repos","events_url":"https://api.github.com/users/ftwrobert/events{/privacy}","received_events_url":"https://api.github.com/users/ftwrobert/received_events","type":"User","site_admin":false},"labels":[{"id":145665855,"url":"https://api.github.com/repos/lxc/lxd/labels/Incomplete","name":"Incomplete","color":"5319e7","default":false}],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":1,"created_at":"2018-04-09T17:27:39Z","updated_at":"2018-04-09T17:38:02Z","closed_at":null,"author_association":"NONE","body":"# Required information\r\n\r\n * Distribution: Ubuntu\r\n * Distribution version: 16.04.4 LTS (Xenial Xerus)\r\n * The output of \"lxc info\":\r\nrobertj@vh3:~$ lxc info\r\nconfig:\r\n  core.https_address: <removed>:8443\r\n  core.trust_password: true\r\napi_extensions:\r\n- storage_zfs_remove_snapshots\r\n- container_host_shutdown_timeout\r\n- container_stop_priority\r\n- container_syscall_filtering\r\n- auth_pki\r\n- container_last_used_at\r\n- etag\r\n- patch\r\n- usb_devices\r\n- https_allowed_credentials\r\n- image_compression_algorithm\r\n- directory_manipulation\r\n- container_cpu_time\r\n- storage_zfs_use_refquota\r\n- storage_lvm_mount_options\r\n- network\r\n- profile_usedby\r\n- container_push\r\n- container_exec_recording\r\n- certificate_update\r\n- container_exec_signal_handling\r\n- gpu_devices\r\n- container_image_properties\r\n- migration_progress\r\n- id_map\r\n- network_firewall_filtering\r\n- network_routes\r\n- storage\r\n- file_delete\r\n- file_append\r\n- network_dhcp_expiry\r\n- storage_lvm_vg_rename\r\n- storage_lvm_thinpool_rename\r\n- network_vlan\r\n- image_create_aliases\r\n- container_stateless_copy\r\n- container_only_migration\r\n- storage_zfs_clone_copy\r\n- unix_device_rename\r\n- storage_lvm_use_thinpool\r\n- storage_rsync_bwlimit\r\n- network_vxlan_interface\r\n- storage_btrfs_mount_options\r\n- entity_description\r\n- image_force_refresh\r\n- storage_lvm_lv_resizing\r\n- id_map_base\r\n- file_symlinks\r\n- container_push_target\r\n- network_vlan_physical\r\n- storage_images_delete\r\n- container_edit_metadata\r\n- container_snapshot_stateful_migration\r\n- storage_driver_ceph\r\n- storage_ceph_user_name\r\n- resource_limits\r\n- storage_volatile_initial_source\r\n- storage_ceph_force_osd_reuse\r\n- storage_block_filesystem_btrfs\r\n- resources\r\n- kernel_limits\r\n- storage_api_volume_rename\r\n- macaroon_authentication\r\n- network_sriov\r\n- console\r\n- restrict_devlxd\r\n- migration_pre_copy\r\n- infiniband\r\n- maas_network\r\n- devlxd_events\r\n- proxy\r\n- network_dhcp_gateway\r\n- file_get_symlink\r\n- network_leases\r\n- unix_device_hotplug\r\n- storage_api_local_volume_handling\r\n- operation_description\r\n- clustering\r\n- event_lifecycle\r\n- storage_api_remote_volume_handling\r\n- nvidia_runtime\r\napi_status: stable\r\napi_version: \"1.0\"\r\nauth: trusted\r\npublic: false\r\nauth_methods:\r\n- tls\r\nenvironment:\r\n  addresses:\r\n  - <removed>:8443\r\n  architectures:\r\n  - x86_64\r\n  - i686\r\n  certificate: |\r\n    -----BEGIN CERTIFICATE-----\r\n<removed>\r\n    -----END CERTIFICATE-----\r\n  certificate_fingerprint: 6bc0eddc9bf7c8edfbb79c9c4b805c77758cd98feecce6b3a43bdc0c8ee91634\r\n  driver: lxc\r\n  driver_version: 3.0.0\r\n  kernel: Linux\r\n  kernel_architecture: x86_64\r\n  kernel_version: 4.4.0-119-generic\r\n  server: lxd\r\n  server_pid: 23309\r\n  server_version: 3.0.0\r\n  storage: btrfs\r\n  storage_version: \"4.4\"\r\n  server_clustered: false\r\n  server_name: <removed>\r\n\r\n# Issue description\r\n\r\nThis is a new LXD host running from the snap system.\r\n\r\nInitially, this was a working system, but as of this morning, I am unable to start existing containers and am unable to launch new ones. When existing containers are stopped, they are unable to start up again.\r\n\r\n# Steps to reproduce\r\n\r\nOn three occasions now, I have uninstalled LXD entirely, reinstalled it, and reconfigured it. After some amount of time, The problem reappears. In this most recent case, I went home for the weekend with a working system and came in Monday morning with a \"broken\" system.\r\n\r\n# Information to attach\r\n\r\n\r\nrobertj@vh3:~$ lxd --version\r\n2.21\r\n\r\n\r\n\r\n\r\nrobertj@vh3:~$ lxc launch ubuntu:\r\nCreating the container\r\nContainer name is: casual-mammal\r\nStarting casual-mammal\r\nError: Failed to run: /snap/lxd/current/bin/lxd forkstart casual-mammal /var/snap/lxd/common/lxd/containers /var/snap/lxd/common/lxd/logs/casual-mammal/lxc.conf: \r\nTry `lxc info --show-log local:casual-mammal` for more info\r\n\r\n\r\n\r\n\r\nrobertj@vh3:~$ lxc info --show-log local:casual-mammal\r\nName: casual-mammal\r\nRemote: unix://\r\nArchitecture: x86_64\r\nCreated: 2018/04/09 17:20 UTC\r\nStatus: Stopped\r\nType: persistent\r\nProfiles: default\r\n\r\nLog:\r\n\r\nlxc 20180409172021.990 WARN     lxc_conf - conf.c:lxc_map_ids:2831 - newuidmap binary is missing\r\nlxc 20180409172021.990 WARN     lxc_conf - conf.c:lxc_map_ids:2837 - newgidmap binary is missing\r\nlxc 20180409172022.620 WARN     lxc_conf - conf.c:lxc_map_ids:2831 - newuidmap binary is missing\r\nlxc 20180409172022.623 WARN     lxc_conf - conf.c:lxc_map_ids:2837 - newgidmap binary is missing\r\nlxc 20180409172022.467 ERROR    dir - storage/dir.c:dir_mount:189 - Permission denied - Failed to mount \"/var/snap/lxd/common/lxd/containers/casual-mammal/rootfs\" on \"/var/snap/lxd/common/lxc/\"\r\nlxc 20180409172022.467 ERROR    lxc_conf - conf.c:lxc_setup_rootfs:1341 - Failed to mount rootfs \"/var/snap/lxd/common/lxd/containers/casual-mammal/rootfs\" onto \"/var/snap/lxd/common/lxc/\" with options \"(null)\"\r\nlxc 20180409172022.467 ERROR    lxc_conf - conf.c:do_rootfs_setup:3275 - Failed to setup rootfs for\r\nlxc 20180409172022.467 ERROR    lxc_conf - conf.c:lxc_setup:3320 - Failed to setup rootfs\r\nlxc 20180409172022.467 ERROR    lxc_start - start.c:do_start:1198 - Failed to setup container \"casual-mammal\"\r\nlxc 20180409172022.468 ERROR    lxc_sync - sync.c:__sync_wait:57 - An error occurred in another process (expected sequence number 5)\r\nlxc 20180409172022.110 ERROR    lxc_start - start.c:__lxc_start:1866 - Failed to spawn container \"casual-mammal\"\r\nlxc 20180409172022.110 ERROR    lxc_container - lxccontainer.c:wait_on_daemonized_start:824 - Received container state \"ABORTING\" instead of \"RUNNING\"\r\nlxc 20180409172022.110 WARN     lxc_conf - conf.c:lxc_map_ids:2831 - newuidmap binary is missing\r\nlxc 20180409172022.110 WARN     lxc_conf - conf.c:lxc_map_ids:2837 - newgidmap binary is missing\r\nlxc 20180409172022.112 WARN     lxc_commands - commands.c:lxc_cmd_rsp_recv:130 - Connection reset by peer - Failed to receive response for command \"get_cgroup\"\r\n\r\n\r\n\r\n\r\nrobertj@vh3:~$ lxc storage list\r\n+---------+-------------+--------+--------------------------------------+---------+\r\n|  NAME   | DESCRIPTION | DRIVER |                SOURCE                | USED BY |\r\n+---------+-------------+--------+--------------------------------------+---------+\r\n| default |             | btrfs  | 9b44aeca-d155-428e-a66a-9cf12ff38993 | 8       |\r\n+---------+-------------+--------+--------------------------------------+---------+\r\n\r\n\r\n\r\n\r\n\r\nrobertj@vh3:~$ lxc storage show default\r\nconfig:\r\n  source: 9b44aeca-d155-428e-a66a-9cf12ff38993\r\n  volatile.initial_source: /dev/md2\r\ndescription: \"\"\r\nname: default\r\ndriver: btrfs\r\nused_by:\r\n- /1.0/containers/casual-mammal\r\n- /1.0/containers/eternal-bobcat\r\n- /1.0/images/be7cec7c948958adfbb9bc7dbd292762d2388cc883466815fc2b6bc06bf06f5a\r\n- /1.0/profiles/carrier\r\n- /1.0/profiles/default\r\n- /1.0/profiles/hosted-pbx\r\n- /1.0/profiles/pubserver\r\n- /1.0/profiles/sbc\r\nstatus: Created\r\nlocations:\r\n- none\r\n\r\n\r\n\r\nrobertj@vh3:~$ sudo mdadm --misc --detail /dev/md2\r\n[sudo] password for robertj:\r\n/dev/md2:\r\n        Version : 1.2\r\n  Creation Time : Mon Mar 12 09:35:59 2018\r\n     Raid Level : raid5\r\n     Array Size : 855400448 (815.77 GiB 875.93 GB)\r\n  Used Dev Size : 427700224 (407.89 GiB 437.97 GB)\r\n   Raid Devices : 3\r\n  Total Devices : 4\r\n    Persistence : Superblock is persistent\r\n\r\n  Intent Bitmap : Internal\r\n\r\n    Update Time : Mon Mar 26 13:28:24 2018\r\n          State : clean\r\n Active Devices : 3\r\nWorking Devices : 4\r\n Failed Devices : 0\r\n  Spare Devices : 1\r\n\r\n         Layout : left-symmetric\r\n     Chunk Size : 512K\r\n\r\n           Name : vh2:2\r\n           UUID : 1e352da5:d29704f3:31848563:45ee998f\r\n         Events : 415\r\n\r\n    Number   Major   Minor   RaidDevice State\r\n       0       8        5        0      active sync   /dev/sda5\r\n       1       8       20        1      active sync   /dev/sdb4\r\n       2       8       36        2      active sync   /dev/sdc4\r\n\r\n       3       8       52        -      spare   /dev/sdd4 \r\n\r\n\r\n\r\n\r\nrobertj@vh3:~$ lxc config show casual-mammal --expanded\r\narchitecture: x86_64\r\nconfig:\r\n  image.architecture: amd64\r\n  image.description: ubuntu 16.04 LTS amd64 (release) (20180405)\r\n  image.label: release\r\n  image.os: ubuntu\r\n  image.release: xenial\r\n  image.serial: \"20180405\"\r\n  image.version: \"16.04\"\r\n  volatile.base_image: be7cec7c948958adfbb9bc7dbd292762d2388cc883466815fc2b6bc06bf06f5a\r\n  volatile.eth0.hwaddr: 00:16:3e:6e:ff:a7\r\n  volatile.eth0.name: eth0\r\n  volatile.idmap.base: \"0\"\r\n  volatile.idmap.next: '[{\"Isuid\":true,\"Isgid\":true,\"Hostid\":1000000,\"Nsid\":0,\"Maprange\":1000000000}]'\r\n  volatile.last_state.idmap: '[{\"Isuid\":true,\"Isgid\":true,\"Hostid\":1000000,\"Nsid\":0,\"Maprange\":1000000000}]'\r\n  volatile.last_state.power: STOPPED\r\ndevices:\r\n  eth0:\r\n    nictype: bridged\r\n    parent: lxdbr0\r\n    type: nic\r\n  root:\r\n    path: /\r\n    pool: default\r\n    type: disk\r\nephemeral: false\r\nprofiles:\r\n- default\r\nstateful: false\r\ndescription: \"\"\r\n\r\n\r\n\r\n\r\n\r\n\r\nrobertj@vh3:~$ sudo cat /var/snap/lxd/common/lxd/logs/lxd.log\r\nlvl=info msg=\"LXD 3.0.0 is starting in normal mode\" path=/var/snap/lxd/common/lxd t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\"Kernel uid/gid map:\" t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\" - u 0 0 4294967295\" t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\" - g 0 0 4294967295\" t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\"Configured LXD uid/gid map:\" t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\" - u 0 1000000 1000000000\" t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\" - g 0 1000000 1000000000\" t=2018-04-09T16:26:57+0000\r\nlvl=warn msg=\"CGroup memory swap accounting is disabled, swap limits will be ignored.\" t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\"Initializing database gateway\" t=2018-04-09T16:26:57+0000\r\naddress= id=1 lvl=info msg=\"Start database node\" t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\"Raft: Initial configuration (index=1): [{Suffrage:Voter ID:1 Address:0}]\" t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\"Raft: Node at 0 [Leader] entering Leader state\" t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\"LXD isn't socket activated\" t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\"Starting /dev/lxd handler:\" t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\" - binding devlxd socket\" socket=/var/snap/lxd/common/lxd/devlxd/sock t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\"REST API daemon:\" t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\" - binding Unix socket\" socket=/var/snap/lxd/common/lxd/unix.socket t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\" - binding TCP socket\" socket=66.39.177.93:8443 t=2018-04-09T16:26:57+0000\r\nlvl=info msg=\"Pruning expired images\" t=2018-04-09T16:26:58+0000\r\nlvl=info msg=\"Done pruning expired images\" t=2018-04-09T16:26:58+0000\r\nlvl=info msg=\"Expiring log files\" t=2018-04-09T16:26:58+0000\r\nlvl=info msg=\"Updating instance types\" t=2018-04-09T16:26:58+0000\r\nlvl=info msg=\"Done expiring log files\" t=2018-04-09T16:26:58+0000\r\nlvl=info msg=\"Updating images\" t=2018-04-09T16:26:58+0000\r\nlvl=info msg=\"Done updating instance types\" t=2018-04-09T16:27:01+0000\r\nlvl=info msg=\"Done updating images\" t=2018-04-09T16:27:02+0000\r\nephemeral=false lvl=info msg=\"Creating container\" name=glad-rhino t=2018-04-09T16:27:02+0000\r\nephemeral=false lvl=info msg=\"Created container\" name=glad-rhino t=2018-04-09T16:27:02+0000\r\naction=start created=2018-04-09T16:27:02+0000 ephemeral=false lvl=info msg=\"Starting container\" name=glad-rhino stateful=false t=2018-04-09T16:27:03+0000 used=1970-01-01T00:00:00+0000\r\naction=start created=2018-04-09T16:27:02+0000 ephemeral=false lvl=eror msg=\"Failed starting container\" name=glad-rhino stateful=false t=2018-04-09T16:27:04+0000 used=1970-01-01T00:00:00+0000\r\naction=stop created=2018-04-09T16:27:02+0000 ephemeral=false lvl=info msg=\"Container initiated stop\" name=glad-rhino stateful=false t=2018-04-09T16:27:04+0000 used=2018-04-09T16:27:03+0000\r\ncreated=2018-04-09T15:14:17+0000 ephemeral=false lvl=info msg=\"Deleting container\" name=enabling-escargot t=2018-04-09T16:27:10+0000 used=2018-04-09T15:14:18+0000\r\ncreated=2018-04-09T15:14:17+0000 ephemeral=false lvl=info msg=\"Deleted container\" name=enabling-escargot t=2018-04-09T16:27:10+0000 used=2018-04-09T15:14:18+0000\r\ncreated=2018-04-09T16:27:02+0000 ephemeral=false lvl=info msg=\"Deleting container\" name=glad-rhino t=2018-04-09T16:27:13+0000 used=2018-04-09T16:27:03+0000\r\ncreated=2018-04-09T16:27:02+0000 ephemeral=false lvl=info msg=\"Deleted container\" name=glad-rhino t=2018-04-09T16:27:13+0000 used=2018-04-09T16:27:03+0000\r\nephemeral=false lvl=info msg=\"Creating container\" name=eternal-bobcat t=2018-04-09T17:08:09+0000\r\nephemeral=false lvl=info msg=\"Created container\" name=eternal-bobcat t=2018-04-09T17:08:09+0000\r\naction=start created=2018-04-09T17:08:09+0000 ephemeral=false lvl=info msg=\"Starting container\" name=eternal-bobcat stateful=false t=2018-04-09T17:08:10+0000 used=1970-01-01T00:00:00+0000\r\naction=start created=2018-04-09T17:08:09+0000 ephemeral=false lvl=eror msg=\"Failed starting container\" name=eternal-bobcat stateful=false t=2018-04-09T17:08:10+0000 used=1970-01-01T00:00:00+0000\r\naction=stop created=2018-04-09T17:08:09+0000 ephemeral=false lvl=info msg=\"Container initiated stop\" name=eternal-bobcat stateful=false t=2018-04-09T17:08:11+0000 used=2018-04-09T17:08:10+0000\r\nephemeral=false lvl=info msg=\"Creating container\" name=casual-mammal t=2018-04-09T17:20:20+0000\r\nephemeral=false lvl=info msg=\"Created container\" name=casual-mammal t=2018-04-09T17:20:20+0000\r\naction=start created=2018-04-09T17:20:20+0000 ephemeral=false lvl=info msg=\"Starting container\" name=casual-mammal stateful=false t=2018-04-09T17:20:21+0000 used=1970-01-01T00:00:00+0000\r\naction=start created=2018-04-09T17:20:20+0000 ephemeral=false lvl=eror msg=\"Failed starting container\" name=casual-mammal stateful=false t=2018-04-09T17:20:22+0000 used=1970-01-01T00:00:00+0000\r\naction=stop created=2018-04-09T17:20:20+0000 ephemeral=false lvl=info msg=\"Container initiated stop\" name=casual-mammal stateful=false t=2018-04-09T17:20:22+0000 used=2018-04-09T17:20:21+0000\r\n\r\n\r\n\r\n\r\n\r\n\r\n\r\n\r\n\r\nrobertj@vh3:~$ lxc monitor \r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: 'New event listener: 254a9f91-b32e-47a0-9c19-b1cec150f2dc'\r\ntimestamp: \"2018-04-09T17:25:11.954714274Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context:\r\n    ip: '@'\r\n    method: GET\r\n    url: /1.0\r\n  level: dbug\r\n  message: handling\r\ntimestamp: \"2018-04-09T17:25:16.461650325Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: 'New event listener: cb35f90f-60b6-46df-8915-c8d5266fefa6'\r\ntimestamp: \"2018-04-09T17:25:16.468771131Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context:\r\n    ip: '@'\r\n    method: GET\r\n    url: /1.0/events\r\n  level: dbug\r\n  message: handling\r\ntimestamp: \"2018-04-09T17:25:16.468704017Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Responding to container create\r\ntimestamp: \"2018-04-09T17:25:16.46973573Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context:\r\n    ip: '@'\r\n    method: POST\r\n    url: /1.0/containers\r\n  level: dbug\r\n  message: handling\r\ntimestamp: \"2018-04-09T17:25:16.469708972Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: No name provided, creating optimum-cattle\r\ntimestamp: \"2018-04-09T17:25:16.471169211Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: 'New task operation: 0ad407b2-d4cf-4557-b4ed-2066c81f14e1'\r\ntimestamp: \"2018-04-09T17:25:16.479883019Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  class: task\r\n  created_at: \"2018-04-09T17:25:16.471194958Z\"\r\n  description: Creating container\r\n  err: \"\"\r\n  id: 0ad407b2-d4cf-4557-b4ed-2066c81f14e1\r\n  may_cancel: false\r\n  metadata: null\r\n  resources:\r\n    containers:\r\n    - /1.0/containers/optimum-cattle\r\n  status: Running\r\n  status_code: 103\r\n  updated_at: \"2018-04-09T17:25:16.471194958Z\"\r\ntimestamp: \"2018-04-09T17:25:16.479980437Z\"\r\ntype: operation\r\n\r\n\r\nmetadata:\r\n  class: task\r\n  created_at: \"2018-04-09T17:25:16.471194958Z\"\r\n  description: Creating container\r\n  err: \"\"\r\n  id: 0ad407b2-d4cf-4557-b4ed-2066c81f14e1\r\n  may_cancel: false\r\n  metadata: null\r\n  resources:\r\n    containers:\r\n    - /1.0/containers/optimum-cattle\r\n  status: Pending\r\n  status_code: 105\r\n  updated_at: \"2018-04-09T17:25:16.471194958Z\"\r\ntimestamp: \"2018-04-09T17:25:16.479924608Z\"\r\ntype: operation\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: 'Started task operation: 0ad407b2-d4cf-4557-b4ed-2066c81f14e1'\r\ntimestamp: \"2018-04-09T17:25:16.479962277Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context:\r\n    expiry: 2018-04-09 17:27:02.774967241 +0000 UTC m=+3605.364378815\r\n    server: https://cloud-images.ubuntu.com/releases\r\n  level: dbug\r\n  message: Using SimpleStreams cache entry\r\ntimestamp: \"2018-04-09T17:25:16.481644632Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context:\r\n    ip: '@'\r\n    method: GET\r\n    url: /1.0/operations/0ad407b2-d4cf-4557-b4ed-2066c81f14e1\r\n  level: dbug\r\n  message: handling\r\ntimestamp: \"2018-04-09T17:25:16.486610483Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context:\r\n    image: be7cec7c948958adfbb9bc7dbd292762d2388cc883466815fc2b6bc06bf06f5a\r\n  level: dbug\r\n  message: Image already exists in the db\r\ntimestamp: \"2018-04-09T17:25:16.487646027Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: 'Database error: &errors.errorString{s:\"sql: no rows in result set\"}'\r\ntimestamp: \"2018-04-09T17:25:16.490468144Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context:\r\n    ephemeral: \"false\"\r\n    name: optimum-cattle\r\n  level: info\r\n  message: Creating container\r\ntimestamp: \"2018-04-09T17:25:16.502593833Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Initializing a BTRFS driver.\r\ntimestamp: \"2018-04-09T17:25:16.513358277Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  action: container-updated\r\n  source: /1.0/containers/optimum-cattle\r\ntimestamp: \"2018-04-09T17:25:16.53679028Z\"\r\ntype: lifecycle\r\n\r\n\r\nmetadata:\r\n  action: container-updated\r\n  source: /1.0/containers/optimum-cattle\r\ntimestamp: \"2018-04-09T17:25:16.550312544Z\"\r\ntype: lifecycle\r\n\r\n\r\nmetadata:\r\n  action: container-updated\r\n  source: /1.0/containers/optimum-cattle\r\ntimestamp: \"2018-04-09T17:25:16.565085239Z\"\r\ntype: lifecycle\r\n\r\n\r\nmetadata:\r\n  action: container-created\r\n  source: /1.0/containers/optimum-cattle\r\ntimestamp: \"2018-04-09T17:25:16.583699431Z\"\r\ntype: lifecycle\r\n\r\n\r\nmetadata:\r\n  context:\r\n    ephemeral: \"false\"\r\n    name: optimum-cattle\r\n  level: info\r\n  message: Created container\r\ntimestamp: \"2018-04-09T17:25:16.583659967Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Mounting BTRFS storage pool \"default\".\r\ntimestamp: \"2018-04-09T17:25:16.59381703Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Creating BTRFS storage volume for container \"optimum-cattle\" on storage\r\n    pool \"default\".\r\ntimestamp: \"2018-04-09T17:25:16.593775971Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Shifting root filesystem \"/var/snap/lxd/common/lxd/containers/optimum-cattle/rootfs\"\r\n    for \"optimum-cattle\".\r\ntimestamp: \"2018-04-09T17:25:16.610099039Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Created BTRFS storage volume for container \"optimum-cattle\" on storage\r\n    pool \"default\".\r\ntimestamp: \"2018-04-09T17:25:17.507826324Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Mounting BTRFS storage pool \"default\".\r\ntimestamp: \"2018-04-09T17:25:17.520614943Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  action: container-updated\r\n  source: /1.0/containers/optimum-cattle\r\ntimestamp: \"2018-04-09T17:25:17.520585895Z\"\r\ntype: lifecycle\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Mounting BTRFS storage volume for container \"optimum-cattle\" on storage\r\n    pool \"default\".\r\ntimestamp: \"2018-04-09T17:25:17.520606188Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Mounted BTRFS storage volume for container \"optimum-cattle\" on storage\r\n    pool \"default\".\r\ntimestamp: \"2018-04-09T17:25:17.520931715Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: 'Success for task operation: 0ad407b2-d4cf-4557-b4ed-2066c81f14e1'\r\ntimestamp: \"2018-04-09T17:25:17.523109329Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  class: task\r\n  created_at: \"2018-04-09T17:25:16.471194958Z\"\r\n  description: Creating container\r\n  err: \"\"\r\n  id: 0ad407b2-d4cf-4557-b4ed-2066c81f14e1\r\n  may_cancel: false\r\n  metadata: null\r\n  resources:\r\n    containers:\r\n    - /1.0/containers/optimum-cattle\r\n  status: Success\r\n  status_code: 200\r\n  updated_at: \"2018-04-09T17:25:16.471194958Z\"\r\ntimestamp: \"2018-04-09T17:25:17.523124719Z\"\r\ntype: operation\r\n\r\n\r\nmetadata:\r\n  context:\r\n    ip: '@'\r\n    method: GET\r\n    url: /1.0/containers/optimum-cattle\r\n  level: dbug\r\n  message: handling\r\ntimestamp: \"2018-04-09T17:25:17.524013542Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: 'New event listener: c0a074e2-39c5-4f99-90e3-e579c7ca081d'\r\ntimestamp: \"2018-04-09T17:25:17.528877634Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context:\r\n    ip: '@'\r\n    method: GET\r\n    url: /1.0/events\r\n  level: dbug\r\n  message: handling\r\ntimestamp: \"2018-04-09T17:25:17.528833804Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: 'Disconnected event listener: cb35f90f-60b6-46df-8915-c8d5266fefa6'\r\ntimestamp: \"2018-04-09T17:25:17.52888293Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context:\r\n    ip: '@'\r\n    method: PUT\r\n    url: /1.0/containers/optimum-cattle/state\r\n  level: dbug\r\n  message: handling\r\ntimestamp: \"2018-04-09T17:25:17.530043166Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: 'New task operation: 37d76920-c16c-43d9-9043-70822817b1ee'\r\ntimestamp: \"2018-04-09T17:25:17.537966583Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: 'Started task operation: 37d76920-c16c-43d9-9043-70822817b1ee'\r\ntimestamp: \"2018-04-09T17:25:17.537998387Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  class: task\r\n  created_at: \"2018-04-09T17:25:17.533699541Z\"\r\n  description: Starting container\r\n  err: \"\"\r\n  id: 37d76920-c16c-43d9-9043-70822817b1ee\r\n  may_cancel: false\r\n  metadata: null\r\n  resources:\r\n    containers:\r\n    - /1.0/containers/optimum-cattle\r\n  status: Running\r\n  status_code: 103\r\n  updated_at: \"2018-04-09T17:25:17.533699541Z\"\r\ntimestamp: \"2018-04-09T17:25:17.53800634Z\"\r\ntype: operation\r\n\r\n\r\nmetadata:\r\n  class: task\r\n  created_at: \"2018-04-09T17:25:17.533699541Z\"\r\n  description: Starting container\r\n  err: \"\"\r\n  id: 37d76920-c16c-43d9-9043-70822817b1ee\r\n  may_cancel: false\r\n  metadata: null\r\n  resources:\r\n    containers:\r\n    - /1.0/containers/optimum-cattle\r\n  status: Pending\r\n  status_code: 105\r\n  updated_at: \"2018-04-09T17:25:17.533699541Z\"\r\ntimestamp: \"2018-04-09T17:25:17.537983349Z\"\r\ntype: operation\r\n\r\n\r\nmetadata:\r\n  context:\r\n    ip: '@'\r\n    method: GET\r\n    url: /1.0/operations/37d76920-c16c-43d9-9043-70822817b1ee\r\n  level: dbug\r\n  message: handling\r\ntimestamp: \"2018-04-09T17:25:17.542118779Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Initializing a BTRFS driver.\r\ntimestamp: \"2018-04-09T17:25:17.547202284Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  action: container-updated\r\n  source: /1.0/containers/optimum-cattle\r\ntimestamp: \"2018-04-09T17:25:17.554869172Z\"\r\ntype: lifecycle\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Mounting BTRFS storage pool \"default\".\r\ntimestamp: \"2018-04-09T17:25:17.556058714Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Mounting BTRFS storage volume for container \"optimum-cattle\" on storage\r\n    pool \"default\".\r\ntimestamp: \"2018-04-09T17:25:17.55604189Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Mounted BTRFS storage volume for container \"optimum-cattle\" on storage\r\n    pool \"default\".\r\ntimestamp: \"2018-04-09T17:25:17.556301449Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Mounting BTRFS storage pool \"default\".\r\ntimestamp: \"2018-04-09T17:25:17.563141244Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Mounting BTRFS storage volume for container \"optimum-cattle\" on storage\r\n    pool \"default\".\r\ntimestamp: \"2018-04-09T17:25:17.563125475Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Mounted BTRFS storage volume for container \"optimum-cattle\" on storage\r\n    pool \"default\".\r\ntimestamp: \"2018-04-09T17:25:17.563368294Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context:\r\n    action: start\r\n    created: 2018-04-09 17:25:16 +0000 UTC\r\n    ephemeral: \"false\"\r\n    name: optimum-cattle\r\n    stateful: \"false\"\r\n    used: 1970-01-01 00:00:00 +0000 UTC\r\n  level: info\r\n  message: Starting container\r\ntimestamp: \"2018-04-09T17:25:17.563408071Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context:\r\n    ip: '@'\r\n    method: GET\r\n    url: /1.0\r\n  level: dbug\r\n  message: handling\r\ntimestamp: \"2018-04-09T17:25:17.578467086Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context:\r\n    ip: '@'\r\n    method: GET\r\n    url: /internal/containers/13/onstart\r\n  level: dbug\r\n  message: handling\r\ntimestamp: \"2018-04-09T17:25:17.581942794Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Mounting BTRFS storage pool \"default\".\r\ntimestamp: \"2018-04-09T17:25:17.586020885Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Mounting BTRFS storage volume for container \"optimum-cattle\" on storage\r\n    pool \"default\".\r\ntimestamp: \"2018-04-09T17:25:17.586012105Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Initializing a BTRFS driver.\r\ntimestamp: \"2018-04-09T17:25:17.585995415Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Mounted BTRFS storage volume for container \"optimum-cattle\" on storage\r\n    pool \"default\".\r\ntimestamp: \"2018-04-09T17:25:17.586311978Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: 'Scheduler: container optimum-cattle started: re-balancing'\r\ntimestamp: \"2018-04-09T17:25:17.651935509Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: 'Scheduler: network: vethIHBVLG has been added: updating network priorities'\r\ntimestamp: \"2018-04-09T17:25:17.797826011Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  class: task\r\n  created_at: \"2018-04-09T17:25:17.533699541Z\"\r\n  description: Starting container\r\n  err: 'Failed to run: /snap/lxd/current/bin/lxd forkstart optimum-cattle /var/snap/lxd/common/lxd/containers\r\n    /var/snap/lxd/common/lxd/logs/optimum-cattle/lxc.conf: '\r\n  id: 37d76920-c16c-43d9-9043-70822817b1ee\r\n  may_cancel: false\r\n  metadata: null\r\n  resources:\r\n    containers:\r\n    - /1.0/containers/optimum-cattle\r\n  status: Failure\r\n  status_code: 400\r\n  updated_at: \"2018-04-09T17:25:17.533699541Z\"\r\ntimestamp: \"2018-04-09T17:25:17.798266077Z\"\r\ntype: operation\r\n\r\n\r\nmetadata:\r\n  context:\r\n    action: start\r\n    created: 2018-04-09 17:25:16 +0000 UTC\r\n    ephemeral: \"false\"\r\n    name: optimum-cattle\r\n    stateful: \"false\"\r\n    used: 1970-01-01 00:00:00 +0000 UTC\r\n  level: eror\r\n  message: Failed starting container\r\ntimestamp: \"2018-04-09T17:25:17.79814564Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: 'Failure for task operation: 37d76920-c16c-43d9-9043-70822817b1ee: Failed\r\n    to run: /snap/lxd/current/bin/lxd forkstart optimum-cattle /var/snap/lxd/common/lxd/containers\r\n    /var/snap/lxd/common/lxd/logs/optimum-cattle/lxc.conf: '\r\ntimestamp: \"2018-04-09T17:25:17.798223272Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: 'Disconnected event listener: c0a074e2-39c5-4f99-90e3-e579c7ca081d'\r\ntimestamp: \"2018-04-09T17:25:18.31948885Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context:\r\n    ip: '@'\r\n    method: GET\r\n    url: /1.0\r\n  level: dbug\r\n  message: handling\r\ntimestamp: \"2018-04-09T17:25:18.319429868Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context:\r\n    ip: '@'\r\n    method: GET\r\n    url: /internal/containers/13/onstop?target=stop\r\n  level: dbug\r\n  message: handling\r\ntimestamp: \"2018-04-09T17:25:18.32917656Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: Initializing a BTRFS driver.\r\ntimestamp: \"2018-04-09T17:25:18.334553448Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context:\r\n    action: stop\r\n    created: 2018-04-09 17:25:16 +0000 UTC\r\n    ephemeral: \"false\"\r\n    name: optimum-cattle\r\n    stateful: \"false\"\r\n    used: 2018-04-09 17:25:17 +0000 UTC\r\n  level: info\r\n  message: Container initiated stop\r\ntimestamp: \"2018-04-09T17:25:18.334612769Z\"\r\ntype: logging\r\n\r\n\r\nmetadata:\r\n  context: {}\r\n  level: dbug\r\n  message: 'Scheduler: container optimum-cattle stopped: re-balancing'\r\ntimestamp: \"2018-04-09T17:25:18.393908056Z\"\r\ntype: logging\r\n\r\n\r\n^C\r\nrobertj@vh3:~$ \r\n"},"comment":{"url":"https://api.github.com/repos/lxc/lxd/issues/comments/379833283","html_url":"https://github.com/lxc/lxd/issues/4433#issuecomment-379833283","issue_url":"https://api.github.com/repos/lxc/lxd/issues/4433","id":379833283,"user":{"login":"ftwrobert","id":2131279,"avatar_url":"https://avatars3.githubusercontent.com/u/2131279?v=4","gravatar_id":"","url":"https://api.github.com/users/ftwrobert","html_url":"https://github.com/ftwrobert","followers_url":"https://api.github.com/users/ftwrobert/followers","following_url":"https://api.github.com/users/ftwrobert/following{/other_user}","gists_url":"https://api.github.com/users/ftwrobert/gists{/gist_id}","starred_url":"https://api.github.com/users/ftwrobert/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/ftwrobert/subscriptions","organizations_url":"https://api.github.com/users/ftwrobert/orgs","repos_url":"https://api.github.com/users/ftwrobert/repos","events_url":"https://api.github.com/users/ftwrobert/events{/privacy}","received_events_url":"https://api.github.com/users/ftwrobert/received_events","type":"User","site_admin":false},"created_at":"2018-04-09T17:38:01Z","updated_at":"2018-04-09T17:38:01Z","author_association":"NONE","body":"I'm unable to access the mount with my user, but am able to do so as root.\r\n\r\nrobertj@vh3:~$ nsenter -t $(pgrep daemon.start) -m\r\nnsenter: cannot open /proc/23224/ns/mnt: Permission denied\r\nrobertj@vh3:~$ sudo nsenter -t $(pgrep daemon.start) -m\r\n[sudo] password for robertj: \r\nroot@vh3:/# ls -lh /var/snap/lxd/common/lxd/containers/casual-mammal/rootfs/\r\ntotal 0\r\ndrwxr-xr-x 1 1000000 1000000 2.5K Apr  5 08:20 bin\r\ndrwxr-xr-x 1 1000000 1000000    8 Apr  5 08:20 boot\r\ndrwxr-xr-x 1 1000000 1000000  882 Apr  5 08:19 dev\r\ndrwxr-xr-x 1 1000000 1000000 2.9K Apr  5 08:20 etc\r\ndrwxr-xr-x 1 1000000 1000000    0 Apr 12  2016 home\r\ndrwxr-xr-x 1 1000000 1000000  432 Apr  5 08:20 lib\r\ndrwxr-xr-x 1 1000000 1000000   40 Apr  5 08:17 lib64\r\ndrwxr-xr-x 1 1000000 1000000    0 Apr  5 08:17 media\r\ndrwxr-xr-x 1 1000000 1000000    0 Apr  5 08:17 mnt\r\ndrwxr-xr-x 1 1000000 1000000    0 Apr  5 08:17 opt\r\ndrwxr-xr-x 1 1000000 1000000    0 Apr 12  2016 proc\r\ndrwx------ 1 1000000 1000000   30 Apr  5 08:19 root\r\ndrwxr-xr-x 1 1000000 1000000   16 Apr  5 08:20 run\r\ndrwxr-xr-x 1 1000000 1000000 3.7K Apr  5 08:20 sbin\r\ndrwxr-xr-x 1 1000000 1000000    0 Nov 30 19:48 snap\r\ndrwxr-xr-x 1 1000000 1000000    0 Apr  5 08:17 srv\r\ndrwxr-xr-x 1 1000000 1000000    0 Feb  5  2016 sys\r\ndrwxrwxrwt 1 1000000 1000000    0 Apr  5 08:20 tmp\r\ndrwxr-xr-x 1 1000000 1000000   70 Apr  5 08:17 usr\r\ndrwxr-xr-x 1 1000000 1000000  108 Apr  5 08:20 var\r\n"}}
{"actor":{"display_login":"ftwrobert"}}