canonical / lxd

Powerful system container and virtual machine manager
https://canonical.com/lxd
GNU Affero General Public License v3.0
4.38k stars 931 forks source link

Correct storage pool for snapshots is not found #6862

Closed ThomasLeister closed 4 years ago

ThomasLeister commented 4 years ago

Required information

config: {}
api_extensions:
- storage_zfs_remove_snapshots
- container_host_shutdown_timeout
- container_stop_priority
- container_syscall_filtering
- auth_pki
- container_last_used_at
- etag
- patch
- usb_devices
- https_allowed_credentials
- image_compression_algorithm
- directory_manipulation
- container_cpu_time
- storage_zfs_use_refquota
- storage_lvm_mount_options
- network
- profile_usedby
- container_push
- container_exec_recording
- certificate_update
- container_exec_signal_handling
- gpu_devices
- container_image_properties
- migration_progress
- id_map
- network_firewall_filtering
- network_routes
- storage
- file_delete
- file_append
- network_dhcp_expiry
- storage_lvm_vg_rename
- storage_lvm_thinpool_rename
- network_vlan
- image_create_aliases
- container_stateless_copy
- container_only_migration
- storage_zfs_clone_copy
- unix_device_rename
- storage_lvm_use_thinpool
- storage_rsync_bwlimit
- network_vxlan_interface
- storage_btrfs_mount_options
- entity_description
- image_force_refresh
- storage_lvm_lv_resizing
- id_map_base
- file_symlinks
- container_push_target
- network_vlan_physical
- storage_images_delete
- container_edit_metadata
- container_snapshot_stateful_migration
- storage_driver_ceph
- storage_ceph_user_name
- resource_limits
- storage_volatile_initial_source
- storage_ceph_force_osd_reuse
- storage_block_filesystem_btrfs
- resources
- kernel_limits
- storage_api_volume_rename
- macaroon_authentication
- network_sriov
- console
- restrict_devlxd
- migration_pre_copy
- infiniband
- maas_network
- devlxd_events
- proxy
- network_dhcp_gateway
- file_get_symlink
- network_leases
- unix_device_hotplug
- storage_api_local_volume_handling
- operation_description
- clustering
- event_lifecycle
- storage_api_remote_volume_handling
- nvidia_runtime
- container_mount_propagation
- container_backup
- devlxd_images
- container_local_cross_pool_handling
- proxy_unix
- proxy_udp
- clustering_join
- proxy_tcp_udp_multi_port_handling
- network_state
- proxy_unix_dac_properties
- container_protection_delete
- unix_priv_drop
- pprof_http
- proxy_haproxy_protocol
- network_hwaddr
- proxy_nat
- network_nat_order
- container_full
- candid_authentication
- backup_compression
- candid_config
- nvidia_runtime_config
- storage_api_volume_snapshots
- storage_unmapped
- projects
- candid_config_key
- network_vxlan_ttl
- container_incremental_copy
- usb_optional_vendorid
- snapshot_scheduling
- container_copy_project
- clustering_server_address
- clustering_image_replication
- container_protection_shift
- snapshot_expiry
- container_backup_override_pool
- snapshot_expiry_creation
- network_leases_location
- resources_cpu_socket
- resources_gpu
- resources_numa
- kernel_features
- id_map_current
- event_location
- storage_api_remote_volume_snapshots
- network_nat_address
- container_nic_routes
- rbac
- cluster_internal_copy
- seccomp_notify
- lxc_features
- container_nic_ipvlan
- network_vlan_sriov
- storage_cephfs
- container_nic_ipfilter
- resources_v2
- container_exec_user_group_cwd
- container_syscall_intercept
- container_disk_shift
- storage_shifted
- resources_infiniband
- daemon_storage
- instances
- image_types
- resources_disk_sata
- clustering_roles
- images_expiry
- resources_network_firmware
- backup_compression_algorithm
- ceph_data_pool_name
- container_syscall_intercept_mount
- compression_squashfs
- container_raw_mount
- container_nic_routed
- container_syscall_intercept_mount_fuse
- container_disk_ceph
- virtual-machines
- image_profiles
- clustering_architecture
- resources_disk_id
- storage_lvm_stripes
- vm_boot_priority
- unix_hotplug_devices
- api_filtering
api_status: stable
api_version: "1.0"
auth: trusted
public: false
auth_methods:
- tls
environment:
  addresses: []
  architectures:
  - x86_64
  - i686
  certificate: |
    -----BEGIN CERTIFICATE-----
    -----END CERTIFICATE-----
  certificate_fingerprint: kjadslkfhksajhfdksajhdfkjsahfdjkh
  driver: lxc
  driver_version: 3.2.1
  kernel: Linux
  kernel_architecture: x86_64
  kernel_features:
    netnsid_getifaddrs: "false"
    seccomp_listener: "false"
    seccomp_listener_continue: "false"
    shiftfs: "false"
    uevent_injection: "true"
    unpriv_fscaps: "true"
  kernel_version: 4.19.0-6-amd64
  lxc_features:
    cgroup2: "false"
    mount_injection_file: "true"
    network_gateway_device_route: "true"
    network_ipvlan: "true"
    network_l2proxy: "true"
    network_phys_macvlan_mtu: "true"
    network_veth_router: "true"
    seccomp_notify: "true"
  project: default
  server: lxd
  server_clustered: false
  server_name: lxd2
  server_pid: 4531
  server_version: "3.20"
  storage: zfs
  storage_version: 0.7.12-2+deb10u1

