@monstermunchkin please could you help with this? Thanks
I’ll take a look at this.
So I had exactly the same issue as @DanielBull, with btrfs also. I had to manually delete the containers, their snapshots via btrfs, remove reference in LXD database (via lxd sql). Now, with 5.1, initial copy and subsequent refreshes work.
Thank you to LXD team and to Daniel for the advices and fixes !
This looks like the source server is crashing. Could you please enable debug log (snap set daemon.debug=true) and paste the log?
Hello Thomas,
when i execute the above copy command the following lines are written to the log:
I think your guess is right.
panic: runtime error: slice bounds out of range [:-1]
LXD failed with return code 2
2022-05-05T08:28:44+02:00 lxd.daemon[441075]: time="2022-05-05T08:28:44+02:00" level=debug msg="MigrateInstance started" args="&{archive [] {ZFS [migration_header compress]} true true false <nil> false true}" instance=archive project=default
2022-05-05T08:28:44+02:00 lxd.daemon[441075]: time="2022-05-05T08:28:44+02:00" level=debug msg="MigrateInstance finished" args="&{archive [] {ZFS [migration_header compress]} true true false map[filesystem:dpool/lxd/containers/archive@migration-e049046a-1feb-49fa-87d8-0ec8b4b9fe44] false true}" instance=archive project=default
2022-05-05T08:28:44+02:00 lxd.daemon[441075]: time="2022-05-05T08:28:44+02:00" level=debug msg="MigrateInstance started" args="&{archive [] {ZFS [migration_header compress]} true true true map[filesystem:dpool/lxd/containers/archive@migration-e049046a-1feb-49fa-87d8-0ec8b4b9fe44] false true}" instance=archive project=default
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: time="2022-05-05T08:28:45+02:00" level=debug msg="MigrateInstance finished" args="&{archive [] {ZFS [migration_header compress]} true true true map[filesystem:dpool/lxd/containers/archive@migration-e049046a-1feb-49fa-87d8-0ec8b4b9fe44] false true}" instance=archive project=default
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: panic: runtime error: slice bounds out of range [:-1]
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: goroutine 7832 [running]:
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: io.ReadAll({0x7f5de0516e70, 0xc0016a5d80})
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: /snap/go/9605/src/io/io.go:646 +0x197
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: io/ioutil.ReadAll(...)
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: /snap/go/9605/src/io/ioutil/ioutil.go:27
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: github.com/lxc/lxd/lxd/storage/drivers.(*zfs).MigrateVolume(0xc0004c2a50, {{0xc00127e470, 0x7}, {0xc000fe0af0, 0x7}, 0xc000f40360, {0x188a56e, 0xa}, {0x188a9ce, 0xa}, ...}, ...)
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: /build/lxd/parts/lxd/src/lxd/storage/drivers/driver_zfs_volumes.go:1900 +0x672
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: github.com/lxc/lxd/lxd/storage.(*lxdBackend).MigrateInstance(0xc000377a40, {0x1baf778, 0xc0004c0000}, {0x1b96140, 0xc0016a5d80}, 0xc000a40f80, 0x0?)
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: /build/lxd/parts/lxd/src/lxd/storage/backend_lxd.go:2176 +0x753
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: main.(*migrationSourceWs).Do(0xc000238a00, 0xc0003fe420, 0x0?)
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: /build/lxd/parts/lxd/src/lxd/migrate_instance.go:712 +0x1850
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: main.instancePost.func5(0x0?)
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: /build/lxd/parts/lxd/src/lxd/instance_post.go:315 +0x45
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: github.com/lxc/lxd/lxd/operations.(*Operation).Run.func1(0xc0003be360, 0xc00175a200?)
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: /build/lxd/parts/lxd/src/lxd/operations/operations.go:280 +0x42
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: created by github.com/lxc/lxd/lxd/operations.(*Operation).Run
2022-05-05T08:28:45+02:00 lxd.daemon[441075]: /build/lxd/parts/lxd/src/lxd/operations/operations.go:279 +0x118
2022-05-05T08:28:45+02:00 lxd.daemon[440924]: => LXD failed with return code 2
Thanks, I’ve reopened Optimized refresh broken · Issue #10186 · lxc/lxd · GitHub with your stack trace.
With 5.2 still issues with the migration statment above. Same Error 1006.
Debug log on source:
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0 username=root
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: - (error decoding original message: message key "MESSAGE" truncated)
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0/instances/archive username=root
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=debug msg="WriteJSON\n\t{\n\t\t\"type\": \"sync\",\n\t\t\"status\": \"Success\",\n\t\t\"status_code\": 200,\n\t\t\"operation\": \"\",\n\t\t\"error_code\": 0,\n\t\t\"error\": \"\",\n\t\t\"metadata\": {\n\t\t\t\"architecture\": \"x86_64\",\n\t\t\t\"config\": {\n\t\t\t\t\"boot.autostart\": \"true\",\n\t\t\t\t\"image.architecture\": \"amd64\",\n\t\t\t\t\"image.description\": \"Debian buster amd64 (20200819_05:24)\",\n\t\t\t\t\"image.os\": \"Debian\",\n\t\t\t\t\"image.release\": \"buster\",\n\t\t\t\t\"image.serial\": \"20200819_05:24\",\n\t\t\t\t\"image.type\": \"squashfs\",\n\t\t\t\t\"raw.apparmor\": \"mount fstype=nfs,\",\n\t\t\t\t\"security.nesting\": \"true\",\n\t\t\t\t\"security.privileged\": \"true\",\n\t\t\t\t\"snapshots.expiry\": \"1w\",\n\t\t\t\t\"snapshots.pattern\": \"snapshot-%d\",\n\t\t\t\t\"snapshots.schedule\": \"0 0 * * *\",\n\t\t\t\t\"snapshots.schedule.stopped\": \"false\",\n\t\t\t\t\"volatile.base_image\": \"aa68be27609634dffd06ef1510bd7ba97cd5d511d93992c0cb8b9e036cd7fa17\",\n\t\t\t\t\"volatile.eth0.host_name\": \"veth5698a127\",\n\t\t\t\t\"volatile.eth0.hwaddr\": \"00:16:3e:d9:2c:0e\",\n\t\t\t\t\"volatile.idmap.base\": \"0\",\n\t\t\t\t\"volatile.idmap.current\": \"[]\",\n\t\t\t\t\"volatile.idmap.next\": \"[]\",\n\t\t\t\t\"volatile.last_state.idmap\": \"[]\",\n\t\t\t\t\"volatile.last_state.power\": \"RUNNING\",\n\t\t\t\t\"volatile.uuid\": \"9d4b4276-ee24-424c-84ca-aa197bd2e0fa\"\n\t\t\t},\n\t\t\t\"devices\": {\n\t\t\t\t\"archive-data\": {\n\t\t\t\t\t\"path\": \"/data\",\n\t\t\t\t\t\"source\": \"/dpool/archive-data\",\n\t\t\t\t\t\"type\": \"disk\"\n\t\t\t\t},\n\t\t\t\t\"root\": {\n\t\t\t\t\t\"path\": \"/\",\n\t\t\t\t\t\"pool\": \"default\",\n\t\t\t\t\t\"size\": \"20GB\",\n\t\t\t\t\t\"type\": \"disk\"\n\t\t\t\t}\n\t\t\t},\n\t\t\t\"ephemeral\": false,\n\t\t\t\"profiles\": [\n\t\t\t\t\"default\"\n\t\t\t],\n\t\t\t\"stateful\": false,\n\t\t\t\"description\": \"\",\n\t\t\t\"created_at\": \"2021-04-27T19:27:25.6299956+02:00\",\n\t\t\t\"expanded_config\": {\n\t\t\t\t\"boot.autostart\": \"true\",\n\t\t\t\t\"image.architecture\": \"amd64\",\n\t\t\t\t\"image.description\": \"Debian buster amd64 (20200819_05:24)\",\n\t\t\t\t\"image.os\": \"Debian\",\n\t\t\t\t\"image.release\": \"buster\",\n\t\t\t\t\"image.serial\": \"20200819_05:24\",\n\t\t\t\t\"image.type\": \"squashfs\",\n\t\t\t\t\"raw.apparmor\": \"mount fstype=nfs,\",\n\t\t\t\t\"security.nesting\": \"true\",\n\t\t\t\t\"security.privileged\": \"true\",\n\t\t\t\t\"snapshots.expiry\": \"1w\",\n\t\t\t\t\"snapshots.pattern\": \"snapshot-%d\",\n\t\t\t\t\"snapshots.schedule\": \"0 0 * * *\",\n\t\t\t\t\"snapshots.schedule.stopped\": \"false\",\n\t\t\t\t\"volatile.base_image\": \"aa68be27609634dffd06ef1510bd7ba97cd5d511d93992c0cb8b9e036cd7fa17\",\n\t\t\t\t\"volatile.eth0.host_name\": \"veth5698a127\",\n\t\t\t\t\"volatile.eth0.hwaddr\": \"00:16:3e:d9:2c:0e\",\n\t\t\t\t\"volatile.idmap.base\": \"0\",\n\t\t\t\t\"volatile.idmap.current\": \"[]\",\n\t\t\t\t\"volatile.idmap.next\": \"[]\",\n\t\t\t\t\"volatile.last_state.idmap\": \"[]\",\n\t\t\t\t\"volatile.last_state.power\": \"RUNNING\",\n\t\t\t\t\"volatile.uuid\": \"9d4b4276-ee24-424c-84ca-aa197bd2e0fa\"\n\t\t\t},\n\t\t\t\"expanded_devices\": {\n\t\t\t\t\"archive-data\": {\n\t\t\t\t\t\"path\": \"/data\",\n\t\t\t\t\t\"source\": \"/dpool/archive-data\",\n\t\t\t\t\t\"type\": \"disk\"\n\t\t\t\t},\n\t\t\t\t\"eth0\": {\n\t\t\t\t\t\"name\": \"eth0\",\n\t\t\t\t\t\"nictype\": \"bridged\",\n\t\t\t\t\t\"parent\": \"br0\",\n\t\t\t\t\t\"type\": \"nic\"\n\t\t\t\t},\n\t\t\t\t\"root\": {\n\t\t\t\t\t\"path\": \"/\",\n\t\t\t\t\t\"pool\": \"default\",\n\t\t\t\t\t\"size\": \"20GB\",\n\t\t\t\t\t\"type\": \"disk\"\n\t\t\t\t}\n\t\t\t},\n\t\t\t\"name\": \"archive\",\n\t\t\t\"status\": \"Running\",\n\t\t\t\"status_code\": 103,\n\t\t\t\"last_used_at\": \"2022-04-17T06:51:38.346975063Z\",\n\t\t\t\"location\": \"none\",\n\t\t\t\"type\": \"container\",\n\t\t\t\"project\": \"default\"\n\t\t}\n\t}" http_code=200
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0/events username=root
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=debug msg="Event listener server handler started" id=e369979f-4296-491c-81c4-69a961fab040 local=/var/snap/lxd/common/lxd/unix.socket remote=@
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=debug msg="Handling API request" ip=@ method=POST protocol=unix url=/1.0/instances/archive username=root
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=debug msg="API Request\n\t{\n\t\t\"name\": \"\",\n\t\t\"migration\": true,\n\t\t\"live\": false,\n\t\t\"instance_only\": false,\n\t\t\"container_only\": false,\n\t\t\"target\": {\n\t\t\t\"certificate\": \"-----BEGIN CERTIFICATE-----\\nMIICDzCCAZagAwIBAgIRAPH4uf7uzU3XsVWyLIC5l/MwCgYIKoZIzj0EAwMwODEc\\nMBoGA1UEChMTbGludXhjb250YWluZXJzLm9yZzEYMBYGA1UEAwwPcm9vdEBWSVJU\\nLVNMQVZFMB4XDTIxMDQxODEyMzkxNVoXDTMxMDQxNjEyMzkxNVowODEcMBoGA1UE\\nChMTbGludXhjb250YWluZXJzLm9yZzEYMBYGA1UEAwwPcm9vdEBWSVJULVNMQVZF\\nMHYwEAYHKoZIzj0CAQYFK4EEACIDYgAEgktEB6bBZo2AI3a4kTTiLU0Xy9lWaKAx\\nKyYul4VIOpiozD2pdJdapaJgVlFz2VCpdCdekEphASMx6n57N/GqeWPhen0jZ2qZ\\nelZCVIysHoEx73zlVjkIjITW1rP+Wswgo2QwYjAOBgNVHQ8BAf8EBAMCBaAwEwYD\\nVR0lBAwwCgYIKwYBBQUHAwEwDAYDVR0TAQH/BAIwADAtBgNVHREEJjAkggpWSVJU\\nLVNMQVZFhwR/AAABhxAAAAAAAAAAAAAAAAAAAAABMAoGCCqGSM49BAMDA2cAMGQC\\nMDGe829FEhXv91uAIML+1hb4qqHBr0mEwHv7WDnAc8LuwzlYOC0+9Nea0rrI7UDz\\nJAIwFIJwoqfSUbtN5uMa0gwMiRj8ZPKXgEAL7Z4L12pUP8bgXDhGnAZyL9t9Ydew\\nwwgG\\n-----END CERTIFICATE-----\\n\",\n\t\t\t\"operation\": \"https://172.16.88.2:8443/1.0/operations/8d1bbc02-c309-4331-aede-b40053de7003\",\n\t\t\t\"secrets\": {\n\t\t\t\t\"control\": \"6059ad24c6d0529ccfad3c3c87861f001938e5f535bb14c0078b668738624da0\",\n\t\t\t\t\"fs\": \"ed86fd834b0dbddd8ef59e8873e5dce755f21908e077e463a4839ffe11bf9500\"\n\t\t\t}\n\t\t},\n\t\t\"pool\": \"\",\n\t\t\"project\": \"\",\n\t\t\"allow_inconsistent\": false\n\t}" ip=@ method=POST protocol=unix url=/1.0/instances/archive username=root
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=debug msg="New task Operation: c658d360-43d5-4f76-87b8-1184601c8c40"
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=debug msg="Started task operation: c658d360-43d5-4f76-87b8-1184601c8c40"
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=info msg="Waiting for migration channel connections"
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=info msg="Migration channels connected"
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=debug msg="WriteJSON\n\t{\n\t\t\"type\": \"async\",\n\t\t\"status\": \"Operation created\",\n\t\t\"status_code\": 100,\n\t\t\"operation\": \"/1.0/operations/c658d360-43d5-4f76-87b8-1184601c8c40\",\n\t\t\"error_code\": 0,\n\t\t\"error\": \"\",\n\t\t\"metadata\": {\n\t\t\t\"id\": \"c658d360-43d5-4f76-87b8-1184601c8c40\",\n\t\t\t\"class\": \"task\",\n\t\t\t\"description\": \"Migrating instance\",\n\t\t\t\"created_at\": \"2022-06-06T17:02:26.201844461+02:00\",\n\t\t\t\"updated_at\": \"2022-06-06T17:02:26.201844461+02:00\",\n\t\t\t\"status\": \"Running\",\n\t\t\t\"status_code\": 103,\n\t\t\t\"resources\": {\n\t\t\t\t\"containers\": [\n\t\t\t\t\t\"/1.0/containers/archive\"\n\t\t\t\t],\n\t\t\t\t\"instances\": [\n\t\t\t\t\t\"/1.0/instances/archive\"\n\t\t\t\t]\n\t\t\t},\n\t\t\t\"metadata\": null,\n\t\t\t\"may_cancel\": false,\n\t\t\t\"err\": \"\",\n\t\t\t\"location\": \"none\"\n\t\t}\n\t}" http_code=202
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0/operations/c658d360-43d5-4f76-87b8-1184601c8c40 username=root
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=debug msg="WriteJSON\n\t{\n\t\t\"type\": \"sync\",\n\t\t\"status\": \"Success\",\n\t\t\"status_code\": 200,\n\t\t\"operation\": \"\",\n\t\t\"error_code\": 0,\n\t\t\"error\": \"\",\n\t\t\"metadata\": {\n\t\t\t\"id\": \"c658d360-43d5-4f76-87b8-1184601c8c40\",\n\t\t\t\"class\": \"task\",\n\t\t\t\"description\": \"Migrating instance\",\n\t\t\t\"created_at\": \"2022-06-06T17:02:26.201844461+02:00\",\n\t\t\t\"updated_at\": \"2022-06-06T17:02:26.201844461+02:00\",\n\t\t\t\"status\": \"Running\",\n\t\t\t\"status_code\": 103,\n\t\t\t\"resources\": {\n\t\t\t\t\"containers\": [\n\t\t\t\t\t\"/1.0/containers/archive\"\n\t\t\t\t],\n\t\t\t\t\"instances\": [\n\t\t\t\t\t\"/1.0/instances/archive\"\n\t\t\t\t]\n\t\t\t},\n\t\t\t\"metadata\": null,\n\t\t\t\"may_cancel\": false,\n\t\t\t\"err\": \"\",\n\t\t\t\"location\": \"none\"\n\t\t}\n\t}" http_code=200
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=debug msg="MigrateInstance started" args="&{0 archive [] {ZFS [migration_header compress]} true true false <nil> false true <nil>}" instance=archive project=default
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=debug msg="MigrateInstance finished" args="&{0 archive [] {ZFS [migration_header compress]} true true false map[filesystem:dpool/lxd/containers/archive@migration-77b8bd00-cd07-47e8-a0cf-ccf4ea3b3e72] false true <nil>}" instance=archive project=default
2022-06-06T17:02:26+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:26+02:00" level=debug msg="MigrateInstance started" args="&{0 archive [] {ZFS [migration_header compress]} true true true map[filesystem:dpool/lxd/containers/archive@migration-77b8bd00-cd07-47e8-a0cf-ccf4ea3b3e72] false true <nil>}" instance=archive project=default
2022-06-06T17:02:27+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:27+02:00" level=debug msg="MigrateInstance finished" args="&{0 archive [] {ZFS [migration_header compress]} true true true map[filesystem:dpool/lxd/containers/archive@migration-77b8bd00-cd07-47e8-a0cf-ccf4ea3b3e72] false true <nil>}" instance=archive project=default
2022-06-06T17:02:27+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:27+02:00" level=debug msg="Failure for task operation: c658d360-43d5-4f76-87b8-1184601c8c40: Failed reading migration header: websocket: close 1006 (abnormal closure): unexpected EOF"
2022-06-06T17:02:27+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:27+02:00" level=debug msg="Event listener server handler stopped" listener=e369979f-4296-491c-81c4-69a961fab040 local=/var/snap/lxd/common/lxd/unix.socket remote=@
2022-06-06T17:02:27+02:00 lxd.daemon[2145677]: time="2022-06-06T17:02:27+02:00" level=error msg="Failed closing listener connection" err="close unix /var/snap/lxd/common/lxd/unix.socket->@: use of closed network connection" listener=e369979f-4296-491c-81c4-69a961fab040
Can you show lxc config show <instance> --expanded and lxc info <instance> on both the source and the target.
I added a PR the other day that will improve the reporting on the specific error from the target:
Are you able to try this on latest/edge snap channel to see if it reports on a specific error?
Can I switch back to a release after using latest/edge snap channel ?
You should be able to at the moment as to my knowledge no api or schema changes have been merged since 5.2.
I’ll try it and let you know.
Can you show lxc config show <instance> --expanded and lxc info <instance> on both the source and the target.
Source:
VIRT-MASTER:~ root @ lxc config show archive --expanded
architecture: x86_64
config:
boot.autostart: "true"
image.architecture: amd64
image.description: Debian buster amd64 (20200819_05:24)
image.os: Debian
image.release: buster
image.serial: "20200819_05:24"
image.type: squashfs
raw.apparmor: mount fstype=nfs,
security.nesting: "true"
security.privileged: "true"
snapshots.expiry: 1w
snapshots.pattern: snapshot-%d
snapshots.schedule: 0 0 * * *
snapshots.schedule.stopped: "false"
volatile.base_image: aa68be27609634dffd06ef1510bd7ba97cd5d511d93992c0cb8b9e036cd7fa17
volatile.eth0.host_name: veth5698a127
volatile.eth0.hwaddr: 00:16:3e:d9:2c:0e
volatile.idmap.base: "0"
volatile.idmap.current: '[]'
volatile.idmap.next: '[]'
volatile.last_state.idmap: '[]'
volatile.last_state.power: RUNNING
volatile.uuid: 9d4b4276-ee24-424c-84ca-aa197bd2e0fa
devices:
archive-data:
path: /data
source: /dpool/archive-data
type: disk
eth0:
name: eth0
nictype: bridged
parent: br0
type: nic
root:
path: /
pool: default
size: 20GB
type: disk
ephemeral: false
profiles:
- default
stateful: false
description: ""
VIRT-MASTER:~ root @ lxc info archive
Name: archive
Status: RUNNING
Type: container
Architecture: x86_64
PID: 1176905
Created: 2021/04/27 19:27 CEST
Last Used: 2022/04/17 08:51 CEST
Resources:
Processes: 77
Disk usage:
root: 1.84GiB
CPU usage:
CPU usage (in seconds): 8190
Memory usage:
Memory (current): 1.91GiB
Network usage:
eth0:
Type: broadcast
State: UP
Host interface: veth5698a127
MAC address: 00:16:3e:d9:2c:0e
MTU: 1500
Bytes received: 20.63GB
Bytes sent: 1.06GB
Packets received: 179219965
Packets sent: 5205343
IP addresses:
inet: 192.168.250.31/24 (global)
inet6: fe80::216:3eff:fed9:2c0e/64 (link)
lo:
Type: loopback
State: UP
MTU: 65536
Bytes received: 7.52kB
Bytes sent: 7.52kB
Packets received: 74
Packets sent: 74
IP addresses:
inet: 127.0.0.1/8 (local)
inet6: ::1/128 (local)
Snapshots:
+--------------+-----------------------+-----------------------+----------+
| NAME | TAKEN AT | EXPIRES AT | STATEFUL |
+--------------+-----------------------+-----------------------+----------+
| snapshot-645 | 2022/05/31 23:59 CEST | 2022/06/07 23:59 CEST | NO |
+--------------+-----------------------+-----------------------+----------+
| snapshot-646 | 2022/06/01 23:59 CEST | 2022/06/08 23:59 CEST | NO |
+--------------+-----------------------+-----------------------+----------+
| snapshot-647 | 2022/06/02 23:59 CEST | 2022/06/09 23:59 CEST | NO |
+--------------+-----------------------+-----------------------+----------+
| snapshot-648 | 2022/06/03 23:59 CEST | 2022/06/10 23:59 CEST | NO |
+--------------+-----------------------+-----------------------+----------+
| snapshot-649 | 2022/06/04 23:59 CEST | 2022/06/11 23:59 CEST | NO |
+--------------+-----------------------+-----------------------+----------+
| snapshot-650 | 2022/06/05 23:59 CEST | 2022/06/12 23:59 CEST | NO |
+--------------+-----------------------+-----------------------+----------+
| snapshot-651 | 2022/06/06 23:59 CEST | 2022/06/13 23:59 CEST | NO |
+--------------+-----------------------+-----------------------+----------+
Target:
VIRT-SLAVE:~ root @ lxc config show archive --expanded
architecture: x86_64
config:
boot.autostart: "false"
image.architecture: amd64
image.description: Debian buster amd64 (20200819_05:24)
image.os: Debian
image.release: buster
image.serial: "20200819_05:24"
image.type: squashfs
raw.apparmor: mount fstype=nfs,
security.nesting: "true"
security.privileged: "true"
snapshots.expiry: 1w
snapshots.pattern: snapshot-%d
snapshots.schedule: 0 0 * * *
snapshots.schedule.stopped: "false"
volatile.apply_template: copy
volatile.base_image: aa68be27609634dffd06ef1510bd7ba97cd5d511d93992c0cb8b9e036cd7fa17
volatile.eth0.host_name: veth5698a127
volatile.eth0.hwaddr: 00:16:3e:d9:2c:0e
volatile.idmap.base: "0"
volatile.idmap.current: '[]'
volatile.idmap.next: '[]'
volatile.last_state.idmap: '[]'
volatile.uuid: 9d4b4276-ee24-424c-84ca-aa197bd2e0fa
devices:
archive-data:
path: /data
source: /dpool/archive-data
type: disk
eth0:
name: eth0
nictype: bridged
parent: br0
type: nic
root:
path: /
pool: default
size: 20GB
type: disk
ephemeral: false
profiles:
- default
stateful: false
description: ""
VIRT-SLAVE:~ root @ lxc info archive
Name: archive
Status: STOPPED
Type: container
Architecture: x86_64
Created: 2022/06/06 16:37 CEST
Snapshots:
+--------------+-----------------------+-----------------------+----------+
| NAME | TAKEN AT | EXPIRES AT | STATEFUL |
+--------------+-----------------------+-----------------------+----------+
| snapshot-645 | 2022/05/31 23:59 CEST | 2022/06/07 23:59 CEST | NO |
+--------------+-----------------------+-----------------------+----------+
| snapshot-646 | 2022/06/01 23:59 CEST | 2022/06/08 23:59 CEST | NO |
+--------------+-----------------------+-----------------------+----------+
| snapshot-647 | 2022/06/02 23:59 CEST | 2022/06/09 23:59 CEST | NO |
+--------------+-----------------------+-----------------------+----------+
| snapshot-648 | 2022/06/03 23:59 CEST | 2022/06/10 23:59 CEST | NO |
+--------------+-----------------------+-----------------------+----------+
| snapshot-649 | 2022/06/04 23:59 CEST | 2022/06/11 23:59 CEST | NO |
+--------------+-----------------------+-----------------------+----------+
| snapshot-650 | 2022/06/05 23:59 CEST | 2022/06/12 23:59 CEST | NO |
+--------------+-----------------------+-----------------------+----------+
| snapshot-651 | 2022/06/06 23:59 CEST | 2022/06/13 23:59 CEST | NO |
+--------------+-----------------------+-----------------------+----------+
And both source and target are running LXD 5.2 with ZFS?
Yes, both machines running Debian11 with snap/lxd 5.2/ZFS.
Great, if you take https://tomp.uk/files/lxd.debug and copy it to /var/snap/lxd/common/lxd.debug on each system, and then run sudo systemctl reload snap.lxd.daemon on each system, you should then see that the lxd.debug program is running instead of the lxd program inside the snap package.
If you could then retest and advise if you see the error and if a more helpful error message is returned?
Once done, you can remove the /var/snap/lxd/common/lxd.debug and then sudo systemctl reload snap.lxd.daemon to return to the snap lxd program.
I’ve tested and revert back to LXD 5.2 seems to work fine.
Binary started successfully /var/snap/lxd/common/lxd.debug --logfile /var/snap/lxd/common/lxd/logs/lxd.log --group lxd --debug .
Source:
2022-06-07T11:13:35+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:35+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0 username=root
2022-06-07T11:13:35+02:00 lxd.daemon[1161204]: - (error decoding original message: message key "MESSAGE" truncated)
2022-06-07T11:13:35+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:35+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0/instances/archive username=root
2022-06-07T11:13:35+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:35+02:00" level=debug msg="WriteJSON\n\t{\n\t\t\"type\": \"sync\",\n\t\t\"status\": \"Success\",\n\t\t\"status_code\": 200,\n\t\t\"operation\": \"\",\n\t\t\"error_code\": 0,\n\t\t\"error\": \"\",\n\t\t\"metadata\": {\n\t\t\t\"architecture\": \"x86_64\",\n\t\t\t\"config\": {\n\t\t\t\t\"boot.autostart\": \"true\",\n\t\t\t\t\"image.architecture\": \"amd64\",\n\t\t\t\t\"image.description\": \"Debian buster amd64 (20200819_05:24)\",\n\t\t\t\t\"image.os\": \"Debian\",\n\t\t\t\t\"image.release\": \"buster\",\n\t\t\t\t\"image.serial\": \"20200819_05:24\",\n\t\t\t\t\"image.type\": \"squashfs\",\n\t\t\t\t\"raw.apparmor\": \"mount fstype=nfs,\",\n\t\t\t\t\"security.nesting\": \"true\",\n\t\t\t\t\"security.privileged\": \"true\",\n\t\t\t\t\"snapshots.expiry\": \"1w\",\n\t\t\t\t\"snapshots.pattern\": \"snapshot-%d\",\n\t\t\t\t\"snapshots.schedule\": \"0 0 * * *\",\n\t\t\t\t\"snapshots.schedule.stopped\": \"false\",\n\t\t\t\t\"volatile.base_image\": \"aa68be27609634dffd06ef1510bd7ba97cd5d511d93992c0cb8b9e036cd7fa17\",\n\t\t\t\t\"volatile.eth0.host_name\": \"veth5698a127\",\n\t\t\t\t\"volatile.eth0.hwaddr\": \"00:16:3e:d9:2c:0e\",\n\t\t\t\t\"volatile.idmap.base\": \"0\",\n\t\t\t\t\"volatile.idmap.current\": \"[]\",\n\t\t\t\t\"volatile.idmap.next\": \"[]\",\n\t\t\t\t\"volatile.last_state.idmap\": \"[]\",\n\t\t\t\t\"volatile.last_state.power\": \"RUNNING\",\n\t\t\t\t\"volatile.uuid\": \"9d4b4276-ee24-424c-84ca-aa197bd2e0fa\"\n\t\t\t},\n\t\t\t\"devices\": {\n\t\t\t\t\"archive-data\": {\n\t\t\t\t\t\"path\": \"/data\",\n\t\t\t\t\t\"source\": \"/dpool/archive-data\",\n\t\t\t\t\t\"type\": \"disk\"\n\t\t\t\t},\n\t\t\t\t\"root\": {\n\t\t\t\t\t\"path\": \"/\",\n\t\t\t\t\t\"pool\": \"default\",\n\t\t\t\t\t\"size\": \"20GB\",\n\t\t\t\t\t\"type\": \"disk\"\n\t\t\t\t}\n\t\t\t},\n\t\t\t\"ephemeral\": false,\n\t\t\t\"profiles\": [\n\t\t\t\t\"default\"\n\t\t\t],\n\t\t\t\"stateful\": false,\n\t\t\t\"description\": \"\",\n\t\t\t\"created_at\": \"2021-04-27T19:27:25.6299956+02:00\",\n\t\t\t\"expanded_config\": {\n\t\t\t\t\"boot.autostart\": \"true\",\n\t\t\t\t\"image.architecture\": \"amd64\",\n\t\t\t\t\"image.description\": \"Debian buster amd64 (20200819_05:24)\",\n\t\t\t\t\"image.os\": \"Debian\",\n\t\t\t\t\"image.release\": \"buster\",\n\t\t\t\t\"image.serial\": \"20200819_05:24\",\n\t\t\t\t\"image.type\": \"squashfs\",\n\t\t\t\t\"raw.apparmor\": \"mount fstype=nfs,\",\n\t\t\t\t\"security.nesting\": \"true\",\n\t\t\t\t\"security.privileged\": \"true\",\n\t\t\t\t\"snapshots.expiry\": \"1w\",\n\t\t\t\t\"snapshots.pattern\": \"snapshot-%d\",\n\t\t\t\t\"snapshots.schedule\": \"0 0 * * *\",\n\t\t\t\t\"snapshots.schedule.stopped\": \"false\",\n\t\t\t\t\"volatile.base_image\": \"aa68be27609634dffd06ef1510bd7ba97cd5d511d93992c0cb8b9e036cd7fa17\",\n\t\t\t\t\"volatile.eth0.host_name\": \"veth5698a127\",\n\t\t\t\t\"volatile.eth0.hwaddr\": \"00:16:3e:d9:2c:0e\",\n\t\t\t\t\"volatile.idmap.base\": \"0\",\n\t\t\t\t\"volatile.idmap.current\": \"[]\",\n\t\t\t\t\"volatile.idmap.next\": \"[]\",\n\t\t\t\t\"volatile.last_state.idmap\": \"[]\",\n\t\t\t\t\"volatile.last_state.power\": \"RUNNING\",\n\t\t\t\t\"volatile.uuid\": \"9d4b4276-ee24-424c-84ca-aa197bd2e0fa\"\n\t\t\t},\n\t\t\t\"expanded_devices\": {\n\t\t\t\t\"archive-data\": {\n\t\t\t\t\t\"path\": \"/data\",\n\t\t\t\t\t\"source\": \"/dpool/archive-data\",\n\t\t\t\t\t\"type\": \"disk\"\n\t\t\t\t},\n\t\t\t\t\"eth0\": {\n\t\t\t\t\t\"name\": \"eth0\",\n\t\t\t\t\t\"nictype\": \"bridged\",\n\t\t\t\t\t\"parent\": \"br0\",\n\t\t\t\t\t\"type\": \"nic\"\n\t\t\t\t},\n\t\t\t\t\"root\": {\n\t\t\t\t\t\"path\": \"/\",\n\t\t\t\t\t\"pool\": \"default\",\n\t\t\t\t\t\"size\": \"20GB\",\n\t\t\t\t\t\"type\": \"disk\"\n\t\t\t\t}\n\t\t\t},\n\t\t\t\"name\": \"archive\",\n\t\t\t\"status\": \"Running\",\n\t\t\t\"status_code\": 103,\n\t\t\t\"last_used_at\": \"2022-04-17T06:51:38.346975063Z\",\n\t\t\t\"location\": \"none\",\n\t\t\t\"type\": \"container\",\n\t\t\t\"project\": \"default\"\n\t\t}\n\t}" http_code=200
2022-06-07T11:13:35+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:35+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0/events username=root
2022-06-07T11:13:35+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:35+02:00" level=debug msg="Event listener server handler started" id=92efde2d-2bb8-4af1-b90a-b6cc20a867ad local=/var/snap/lxd/common/lxd/unix.socket remote=@
2022-06-07T11:13:35+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:35+02:00" level=debug msg="Handling API request" ip=@ method=POST protocol=unix url=/1.0/instances/archive username=root
2022-06-07T11:13:35+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:35+02:00" level=debug msg="API Request\n\t{\n\t\t\"name\": \"\",\n\t\t\"migration\": true,\n\t\t\"live\": false,\n\t\t\"instance_only\": false,\n\t\t\"container_only\": false,\n\t\t\"target\": {\n\t\t\t\"certificate\": \"-----BEGIN CERTIFICATE-----\\nMIICDzCCAZagAwIBAgIRAPH4uf7uzU3XsVWyLIC5l/MwCgYIKoZIzj0EAwMwODEc\\nMBoGA1UEChMTbGludXhjb250YWluZXJzLm9yZzEYMBYGA1UEAwwPcm9vdEBWSVJU\\nLVNMQVZFMB4XDTIxMDQxODEyMzkxNVoXDTMxMDQxNjEyMzkxNVowODEcMBoGA1UE\\nChMTbGludXhjb250YWluZXJzLm9yZzEYMBYGA1UEAwwPcm9vdEBWSVJULVNMQVZF\\nMHYwEAYHKoZIzj0CAQYFK4EEACIDYgAEgktEB6bBZo2AI3a4kTTiLU0Xy9lWaKAx\\nKyYul4VIOpiozD2pdJdapaJgVlFz2VCpdCdekEphASMx6n57N/GqeWPhen0jZ2qZ\\nelZCVIysHoEx73zlVjkIjITW1rP+Wswgo2QwYjAOBgNVHQ8BAf8EBAMCBaAwEwYD\\nVR0lBAwwCgYIKwYBBQUHAwEwDAYDVR0TAQH/BAIwADAtBgNVHREEJjAkggpWSVJU\\nLVNMQVZFhwR/AAABhxAAAAAAAAAAAAAAAAAAAAABMAoGCCqGSM49BAMDA2cAMGQC\\nMDGe829FEhXv91uAIML+1hb4qqHBr0mEwHv7WDnAc8LuwzlYOC0+9Nea0rrI7UDz\\nJAIwFIJwoqfSUbtN5uMa0gwMiRj8ZPKXgEAL7Z4L12pUP8bgXDhGnAZyL9t9Ydew\\nwwgG\\n-----END CERTIFICATE-----\\n\",\n\t\t\t\"operation\": \"https://172.16.88.2:8443/1.0/operations/2ccee106-d740-4fd1-9df3-cb47491bbcd8\",\n\t\t\t\"secrets\": {\n\t\t\t\t\"control\": \"c77612b434035341b5afb71e76420076085cc6af09894b3e3c749408152bbf30\",\n\t\t\t\t\"fs\": \"5e7c7e2b491a07a76b4c3f335e0bdc83fbd2f8047da810e15d4b695caa2c2386\"\n\t\t\t}\n\t\t},\n\t\t\"pool\": \"\",\n\t\t\"project\": \"\",\n\t\t\"allow_inconsistent\": false\n\t}" ip=@ method=POST protocol=unix url=/1.0/instances/archive username=root
2022-06-07T11:13:36+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:36+02:00" level=debug msg="New operation" class=task description="Migrating instance" operation=c303efca-b7cf-4e8c-bf20-8ccc2dc43f43 project=default
2022-06-07T11:13:36+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:36+02:00" level=debug msg="Started operation" class=task description="Migrating instance" operation=c303efca-b7cf-4e8c-bf20-8ccc2dc43f43 project=default
2022-06-07T11:13:36+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:36+02:00" level=info msg="Waiting for migration channel connections"
2022-06-07T11:13:36+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:36+02:00" level=debug msg="WriteJSON\n\t{\n\t\t\"type\": \"async\",\n\t\t\"status\": \"Operation created\",\n\t\t\"status_code\": 100,\n\t\t\"operation\": \"/1.0/operations/c303efca-b7cf-4e8c-bf20-8ccc2dc43f43\",\n\t\t\"error_code\": 0,\n\t\t\"error\": \"\",\n\t\t\"metadata\": {\n\t\t\t\"id\": \"c303efca-b7cf-4e8c-bf20-8ccc2dc43f43\",\n\t\t\t\"class\": \"task\",\n\t\t\t\"description\": \"Migrating instance\",\n\t\t\t\"created_at\": \"2022-06-07T11:13:36.016934074+02:00\",\n\t\t\t\"updated_at\": \"2022-06-07T11:13:36.016934074+02:00\",\n\t\t\t\"status\": \"Running\",\n\t\t\t\"status_code\": 103,\n\t\t\t\"resources\": {\n\t\t\t\t\"containers\": [\n\t\t\t\t\t\"/1.0/containers/archive\"\n\t\t\t\t],\n\t\t\t\t\"instances\": [\n\t\t\t\t\t\"/1.0/instances/archive\"\n\t\t\t\t]\n\t\t\t},\n\t\t\t\"metadata\": null,\n\t\t\t\"may_cancel\": false,\n\t\t\t\"err\": \"\",\n\t\t\t\"location\": \"none\"\n\t\t}\n\t}" http_code=202
2022-06-07T11:13:36+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:36+02:00" level=info msg="Migration channels connected"
2022-06-07T11:13:36+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:36+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0/operations/c303efca-b7cf-4e8c-bf20-8ccc2dc43f43 username=root
2022-06-07T11:13:36+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:36+02:00" level=debug msg="WriteJSON\n\t{\n\t\t\"type\": \"sync\",\n\t\t\"status\": \"Success\",\n\t\t\"status_code\": 200,\n\t\t\"operation\": \"\",\n\t\t\"error_code\": 0,\n\t\t\"error\": \"\",\n\t\t\"metadata\": {\n\t\t\t\"id\": \"c303efca-b7cf-4e8c-bf20-8ccc2dc43f43\",\n\t\t\t\"class\": \"task\",\n\t\t\t\"description\": \"Migrating instance\",\n\t\t\t\"created_at\": \"2022-06-07T11:13:36.016934074+02:00\",\n\t\t\t\"updated_at\": \"2022-06-07T11:13:36.016934074+02:00\",\n\t\t\t\"status\": \"Running\",\n\t\t\t\"status_code\": 103,\n\t\t\t\"resources\": {\n\t\t\t\t\"containers\": [\n\t\t\t\t\t\"/1.0/containers/archive\"\n\t\t\t\t],\n\t\t\t\t\"instances\": [\n\t\t\t\t\t\"/1.0/instances/archive\"\n\t\t\t\t]\n\t\t\t},\n\t\t\t\"metadata\": null,\n\t\t\t\"may_cancel\": false,\n\t\t\t\"err\": \"\",\n\t\t\t\"location\": \"none\"\n\t\t}\n\t}" http_code=200
2022-06-07T11:13:36+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:36+02:00" level=debug msg="MigrateInstance started" args="&{0 archive [] {ZFS [migration_header compress]} true true false <nil> false true <nil>}" instance=archive project=default
2022-06-07T11:13:36+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:36+02:00" level=debug msg="MigrateInstance finished" args="&{0 archive [] {ZFS [migration_header compress]} true true false map[filesystem:dpool/lxd/containers/archive@migration-adeaba21-618b-4bfc-a500-f27189eaa890] false true <nil>}" instance=archive project=default
2022-06-07T11:13:36+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:36+02:00" level=debug msg="MigrateInstance started" args="&{0 archive [] {ZFS [migration_header compress]} true true true map[filesystem:dpool/lxd/containers/archive@migration-adeaba21-618b-4bfc-a500-f27189eaa890] false true <nil>}" instance=archive project=default
2022-06-07T11:13:37+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:37+02:00" level=debug msg="MigrateInstance finished" args="&{0 archive [] {ZFS [migration_header compress]} true true true map[filesystem:dpool/lxd/containers/archive@migration-adeaba21-618b-4bfc-a500-f27189eaa890] false true <nil>}" instance=archive project=default
2022-06-07T11:13:37+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:37+02:00" level=debug msg="Failure for operation" class=task description="Migrating instance" err="Failed reading migration header: websocket: close 1006 (abnormal closure): unexpected EOF" operation=c303efca-b7cf-4e8c-bf20-8ccc2dc43f43 project=default
2022-06-07T11:13:37+02:00 lxd.daemon[1161204]: time="2022-06-07T11:13:37+02:00" level=debug msg="Event listener server handler stopped" listener=92efde2d-2bb8-4af1-b90a-b6cc20a867ad local=/var/snap/lxd/common/lxd/unix.socket remote=@
Target:
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=debug msg="Matched trusted cert" fingerprint=91c4f757297b3caaa658144c545137e95ba2a0466ec140f0071370e8985fce29 subject="CN=root@VIRT-MASTER,O=linuxcontainers.org"
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=debug msg="Handling API request" ip="172.16.88.1:54144" method=GET protocol=tls url=/1.0 username=91c4f757297b3caaa658144c545137e95ba2a0466ec140f0071370e8985fce29
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=debug msg="Matched trusted cert" fingerprint=91c4f757297b3caaa658144c545137e95ba2a0466ec140f0071370e8985fce29 subject="CN=root@VIRT-MASTER,O=linuxcontainers.org"
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: - (error decoding original message: message key "MESSAGE" truncated)
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=debug msg="Matched trusted cert" fingerprint=91c4f757297b3caaa658144c545137e95ba2a0466ec140f0071370e8985fce29 subject="CN=root@VIRT-MASTER,O=linuxcontainers.org"
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=debug msg="Handling API request" ip="172.16.88.1:54146" method=GET protocol=tls url=/1.0/events username=91c4f757297b3caaa658144c545137e95ba2a0466ec140f0071370e8985fce29
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=debug msg="Event listener server handler started" id=2393c607-acb6-42a8-992a-2b4c3e2c7614 local="172.16.88.2:8443" remote="172.16.88.1:54146"
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=debug msg="Matched trusted cert" fingerprint=91c4f757297b3caaa658144c545137e95ba2a0466ec140f0071370e8985fce29 subject="CN=root@VIRT-MASTER,O=linuxcontainers.org"
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=debug msg="Handling API request" ip="172.16.88.1:54148" method=POST protocol=tls url=/1.0/instances username=91c4f757297b3caaa658144c545137e95ba2a0466ec140f0071370e8985fce29
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=debug msg="API Request\n\t{\n\t\t\"architecture\": \"x86_64\",\n\t\t\"config\": {\n\t\t\t\"boot.autostart\": \"false\",\n\t\t\t\"image.architecture\": \"amd64\",\n\t\t\t\"image.description\": \"Debian buster amd64 (20200819_05:24)\",\n\t\t\t\"image.os\": \"Debian\",\n\t\t\t\"image.release\": \"buster\",\n\t\t\t\"image.serial\": \"20200819_05:24\",\n\t\t\t\"image.type\": \"squashfs\",\n\t\t\t\"raw.apparmor\": \"mount fstype=nfs,\",\n\t\t\t\"security.nesting\": \"true\",\n\t\t\t\"security.privileged\": \"true\",\n\t\t\t\"snapshots.expiry\": \"1w\",\n\t\t\t\"snapshots.pattern\": \"snapshot-%d\",\n\t\t\t\"snapshots.schedule\": \"0 0 * * *\",\n\t\t\t\"snapshots.schedule.stopped\": \"false\",\n\t\t\t\"volatile.base_image\": \"aa68be27609634dffd06ef1510bd7ba97cd5d511d93992c0cb8b9e036cd7fa17\",\n\t\t\t\"volatile.eth0.host_name\": \"veth5698a127\",\n\t\t\t\"volatile.eth0.hwaddr\": \"00:16:3e:d9:2c:0e\",\n\t\t\t\"volatile.idmap.base\": \"0\",\n\t\t\t\"volatile.idmap.current\": \"[]\",\n\t\t\t\"volatile.idmap.next\": \"[]\",\n\t\t\t\"volatile.last_state.idmap\": \"[]\",\n\t\t\t\"volatile.uuid\": \"9d4b4276-ee24-424c-84ca-aa197bd2e0fa\"\n\t\t},\n\t\t\"devices\": {\n\t\t\t\"archive-data\": {\n\t\t\t\t\"path\": \"/data\",\n\t\t\t\t\"source\": \"/dpool/archive-data\",\n\t\t\t\t\"type\": \"disk\"\n\t\t\t},\n\t\t\t\"root\": {\n\t\t\t\t\"path\": \"/\",\n\t\t\t\t\"pool\": \"default\",\n\t\t\t\t\"size\": \"20GB\",\n\t\t\t\t\"type\": \"disk\"\n\t\t\t}\n\t\t},\n\t\t\"ephemeral\": false,\n\t\t\"profiles\": [\n\t\t\t\"default\"\n\t\t],\n\t\t\"stateful\": false,\n\t\t\"description\": \"\",\n\t\t\"name\": \"archive\",\n\t\t\"source\": {\n\t\t\t\"type\": \"migration\",\n\t\t\t\"certificate\": \"\",\n\t\t\t\"base-image\": \"aa68be27609634dffd06ef1510bd7ba97cd5d511d93992c0cb8b9e036cd7fa17\",\n\t\t\t\"mode\": \"push\",\n\t\t\t\"refresh\": true,\n\t\t\t\"allow_inconsistent\": false\n\t\t},\n\t\t\"instance_type\": \"\",\n\t\t\"type\": \"container\"\n\t}" ip="172.16.88.1:54148" method=POST protocol=tls url=/1.0/instances username=91c4f757297b3caaa658144c545137e95ba2a0466ec140f0071370e8985fce29
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=debug msg="Responding to instance create"
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=debug msg="Instance operation lock created" action=create instance=archive project=default reusable=false
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=debug msg="New operation" class=websocket description="Creating instance" operation=2ccee106-d740-4fd1-9df3-cb47491bbcd8 project=default
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=debug msg="Instance operation lock finished" action=create err="<nil>" instance=archive project=default reusable=false
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=debug msg="Started operation" class=websocket description="Creating instance" operation=2ccee106-d740-4fd1-9df3-cb47491bbcd8 project=default
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=info msg="Waiting for migration channel connections"
2022-06-07T11:13:35+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:35+02:00" level=debug msg="WriteJSON\n\t{\n\t\t\"type\": \"async\",\n\t\t\"status\": \"Operation created\",\n\t\t\"status_code\": 100,\n\t\t\"operation\": \"/1.0/operations/2ccee106-d740-4fd1-9df3-cb47491bbcd8\",\n\t\t\"error_code\": 0,\n\t\t\"error\": \"\",\n\t\t\"metadata\": {\n\t\t\t\"id\": \"2ccee106-d740-4fd1-9df3-cb47491bbcd8\",\n\t\t\t\"class\": \"websocket\",\n\t\t\t\"description\": \"Creating instance\",\n\t\t\t\"created_at\": \"2022-06-07T11:13:35.995868288+02:00\",\n\t\t\t\"updated_at\": \"2022-06-07T11:13:35.995868288+02:00\",\n\t\t\t\"status\": \"Running\",\n\t\t\t\"status_code\": 103,\n\t\t\t\"resources\": {\n\t\t\t\t\"containers\": [\n\t\t\t\t\t\"/1.0/containers/archive\"\n\t\t\t\t],\n\t\t\t\t\"instances\": [\n\t\t\t\t\t\"/1.0/instances/archive\"\n\t\t\t\t]\n\t\t\t},\n\t\t\t\"metadata\": {\n\t\t\t\t\"control\": \"c77612b434035341b5afb71e76420076085cc6af09894b3e3c749408152bbf30\",\n\t\t\t\t\"fs\": \"5e7c7e2b491a07a76b4c3f335e0bdc83fbd2f8047da810e15d4b695caa2c2386\"\n\t\t\t},\n\t\t\t\"may_cancel\": false,\n\t\t\t\"err\": \"\",\n\t\t\t\"location\": \"none\"\n\t\t}\n\t}" http_code=202
2022-06-07T11:13:36+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:36+02:00" level=debug msg="Allowing untrusted GET" ip="172.16.88.1:54150" url="/1.0/operations/2ccee106-d740-4fd1-9df3-cb47491bbcd8/websocket?secret=c77612b434035341b5afb71e76420076085cc6af09894b3e3c749408152bbf30"
2022-06-07T11:13:36+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:36+02:00" level=debug msg="Connecting to operation" class=websocket description="Creating instance" operation=2ccee106-d740-4fd1-9df3-cb47491bbcd8 project=default
2022-06-07T11:13:36+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:36+02:00" level=debug msg="Connected to operation" class=websocket description="Creating instance" operation=2ccee106-d740-4fd1-9df3-cb47491bbcd8 project=default
2022-06-07T11:13:36+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:36+02:00" level=debug msg="Allowing untrusted GET" ip="172.16.88.1:54152" url="/1.0/operations/2ccee106-d740-4fd1-9df3-cb47491bbcd8/websocket?secret=5e7c7e2b491a07a76b4c3f335e0bdc83fbd2f8047da810e15d4b695caa2c2386"
2022-06-07T11:13:36+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:36+02:00" level=debug msg="Connecting to operation" class=websocket description="Creating instance" operation=2ccee106-d740-4fd1-9df3-cb47491bbcd8 project=default
2022-06-07T11:13:36+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:36+02:00" level=info msg="Migration channels connected"
2022-06-07T11:13:36+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:36+02:00" level=debug msg="Connected to operation" class=websocket description="Creating instance" operation=2ccee106-d740-4fd1-9df3-cb47491bbcd8 project=default
2022-06-07T11:13:36+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:36+02:00" level=debug msg="CreateInstanceFromMigration started" args="{0 archive map[] [] {ZFS [migration_header compress]} true true true 0 }" instance=archive project=default
2022-06-07T11:13:36+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:36+02:00" level=debug msg="Using volume size from root disk config" driver=zfs pool=default size=20GB
2022-06-07T11:13:37+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:37+02:00" level=debug msg="CreateInstanceFromMigration finished" args="{0 archive map[] [] {ZFS [migration_header compress]} true true true 0 }" instance=archive project=default
2022-06-07T11:13:37+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:37+02:00" level=debug msg="Success for operation" class=websocket description="Creating instance" operation=2ccee106-d740-4fd1-9df3-cb47491bbcd8 project=default
2022-06-07T11:13:37+02:00 lxd.daemon[2164680]: time="2022-06-07T11:13:37+02:00" level=debug msg="Event listener server handler stopped" listener=2393c607-acb6-42a8-992a-2b4c3e2c7614 local="172.16.88.2:8443" remote="172.16.88.1:54146"
Hrm that 2nd MigrateInstance started looks suspicious, perhaps the other side is not expecting it and this is why you get the connection closed error.
Do you still get the error if you stop the source container before doing the copy?
No error when i stop the source container 