Moving running LXD virtual machines from one server to another

rimelek · July 15, 2023, 7:07pm

Hi. I’ve been using LXD for years on my laptop and recommending to my friends and colleagues and recently I started to have a pretty bad experience with LXD. It looks like I also picked the wrong time to join the community as the old forum is closed and this new category here is just “new” but I hope someone can point me to the right direction. It is possible that most of my problems are because I just misunderstand the documentation and announcements and want to do something that is not possible. I’ve spent some days on solving the following issue and I’m not going to give up unless you confirm that it is not possible.

My goal:

I would like to move an LXD virtual machine from one LXD server to another while the virtual machine is still running.

The issue

Whenever I try lxc move (exact command is below in this post) to move the vitrual machine to a registered remote or to another LXD cluster member, moving the VM fails and sometimes it also breaks the LXD api (I guess) because lxc commands doesn’t work until I find the process id of the failed VM’s qemu process and kill it (kill -9 <PID>)

My environment

I’m using two Ubuntu 22.04 hosts and installed LXD with the folowing command:

snap install lxd --channel 5.15/stable

Note that I also tried the 5.0 LTS version. In fact I tried that first but that gave me less informative error messages.

I have two “servers”. ta-lxlt is an actual Ubuntu 22.04 server installed on a laptop and ta-lteg is an Ubuntu 22.04 desktop on another laptop.

I also have to add that I tried everything on two actual server machines before with the same operating system version.

Steps to reproduce

I tried to enable live migration and I believe I did it according to the documentation.

Created a VM:

lxc init --vm images:ubuntu/jammy ubuntu-jammy

Note: I also tried with ubuntu:jammy
I edited the config section:

lxc config edit ubuntu-jammy

config:
  limits.memory: 2GiB
  migration.stateful: "true"
  # ...

and the devices section:

devices:
  root:
    path: /
    pool: default
    size: 10GiB
    size.state: 3GiB
    type: disk

Note: As far as I know 2GiB for the state would have been enough, but I wanted to make sure it will be.

I use “zfs” as storage driver and I configured a phisycal partition for it if that matters.

lxc move ubuntu-jammy ta-lxlt:ubuntu-jammy

This is the error message I got in the terminal:

Error: Failed instance creation: Error transferring instance data: Failed migration on target: Failed restoring checkpoint from source: Monitor is disconnected

The error message in the logs of the source server (output of snap logs lxd):

... level=warning msg="Unable to use virtio-fs for config drive, using 9p as a fallback" err="Stateful migration unsupported" instance=ubuntu-jammy-cloud instanceType=virtual-machine project=default

I found it in the source code: https://github.com/canonical/lxd/blob/0c2f4271a6326a2a24bc57b50abe0456ae94e7f1/lxd/device/disk.go#L851