Issue description

When trying to create snapshots of containers which reside in storage pools other than default, the snapshot command fails:

lxc snapshot mastodon
Error: Create instance snapshot: Failed to run: zfs snapshot default/containers/mastodon@snapshot-snap111: cannot open 'default/containers/mastodon': dataset does not exist
usage:
    snapshot|snap [-r] [-o property=value] ... <filesystem|volume>@<snap> ...

For the property list, run: zfs set|get

For the delegated permission list, run: zfs allow|unallow

The lxd config command reports the correct storage pool ("mega2tbstor" - not "default"):

$ lxc config show mastodon

lxc config show mastodon
architecture: x86_64
config:
  image.architecture: amd64
  image.description: Debian stretch amd64 (20180228_03:13)
  image.os: Debian
  image.release: stretch
  image.serial: "20180228_03:13"
  snapshots.expiry: 1w
  snapshots.schedule: 0 3 */1 * *
  volatile.base_image: f9ee79ccf84f210ae77c45f967f30f2e5dcfb82fc6b6f0e98eaf204250871e33
  volatile.eth0.host_name: veth8115c14a
  volatile.eth0.hwaddr: 00:16:3e:2d:49:a4
  volatile.idmap.base: "0"
  volatile.idmap.current: '[{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.idmap.next: '[{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.last_state.idmap: '[{"Isuid":true,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.last_state.power: RUNNING
devices:
  root:
    path: /
    pool: mega2tbstor
    type: disk
ephemeral: false
profiles:
- default
stateful: false
description: ""

The "mega2tbstor" is listed as storage pool:

$ lxc storage list
+-------------+-------------+--------+-------------+---------+
|    NAME     | DESCRIPTION | DRIVER |   SOURCE    | USED BY |
+-------------+-------------+--------+-------------+---------+
| default     |             | zfs    | default     | 7840    |
+-------------+-------------+--------+-------------+---------+
| mega2tbstor |             | zfs    | mega2tbstor | 114     |
+-------------+-------------+--------+-------------+---------+

Maybe this issue has been introduced with Version 3.20?

I can reproduce the same issue with version 3.20 on another system of mine. Both have existed for at least 2 years.

stgraber commented 4 years ago

Can you show lxc storage show default and lxc storage show mega2tbstor?

I just tried to reproduce the issue here using a secondary zfs pool and I'm not getting any issues creating snapshots, which lines up with what we have in our automated testing too, so there's more to this.

stgraber commented 4 years ago

My suspicion is a bad zfs.pool_name on the mega2tbstor but we'll see.

ThomasLeister commented 4 years ago
$ lxc storage show default
config:
  source: default
  volatile.initial_source: /dev/vdb
  zfs.pool_name: default
description: ""
name: default
driver: zfs
used_by:
- /1.0/containers/ejabberd
- /1.0/containers/ejabberd/snapshots/snap102
[...]
- /1.0/containers/wordpress/snapshots/snap93
- /1.0/images/2deb9f8fc62c5b80073a6fc5970a7011373a5a58f54bd328156551c59f3dd53a
- /1.0/images/7052b75fff2dce6ca06d9bc2a0792bd782e99249cc99aa7d7d19e5837823d4e8
- /1.0/profiles/default
status: Created
locations:
- none

(I shortened the list of containers / snapshot, because it was huuuge ;-) )

$ lxc storage show mega2tbstor

config:
  source: mega2tbstor
  volatile.initial_source: mega2tbstor
  zfs.pool_name: mega2tbstor
description: ""
name: mega2tbstor
driver: zfs
used_by:
- /1.0/containers/mastodon
- /1.0/containers/mastodon/snapshots/snap1
- /1.0/containers/mastodon/snapshots/snap105
- /1.0/containers/mastodon/snapshots/snap106
- /1.0/containers/testdebian
- /1.0/images/7052b75fff2dce6ca06d9bc2a0792bd782e99249cc99aa7d7d19e5837823d4e8
status: Created
locations:
- none

(list of containers / snapshots also shortened)

stgraber commented 4 years ago

Ok, that config looks correct, I'm really not sure why it's crossing pools somehow...

Can you run lxc monitor --type=logging --pretty in a shell while running the lxc snapshot again in another?

stgraber commented 4 years ago

Ah and can you show lxc config show --expanded mastodon and lxc profile show default too for good measure?

ThomasLeister commented 4 years ago

Hi @stgraber ,

this is the Output of lxc monitor --type=logging --pretty:

$ lxc monitor --type=logging --pretty
DBUG[02-11|07:59:35] New event listener: 6f17440b-6bbd-41fc-a81c-b6a5bda3a0e7 
DBUG[02-11|07:59:45] Handling                                 ip=@ method=GET url=/1.0 user=
DBUG[02-11|07:59:45] Handling                                 url=/1.0/events user= ip=@ method=GET
DBUG[02-11|07:59:45] New event listener: 2088f556-7e81-4a45-8438-2108cf2d6ba0 
DBUG[02-11|07:59:45] Handling                                 ip=@ method=POST url=/1.0/instances/mastodon/snapshots user=
DBUG[02-11|07:59:45] New task Operation: ee823073-1b1f-4915-8060-fbb6268ffdf3 
DBUG[02-11|07:59:45] Started task operation: ee823073-1b1f-4915-8060-fbb6268ffdf3 
DBUG[02-11|07:59:45] Handling                                 user= ip=@ method=GET url=/1.0/operations/ee823073-1b1f-4915-8060-fbb6268ffdf3
INFO[02-11|07:59:45] Creating container                       ephemeral=false name=mastodon/snap116 project=default
INFO[02-11|07:59:45] Created container                        ephemeral=false name=mastodon/snap116 project=default
DBUG[02-11|07:59:45] CreateInstanceSnapshot started           pool=default project=default src=mastodon driver=zfs instance=mastodon/snap116
DBUG[02-11|07:59:45] CreateInstanceSnapshot finished          driver=zfs instance=mastodon/snap116 pool=default project=default src=mastodon
INFO[02-11|07:59:45] Deleting container                       created="2020-02-11 07:59:45.024449305 +0100 CET" ephemeral=false name=mastodon/snap116 project=default used="0001-01-01 00:00:00 +0000 UTC"
DBUG[02-11|07:59:45] Deleting instance snapshot volume        instance=mastodon/snap116 pool=default project=default snapshotName=snap116 volName=mastodon driver=zfs
DBUG[02-11|07:59:45] DeleteInstanceSnapshot started           driver=zfs instance=mastodon/snap116 pool=default project=default
DBUG[02-11|07:59:45] Failure for task operation: ee823073-1b1f-4915-8060-fbb6268ffdf3: Create instance snapshot: Failed to run: zfs snapshot default/containers/mastodon@snapshot-snap116: cannot open 'default/containers/mastodon': dataset does not exist
usage:
    snapshot|snap [-r] [-o property=value] ... <filesystem|volume>@<snap> ...

For the property list, run: zfs set|get

For the delegated permission list, run: zfs allow|unallow 
DBUG[02-11|07:59:45] DeleteInstanceSnapshot finished          driver=zfs instance=mastodon/snap116 pool=default project=default
DBUG[02-11|07:59:45] Disconnected event listener: 2088f556-7e81-4a45-8438-2108cf2d6ba0 
DBUG[02-11|07:59:45] Event listener finished: 2088f556-7e81-4a45-8438-2108cf2d6ba0 
DBUG[02-11|08:00:00] New task Operation: caa3a465-3257-4d31-87ad-1bb68e564949 
INFO[02-11|08:00:00] Pruning expired instance snapshots 
DBUG[02-11|08:00:00] Started task operation: caa3a465-3257-4d31-87ad-1bb68e564949 
INFO[02-11|08:00:00] Deleting container                       created="2020-01-17 03:00:14.778955484 +0100 CET" ephemeral=false name=mastodon/snap82 project=default used="0001-01-01 00:00:00 +0000 UTC"
INFO[02-11|08:00:00] Done pruning expired instance snapshots 
DBUG[02-11|08:00:00] DeleteInstanceSnapshot started           driver=zfs instance=mastodon/snap82 pool=default project=default
DBUG[02-11|08:00:00] Deleting instance snapshot volume        pool=default project=default snapshotName=snap82 volName=mastodon driver=zfs instance=mastodon/snap82
DBUG[02-11|08:00:00] Failure for task operation: caa3a465-3257-4d31-87ad-1bb68e564949: Failed to delete expired snapshot 'mastodon/snap82' in project 'default': Failed to run: zfs get -H -p -r -o value clones default/containers/mastodon@snapshot-snap82: cannot open 'default/containers/mastodon@snapshot-snap82': dataset does not exist 
DBUG[02-11|08:00:00] DeleteInstanceSnapshot finished          driver=zfs instance=mastodon/snap82 pool=default project=default

Output of lxc config show --expanded mastodon:

$ lxc config show --expanded mastodon
architecture: x86_64
config:
  image.architecture: amd64
  image.description: Debian stretch amd64 (20180228_03:13)
  image.os: Debian
  image.release: stretch
  image.serial: "20180228_03:13"
  snapshots.expiry: 1w
  snapshots.schedule: 0 3 */1 * *
  volatile.base_image: f9ee79ccf84f210ae77c45f967f30f2e5dcfb82fc6b6f0e98eaf204250871e33
  volatile.eth0.host_name: veth4913061a
  volatile.eth0.hwaddr: 00:16:3e:2d:49:a4
  volatile.idmap.base: "0"
  volatile.idmap.current: '[{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.idmap.next: '[{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.last_state.idmap: '[{"Isuid":true,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.last_state.power: RUNNING
devices:
  eth0:
    name: eth0
    nictype: bridged
    parent: lxdbr0
    type: nic
  root:
    path: /
    pool: mega2tbstor
    type: disk
ephemeral: false
profiles:
- default
stateful: false
description: "

Output of lxc profile show default:

$ lxc profile show default
config: {}
description: Default LXD profile
devices:
  eth0:
    name: eth0
    nictype: bridged
    parent: lxdbr0
    type: nic
  root:
    path: /
    pool: default
    type: disk
name: default
used_by:
- /1.0/instances/ejabberd
- /1.0/instances/mastodon

I noticed from the log that not only creating snapshots is affected, but also (auto-)deleting snapshots: (it's looking into the wrong pool)

Failed to delete expired snapshot 'mastodon/snap82' in project 'default': [...] cannot open 'default/containers/mastodon@snapshot-snap82': dataset does not exist

I remember that I have moved the Mastodon container from the "default" pool to the "mega2tbstor" about a year ago like this: https://discuss.linuxcontainers.org/t/how-to-move-containers-to-a-new-storage-pool-on-the-same-host/2798

Maybe that helps to keep in mind?

stgraber commented 4 years ago

Okay, that smells like a DB problem. Can you show lxd sql global "SELECT * FROM storage_volumes;"?

It sounds like you have mastodon listed in both storage pools, likely due to a much older bug from that cross pool copy. We'll need to manually cleanup those entries and then things should behave again.

@freeekanayaka has some planned work to straighten the DB model around that particular table to make such issues impossible in the future.

ThomasLeister commented 4 years ago

The original output of the SQL command was way too big ( > 7,900 lines due to https://github.com/lxc/lxd/issues/5678), so I modified it a little bit :-)

$ lxd sql global "SELECT distinct storage_pool_id FROM storage_volumes where name like 'mastodon%';"
+-----------------+
| storage_pool_id |
+-----------------+
| 1               |
| 4               |
+-----------------+

I also confirmed by reading through the original lines that there are lots and lots of mastodon/snapNN entries for storage pool 1. Storage pool 4 is the mega2tbstor pool in which the Mastodon container resides now.

How do we continue from here?

stgraber commented 4 years ago
lxd sql global "DELETE FROM storage_volumes WHERE name='mastodon' AND storage_pool_id=1";

This assumes that the storage pool with id 1 is default. You'll want to do that for any instance or snapshot that's incorrect.

ThomasLeister commented 4 years ago

Great! The issue is fixed :-) Thank you very much for your quick assistance. I was not sure if this is a bug or something very specific to my setup. Should I contact you via the LXD forums, first, or is this the correct place for incidents like this?

stgraber commented 4 years ago

Sometimes you may have a faster response on the forum (https://discuss.linuxcontainers.org) but for such weird issues, it's likely to be one of us answering anyway :)

As it's unlikely that we can track down the logic which duplicated the record and it's most likely in an old release that's now gone. I'm considering this issue closed with the planned follow-up work from @freeekanayaka that will have schema level enforcement in the near future, making such issues impossible.