Database error: &errors.errorString{s:"No such object"} even the container is existing

Hi,

to start from the beginning:

Running:

[root@manager /]# ssh root@lxdnode -i .ssh/lxdnode-key "lxc init local:centos/6/cloud lxc1610 -s node2-lxc-filestorage -p lxc1610"

Will trigger on the lxdnode this process:

38417 ? Ssl 0:00 lxc init local:centos/6/cloud lxc1610 -s node2-lxc-filestorage -p lxc1610

But nothing happens. And i mean right nothing. lxd, started in debugging mode will print right nothing.

Now, when i press CTRL+C on the manager host who called ssh to connect to the lxdnode to start this lxc init command, the lxd debugging log will explode at an instant.

Writing:

DBUG[09-13|17:35:41] Handling                                 user= method=GET url=/1.0 ip=@
DBUG[09-13|17:35:41] 
	{
		"type": "sync",
		"status": "Success",
		"status_code": 200,
		"operation": "",
		"error_code": 0,
		"error": "",
		"metadata": {
			"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"
			],
			"api_status": "stable",
			"api_version": "1.0",
			"auth": "trusted",
			"public": false,
			"auth_methods": [
				"tls"
			],
			"environment": {
				"addresses": [],
				"architectures": [
					"x86_64",
					"i686"
				],
				"certificate": "-----BEGIN CERTIFICATE-----\nMII[....]2h8\n-----END CERTIFICATE-----\n",
				"certificate_fingerprint": "0ec634dbb5e[....]d1e6af4734cd6819d",
				"driver": "lxc",
				"driver_version": "3.2.1",
				"kernel": "Linux",
				"kernel_architecture": "x86_64",
				"kernel_features": {
					"netnsid_getifaddrs": "true",
					"seccomp_listener": "true",
					"shiftfs": "false",
					"uevent_injection": "true",
					"unpriv_fscaps": "true"
				},
				"kernel_version": "5.2.9-200.fc30.x86_64",
				"lxc_features": {
					"mount_injection_file": "true",
					"network_gateway_device_route": "true",
					"network_ipvlan": "true",
					"network_l2proxy": "true",
					"network_phys_macvlan_mtu": "true",
					"seccomp_notify": "true"
				},
				"project": "default",
				"server": "lxd",
				"server_clustered": false,
				"server_name": "lxdnode",
				"server_pid": 29869,
				"server_version": "3.17",
				"storage": "dir | zfs",
				"storage_version": "1 | 0.8.1-1"
			}
		}
	} 
DBUG[09-13|17:35:41] Handling                                 method=GET url=/1.0/containers/lxc1607 ip=@ user=
DBUG[09-13|17:35:41] Database error: &errors.errorString{s:"No such object"} 
DBUG[09-13|17:35:41] 
	{
		"error": "not found",
		"error_code": 404,
		"type": "error"
	} 

This will be printed 3 times ( the whole block ).

After this it will print:

