Noticed a proxmox-zfs bug

dmora

New Member
Oct 17, 2016
28
0
1
40
tldr;
If you start a VM migration whos disks reside on a zfs volume and for whatever reason cancel in the middle of its progress, proxmox will not properly clean itself up resulting in failures of consequent attempts to migrate that same VM. Solution is to manually remove the zfs snapshots proxmox left behind on the ORIGINATING host.

Detailed version...
Running pve 4.3, cluster of 10 nodes, if you cancel an offline migration of zfs local storage, proxmox will fail to clean up the volume snapshot(s) that were created to migrate the VM on the originating host. The next time you try to migrate that VM, you'll get an error like this:
"Dec 25 17:19:38 ERROR: found stale volume copy 'zfsLocalStorage:vm-103-disk-2' on node 'prx019'"

So in this case I migrated vmid 103 , from node prx027 to prx019 and purposely canceled the migration. The procedure has been confirmed to be repeatable across any node.
The error above is also deceiving and incorrect. The "stale volume" actually resides on the originating node(prx027 in this case) and not the receiver(prx019) as the error indicates.

Migration and migration cancellation
Dec 25 17:16:21 starting migration of VM 103 to node 'prx019' (x.x.x.x)
Dec 25 17:16:21 copying disk images
Dec 25 17:16:21 found local disk 'zfsLocalStorage:vm-103-disk-1' (in current VM config)
Dec 25 17:16:21 found local disk 'zfsLocalStorage:vm-103-disk-2' (in current VM config)
Dec 25 17:16:21 found local disk 'zfsLocalStorage:vm-103-disk-3' (in current VM config)
Dec 25 17:16:21 found local disk 'zfsLocalStorage:vm-103-disk-4' (in current VM config)
send from @ to zfsStoragePool001/vm-103-disk-2@__migration__ estimated size is 17.0M
total estimated size is 17.0M
TIME SENT SNAPSHOT
send from @ to zfsStoragePool001/vm-103-disk-4@__migration__ estimated size is 19.3M
total estimated size is 19.3M
TIME SENT SNAPSHOT
send from @ to zfsStoragePool001/vm-103-disk-1@__migration__ estimated size is 4.00G
total estimated size is 4.00G
TIME SENT SNAPSHOT
17:16:23 109M zfsStoragePool001/vm-103-disk-1@__migration__
17:16:24 218M zfsStoragePool001/vm-103-disk-1@__migration__
17:16:25 330M zfsStoragePool001/vm-103-disk-1@__migration__
17:16:26 441M zfsStoragePool001/vm-103-disk-1@__migration__
17:16:27 553M zfsStoragePool001/vm-103-disk-1@__migration__
17:16:28 661M zfsStoragePool001/vm-103-disk-1@__migration__
Dec 25 17:16:28 ERROR: Failed to sync data - command 'set -o pipefail && zfs send -Rpv zfsStoragePool001/vm-103-disk-1@__migration__ | ssh root@x.x.x.x zfs recv zfsStoragePool001/vm-103-disk-1' failed: interrupted by signal
Dec 25 17:16:28 aborting phase 1 - cleanup resources
Dec 25 17:16:28 ERROR: found stale volume copy 'zfsLocalStorage:vm-103-disk-2' on node 'prx019'
Dec 25 17:16:28 ERROR: found stale volume copy 'zfsLocalStorage:vm-103-disk-4' on node 'prx019'
Dec 25 17:16:28 ERROR: found stale volume copy 'zfsLocalStorage:vm-103-disk-1' on node 'prx019'
Dec 25 17:16:28 ERROR: migration aborted (duration 00:00:07): Failed to sync data - command 'set -o pipefail && zfs send -Rpv zfsStoragePool001/vm-103-disk-1@__migration__ | ssh root@x.x.x.x zfs recv zfsStoragePool001/vm-103-disk-1' failed: interrupted by signal
TASK ERROR: migration aborted

So heres what happens when you go to migrate that same VM again:
()
Dec 25 17:19:38 starting migration of VM 103 to node 'prx019' (x.x.x.x)
Dec 25 17:19:38 copying disk images
Dec 25 17:19:38 found local disk 'zfsLocalStorage:vm-103-disk-1' (in current VM config)
Dec 25 17:19:38 found local disk 'zfsLocalStorage:vm-103-disk-2' (in current VM config)
Dec 25 17:19:38 found local disk 'zfsLocalStorage:vm-103-disk-3' (in current VM config)
Dec 25 17:19:38 found local disk 'zfsLocalStorage:vm-103-disk-4' (in current VM config)
cannot create snapshot 'zfsStoragePool001/vm-103-disk-2@__migration__': dataset already exists
Dec 25 17:19:38 ERROR: Failed to sync data - command 'zfs snapshot zfsStoragePool001/vm-103-disk-2@__migration__' failed: exit code 1
Dec 25 17:19:38 aborting phase 1 - cleanup resources
Dec 25 17:19:38 ERROR: found stale volume copy 'zfsLocalStorage:vm-103-disk-2' on node 'prx019'
Dec 25 17:19:38 ERROR: migration aborted (duration 00:00:00): Failed to sync data - command 'zfs snapshot zfsStoragePool001/vm-103-disk-2@__migration__' failed: exit code 1
TASK ERROR: migration aborted