revertFunc, unixListener, err := DiskVMVirtiofsdStart(d.state.OS.ExecPath, d.inst, sockPath, pidPath, logPath, mount.DevPath, rawIDMaps)
if err != nil {
	var errUnsupported UnsupportedError
	if errors.As(err, &errUnsupported) {
		d.logger.Warn("Unable to use virtio-fs for device, using 9p as a fallback", logger.Ctx{"err": errUnsupported})

On the target server I get this error message (besides the line I got in the terminal too)

... level=warning msg="Error getting disk usage" err="Failed to run: zfs get -H -p -o value used default/virtual-machines/ubuntu-jammy.block: exit status 1 (cannot open 'default/virtual-machines/ubuntu-jammy.block': dataset does not exist)" instance=ubuntu-jammy instanceType=virtual-machine project=default

Why I think it should work

I found this in the documentation:

https://documentation.ubuntu.com/lxd/en/latest/howto/move_instances/#how-to-move-existing-lxd-instances-between-servers

It starts with the following statement:

When moving a virtual machine, you must either enable Live migration for virtual machines or stop it first.

What I tried after the error messages

I tried to search for similar issues among the issues on GitHub and also on the old forum. I found issues with similar error messages mentioning virtio-fs but the rest of the error messages were different: https://discuss.linuxcontainers.org/t/unable-to-use-virtio-fs-for-config-drive-using-9p-as-a-fallback-err-stateful-migration-unsupported/13318
I tried to search for clues in the source code
I tried to enable 9p, 9pnet_virtio and virtiofs in the host machines’ kernel.
I tried to enter the mount namespace of the lxd snap to find out if virtiofsd can’t be found.
```
PID="$(pidof lxd)"
nsenter \
  --all \
  -t $PID  \
  env -i - $(sudo cat /proc/$PID/environ | xargs -0) which virtiofsd
```
Note that I needed env -i - $(sudo cat /proc/$PID/environ | xargs -0) to have the correct value for $PATH
Output:
```
 /snap/lxd/25086/bin/virtiofsd
```

I got confused because of an announcement

https://discuss.linuxcontainers.org/t/lxd-online-vm-live-migration-qemu-to-qemu/16635

If I understand it correctly there was a limited support for moving virtual machines between host machines and that “Specification” topic indicates a new way was implemented in LXD 5.13, but I couldn’t move virtual machines with either v5.0 LTS nor v5.15.

Stopped virtual machines could be moved

When I stopped the virtual machine first and ran the same command to move the VM, that worked perfectly without any issue.

Possible related issues

After I saw I was not able to successfully move virtual machines between servers, I tried creating a snapshot which also required stateful settings. So I tried

lxc snapshot --stateful ubuntu-jammy snap0

It never finished but the virtual machine got frozen and the logs showed the following indicating that something was wrong with the socket:

level=warning msg="Could not get VM state from agent" err="Failed connecting to agent: Get \"https://custom.socket/1.0\": dial vsock vm(6):8443: connect: connection timed out" instance=ubuntu-jammy instanceType=virtual-machine project=default

So again, I killed qemu manually because I was unable to unfreeze the VM

vm_name=ubuntu-jammy
kill -9 "$(ps aux | grep "lxd/logs/$vm_name/" | grep 'qemu' | awk '{print $2}')"

Note: I needed this double grep to not include the pid of the grep command itself

But the snapshot was created when I forced LXD to use the local socket instead of core.https_address

lxc snapshot --stateful ubuntu-jammy snap1 --force-local

Can the original issue be caused by the self-signed TLS certificate somehow?

tomp · July 17, 2023, 7:17am

Lets try and break the problem down, is it a general migration problem or one specific to stateful migration?

Can you confirm if you can take snapshots and migrate the VM between servers if it is not running?

rimelek · July 17, 2023, 8:26am

As I see it, it is specific to stateful migration. Yes, I can take snapshots without the --stateful flag and move stopped VMs between servers. If you have any suggestion what I should test, I would be happy to do that. I also thought I would install the new lxd-ui again to see if that has a migration feature to find out if I’m doing something wrong, but I can’t do that right now.

Update:

One more thing. I was able to take a snapshot with the --stateful flag in an LXD cluster. The other environment where I could not do it, was just two laptops not in a cluster. I don’t know why that would matter, but it could be important.

dj10023 · July 24, 2023, 3:03pm

Quick question since I am considering moving VM’s to LXD, if this actually works - is a cluster required for moving running VM’s from one host to the other?
Thank you

tomp · July 24, 2023, 4:02pm

No it is not, you can move between standalone LXD remotes as well.

tomp · July 24, 2023, 4:04pm

Yes lets narrow down why stateful snapshots dont work in your environment.

Please can you run lxc monitor --pretty when doing a stateful snapshot and gather the output here.

Also please show lxc info <instance> --show-log after it fails.

rimelek · July 25, 2023, 11:11pm

Well, it didn’t fail now on my laptops. I will try to reproduce it again later and I also wanted to try it in a cluster on my two laptops, but it failed to create it. I will come back when I find out what I did differently. Until then, thanks for the monitor command.

rimelek · July 26, 2023, 9:59pm

I couldn’t reproduce the snapshot error, but I did something similar. I would continue with the investigation, but I don’t have more time for today so I thought I would share what I have found so far. Excuse me if I don’t provide a complete log sometimes. To be honest I can’t always follow what is happening, because somehow I always get a new error and I didn’t always saved the logs because I thought I could get the same errors again.

So as I mentioned before, I tried to create a cluster, but it wasn’t right. ONe of my mistakes was that I set a subnet for the cluster which did not exist on the second laptop and the fan network couldn’t be created I guess. I useed to have that subnet on both laptops, but now I chose to remove the second laptop from the cluster. I left the first one as a single node cluster.

I added the second machine as remote on the first.

lxc remote add ta-lteg https://192.168.4.200:8443

I also set a trust password on the second and started

lxc monitor --pretty | tee monitor.log

on both machines in new terminal windows and tried the following command in the main terminal on the single node cluster machine.

At the end I got this in the main terminal as a result of the move command:

msg="Unable to use virtio-fs for config drive, using 9p as a fallback" err="Stateful migration unsupported" instance=ubuntu-vm instanceType=virtual-machine project=default

10 minutes before that I had the same error log and more, like this:

Failed connecting to agent: Get \"https://custom.socket/1.0\": dial vsock vm(6):8443: connect: connection timed out

I’m not sure though that it was caused by the move command since ten minutes aa long time. On the other hand, it indeed took long for the command to fail. The above custom socket error message is similar to what I got during snapshotting. In that case I suspected

And in this case I also got this from the monitor on the target machine:

time="2023-07-26T22:24:03+02:00" level=debug msg="Event listener server handler started" id=6a9c1b7b-807b-4549-956e-94769dbcf233 local=/var/snap/lxd/common/lxd/unix.socket remote=@
time="2023-07-26T22:24:04+02:00" level=info msg="http: TLS handshake error from 192.168.4.58:43860: remote error: tls: bad certificate"

The TLS handshake error was constanty thrown. Then I got the following part

time="2023-07-26T22:24:06+02:00" level=debug msg="Matched trusted cert" fingerprint=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0 subject="CN=ta@ta-lxlt,O=linuxcontainers.org"
time="2023-07-26T22:24:06+02:00" level=debug msg="Matched trusted cert" fingerprint=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0 subject="CN=ta@ta-lxlt,O=linuxcontainers.org"
time="2023-07-26T22:24:06+02:00" level=debug msg="Handling API request" ip="192.168.4.58:43886" method=GET protocol=tls url=/1.0 username=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0
time="2023-07-26T22:24:06+02:00" level=debug msg="Handling API request" ip="192.168.4.58:43902" method=GET protocol=tls url=/1.0/events username=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0
time="2023-07-26T22:24:06+02:00" level=debug msg="Matched trusted cert" fingerprint=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0 subject="CN=ta@ta-lxlt,O=linuxcontainers.org"
time="2023-07-26T22:24:06+02:00" level=debug msg="Event listener server handler started" id=bdc749ae-2f88-4675-b851-b9a399981d96 local="192.168.4.200:8443" remote="192.168.4.58:43902"
time="2023-07-26T22:24:06+02:00" level=debug msg="Matched trusted cert" fingerprint=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0 subject="CN=ta@ta-lxlt,O=linuxcontainers.org"
time="2023-07-26T22:24:06+02:00" level=debug msg="Handling API request" ip="192.168.4.58:43914" method=POST protocol=tls url=/1.0/instances username=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0
time="2023-07-26T22:24:06+02:00" level=debug msg="Responding to instance create"
time="2023-07-26T22:24:06+02:00" level=debug msg="Instance operation lock created" action=create instance=ubuntu-vm project=default reusable=false
time="2023-07-26T22:24:06+02:00" level=info msg="Creating instance" ephemeral=false instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T22:24:06+02:00" level=debug msg="Adding device" device=root instance=ubuntu-vm instanceType=virtual-machine project=default type=disk
time="2023-07-26T22:24:06+02:00" level=info msg="Created instance" ephemeral=false instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T22:24:06+02:00" level=info msg="Action: instance-created, Source: /1.0/instances/ubuntu-vm" location=none storage-pool=default type=virtual-machine
time="2023-07-26T22:24:06+02:00" level=debug msg="Started operation" class=task description="Creating instance" operation=7c70d350-094c-4275-bf18-83dbd86ba2e8 project=default
time="2023-07-26T22:24:06+02:00" level=debug msg="New operation" class=task description="Creating instance" operation=7c70d350-094c-4275-bf18-83dbd86ba2e8 project=default
time="2023-07-26T22:24:06+02:00" level=info msg="ID: 7c70d350-094c-4275-bf18-83dbd86ba2e8, Class: task, Description: Creating instance" CreatedAt="2023-07-26 22:24:06.803837125 +0200 CEST" Err= Location=none MayCancel=false Metadata="map[]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 22:24:06.803837125 +0200 CEST"
time="2023-07-26T22:24:06+02:00" level=info msg="ID: 7c70d350-094c-4275-bf18-83dbd86ba2e8, Class: task, Description: Creating instance" CreatedAt="2023-07-26 22:24:06.803837125 +0200 CEST" Err= Location=none MayCancel=false Metadata="map[]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Pending StatusCode=Pending UpdatedAt="2023-07-26 22:24:06.803837125 +0200 CEST"
time="2023-07-26T22:24:06+02:00" level=info msg="Waiting for migration control connection on target" clusterMoveSourceName= instance=ubuntu-vm live=true project=default push=false
time="2023-07-26T22:24:06+02:00" level=debug msg="Handling API request" ip="192.168.4.58:43920" method=GET protocol=tls url=/1.0/operations/7c70d350-094c-4275-bf18-83dbd86ba2e8 username=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0
time="2023-07-26T22:24:06+02:00" level=debug msg="Matched trusted cert" fingerprint=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0 subject="CN=ta@ta-lxlt,O=linuxcontainers.org"
time="2023-07-26T22:24:06+02:00" level=info msg="Migration control connection established on target" clusterMoveSourceName= instance=ubuntu-vm live=true project=default push=false
time="2023-07-26T22:24:06+02:00" level=info msg="Migration receive starting" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T22:24:06+02:00" level=debug msg="Waiting for migration offer from source" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T22:24:06+02:00" level=debug msg="Sent migration response to source" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T22:24:06+02:00" level=debug msg="Sending migration response to source" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T22:24:07+02:00" level=debug msg="Migrate receive control monitor started" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T22:24:07+02:00" level=debug msg="Migrate receive transfer started" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T22:24:07+02:00" level=debug msg="CreateInstanceFromMigration started" args="{IndexHeaderVersion:1 Name:ubuntu-vm Description: Config:map[] Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true Refresh:false Live:false VolumeSize:10737418240 ContentType: VolumeOnly:false ClusterMoveSourceName:}" driver=zfs instance=ubuntu-vm pool=default project=default
time="2023-07-26T22:24:07+02:00" level=debug msg="Waiting for migration index header" args="{IndexHeaderVersion:1 Name:ubuntu-vm Description: Config:map[] Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true Refresh:false Live:false VolumeSize:10737418240 ContentType: VolumeOnly:false ClusterMoveSourceName:}" driver=zfs instance=ubuntu-vm pool=default project=default version=1
time="2023-07-26T22:24:07+02:00" level=debug msg="Websocket: Got barrier message" address="192.168.4.58:8443"
time="2023-07-26T22:24:07+02:00" level=info msg="Received migration index header, sending response" args="{IndexHeaderVersion:1 Name:ubuntu-vm Description: Config:map[] Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true Refresh:false Live:false VolumeSize:10737418240 ContentType: VolumeOnly:false ClusterMoveSourceName:}" driver=zfs instance=ubuntu-vm pool=default project=default version=1
time="2023-07-26T22:24:07+02:00" level=debug msg="Websocket: Sending barrier message" address="192.168.4.58:8443"
time="2023-07-26T22:24:07+02:00" level=debug msg="Sent migration index header response" args="{IndexHeaderVersion:1 Name:ubuntu-vm Description: Config:map[] Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true Refresh:false Live:false VolumeSize:10737418240 ContentType: VolumeOnly:false ClusterMoveSourceName:}" driver=zfs instance=ubuntu-vm pool=default project=default version=1
time="2023-07-26T22:24:07+02:00" level=debug msg="Setting volume size from offer header" driver=zfs pool=default size=10737418240
time="2023-07-26T22:24:07+02:00" level=debug msg="Websocket: Got barrier message" address="192.168.4.58:8443"
time="2023-07-26T22:24:07+02:00" level=debug msg="Websocket: Got barrier message" address="192.168.4.58:8443"

And then the TLS errors again. Only the ports are different every time which is not a surprise as a source port.

And this is the source machine’s monitor log, although I couldn’t see anything imortant in it:

time="2023-07-26T20:24:04Z" level=debug msg="Event listener server handler started" id=3270a6e4-c9c3-4de4-aee5-bc4d2ef60a1c local=/var/snap/lxd/common/lxd/unix.socket remote=@
time="2023-07-26T20:24:06Z" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0 username=ta
time="2023-07-26T20:24:06Z" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0/instances/ubuntu-vm username=ta
time="2023-07-26T20:24:06Z" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0/events username=ta
time="2023-07-26T20:24:06Z" level=debug msg="Event listener server handler started" id=82eff7d7-1bd0-43f7-aa45-e09587d23301 local=/var/snap/lxd/common/lxd/unix.socket remote=@
time="2023-07-26T20:24:06Z" level=debug msg="Handling API request" ip=@ method=POST protocol=unix url=/1.0/instances/ubuntu-vm username=ta
time="2023-07-26T20:24:06Z" level=info msg="Waiting for migration control connection on source" clusterMoveSourceName= instance=ubuntu-vm live=true project=default push=false
time="2023-07-26T20:24:06Z" level=debug msg="Started operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:06Z" level=debug msg="New operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:06Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:06.738708194 +0000 UTC"
time="2023-07-26T20:24:06Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Pending StatusCode=Pending UpdatedAt="2023-07-26 20:24:06.738708194 +0000 UTC"
time="2023-07-26T20:24:06Z" level=debug msg="Allowing untrusted GET" ip="192.168.4.200:41866" url="/1.0/operations/c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e/websocket?secret=4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203"
time="2023-07-26T20:24:06Z" level=info msg="Migration control connection established on source" clusterMoveSourceName= instance=ubuntu-vm live=true project=default push=false
time="2023-07-26T20:24:06Z" level=info msg="Migration send starting" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:24:06Z" level=debug msg="Connected to operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:06Z" level=debug msg="Connecting to operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:06Z" level=debug msg="Allowing untrusted GET" ip="192.168.4.200:41888" url="/1.0/operations/c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e/websocket?secret=69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872"
time="2023-07-26T20:24:06Z" level=debug msg="Connected to operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:06Z" level=debug msg="Connecting to operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:06Z" level=debug msg="MountInstance started" driver=zfs instance=ubuntu-vm pool=local project=default
time="2023-07-26T20:24:06Z" level=debug msg="UnmountInstance started" driver=zfs instance=ubuntu-vm pool=local project=default
time="2023-07-26T20:24:06Z" level=debug msg="MountInstance finished" driver=zfs instance=ubuntu-vm pool=local project=default
time="2023-07-26T20:24:06Z" level=debug msg="UnmountInstance finished" driver=zfs instance=ubuntu-vm pool=local project=default
time="2023-07-26T20:24:06Z" level=debug msg="Skipping unmount as in use" driver=zfs pool=local refCount=1 volName=ubuntu-vm
time="2023-07-26T20:24:06Z" level=debug msg="Set migration offer volume size" blockSize=10737418240 instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:24:06Z" level=debug msg="Sending migration offer to target" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:24:06Z" level=debug msg="Waiting for migration offer response from target" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:24:06Z" level=debug msg="Got migration offer response from target" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:24:07Z" level=debug msg="Connecting to operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:07Z" level=debug msg="Allowing untrusted GET" ip="192.168.4.200:41906" url="/1.0/operations/c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e/websocket?secret=c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7"
time="2023-07-26T20:24:07Z" level=debug msg="Connected to operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:07Z" level=debug msg="Migrate send control monitor started" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:24:07Z" level=debug msg="Migrate send transfer started" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:24:07Z" level=debug msg="Setup temporary migration storage snapshot" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:24:07Z" level=debug msg="MigrateInstance started" args="&{IndexHeaderVersion:1 Name:ubuntu-vm Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true MultiSync:false FinalSync:false Data:<nil> ContentType: AllowInconsistent:true Refresh:false Info:0xc00054a198 VolumeOnly:false ClusterMove:false}" driver=zfs instance=ubuntu-vm pool=local project=default
time="2023-07-26T20:24:07Z" level=debug msg="Sent migration index header, waiting for response" args="&{IndexHeaderVersion:1 Name:ubuntu-vm Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true MultiSync:false FinalSync:false Data:<nil> ContentType: AllowInconsistent:true Refresh:false Info:0xc00054a198 VolumeOnly:false ClusterMove:false}" driver=zfs instance=ubuntu-vm pool=local project=default version=1
time="2023-07-26T20:24:07Z" level=debug msg="Websocket: Sending barrier message" address="192.168.4.200:41888"
time="2023-07-26T20:24:07Z" level=info msg="Received migration index header response" args="&{IndexHeaderVersion:1 Name:ubuntu-vm Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true MultiSync:false FinalSync:false Data:<nil> ContentType: AllowInconsistent:true Refresh:false Info:0xc00054a198 VolumeOnly:false ClusterMove:false}" driver=zfs instance=ubuntu-vm pool=local project=default response="{StatusCode:200 Error: Refresh:0xc00206a6cb}" version=1
time="2023-07-26T20:24:07Z" level=debug msg="Websocket: Got barrier message" address="192.168.4.200:41888"
time="2023-07-26T20:24:07Z" level=debug msg="Websocket: Sending barrier message" address="192.168.4.200:41888"
time="2023-07-26T20:24:07Z" level=debug msg="Websocket: Sending barrier message" address="192.168.4.200:41888"
time="2023-07-26T20:24:08Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T20:24:08Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T20:24:08Z" level=debug msg="Completed heartbeat round" duration=12.629137ms local="192.168.4.58:8443"
time="2023-07-26T20:24:09Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:09Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 17.30MB (9.66MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:09.202071051 +0000 UTC"
time="2023-07-26T20:24:10Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:10Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 135.70MB (48.49MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:10.210601324 +0000 UTC"
time="2023-07-26T20:24:11Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:11Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 253.35MB (66.66MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:11.212700855 +0000 UTC"
time="2023-07-26T20:24:12Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:12Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 371.56MB (77.29MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:12.219515291 +0000 UTC"
time="2023-07-26T20:24:13Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:13Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 489.80MB (84.23MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:13.226906671 +0000 UTC"
time="2023-07-26T20:24:14Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:14Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 607.85MB (89.13MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:14.232186017 +0000 UTC"
time="2023-07-26T20:24:15Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:15Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 725.93MB (92.76MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:15.238001787 +0000 UTC"
time="2023-07-26T20:24:16Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:16Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 844.03MB (95.57MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:16.24383617 +0000 UTC"
time="2023-07-26T20:24:17Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:17Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 962.06MB (97.80MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:17.249050368 +0000 UTC"
time="2023-07-26T20:24:18Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T20:24:18Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T20:24:18Z" level=debug msg="Completed heartbeat round" duration=4.574298ms local="192.168.4.58:8443"
time="2023-07-26T20:24:18Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:18Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 1.08GB (99.62MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:18.254283761 +0000 UTC"
time="2023-07-26T20:24:19Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:19Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 1.20GB (101.13MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:19.260597947 +0000 UTC"
time="2023-07-26T20:24:20Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:20Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 1.32GB (102.40MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:20.26655052 +0000 UTC"
time="2023-07-26T20:24:21Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:21Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 1.43GB (103.49MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:21.272297141 +0000 UTC"
time="2023-07-26T20:24:22Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:22Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 1.55GB (104.43MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:22.278849572 +0000 UTC"
time="2023-07-26T20:24:23Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:23Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 1.67GB (105.26MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:23.285218853 +0000 UTC"
time="2023-07-26T20:24:24Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 1.79GB (105.99MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:24.290059453 +0000 UTC"
time="2023-07-26T20:24:24Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:25Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:25Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 1.91GB (106.63MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:25.298089062 +0000 UTC"
time="2023-07-26T20:24:26Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:26Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 2.02GB (107.20MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:26.298559616 +0000 UTC"
time="2023-07-26T20:24:27Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:27Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 2.14GB (107.70MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:27.300248719 +0000 UTC"
time="2023-07-26T20:24:28Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T20:24:28Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T20:24:28Z" level=debug msg="Completed heartbeat round" duration=4.72779ms local="192.168.4.58:8443"
time="2023-07-26T20:24:28Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:28Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 2.26GB (108.17MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:28.308710454 +0000 UTC"
time="2023-07-26T20:24:29Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:29Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 2.38GB (108.59MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:29.317136506 +0000 UTC"
time="2023-07-26T20:24:30Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:30Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 2.50GB (108.98MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:30.326147946 +0000 UTC"
time="2023-07-26T20:24:31Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:24:31Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 2.61GB (109.34MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 20:24:31.326155442 +0000 UTC"
time="2023-07-26T20:24:32Z" level=debug msg="Websocket: Sending barrier message" address="192.168.4.200:41888"
time="2023-07-26T20:24:32Z" level=debug msg="NBD listener waiting for accept" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:24:32Z" level=debug msg="Connecting to migration NBD storage target" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:24:32Z" level=debug msg="MigrateInstance finished" args="&{IndexHeaderVersion:1 Name:ubuntu-vm Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true MultiSync:false FinalSync:false Data:<nil> ContentType: AllowInconsistent:true Refresh:false Info:0xc00054a198 VolumeOnly:false ClusterMove:false}" driver=zfs instance=ubuntu-vm pool=local project=default
time="2023-07-26T20:24:32Z" level=debug msg="NBD connection on source started" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:24:38Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T20:24:38Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T20:24:38Z" level=debug msg="Completed heartbeat round" duration=7.285785ms local="192.168.4.58:8443"
time="2023-07-26T20:24:48Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T20:24:48Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T20:24:48Z" level=debug msg="Completed heartbeat round" duration=4.149712ms local="192.168.4.58:8443"
time="2023-07-26T20:24:58Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T20:24:58Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T20:24:58Z" level=debug msg="Completed heartbeat round" duration=3.687754ms local="192.168.4.58:8443"
time="2023-07-26T20:25:00Z" level=debug msg="Migration storage snapshot transfer started" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:25:00Z" level=debug msg="Connected to migration NBD storage target" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:25:01Z" level=debug msg="Migration storage snapshot transfer finished" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:25:01Z" level=debug msg="Stateful migration checkpoint send starting" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:25:02Z" level=debug msg="NBD connection on source finished" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:25:02Z" level=debug msg="Websocket: Got barrier message" address="192.168.4.200:41888"
time="2023-07-26T20:25:02Z" level=debug msg="Migrate send control monitor finished" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T20:25:03Z" level=debug msg="Handling API request" ip=@ method=DELETE protocol=unix url=/1.0/operations/c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e username=ta
time="2023-07-26T20:25:03Z" level=debug msg="Cancelling operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:25:03Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 2.61GB (109.34MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Cancelling StatusCode=Cancelling UpdatedAt="2023-07-26 20:24:31.326155442 +0000 UTC"
time="2023-07-26T20:25:03Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 2.61GB (109.34MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Cancelling StatusCode=Cancelling UpdatedAt="2023-07-26 20:24:31.326155442 +0000 UTC"
time="2023-07-26T20:25:03Z" level=info msg="Action: operation-cancelled, Source: /1.0/operations/c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Requestor: unix/ta (@)"
time="2023-07-26T20:25:03Z" level=debug msg="Cancelled operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:25:03Z" level=debug msg="Cancelled operation" class=websocket description="Migrating instance" operation=c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e project=default
time="2023-07-26T20:25:03Z" level=info msg="ID: c2dbc6dd-0e0e-481d-a0c4-1cb39a02122e, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 20:24:06.738708194 +0000 UTC" Err= Location=ta-lxlt MayCancel=false Metadata="map[control:4aee010b6069f169a9b301a72c07569e470abb7eee58655a2d3e8532ec460203 criu:c528830613b6ee27c9f6026b43977319abf19abb6795bf1fb84abd462c033fb7 fs:69c991b2ad3540962047f33ccc5a006a040a8ef5c808b4301fa42db21482a872 fs_progress:ubuntu-vm: 2.61GB (109.34MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Cancelled StatusCode=Cancelled UpdatedAt="2023-07-26 20:24:31.326155442 +0000 UTC"
time="2023-07-26T20:25:03Z" level=debug msg="Event listener server handler stopped" listener=82eff7d7-1bd0-43f7-aa45-e09587d23301 local=/var/snap/lxd/common/lxd/unix.socket remote=@
time="2023-07-26T20:25:08Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T20:25:08Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T20:25:08Z" level=debug msg="Completed heartbeat round" duration=10.326334ms local="192.168.4.58:8443"

Don’t ask why, but I tried the move command again and got this new error message:

Error: Failed instance creation: Error transferring instance data: Failed migration on target: Failed creating instance on target: Failed reading migration index header: websocket: close 1006 (abnormal closure): unexpected EOF

I got it every time until I restarted lxd. Which is sad, because it is not the first that I see that something fails and only lxd restarts helps or killing a process manually like when I couldn’t restore a frozen VM only after manually killing qemu. Maybe I’m wrong and I just don’t know the right way.

So here comes my next attempt. Because I wasn’t sure what caused what, I tried to reproduce everything again, but I changed the configuration (I know, I shouldn’t change anything when I try to reproduce something) on the target laptop. This was my original https address:

config:
  core.https_address: '[::]:8443'

And I changed it to this:

config:
  core.https_address: '0.0.0.0:8443'

I think I also restarted lxd but I’m not sure. Ran the whole test again, but I didn’t get the TLS handshake error anymore. This was the monitor log on the target server:

time="2023-07-26T23:02:48+02:00" level=debug msg="Event listener server handler started" id=fd1a2f29-42a7-4e09-9751-f38f203031d5 local=/var/snap/lxd/common/lxd/unix.socket remote=@
time="2023-07-26T23:02:51+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0 username=root
time="2023-07-26T23:02:51+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0/networks username=root
time="2023-07-26T23:02:51+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0 username=root
time="2023-07-26T23:02:51+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0/profiles/default username=root
time="2023-07-26T23:02:51+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url="/1.0/storage-pools?recursion=1" username=root
time="2023-07-26T23:02:51+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url="/1.0/networks?recursion=1" username=root
time="2023-07-26T23:02:51+02:00" level=debug msg="Handling API request" ip=@ method=POST protocol=unix url=/1.0/networks username=root
time="2023-07-26T23:03:07+02:00" level=debug msg="Matched trusted cert" fingerprint=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0 subject="CN=ta@ta-lxlt,O=linuxcontainers.org"
time="2023-07-26T23:03:07+02:00" level=debug msg="Handling API request" ip="192.168.4.58:58792" method=GET protocol=tls url=/1.0 username=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0
time="2023-07-26T23:03:07+02:00" level=debug msg="Matched trusted cert" fingerprint=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0 subject="CN=ta@ta-lxlt,O=linuxcontainers.org"
time="2023-07-26T23:03:07+02:00" level=debug msg="Handling API request" ip="192.168.4.58:58806" method=GET protocol=tls url=/1.0/events username=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0
time="2023-07-26T23:03:07+02:00" level=debug msg="Matched trusted cert" fingerprint=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0 subject="CN=ta@ta-lxlt,O=linuxcontainers.org"
time="2023-07-26T23:03:07+02:00" level=debug msg="Event listener server handler started" id=9a73d80b-f579-4db8-9be6-1b27ced3483e local="192.168.4.200:8443" remote="192.168.4.58:58806"
time="2023-07-26T23:03:07+02:00" level=debug msg="Responding to instance create"
time="2023-07-26T23:03:07+02:00" level=debug msg="Matched trusted cert" fingerprint=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0 subject="CN=ta@ta-lxlt,O=linuxcontainers.org"
time="2023-07-26T23:03:07+02:00" level=debug msg="Handling API request" ip="192.168.4.58:58810" method=POST protocol=tls url=/1.0/instances username=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0
time="2023-07-26T23:03:07+02:00" level=debug msg="Instance operation lock created" action=create instance=ubuntu-vm project=default reusable=false
time="2023-07-26T23:03:07+02:00" level=info msg="Creating instance" ephemeral=false instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:07+02:00" level=debug msg="Adding device" device=root instance=ubuntu-vm instanceType=virtual-machine project=default type=disk
time="2023-07-26T23:03:07+02:00" level=info msg="Created instance" ephemeral=false instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:07+02:00" level=info msg="Action: instance-created, Source: /1.0/instances/ubuntu-vm" location=none storage-pool=default type=virtual-machine
time="2023-07-26T23:03:07+02:00" level=debug msg="New operation" class=task description="Creating instance" operation=86016410-5f55-4f20-a72c-813a19439272 project=default
time="2023-07-26T23:03:07+02:00" level=info msg="Waiting for migration control connection on target" clusterMoveSourceName= instance=ubuntu-vm live=true project=default push=false
time="2023-07-26T23:03:07+02:00" level=debug msg="Started operation" class=task description="Creating instance" operation=86016410-5f55-4f20-a72c-813a19439272 project=default
time="2023-07-26T23:03:07+02:00" level=info msg="ID: 86016410-5f55-4f20-a72c-813a19439272, Class: task, Description: Creating instance" CreatedAt="2023-07-26 23:03:07.42221753 +0200 CEST" Err= Location=none MayCancel=false Metadata="map[]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Pending StatusCode=Pending UpdatedAt="2023-07-26 23:03:07.42221753 +0200 CEST"
time="2023-07-26T23:03:07+02:00" level=info msg="ID: 86016410-5f55-4f20-a72c-813a19439272, Class: task, Description: Creating instance" CreatedAt="2023-07-26 23:03:07.42221753 +0200 CEST" Err= Location=none MayCancel=false Metadata="map[]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 23:03:07.42221753 +0200 CEST"
time="2023-07-26T23:03:07+02:00" level=debug msg="Handling API request" ip="192.168.4.58:58816" method=GET protocol=tls url=/1.0/operations/86016410-5f55-4f20-a72c-813a19439272 username=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0
time="2023-07-26T23:03:07+02:00" level=debug msg="Matched trusted cert" fingerprint=ede31957d0727ca8573980e5a5a8dad076e5c7f2dd5a4d9caf7b698b3579feb0 subject="CN=ta@ta-lxlt,O=linuxcontainers.org"
time="2023-07-26T23:03:07+02:00" level=info msg="Migration receive starting" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:07+02:00" level=info msg="Migration control connection established on target" clusterMoveSourceName= instance=ubuntu-vm live=true project=default push=false
time="2023-07-26T23:03:07+02:00" level=debug msg="Waiting for migration offer from source" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:07+02:00" level=debug msg="Sending migration response to source" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:07+02:00" level=debug msg="Sent migration response to source" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:07+02:00" level=debug msg="Waiting for migration index header" args="{IndexHeaderVersion:1 Name:ubuntu-vm Description: Config:map[] Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true Refresh:false Live:false VolumeSize:10737418240 ContentType: VolumeOnly:false ClusterMoveSourceName:}" driver=zfs instance=ubuntu-vm pool=default project=default version=1
time="2023-07-26T23:03:07+02:00" level=debug msg="Migrate receive control monitor started" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:07+02:00" level=debug msg="Migrate receive transfer started" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:07+02:00" level=debug msg="CreateInstanceFromMigration started" args="{IndexHeaderVersion:1 Name:ubuntu-vm Description: Config:map[] Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true Refresh:false Live:false VolumeSize:10737418240 ContentType: VolumeOnly:false ClusterMoveSourceName:}" driver=zfs instance=ubuntu-vm pool=default project=default
time="2023-07-26T23:03:07+02:00" level=debug msg="Websocket: Got barrier message" address="192.168.4.58:8443"
time="2023-07-26T23:03:07+02:00" level=debug msg="Websocket: Sending barrier message" address="192.168.4.58:8443"
time="2023-07-26T23:03:07+02:00" level=debug msg="Sent migration index header response" args="{IndexHeaderVersion:1 Name:ubuntu-vm Description: Config:map[] Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true Refresh:false Live:false VolumeSize:10737418240 ContentType: VolumeOnly:false ClusterMoveSourceName:}" driver=zfs instance=ubuntu-vm pool=default project=default version=1
time="2023-07-26T23:03:07+02:00" level=info msg="Received migration index header, sending response" args="{IndexHeaderVersion:1 Name:ubuntu-vm Description: Config:map[] Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true Refresh:false Live:false VolumeSize:10737418240 ContentType: VolumeOnly:false ClusterMoveSourceName:}" driver=zfs instance=ubuntu-vm pool=default project=default version=1
time="2023-07-26T23:03:07+02:00" level=debug msg="Setting volume size from offer header" driver=zfs pool=default size=10737418240
time="2023-07-26T23:03:07+02:00" level=debug msg="Websocket: Got barrier message" address="192.168.4.58:8443"
time="2023-07-26T23:03:08+02:00" level=debug msg="Websocket: Got barrier message" address="192.168.4.58:8443"
time="2023-07-26T23:03:32+02:00" level=debug msg="Websocket: Got barrier message" address="192.168.4.58:8443"
time="2023-07-26T23:03:49+02:00" level=debug msg="CreateInstanceFromMigration finished" args="{IndexHeaderVersion:1 Name:ubuntu-vm Description: Config:map[] Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true Refresh:false Live:false VolumeSize:10737418240 ContentType: VolumeOnly:false ClusterMoveSourceName:}" driver=zfs instance=ubuntu-vm pool=default project=default
time="2023-07-26T23:03:49+02:00" level=debug msg="Start started" instance=ubuntu-vm instanceType=virtual-machine project=default stateful=true
time="2023-07-26T23:03:49+02:00" level=debug msg="MountInstance started" driver=zfs instance=ubuntu-vm pool=default project=default
time="2023-07-26T23:03:49+02:00" level=debug msg="Activated ZFS volume" dev=lxd-default/virtual-machines/ubuntu-vm.block driver=zfs pool=default volName=ubuntu-vm
time="2023-07-26T23:03:50+02:00" level=debug msg="MountInstance finished" driver=zfs instance=ubuntu-vm pool=default project=default
time="2023-07-26T23:03:50+02:00" level=debug msg="Mounted ZFS dataset" dev=lxd-default/virtual-machines/ubuntu-vm driver=zfs path=/var/snap/lxd/common/lxd/storage-pools/default/virtual-machines/ubuntu-vm pool=default volName=ubuntu-vm
time="2023-07-26T23:03:50+02:00" level=debug msg="Skipping lxd-agent install as unchanged" installPath=/var/snap/lxd/common/lxd/virtual-machines/ubuntu-vm/config/lxd-agent instance=ubuntu-vm instanceType=virtual-machine project=default srcPath=/snap/lxd/25086/bin/lxd-agent
time="2023-07-26T23:03:50+02:00" level=debug msg="Starting device" device=root instance=ubuntu-vm instanceType=virtual-machine project=default type=disk
time="2023-07-26T23:03:50+02:00" level=warning msg="Unable to use virtio-fs for config drive, using 9p as a fallback" err="Stateful migration unsupported" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:50+02:00" level=debug msg="UpdateInstanceBackupFile started" driver=zfs instance=ubuntu-vm pool=default project=default
time="2023-07-26T23:03:50+02:00" level=debug msg="Skipping unmount as in use" driver=zfs pool=default refCount=1 volName=ubuntu-vm
time="2023-07-26T23:03:50+02:00" level=debug msg="UpdateInstanceBackupFile finished" driver=zfs instance=ubuntu-vm pool=default project=default
time="2023-07-26T23:03:50+02:00" level=debug msg="QMP monitor started" path=/var/snap/lxd/common/lxd/logs/ubuntu-vm/qemu.monitor
time="2023-07-26T23:03:50+02:00" level=debug msg="Migration NBD server started" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:50+02:00" level=debug msg="Migration storage NBD export starting" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:50+02:00" level=debug msg="Stateful migration checkpoint receive starting" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:51+02:00" level=debug msg="QMP monitor stopped" path=/var/snap/lxd/common/lxd/logs/ubuntu-vm/qemu.monitor
time="2023-07-26T23:03:52+02:00" level=debug msg="Websocket: Sending barrier message" address="192.168.4.58:8443"
time="2023-07-26T23:03:52+02:00" level=debug msg="Instance operation lock finished" action=create err="Failed restoring checkpoint from source: Monitor is disconnected" instance=ubuntu-vm project=default reusable=false
time="2023-07-26T23:03:52+02:00" level=debug msg="Stopping device" device=root instance=ubuntu-vm instanceType=virtual-machine project=default type=disk
time="2023-07-26T23:03:52+02:00" level=debug msg="UnmountInstance started" driver=zfs instance=ubuntu-vm pool=default project=default
time="2023-07-26T23:03:52+02:00" level=debug msg="Unmounted ZFS dataset" dev=lxd-default/virtual-machines/ubuntu-vm driver=zfs path=/var/snap/lxd/common/lxd/storage-pools/default/virtual-machines/ubuntu-vm pool=default volName=ubuntu-vm
time="2023-07-26T23:03:52+02:00" level=debug msg="Migrate receive control monitor finished" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:52+02:00" level=debug msg="Deactivated ZFS volume" dev=lxd-default/virtual-machines/ubuntu-vm.block driver=zfs pool=default volName=ubuntu-vm
time="2023-07-26T23:03:52+02:00" level=debug msg="UnmountInstance finished" driver=zfs instance=ubuntu-vm pool=default project=default
time="2023-07-26T23:03:52+02:00" level=debug msg="Migrate receive transfer finished" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:52+02:00" level=debug msg="Sending migration failure response to source" err="Failed restoring checkpoint from source: Monitor is disconnected" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:52+02:00" level=debug msg="Start finished" instance=ubuntu-vm instanceType=virtual-machine project=default stateful=true
time="2023-07-26T23:03:52+02:00" level=debug msg="Migration storage NBD export finished" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:52+02:00" level=debug msg="DeleteInstance started" driver=zfs instance=ubuntu-vm pool=default project=default
time="2023-07-26T23:03:52+02:00" level=debug msg="Deleting instance volume" driver=zfs instance=ubuntu-vm pool=default project=default volName=ubuntu-vm
time="2023-07-26T23:03:52+02:00" level=info msg="Migration receive stopped" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T23:03:52+02:00" level=debug msg="DeleteInstance finished" driver=zfs instance=ubuntu-vm pool=default project=default
time="2023-07-26T23:03:52+02:00" level=debug msg="Removing device" device=root instance=ubuntu-vm instanceType=virtual-machine project=default type=disk
time="2023-07-26T23:03:52+02:00" level=error msg="Failed migration on target" clusterMoveSourceName= err="Failed restoring checkpoint from source: Monitor is disconnected" instance=ubuntu-vm live=true project=default push=false
time="2023-07-26T23:03:52+02:00" level=info msg="Migration channels disconnected on target" clusterMoveSourceName= instance=ubuntu-vm live=true project=default push=false
time="2023-07-26T23:03:52+02:00" level=info msg="ID: 86016410-5f55-4f20-a72c-813a19439272, Class: task, Description: Creating instance" CreatedAt="2023-07-26 23:03:07.42221753 +0200 CEST" Err="Error transferring instance data: Failed migration on target: Failed restoring checkpoint from source: Monitor is disconnected" Location=none MayCancel=false Metadata="map[]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Failure StatusCode=Failure UpdatedAt="2023-07-26 23:03:07.42221753 +0200 CEST"
time="2023-07-26T23:03:52+02:00" level=debug msg="Failure for operation" class=task description="Creating instance" err="Error transferring instance data: Failed migration on target: Failed restoring checkpoint from source: Monitor is disconnected" operation=86016410-5f55-4f20-a72c-813a19439272 project=default
time="2023-07-26T23:03:52+02:00" level=debug msg="Event listener server handler stopped" listener=9a73d80b-f579-4db8-9be6-1b27ced3483e local="192.168.4.200:8443" remote="192.168.4.58:58806"
time="2023-07-26T23:04:31+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0 username=root
time="2023-07-26T23:04:31+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0/networks username=root
time="2023-07-26T23:04:31+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0 username=root
time="2023-07-26T23:04:31+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0/profiles/default username=root
time="2023-07-26T23:04:31+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url="/1.0/storage-pools?recursion=1" username=root
time="2023-07-26T23:04:31+02:00" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url="/1.0/networks?recursion=1" username=root
time="2023-07-26T23:04:31+02:00" level=debug msg="Handling API request" ip=@ method=POST protocol=unix url=/1.0/networks username=root

I couldn’t see any new details in the logs. And the source machine again.

time="2023-07-26T21:02:50Z" level=debug msg="Event listener server handler started" id=fe885faa-d77c-4d49-83c7-70bc05d70815 local=/var/snap/lxd/common/lxd/unix.socket remote=@
time="2023-07-26T21:02:57Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T21:02:57Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T21:02:57Z" level=debug msg="Completed heartbeat round" duration=12.273811ms local="192.168.4.58:8443"
time="2023-07-26T21:03:07Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T21:03:07Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T21:03:07Z" level=debug msg="Completed heartbeat round" duration=9.729596ms local="192.168.4.58:8443"
time="2023-07-26T21:03:07Z" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0 username=ta
time="2023-07-26T21:03:07Z" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0/instances/ubuntu-vm username=ta
time="2023-07-26T21:03:07Z" level=debug msg="Handling API request" ip=@ method=GET protocol=unix url=/1.0/events username=ta
time="2023-07-26T21:03:07Z" level=debug msg="Handling API request" ip=@ method=POST protocol=unix url=/1.0/instances/ubuntu-vm username=ta
time="2023-07-26T21:03:07Z" level=debug msg="Event listener server handler started" id=f27516fb-6c0e-4915-bc15-591cb0b047c9 local=/var/snap/lxd/common/lxd/unix.socket remote=@
time="2023-07-26T21:03:07Z" level=debug msg="New operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:07Z" level=info msg="Waiting for migration control connection on source" clusterMoveSourceName= instance=ubuntu-vm live=true project=default push=false
time="2023-07-26T21:03:07Z" level=debug msg="Started operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:07Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Pending StatusCode=Pending UpdatedAt="2023-07-26 21:03:07.387342399 +0000 UTC"
time="2023-07-26T21:03:07Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:07.387342399 +0000 UTC"
time="2023-07-26T21:03:07Z" level=debug msg="Connecting to operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:07Z" level=debug msg="Connected to operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:07Z" level=info msg="Migration send starting" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:07Z" level=info msg="Migration control connection established on source" clusterMoveSourceName= instance=ubuntu-vm live=true project=default push=false
time="2023-07-26T21:03:07Z" level=debug msg="Allowing untrusted GET" ip="192.168.4.200:33436" url="/1.0/operations/3a860367-9225-4210-a827-274a35d95551/websocket?secret=df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab"
time="2023-07-26T21:03:07Z" level=debug msg="Connected to operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:07Z" level=debug msg="Allowing untrusted GET" ip="192.168.4.200:33450" url="/1.0/operations/3a860367-9225-4210-a827-274a35d95551/websocket?secret=24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7"
time="2023-07-26T21:03:07Z" level=debug msg="Connecting to operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:07Z" level=debug msg="MountInstance started" driver=zfs instance=ubuntu-vm pool=local project=default
time="2023-07-26T21:03:07Z" level=debug msg="UnmountInstance started" driver=zfs instance=ubuntu-vm pool=local project=default
time="2023-07-26T21:03:07Z" level=debug msg="MountInstance finished" driver=zfs instance=ubuntu-vm pool=local project=default
time="2023-07-26T21:03:07Z" level=debug msg="Skipping unmount as in use" driver=zfs pool=local refCount=1 volName=ubuntu-vm
time="2023-07-26T21:03:07Z" level=debug msg="UnmountInstance finished" driver=zfs instance=ubuntu-vm pool=local project=default
time="2023-07-26T21:03:07Z" level=debug msg="Set migration offer volume size" blockSize=10737418240 instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:07Z" level=debug msg="Sending migration offer to target" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:07Z" level=debug msg="Waiting for migration offer response from target" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:07Z" level=debug msg="Got migration offer response from target" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:07Z" level=debug msg="Allowing untrusted GET" ip="192.168.4.200:33460" url="/1.0/operations/3a860367-9225-4210-a827-274a35d95551/websocket?secret=b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb"
time="2023-07-26T21:03:07Z" level=debug msg="Connecting to operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:07Z" level=debug msg="Connected to operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:07Z" level=debug msg="Migrate send control monitor started" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:07Z" level=debug msg="Migrate send transfer started" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:07Z" level=debug msg="Setup temporary migration storage snapshot" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:07Z" level=debug msg="MigrateInstance started" args="&{IndexHeaderVersion:1 Name:ubuntu-vm Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true MultiSync:false FinalSync:false Data:<nil> ContentType: AllowInconsistent:true Refresh:false Info:0xc000015470 VolumeOnly:false ClusterMove:false}" driver=zfs instance=ubuntu-vm pool=local project=default
time="2023-07-26T21:03:07Z" level=debug msg="Sent migration index header, waiting for response" args="&{IndexHeaderVersion:1 Name:ubuntu-vm Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true MultiSync:false FinalSync:false Data:<nil> ContentType: AllowInconsistent:true Refresh:false Info:0xc000015470 VolumeOnly:false ClusterMove:false}" driver=zfs instance=ubuntu-vm pool=local project=default version=1
time="2023-07-26T21:03:07Z" level=debug msg="Websocket: Sending barrier message" address="192.168.4.200:33450"
time="2023-07-26T21:03:07Z" level=info msg="Received migration index header response" args="&{IndexHeaderVersion:1 Name:ubuntu-vm Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true MultiSync:false FinalSync:false Data:<nil> ContentType: AllowInconsistent:true Refresh:false Info:0xc000015470 VolumeOnly:false ClusterMove:false}" driver=zfs instance=ubuntu-vm pool=local project=default response="{StatusCode:200 Error: Refresh:0xc0001aa493}" version=1
time="2023-07-26T21:03:07Z" level=debug msg="Websocket: Got barrier message" address="192.168.4.200:33450"
time="2023-07-26T21:03:07Z" level=debug msg="Websocket: Sending barrier message" address="192.168.4.200:33450"
time="2023-07-26T21:03:08Z" level=debug msg="Websocket: Sending barrier message" address="192.168.4.200:33450"
time="2023-07-26T21:03:09Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:09Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 19.74MB (19.55MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:09.438995738 +0000 UTC"
time="2023-07-26T21:03:10Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:10Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 137.23MB (68.25MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:10.439853803 +0000 UTC"
time="2023-07-26T21:03:11Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:11Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 255.43MB (84.65MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:11.446673064 +0000 UTC"
time="2023-07-26T21:03:12Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:12Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 373.98MB (92.85MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:12.456735964 +0000 UTC"
time="2023-07-26T21:03:13Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:13Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 492.13MB (97.76MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:13.463087833 +0000 UTC"
time="2023-07-26T21:03:14Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:14Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 610.28MB (101.04MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:14.469358673 +0000 UTC"
time="2023-07-26T21:03:15Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:15Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 728.57MB (103.38MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:15.476770135 +0000 UTC"
time="2023-07-26T21:03:16Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:16Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 846.05MB (105.12MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:16.477295506 +0000 UTC"
time="2023-07-26T21:03:17Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T21:03:17Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T21:03:17Z" level=debug msg="Completed heartbeat round" duration=3.682025ms local="192.168.4.58:8443"
time="2023-07-26T21:03:17Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:17Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 964.10MB (106.49MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:17.482549022 +0000 UTC"
time="2023-07-26T21:03:18Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:18Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 1.08GB (107.58MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:18.487238741 +0000 UTC"
time="2023-07-26T21:03:19Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:19Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 1.20GB (108.44MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:19.492085286 +0000 UTC"
time="2023-07-26T21:03:20Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:20Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 1.32GB (109.19MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:20.498933358 +0000 UTC"
time="2023-07-26T21:03:21Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:21Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 1.44GB (109.83MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:21.500997548 +0000 UTC"
time="2023-07-26T21:03:22Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:22Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 1.55GB (110.37MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:22.511036913 +0000 UTC"
time="2023-07-26T21:03:23Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:23Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 1.67GB (110.84MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:23.514641659 +0000 UTC"
time="2023-07-26T21:03:24Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:24Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 1.79GB (111.25MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:24.525380148 +0000 UTC"
time="2023-07-26T21:03:25Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:25Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 1.91GB (111.61MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:25.525943374 +0000 UTC"
time="2023-07-26T21:03:26Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:26Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 2.03GB (111.93MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:26.526969035 +0000 UTC"
time="2023-07-26T21:03:27Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T21:03:27Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T21:03:27Z" level=debug msg="Completed heartbeat round" duration=3.697149ms local="192.168.4.58:8443"
time="2023-07-26T21:03:27Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:27Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 2.14GB (112.22MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:27.530647414 +0000 UTC"
time="2023-07-26T21:03:28Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:28Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 2.26GB (112.48MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:28.53375345 +0000 UTC"
time="2023-07-26T21:03:29Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:29Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 2.38GB (112.71MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:29.542742149 +0000 UTC"
time="2023-07-26T21:03:30Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:30Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 2.50GB (112.93MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:30.543812363 +0000 UTC"
time="2023-07-26T21:03:31Z" level=debug msg="Updated metadata for operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:31Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 2.62GB (113.16MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Running StatusCode=Running UpdatedAt="2023-07-26 21:03:31.543816503 +0000 UTC"
time="2023-07-26T21:03:32Z" level=debug msg="Websocket: Sending barrier message" address="192.168.4.200:33450"
time="2023-07-26T21:03:32Z" level=debug msg="Connecting to migration NBD storage target" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:32Z" level=debug msg="NBD listener waiting for accept" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:32Z" level=debug msg="MigrateInstance finished" args="&{IndexHeaderVersion:1 Name:ubuntu-vm Snapshots:[] MigrationType:{FSType:ZFS Features:[migration_header compress]} TrackProgress:true MultiSync:false FinalSync:false Data:<nil> ContentType: AllowInconsistent:true Refresh:false Info:0xc000015470 VolumeOnly:false ClusterMove:false}" driver=zfs instance=ubuntu-vm pool=local project=default
time="2023-07-26T21:03:32Z" level=debug msg="NBD connection on source started" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:37Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T21:03:37Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T21:03:37Z" level=debug msg="Completed heartbeat round" duration=3.796998ms local="192.168.4.58:8443"
time="2023-07-26T21:03:47Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T21:03:47Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T21:03:47Z" level=debug msg="Completed heartbeat round" duration=3.795887ms local="192.168.4.58:8443"
time="2023-07-26T21:03:50Z" level=debug msg="Connected to migration NBD storage target" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:50Z" level=debug msg="Migration storage snapshot transfer started" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:51Z" level=debug msg="Stateful migration checkpoint send starting" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:51Z" level=debug msg="Migration storage snapshot transfer finished" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:52Z" level=debug msg="Websocket: Got barrier message" address="192.168.4.200:33450"
time="2023-07-26T21:03:52Z" level=debug msg="NBD connection on source finished" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:52Z" level=debug msg="Migrate send control monitor finished" instance=ubuntu-vm instanceType=virtual-machine project=default
time="2023-07-26T21:03:52Z" level=debug msg="Cancelling operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:52Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 2.62GB (113.16MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Cancelling StatusCode=Cancelling UpdatedAt="2023-07-26 21:03:31.543816503 +0000 UTC"
time="2023-07-26T21:03:52Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=true Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 2.62GB (113.16MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Cancelling StatusCode=Cancelling UpdatedAt="2023-07-26 21:03:31.543816503 +0000 UTC"
time="2023-07-26T21:03:52Z" level=info msg="Action: operation-cancelled, Source: /1.0/operations/3a860367-9225-4210-a827-274a35d95551, Requestor: unix/ta (@)"
time="2023-07-26T21:03:52Z" level=debug msg="Handling API request" ip=@ method=DELETE protocol=unix url=/1.0/operations/3a860367-9225-4210-a827-274a35d95551 username=ta
time="2023-07-26T21:03:52Z" level=debug msg="Cancelled operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:52Z" level=debug msg="Cancelled operation" class=websocket description="Migrating instance" operation=3a860367-9225-4210-a827-274a35d95551 project=default
time="2023-07-26T21:03:52Z" level=info msg="ID: 3a860367-9225-4210-a827-274a35d95551, Class: websocket, Description: Migrating instance" CreatedAt="2023-07-26 21:03:07.387342399 +0000 UTC" Err= Location=ta-lxlt MayCancel=false Metadata="map[control:df908be120cb0f7bbfa720ef9353503020b0327feb7b60cdc47a7eb7b1aa36ab criu:b74f410308ef72f37de9464d7839d2e0deaa110182d0cadcb33fbd95babf4afb fs:24ba6568d8ee8f8d466b537b3c814ee49ce46a471d498c1950e0491290317ce7 fs_progress:ubuntu-vm: 2.62GB (113.16MB/s)]" Resources="map[instances:[/1.0/instances/ubuntu-vm]]" Status=Cancelled StatusCode=Cancelled UpdatedAt="2023-07-26 21:03:31.543816503 +0000 UTC"
time="2023-07-26T21:03:52Z" level=debug msg="Event listener server handler stopped" listener=f27516fb-6c0e-4915-bc15-591cb0b047c9 local=/var/snap/lxd/common/lxd/unix.socket remote=@
time="2023-07-26T21:03:57Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T21:03:57Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T21:03:57Z" level=debug msg="Completed heartbeat round" duration=9.992955ms local="192.168.4.58:8443"
time="2023-07-26T21:04:07Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T21:04:07Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T21:04:07Z" level=debug msg="Completed heartbeat round" duration=12.471181ms local="192.168.4.58:8443"
time="2023-07-26T21:04:17Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T21:04:17Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T21:04:17Z" level=debug msg="Completed heartbeat round" duration=10.186359ms local="192.168.4.58:8443"
time="2023-07-26T21:04:27Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T21:04:27Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T21:04:27Z" level=debug msg="Completed heartbeat round" duration=9.558008ms local="192.168.4.58:8443"
time="2023-07-26T21:04:37Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T21:04:37Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T21:04:37Z" level=debug msg="Completed heartbeat round" duration=10.290316ms local="192.168.4.58:8443"
time="2023-07-26T21:04:47Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T21:04:47Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T21:04:47Z" level=debug msg="Completed heartbeat round" duration=10.224809ms local="192.168.4.58:8443"
time="2023-07-26T21:04:57Z" level=debug msg="Heartbeat updating local raft members" members="[{{1 192.168.4.58:8443 voter} ta-lxlt}]"
time="2023-07-26T21:04:57Z" level=debug msg="Starting heartbeat round" local="192.168.4.58:8443" mode=normal
time="2023-07-26T21:04:57Z" level=debug msg="Completed heartbeat round" duration=10.544922ms local="192.168.4.58:8443"

So I still can’t move a machine. The name of the single existing storage pool is different on the two machines since one machine was a single-node LXD cluster with “local” as storage pool and the other is without cluster with “default” as storage pool. If that matters, I will reinstall LXD again.

This time I tested everything with LXD 5.15.

update:

And I also realized during the test that I didn’t had an network on the target machine at the first time and I had to disable ESET antivirus to create one with automatically detected subnet. ESET also changes the certificates somehow so that could be the reason of my TLS error. So I think I should repeat everything next time again but without ESET. However, when I disabled it, I could still not move the virtual machine and I believe logs were the same, but at this point I’m not sure when and what I ran so I think I will repeat this experiment later and share the correct logs.

chitvan1988 · August 1, 2023, 5:32am

Is VM Live Migration possible using remotes only(i.e without cluster) ?
Reason of fearful of cluster is upgrade part as one single mistake in upgrade can break the entire thing.

ru-fu · August 1, 2023, 7:12am

Yes, there’s no requirement for a cluster.
See https://documentation.ubuntu.com/lxd/en/latest/howto/move_instances/#live-migration

rimelek · August 1, 2023, 9:44pm

I’m still trying to figure out what causes the issue and there is something in the sourcecode that I just don’t understand.

https://github.com/canonical/lxd/blob/b1b45dae878185970b7908fbe00b606beaea19e2/lxd/device/device_utils_disk.go#L460

	if shared.IsTrue(inst.ExpandedConfig()["migration.stateful"]) {
		return nil, nil, UnsupportedError{"Stateful migration unsupported"}
	}

Since “Stateful migration unsupported” is part of my error message, I tried to understand why it would be unsupported. This conditional statement seems odd to me. migration.stateful has to be set to true in order to use live migration, but it looks like when the value is true the function returns this error message. Am I interpreting it wrong? I checked the source of the LTS version as well. It has the same condition.

tomp · August 2, 2023, 6:54am

That’s a warning not the error.

rimelek · August 2, 2023, 7:44pm

Do I misunderstand what stateful migration is? I tried to do stateful migration and I got “Stateful migration is not supported” and it is returned as “UnsupportedError” before virtiofsd could start later in the same function. The reason I don’t understand it, because regardless of what we call it (warning or error) it is returned when “migration.stateful” is enabled which is (as far as I know) required for stateful migration).

Since I wasn’t sure I knew what stateful migration was and couldn’t find more detailed description in the documentation I also asked some AI (although I generally avoid that) and it told me that in order to use stateful migration, the VM must be stateless. Which just confused me more, but I was just cruious what answer it would give me. I could understand if stateful migration worked only with a remote filesystem like ceph, but the virtual machine image seemed to be copied to the remote server and the migration failed when it tried to restore the state of the VM which I guess the memory. Is it true that the state could only be stored on a remote filesystem from which the new VM can restore it?

I really try to understand the concept and I would be willing to read for days about it, but all I found in the documentation about live migrating VMs was basically one paragraph mentioning the thre required configurations. I have no problem with investigating for weeks, but I wouldn’t spend so much time on the problem if it is not for what I wanted: moving a simple virtual machine with the ZFS backend from one physical server to another while the virtual machine is running.

I tried the --instance-only and --allow-inconsistent parameters, but didn’t help. I tried changing the --mode from pull to push, but didn’t help. Then I added --stateless and the VM was moved except that it was stopped before moving and lost its state.

If the conditional statement I found in the sourcecode is not a bug and it is intentionally shared.IsTrue and not something like shared.IsFalseOrEmpty, then It seems I indeed misunderstand this feature.

Can you recommend anything that I should read that helps me to understand it?

(I also considered building LXD from source so I could see what happens when I change something, but it would be probably harder than I have time for at the moment, so it wouldn’t be my first choice.)

Thank you!

ru-fu · August 3, 2023, 6:58am

Not sure if it helps in your particular case, but here’s the specification for VM live migration: https://discuss.linuxcontainers.org/t/lxd-online-vm-live-migration-qemu-to-qemu/16635
(It’s also linked from the documentation.)

rimelek · August 3, 2023, 7:14am

Thank you, ru-fu, but I already shared this link in my first post. Since you recommended it, I will check it again.

tomp · August 24, 2023, 9:16am

This is a misnomer, the warning message is just saying that the config drive will be exported to the VM using 9p rather than virtio-fs as well (because it has migration.stateful enabled and virtio-fs doesn’t support stateful migration).

So the message is actually a good sign that stateful migration should be possible.

It seems to be failing for some other reason.

tomp · August 24, 2023, 9:19am

What I would like you to do is check that a) general offline migration is working and b) that the stateful dump file can be restored on the target machine.