DBUG[09-13|17:35:41] Handling                                 method=GET url="/1.0/containers?recursion=1" ip=@ user=
DBUG[09-13|17:35:41] 
	{
		"type": "sync",
		"status": "Success",
		"status_code": 200,
		"operation": "",
		"error_code": 0,
		"error": "",
		"metadata": [
			{

followed by the whole list of installed lxc containers and their config.

Of which the last one is this lxc1607 ( it was deleted, by i recreated it and hoped the “no such object” problem could be fixed this way:

			    "architecture": "x86_64",
				"config": {
					"image.architecture": "amd64",
					"image.description": "Centos 6 amd64 (20190913_07:08)",
					"image.os": "Centos",
					"image.release": "6",
					"image.serial": "20190913_07:08",
					"image.type": "squashfs",
					"volatile.apply_template": "create",
					"volatile.base_image": "813b589dbcd05568c6c9d3ce0c56bebf35703da95c47ffd2cd7a0cb2678895c6",
					"volatile.eth0.hwaddr": "00:16:3e:fc:f8:ba",
					"volatile.idmap.base": "0",
					"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": "[]"
				},
				"devices": {
					"root": {
						"path": "/",
						"pool": "node2-lxc-filestorage",
						"type": "disk"
					}
				},
				"ephemeral": false,
				"profiles": [
					"lxc1607"
				],
				"stateful": false,
				"description": "",
				"created_at": "2019-09-13T17:39:20.958987679+02:00",
				"expanded_config": {
					"image.architecture": "amd64",
					"image.description": "Centos 6 amd64 (20190913_07:08)",
					"image.os": "Centos",
					"image.release": "6",
					"image.serial": "20190913_07:08",
					"image.type": "squashfs",
					"volatile.apply_template": "create",
					"volatile.base_image": "813b589dbcd05568c6c9d3ce0c56bebf35703da95c47ffd2cd7a0cb2678895c6",
					"volatile.eth0.hwaddr": "00:16:3e:fc:f8:ba",
					"volatile.idmap.base": "0",
					"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": "[]"
				},
				"expanded_devices": {
					"eth0": {
						"host_name": "lxc1607",
						"name": "eth0",
						"nictype": "bridged",
						"parent": "ovsbr",
						"type": "nic"
					},
					"root": {
						"path": "/",
						"pool": "node2-lxc-filestorage",
						"type": "disk"
					}
				},
				"name": "lxc1607",
				"status": "Stopped",
				"status_code": 102,
				"last_used_at": "1970-01-01T01:00:00+01:00",
				"location": "none"
			}
		]
	} 
DBUG[09-13|17:41:03] Handling                                 method=GET url="/1.0/containers/lxc1607/snapshots?recursion=1" ip=@ user=
DBUG[09-13|17:41:03] 
	{
		"type": "sync",
		"status": "Success",
		"status_code": 200,
		"operation": "",
		"error_code": 0,
		"error": "",
		"metadata": []
	} 

I dont know how this happend. The setup worked for 2 months now fine and suddenly lxd init refused to create instances, if its started via ssh.

If its started locally, while logged in into lxdnode calling the identical command it will work as expected:

lxc init local:centos/6/cloud lxc1610 -s node2-lxc-filestorage -p lxc1610
Creating lxc1610

DBUG[09-13|17:52:09] Handling                                 method=GET url=/1.0 ip=@ user=
DBUG[09-13|17:52:09] 
	{
		"type": "sync",
		"status": "Success",
		"status_code": 200,
		"operation": "",
		"error_code": 0,
		"error": "",
		"metadata": {
			"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"
			],
			"api_status": "stable",
			"api_version": "1.0",
			"auth": "trusted",
			"public": false,
			"auth_methods": [
				"tls"
			],
			"environment": {
				"addresses": [],
				"architectures": [
					"x86_64",
					"i686"
				],
				"certificate": "-----BEGIN CERTIFICATE-----\nMIIC[...]kdz2h8\n-----END CERTIFICATE-----\n",
				"certificate_fingerprint": "0ec634dbb5ecba71d5dc70533c720beeefea828f9d75edbd1e6af4734cd6819d",
				"driver": "lxc",
				"driver_version": "3.2.1",
				"kernel": "Linux",
				"kernel_architecture": "x86_64",
				"kernel_features": {
					"netnsid_getifaddrs": "true",
					"seccomp_listener": "true",
					"shiftfs": "false",
					"uevent_injection": "true",
					"unpriv_fscaps": "true"
				},
				"kernel_version": "5.2.9-200.fc30.x86_64",
				"lxc_features": {
					"mount_injection_file": "true",
					"network_gateway_device_route": "true",
					"network_ipvlan": "true",
					"network_l2proxy": "true",
					"network_phys_macvlan_mtu": "true",
					"seccomp_notify": "true"
				},
				"project": "default",
				"server": "lxd",
				"server_clustered": false,
				"server_name": "lxdnode",
				"server_pid": 29869,
				"server_version": "3.17",
				"storage": "dir | zfs",
				"storage_version": "1 | 0.8.1-1"
			}
		}
	} 