Note in the above error, there are 2 conflicting messages
1) Which is accurate
Dec 25 17:19:38 found local disk 'zfsLocalStorage:vm-103-disk-4' (in current VM config)
cannot create snapshot 'zfsStoragePool001/vm-103-disk-2@__migration__': dataset already exists
Dec 25 17:19:38 ERROR: Failed to sync data - command 'zfs snapshot zfsStoragePool001/vm-103-disk-2@__migration__' failed: exit code 1

2) The error people will likely read since its the most explicit and is trying to point you in the direction of where the failure is, but is wrong.
Dec 25 17:19:38 ERROR: found stale volume copy 'zfsLocalStorage:vm-103-disk-2' on node 'prx019'

Here are those snapshots, the error is warning about, however, again they reside on the originating node, not the receiver.
Code:
root@prx027:/home# zfs list -t snapshot
NAME  USED  AVAIL  REFER  MOUNTPOINT
zfsStoragePool001/vm-103-disk-2@__migration__  0  -  17.3M  -
zfsStoragePool001/vm-103-disk-4@__migration__  0  -  19.6M  -

The solution is to simply remove these snapshots at shell from the originating host.
Code:
root@prx027:/home# zfs list -t snapshot
NAME  USED  AVAIL  REFER  MOUNTPOINT
zfsStoragePool001/vm-103-disk-2@__migration__  0  -  17.3M  -
zfsStoragePool001/vm-103-disk-4@__migration__  0  -  19.6M  -

root@prx027:/home# zfs destroy zfsStoragePool001/vm-103-disk-2@__migration__
root@prx027:/home# zfs destroy zfsStoragePool001/vm-103-disk-4@__migration__

root@prx027:/home# zfs list -t snapshot
no datasets available

Might want to fix that in later releases.
 
Hi. I would like to state that I just hit this error condition as well.

The reason why I am writing here, is that this is December 2018. This is still a bug, and I would like to inform of that fact.

The description is of the bug above reflects my situation precisely.
The solution provided also works perfectly (phew!).


HOW I CAUSED THE ERROR:
Behavior - Goal: I flimsily and goofied around the command line - while trying to improve the backup times I was seeing.
I was going to try to change the VZDUMP backup method from SUSPEND to SNAPSHOT.

This worked perfectly. But I needed to try out what was the fastest TMP directory. As I was testing this out, I was starting up the backup procedure with vzdump several times. This led to vzdump not properly cleaning up the zfs snapshots as it probably ought to be doing.
So ... Precisely as the Original Poster described.


Environment information:
- PROXMOX VERSION- pve-manager/5.3-5/97ae681d (running kernel: 4.15.18-9-pve)
- LINUX KERNEL - Linux darkstar.net 4.15.18-9-pve #1 SMP PVE 4.15.18-30 (Thu, 15 Nov 2018 13:32:46 +0100) x86_64 GNU/Linux
- ZFS VERSION (zol version) -
# modinfo zfs | grep version:
version: 0.7.12-1
srcversion: 033C14157650F7B14E630BD

Solution to my problem, as above was to do the following:
Code:
root@prx027:/home# zfs list -t snapshot
NAME  USED  AVAIL  REFER  MOUNTPOINT
zfsStoragePool001/vm-103-disk-2@__migration__  0  -  17.3M  -
zfsStoragePool001/vm-103-disk-4@__migration__  0  -  19.6M  -

root@prx027:/home# zfs destroy zfsStoragePool001/vm-103-disk-2@__migration__
root@prx027:/home# zfs destroy zfsStoragePool001/vm-103-disk-4@__migration__

root@prx027:/home# zfs list -t snapshot
no datasets available
 
Last edited:

About

The Proxmox community has been around for many years and offers help and support for Proxmox VE, Proxmox Backup Server, and Proxmox Mail Gateway.
We think our community is one of the best thanks to people like you!

Get your subscription!

The Proxmox team works very hard to make sure you are running the best software and getting stable updates and security enhancements, as well as quick enterprise support. Tens of thousands of happy customers have a Proxmox subscription. Get yours easily in our online shop.

Buy now!