To do this perform the following steps:

Start the VM on the source.
Perform a stateful stop of it using lxc stop <instance> --stateful.
Move the stopped VM to the target host - does this succeed?
Try and start the VM now its on the target host - does this succeed?

In this way we are breaking down the problem into 2 parts that can be diagnosed separately.
I find this to be a useful tactic when trying to diagnose a problem.

rimelek · August 27, 2023, 1:12pm

It was indeed very useful @tomp, thank you. Moving the virtual machine worked but then I got this error message when I wanted to start:

Error: Failed restoring state from "/var/snap/lxd/common/lxd/virtual-machines/centos-test/state": Monitor is disconnected
Try `lxc info --show-log centos-test` for more info

So I checked the logs:

Name: centos-test
Status: STOPPED
Type: virtual-machine
Architecture: x86_64
Location: vsbud-dl2
Created: 2023/08/27 12:50 UTC

Log:

qemu-system-x86_64: Missing section footer for 0000:00:1f.0/ICH9LPC
qemu-system-x86_64: load of migration failed: Invalid argument

I remember similar error messages from forum topics so I can try to look for those again. Searching for the pci address on my source and target machine, this is what I got:

source:

00:1f.0 ISA bridge: Intel Corporation Comet Lake PCH-LP LPC Premium Controller/eSPI Controller

Target (server):

00:1f.0 ISA bridge: Intel Corporation C621 Series Chipset LPC/eSPI Controller (rev 09)

Target (other laptop)

Logs

Name: centos-test
Status: STOPPED
Type: virtual-machine
Architecture: x86_64
Created: 2023/08/27 13:08 UTC

Log:

qemu-system-x86_64: Missing section footer for 0000:00:1f.0/ICH9LPC
qemu-system-x86_64: warning: TSC frequency mismatch between VM (2304001 kHz) and host (2207997 kHz), and TSC scaling unavailable
qemu-system-x86_64: load of migration failed: Invalid argument

pci

00:1f.0 ISA bridge: Intel Corporation HM470 Chipset LPC/eSPI Controller (rev 10)