DBUG[09-13|17:52:09] Handling                                 user= method=GET url=/1.0/storage-pools/node2-lxc-filestorage ip=@
DBUG[09-13|17:52:09] 
	{
		"type": "sync",
		"status": "Success",
		"status_code": 200,
		"operation": "",
		"error_code": 0,
		"error": "",
		"metadata": {
			"config": {
				"source": "/opt/storages/node2-lxc-filestorage",
				"volatile.initial_source": "/opt/storages/node2-lxc-filestorage"
			},
			"description": "",
			"name": "node2-lxc-filestorage",
			"driver": "dir",
			"used_by": [
				"/1.0/containers/lxc1271",
				"/1.0/containers/lxc1409",
				"/1.0/containers/lxc1564",
				"/1.0/containers/lxc1565",
				"/1.0/containers/lxc1570",
				"/1.0/containers/lxc1571",
				"/1.0/containers/lxc1572",
				"/1.0/containers/lxc1573",
				"/1.0/containers/lxc1574",
				"/1.0/containers/lxc1607",
				"/1.0/profiles/lxc1271",
				"/1.0/profiles/lxc1409",
				"/1.0/profiles/lxc1564",
				"/1.0/profiles/lxc1565",
				"/1.0/profiles/lxc1570",
				"/1.0/profiles/lxc1571",
				"/1.0/profiles/lxc1572",
				"/1.0/profiles/lxc1573",
				"/1.0/profiles/lxc1574",
				"/1.0/profiles/lxc1609",
				"/1.0/profiles/lxc1610"
			],
			"status": "Created",
			"locations": [
				"none"
			]
		}
	} 
DBUG[09-13|17:52:09] Handling                                 method=GET url=/1.0/images/aliases/centos%2F6%2Fcloud ip=@ user=
DBUG[09-13|17:52:09] 
	{
		"type": "sync",
		"status": "Success",
		"status_code": 200,
		"operation": "",
		"error_code": 0,
		"error": "",
		"metadata": {
			"description": "",
			"target": "813b589dbcd05568c6c9d3ce0c56bebf35703da95c47ffd2cd7a0cb2678895c6",
			"name": "centos/6/cloud"
		}
	} 
DBUG[09-13|17:52:09] Handling                                 ip=@ user= method=GET url=/1.0/images/813b589dbcd05568c6c9d3ce0c56bebf35703da95c47ffd2cd7a0cb2678895c6
DBUG[09-13|17:52:09] 
	{
		"type": "sync",
		"status": "Success",
		"status_code": 200,
		"operation": "",
		"error_code": 0,
		"error": "",
		"metadata": {
			"auto_update": false,
			"properties": {
				"architecture": "amd64",
				"description": "Centos 6 amd64 (20190913_07:08)",
				"os": "Centos",
				"release": "6",
				"serial": "20190913_07:08",
				"type": "squashfs"
			},
			"public": false,
			"aliases": [
				{
					"name": "centos/6/cloud",
					"description": ""
				}
			],
			"architecture": "x86_64",
			"cached": false,
			"filename": "lxd.tar.xz",
			"fingerprint": "813b589dbcd05568c6c9d3ce0c56bebf35703da95c47ffd2cd7a0cb2678895c6",
			"size": 88122432,
			"update_source": {
				"alias": "centos/6/cloud",
				"certificate": "",
				"protocol": "simplestreams",
				"server": "https://images.linuxcontainers.org"
			},
			"created_at": "2019-09-13T02:00:00+02:00",
			"expires_at": "1970-01-01T01:00:00+01:00",
			"last_used_at": "2019-09-13T17:39:21.060281367+02:00",
			"uploaded_at": "2019-09-13T12:47:51.163070372+02:00"
		}
	} 
DBUG[09-13|17:52:09] Handling                                 user= method=GET url=/1.0/events ip=@
DBUG[09-13|17:52:09] New event listener: 03537041-316a-4daf-bf87-21a66c29d5fb 
DBUG[09-13|17:52:09] Handling                                 method=POST url=/1.0/containers ip=@ user=
DBUG[09-13|17:52:09] 
	{
		"architecture": "",
		"config": {},
		"devices": {
			"root": {
				"path": "/",
				"pool": "node2-lxc-filestorage",
				"type": "disk"
			}
		},
		"ephemeral": false,
		"profiles": [
			"lxc1610"
		],
		"stateful": false,
		"description": "",
		"name": "lxc1610",
		"source": {
			"type": "image",
			"certificate": "",
			"fingerprint": "813b589dbcd05568c6c9d3ce0c56bebf35703da95c47ffd2cd7a0cb2678895c6"
		},
		"instance_type": ""
	} 
DBUG[09-13|17:52:09] Responding to container create 
DBUG[09-13|17:52:09] New task operation: 5623117d-858c-4827-bf2d-dec778a9c53c 
DBUG[09-13|17:52:09] Started task operation: 5623117d-858c-4827-bf2d-dec778a9c53c 
DBUG[09-13|17:52:09] 
	{
		"type": "async",
		"status": "Operation created",
		"status_code": 100,
		"operation": "/1.0/operations/5623117d-858c-4827-bf2d-dec778a9c53c",
		"error_code": 0,
		"error": "",
		"metadata": {
			"id": "5623117d-858c-4827-bf2d-dec778a9c53c",
			"class": "task",
			"description": "Creating container",
			"created_at": "2019-09-13T17:52:09.598852825+02:00",
			"updated_at": "2019-09-13T17:52:09.598852825+02:00",
			"status": "Running",
			"status_code": 103,
			"resources": {
				"containers": [
					"/1.0/containers/lxc1610"
				]
			},
			"metadata": null,
			"may_cancel": false,
			"err": "",
			"location": "none"
		}
	} 
DBUG[09-13|17:52:09] Handling                                 method=GET url=/1.0/operations/5623117d-858c-4827-bf2d-dec778a9c53c ip=@ user=
DBUG[09-13|17:52:09] 
	{
		"type": "sync",
		"status": "Success",
		"status_code": 200,
		"operation": "",
		"error_code": 0,
		"error": "",
		"metadata": {
			"id": "5623117d-858c-4827-bf2d-dec778a9c53c",
			"class": "task",
			"description": "Creating container",
			"created_at": "2019-09-13T17:52:09.598852825+02:00",
			"updated_at": "2019-09-13T17:52:09.598852825+02:00",
			"status": "Running",
			"status_code": 103,
			"resources": {
				"containers": [
					"/1.0/containers/lxc1610"
				]
			},
			"metadata": null,
			"may_cancel": false,
			"err": "",
			"location": "none"
		}
	} 
INFO[09-13|17:52:09] Creating container                       project=default name=lxc1610 ephemeral=false
INFO[09-13|17:52:09] Created container                        project=default name=lxc1610 ephemeral=false
DBUG[09-13|17:52:09] Creating DIR storage volume for container "lxc1610" on storage pool "node2-lxc-filestorage" 
DBUG[09-13|17:52:09] Mounting DIR storage pool "node2-lxc-filestorage" 
DBUG[09-13|17:52:10] Created DIR storage volume for container "lxc1610" on storage pool "node2-lxc-filestorage" 
DBUG[09-13|17:52:10] Mounting DIR storage pool "node2-lxc-filestorage" 
DBUG[09-13|17:52:10] Success for task operation: 5623117d-858c-4827-bf2d-dec778a9c53c 
DBUG[09-13|17:52:10] Handling                                 method=GET url=/1.0/containers/lxc1610 ip=@ user=
DBUG[09-13|17:52:10] 
	{
		"type": "sync",
		"status": "Success",
		"status_code": 200,
		"operation": "",
		"error_code": 0,
		"error": "",
		"metadata": {
			"architecture": "x86_64",
			"config": {
				"image.architecture": "amd64",
				"image.description": "Centos 6 amd64 (20190913_07:08)",
				"image.os": "Centos",
				"image.release": "6",
				"image.serial": "20190913_07:08",
				"image.type": "squashfs",
				"volatile.apply_template": "create",
				"volatile.base_image": "813b589dbcd05568c6c9d3ce0c56bebf35703da95c47ffd2cd7a0cb2678895c6",
				"volatile.eth0.hwaddr": "00:16:3e:b3:da:29",
				"volatile.idmap.base": "0",
				"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": "[]"
			},
			"devices": {
				"root": {
					"path": "/",
					"pool": "node2-lxc-filestorage",
					"type": "disk"
				}
			},
			"ephemeral": false,
			"profiles": [
				"lxc1610"
			],
			"stateful": false,
			"description": "",
			"created_at": "2019-09-13T17:52:09.623372307+02:00",
			"expanded_config": {
				"image.architecture": "amd64",
				"image.description": "Centos 6 amd64 (20190913_07:08)",
				"image.os": "Centos",
				"image.release": "6",
				"image.serial": "20190913_07:08",
				"image.type": "squashfs",
				"volatile.apply_template": "create",
				"volatile.base_image": "813b589dbcd05568c6c9d3ce0c56bebf35703da95c47ffd2cd7a0cb2678895c6",
				"volatile.eth0.hwaddr": "00:16:3e:b3:da:29",
				"volatile.idmap.base": "0",
				"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": "[]"
			},
			"expanded_devices": {
				"eth0": {
					"host_name": "lxc1610",
					"name": "eth0",
					"nictype": "bridged",
					"parent": "ovsbr",
					"type": "nic"
				},
				"root": {
					"path": "/",
					"pool": "node2-lxc-filestorage",
					"type": "disk"
				}
			},
			"name": "lxc1610",
			"status": "Stopped",
			"status_code": 102,
			"last_used_at": "1970-01-01T01:00:00+01:00",
			"location": "none"
		}
	} 

So, i have no idea why lxd init works, if you first login into the node, and then issue the command, and does not work if you run the command on an ssh session ( by the way i also tried to combine it with bash --login -c ).

But it seems to me, that something in the lxd database gone quiet wrong.

I already experience this behaviour now already on 3 different hosts out of 10 hosts ( all run with snap 3.17 ) that run since around 1/2 year.

So at some point something with adding/removing containers must go wrong in the database, and i will now start to check out the database in detail, but to me it feels like there is somewhere a bug. So i report it and hope we can find it before it bites others too.

Greetings
Oliver

Stupid question:

lxd sql global .sync

saves in

/var/snap/lxd/common/lxd/database/global/db.bin

the current database ( at least according to https://lxd.readthedocs.io/en/latest/database/ ) , right ?

So i wonder how this can be:

lxc list | grep lxc | awk {‘print $2’}

centos6-cloud-test
lxc1271
lxc1409
lxc1564
lxc1565
lxc1570
lxc1571
lxc1572
lxc1573
lxc1574
lxc1587
lxc1588
lxc1589
lxc1590
lxc1591
lxc1592
lxc1593
lxc1594
lxc1595
lxc1596
lxc1597
lxc1598
lxc1599
lxc1600
lxc1602
lxc1605
lxc1607
lxc1610

vs.

?

I mean according to an lxc list, there is lxc1610 and 1607. According to the sqlite dump, they dont exist.
Is lxc list somehow cached ? But even if thats the case, the lxd daemon in debugging mode delivers a json object for both of them.

Executing on the cli:

lxd sql global "select * from instances"
+-----+---------+--------------------+--------------+------+-----------+-------------------------------------+----------+-------------------------------------+-------------+------------+---------------------------+
| id  | node_id |        name        | architecture | type | ephemeral |            creation_date            | stateful |            last_use_date            | description | project_id |        expiry_date        |
+-----+---------+--------------------+--------------+------+-----------+-------------------------------------+----------+-------------------------------------+-------------+------------+---------------------------+
| 6   | 1       | lxc1565            | 2            | 0    | 0         | 2019-08-27T19:46:09.7359248+02:00   | 0        | 2019-09-04T08:42:34.701274723+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 8   | 1       | lxc1564            | 2            | 0    | 0         | 2019-08-28T01:05:11.891020005+02:00 | 0        | 2019-09-13T17:12:32.841411541+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 12  | 1       | lxc1571            | 2            | 0    | 0         | 2019-08-29T02:53:04.612442185+02:00 | 0        | 2019-09-13T17:12:33.092665036+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 14  | 1       | lxc1570            | 2            | 0    | 0         | 2019-08-29T12:44:13.491072383+02:00 | 0        | 2019-09-11T19:23:21.890708258+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 18  | 1       | lxc1271            | 2            | 0    | 0         | 2019-08-31T01:39:13.447034288+02:00 | 0        | 2019-08-31T01:39:17.552327334+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 19  | 1       | lxc1573            | 2            | 0    | 0         | 2019-08-31T12:35:08.554247414+02:00 | 0        | 2019-09-02T19:50:56.503718427+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 36  | 1       | lxc1574            | 2            | 0    | 0         | 2019-09-05T12:07:12.854787731+02:00 | 0        | 2019-09-13T17:12:33.643146404+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 51  | 1       | lxc1587            | 2            | 0    | 0         | 2019-09-07T20:56:03.640939897+02:00 | 0        | 2019-09-07T20:56:08.810108258+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 52  | 1       | lxc1588            | 2            | 0    | 0         | 2019-09-07T20:56:14.602248036+02:00 | 0        | 2019-09-07T20:56:19.458104992+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 53  | 1       | lxc1589            | 2            | 0    | 0         | 2019-09-07T20:56:25.287790624+02:00 | 0        | 2019-09-07T20:56:30.447302036+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 54  | 1       | lxc1590            | 2            | 0    | 0         | 2019-09-07T20:56:36.208732826+02:00 | 0        | 2019-09-07T20:56:41.407568121+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 55  | 1       | lxc1591            | 2            | 0    | 0         | 2019-09-07T20:56:46.780934003+02:00 | 0        | 2019-09-07T20:56:52.02019294+02:00  |             | 1          | 0001-01-01T00:00:00Z      |
| 59  | 1       | lxc1595            | 2            | 0    | 0         | 2019-09-07T20:57:35.522095907+02:00 | 0        | 2019-09-07T20:57:40.671244933+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 60  | 1       | lxc1596            | 2            | 0    | 0         | 2019-09-07T20:57:46.528845171+02:00 | 0        | 2019-09-07T20:57:51.708030257+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 69  | 1       | lxc1597            | 2            | 0    | 0         | 2019-09-08T21:40:04.335520513+02:00 | 0        | 2019-09-13T17:12:34.663269176+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 70  | 1       | lxc1598            | 2            | 0    | 0         | 2019-09-08T21:40:16.026106735+02:00 | 0        | 2019-09-13T17:12:34.913934147+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 71  | 1       | lxc1572            | 2            | 0    | 0         | 2019-09-08T21:58:13.270442667+02:00 | 0        | 2019-09-13T17:12:33.35662521+02:00  |             | 1          | 0001-01-01T00:00:00Z      |
| 76  | 1       | lxc1600            | 2            | 0    | 0         | 2019-09-10T13:50:04.149856301+02:00 | 0        | 2019-09-13T17:12:35.409025449+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 92  | 1       | lxc1602            | 2            | 0    | 0         | 2019-09-12T01:41:11.570367327+02:00 | 0        | 2019-09-13T13:16:54.578621525+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 94  | 1       | lxc1409            | 2            | 0    | 0         | 2019-09-12T02:27:12.634923627+02:00 | 0        | 2019-09-13T17:12:40.453958614+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 95  | 1       | lxc1605            | 2            | 0    | 0         | 2019-09-12T14:40:04.062797439+02:00 | 0        | 2019-09-13T17:12:35.665618871+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 96  | 1       | lxc1592            | 2            | 0    | 0         | 2019-09-12T16:54:11.845161788+02:00 | 0        | 2019-09-13T17:12:33.920391974+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 98  | 1       | lxc1593            | 2            | 0    | 0         | 2019-09-12T17:30:11.969022696+02:00 | 0        | 2019-09-13T17:12:34.168866069+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 100 | 1       | lxc1599            | 2            | 0    | 0         | 2019-09-12T17:44:11.68134028+02:00  | 0        | 2019-09-13T17:12:35.161754434+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 101 | 1       | lxc1594            | 2            | 0    | 0         | 2019-09-12T18:19:12.0015039+02:00   | 0        | 2019-09-13T17:12:34.411033971+02:00 |             | 1          | 0001-01-01T00:00:00Z      |
| 102 | 1       | centos6-cloud-test | 2            | 0    | 0         | 2019-09-13T12:41:43.099145788+02:00 | 0        | 2019-09-13T17:12:32.56573769+02:00  |             | 1          | 0001-01-01T00:53:28+00:53 |
| 105 | 1       | lxc1607            | 2            | 0    | 0         | 2019-09-13T17:39:20.958987679+02:00 | 0        | 1970-01-01T01:00:00+01:00           |             | 1          | 0001-01-01T00:53:28+00:53 |
| 106 | 1       | lxc1610            | 2            | 0    | 0         | 2019-09-13T17:52:09.623372307+02:00 | 0        | 1970-01-01T01:00:00+01:00           |             | 1          | 0001-01-01T00:53:28+00:53 |
+-----+---------+--------------------+--------------+------+-----------+-------------------------------------+----------+-------------------------------------+-------------+------------+---------------------------+

Shows them ( with a fu**ed up creation timestamp ). ( The cli command was before i executed the lxd sql global .sync

And when trying to delete lxc1610:

DBUG[09-13|21:19:38] Handling                                 user= method=GET url=/1.0/events ip=@
DBUG[09-13|21:19:38] New event listener: 78dd6134-bb4a-4bfd-9d95-0a8de51aa050 
DBUG[09-13|21:19:38] Handling                                 method=DELETE url=/1.0/containers/lxc1610 ip=@ user=
DBUG[09-13|21:19:38] New task operation: c2472d7d-01c8-4088-bc2c-5aeed580c0e8 
DBUG[09-13|21:19:38] Started task operation: c2472d7d-01c8-4088-bc2c-5aeed580c0e8 
INFO[09-13|21:19:38] Deleting container                       project=default name=lxc1610 created=2019-09-13T17:52:09+0200 ephemeral=false used=1970-01-01T01:00:00+0100
DBUG[09-13|21:19:38] 
	{
		"type": "async",
		"status": "Operation created",
		"status_code": 100,
		"operation": "/1.0/operations/c2472d7d-01c8-4088-bc2c-5aeed580c0e8",
		"error_code": 0,
		"error": "",
		"metadata": {
			"id": "c2472d7d-01c8-4088-bc2c-5aeed580c0e8",
			"class": "task",
			"description": "Deleting container",
			"created_at": "2019-09-13T21:19:38.17111002+02:00",
			"updated_at": "2019-09-13T21:19:38.17111002+02:00",
			"status": "Running",
			"status_code": 103,
			"resources": {
				"containers": [
					"/1.0/containers/lxc1610"
				]
			},
			"metadata": null,
			"may_cancel": false,
			"err": "",
			"location": "none"
		}
	} 
DBUG[09-13|21:19:38] Handling                                 method=GET url=/1.0/operations/c2472d7d-01c8-4088-bc2c-5aeed580c0e8 ip=@ user=
DBUG[09-13|21:19:38] 
	{
		"type": "sync",
		"status": "Success",
		"status_code": 200,
		"operation": "",
		"error_code": 0,
		"error": "",
		"metadata": {
			"id": "c2472d7d-01c8-4088-bc2c-5aeed580c0e8",
			"class": "task",
			"description": "Deleting container",
			"created_at": "2019-09-13T21:19:38.17111002+02:00",
			"updated_at": "2019-09-13T21:19:38.17111002+02:00",
			"status": "Running",
			"status_code": 103,
			"resources": {
				"containers": [
					"/1.0/containers/lxc1610"
				]
			},
			"metadata": null,
			"may_cancel": false,
			"err": "",
			"location": "none"
		}
	} 
DBUG[09-13|21:19:38] Deleting DIR storage volume for container "lxc1610" on storage pool "node2-lxc-filestorage" 
DBUG[09-13|21:19:38] Mounting DIR storage pool "node2-lxc-filestorage" 
EROR[09-13|21:19:38] Failed deleting container storage        name=lxc1610 err="error removing /var/snap/lxd/common/lxd/storage-pools/node2-lxc-filestorage/containers/lxc1610: "
DBUG[09-13|21:19:38] Failure for task operation: c2472d7d-01c8-4088-bc2c-5aeed580c0e8: error removing /var/snap/lxd/common/lxd/storage-pools/node2-lxc-filestorage/containers/lxc1610:
EROR[09-13|21:19:38] Failed deleting container storage        name=lxc1610 err="error removing /var/snap/lxd/common/lxd/storage-pools/node2-lxc-filestorage/containers/lxc1610: "

That’s the actual error. For the database, you shouldn’t read the .bin directly, this is a cache file used internally by dqlite, it is not the actual database being read on startup (and can in fact be deleted with no issue). You should use lxd sql global .dump if you really want to see what’s in it right now.

The timestamps look correct above, unless your containers were created at some other time?

The error is unfortunately truncated due to a bug we’ve since fixed, so we can’t actually tell what’s going on. The fix for the error message is in the candidate channel and will be rolled out to stable users on Monday, at which point the error should be more informative.

Hi,

well a timestamp like

1970-01-01T01:00:00+01:00

looks to me a bit strange.

Thank you for your clarification with the dump !


As to the monday push:

Can it be forseen, that in case i just switch to candidate right now with

snap refresh --candidate

something will go badly wrong ? I mean in terms of there is unfinished code that will currently just explode right in tht face if used ?

Otherwise, if candidate is equal to the last stable with additional patches, i guess i could also switch right now.
Maybe we can use this 2 days to get an idea of the real problem behind it.

Switching to candidate is fine and will let you get the clearer error message earlier.

The 1970 timestamp is just the 0 timestamp to indicate that the entry has never been used. We have a few variants of such 0 timestamps as you can see, it can be a POSIX 0 Epoch (1970-01-01) or be 0001-01-01

Hi,

thank for the clearification.

snap refresh --candidate lxd
lxd (candidate) 3.17 from Canonical✓ refreshed

lxc delete lxc1602
Error: Failed to destroy ZFS filesystem: Failed to run: zfs destroy -r lxc-vrtx-zfs-storage/containers/lxc1602: cannot destroy ‘lxc-vrtx-zfs-storage/containers/lxc1602’: dataset is busy

lxc delete lxc1610
Error: error removing /var/snap/lxd/common/lxd/storage-pools/node2-lxc-filestorage/containers/lxc1610: Failed to run: rm -Rf /var/snap/lxd/common/lxd/storage-pools/node2-lxc-filestorage/containers/lxc1610: rm: cannot remove ‘/var/snap/lxd/common/lxd/storage-pools/node2-lxc-filestorage/containers/lxc1610’: Device or resource busy

Of course lxc1602 and lxc1610 are stopped and not running.

lxc config show lxc1602
[…]
devices:
root:
path: /
pool: lxc-vrtx-zfs-storage
size: 250GB
type: disk

lxc config show lxc1610
[…]
devices:
root:
path: /
pool: node2-lxc-filestorage
type: disk

lxc storage show lxc-vrtx-zfs-storage
config:
source: lxc-vrtx-zfs-storage
volatile.initial_source: lxc-vrtx-zfs-storage
zfs.pool_name: lxc-vrtx-zfs-storage
description: “”
name: lxc-vrtx-zfs-storage
driver: zfs

lxc storage show node2-lxc-filestorage
config:
source: /opt/storages/node2-lxc-filestorage
volatile.initial_source: /opt/storages/node2-lxc-filestorage
description: “”
name: node2-lxc-filestorage
driver: dir


So we have here a zfs problem and a file storage problem.

The storage problem:

ls -lisa /var/snap/lxd/common/lxd/storage-pools/node2-lxc-filestorage/
total 0
151151608 0 drwxr-xr-x 2 root root 6 Sep 13 22:16 .
193464357 0 drwx–x--x 5 root root 88 Sep 13 22:16 …

Is empty. Thats clear, all the container data is in /opt/storages/node2-lxc-filestorage

lxc storage list

+-----------------------+-------------+--------+------------------------------------------+---------+
|         NAME          | DESCRIPTION | DRIVER |                  SOURCE                  | USED BY |
+-----------------------+-------------+--------+------------------------------------------+---------+
| lxc-vrtx-zfs-storage  |             | zfs    | lxc-vrtx-zfs-storage                     | 37      |
+-----------------------+-------------+--------+------------------------------------------+---------+
| node2-lxc-filestorage |             | dir    | /opt/storages/node2-lxc-filestorage      | 21      |
+-----------------------+-------------+--------+------------------------------------------+---------+

This worked pretty fine. I dont know why lxd suddenly searches inside of /var/snap/lxd/common/lxd/storage-pools/ for something.

ls -lisa /var/snap/lxd/common/lxd/storage-pools/

total 4
193464357 0 drwx--x--x   5 root root   88 Sep 13 22:16 .
126908787 4 drwx--x--x. 15 root root 4096 Sep 14 17:02 ..
  9227900 0 drwxr-xr-x   3 root root   24 Sep 10 11:26 local-filestorage
268946563 0 drwx--x--x   7 root root  104 Sep  7 11:44 lxc-vrtx-zfs-storage
151151608 0 drwxr-xr-x   2 root root    6 Sep 13 22:16 node2-lxc-filestorage

local-filestorage was a lxd directory storage that was deleted in the past and replaced by the node2-lxc-filestorage

So is it a problem to mount / locate the source for directory filestorages outside of the snap directory ?

I also tried to symlink it in place, but that did not solve the problem.

Again, that was working fine, for months. Never had an issue with that.


As to the zfs problem, we already have another thread open:

https://discuss.linuxcontainers.org/t/lxc-delete-result-in-failed-to-destroy-zfs-filesystem-dataset-is-busy/5728/3

By the way:

As it seems:

Version 3.16 via snap does currently not show this problems.
Version 3.17 via snap show that problems.

What was changed there that could be the cause ?

The path is likely mounted, you just can’t see it from the host’s mount namespace. That’s normal behavior for LXD when running in the snap.

Your best bet is to track down what’s holding the zfs mount, fix that, then delete should work.
Run grep lxc1610 /proc/*/mountinfo to find what processes are still holding that mount, then run nsenter -t PID-FROM-GREP -m -- umount /path/to/mount

Once the grep result is empty, the deletion should work fine, unless there are even weird kernel issues going on with the system.