-
Notifications
You must be signed in to change notification settings - Fork 509
Description
Description
Incremental backup fail in flattening proccess when using Ceph and rsync backup driver. There are no errors in the VM logs, but inside the backup image show up an error:
Sat Jan 18 16:11:02 2025 : Error flattening backup increments: ERROR: reconstruct_chains: Command failed: export LANG=C export LC_ALL=C set -e -o pipefail; shopt -qs failglob qemu-img rebase -u -F qcow2 -b '/var/lib/one/datastores/104/28/997b7f/disk.0.rbd2' '/var/lib/one/datastores/104/28/31cdde/disk.0.1.rbdiff'ERROR: reconstruct_chains: [STDOUT] "" ERROR: reconstruct_chains: [STDERR] "WARNING: Image format was not specified for '/var/lib/one/datastores/104/28/31cdde/disk.0.1.rbdiff' and probing guessed raw.\n Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted.\n Specify the 'raw' format explicitly to remove the restrictions.\nqemu-img: Could not change the backing file to '/var/lib/one/datastores/104/28/997b7f/disk.0.rbd2': Operation not supported\n" /var/lib/one/remotes/datastore/rsync/increment_flatten:149:in `<main>': Unable to reconstruct qcow2 chains: WARNING: Image format was not specified for '/var/lib/one/datastores/104/28/31cdde/disk.0.1.rbdiff' and probing guessed raw. (StandardError) Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted. Specify the 'raw' format explicitly to remove the restrictions. qemu-img: Could not change the backing file to '/var/lib/one/datastores/104/28/997b7f/disk.0.rbd2': Operation not supported
Error from FSunstone:
Error from RSunstone:
No error on VM logs:
tail -f /var/log/one/28.log
Sat Jan 18 17:25:50 2025 [Z0][VMM][I]: VM Disk successfully attached.
Sat Jan 18 17:25:50 2025 [Z0][LCM][I]: VM Disk successfully attached.
Sat Jan 18 17:25:50 2025 [Z0][VM][I]: New LCM state is RUNNING
Sat Jan 18 17:29:37 2025 [Z0][VM][I]: New LCM state is BACKUP
Sat Jan 18 17:29:48 2025 [Z0][VMM][I]: Successfully execute transfer manager driver operation: prebackup_live.
Sat Jan 18 17:30:16 2025 [Z0][VMM][I]: Successfully execute datastore driver operation: backup.
Sat Jan 18 17:30:17 2025 [Z0][VMM][I]: Successfully execute transfer manager driver operation: postbackup_live.
Sat Jan 18 17:30:18 2025 [Z0][VMM][I]: VM backup successfully created.
Sat Jan 18 17:30:18 2025 [Z0][VM][I]: New LCM state is RUNNING
Sat Jan 18 17:30:47 2025 [Z0][VM][I]: New LCM state is BACKUP
Sat Jan 18 17:30:58 2025 [Z0][VMM][I]: Successfully execute transfer manager driver operation: prebackup_live.
Sat Jan 18 17:31:26 2025 [Z0][VMM][I]: Successfully execute datastore driver operation: backup.
Sat Jan 18 17:31:27 2025 [Z0][VMM][I]: Successfully execute transfer manager driver operation: postbackup_live.
Sat Jan 18 17:31:27 2025 [Z0][VMM][I]: VM backup successfully created.
Sat Jan 18 17:31:27 2025 [Z0][VM][I]: New LCM state is RUNNING
Sat Jan 18 17:31:53 2025 [Z0][VM][I]: New LCM state is BACKUP
Sat Jan 18 17:31:59 2025 [Z0][VMM][I]: Successfully execute transfer manager driver operation: prebackup_live.
Sat Jan 18 17:32:01 2025 [Z0][VMM][I]: Successfully execute datastore driver operation: backup.
Sat Jan 18 17:32:02 2025 [Z0][VMM][I]: Successfully execute transfer manager driver operation: postbackup_live.
Sat Jan 18 17:32:02 2025 [Z0][VMM][I]: VM backup successfully created.
Sat Jan 18 17:32:02 2025 [Z0][VM][I]: New LCM state is RUNNING
Sat Jan 18 17:32:42 2025 [Z0][VM][I]: New LCM state is BACKUP
Sat Jan 18 17:32:50 2025 [Z0][VMM][I]: Successfully execute transfer manager driver operation: prebackup_live.
Sat Jan 18 17:32:51 2025 [Z0][VMM][I]: Successfully execute datastore driver operation: backup.
Sat Jan 18 17:32:52 2025 [Z0][VMM][I]: Successfully execute transfer manager driver operation: postbackup_live.
Sat Jan 18 17:32:52 2025 [Z0][VMM][I]: VM backup successfully created.
Sat Jan 18 17:32:52 2025 [Z0][VM][I]: New LCM state is RUNNING
Sat Jan 18 17:33:26 2025 [Z0][VM][I]: New LCM state is BACKUP
Sat Jan 18 17:33:32 2025 [Z0][VMM][I]: Successfully execute transfer manager driver operation: prebackup_live.
Sat Jan 18 17:33:33 2025 [Z0][VMM][I]: Successfully execute datastore driver operation: backup.
Sat Jan 18 17:33:34 2025 [Z0][VMM][I]: Successfully execute transfer manager driver operation: postbackup_live.
Sat Jan 18 17:33:34 2025 [Z0][VMM][I]: VM backup successfully created.
Sat Jan 18 17:33:34 2025 [Z0][VM][I]: New LCM state is RUNNING
Sat Jan 18 17:33:34 2025 [Z0][LCM][I]: Removing 1 backup increments
To Reproduce
1-Configure system and images datastores for ceph.
2-Create a VM with 2 disks from images in datastores with TM_MAD: ceph
: one from the OS disk type and the ther one an empty datablock image.
3-Partitionate, format and mount the second disk (Your VM has now 2 disks online).
4-Configure the VM for Single VM Backups, with:
FS_FREEZE=AGENT
INCREMENT_MODE=CBT
KEEP_LAST=3
MODE=INCREMENT
5-Execute 1st backup, 2nd backup, 3rd backup and the 4th backup will not be completed.
FSunstone showing 4 increments instead of 3.
RSunstone showing 4 increments instead of 3.
After this error you cant perform any other backup over that backup image. You need to delete the given backup image and create a new one. The flattening process will fails again and will be on same situation as older backup image. This works when using different TM_MAD, for example, a datastore shared
.
Checking VM configuration:
onevm updateconf 28
The output is as follow:
OS=[
ARCH="x86_64",
BOOT="disk0",
UUID="27c3321c-7ba3-4fe9-9bfe-6ad253b03c9f" ]
FEATURES=[
ACPI="yes" ]
GRAPHICS=[
LISTEN="0.0.0.0",
PORT="5928",
TYPE="VNC" ]
CONTEXT=[
DISK_ID="1",
NETWORK="YES",
PASSWORD="qjASm5JBKqzAzZ6d1aJ25Q==",
ROOT_PASSWORD="123",
SET_HOSTNAME="test-backup-rsync-ceph",
SSH_PUBLIC_KEY="",
TARGET="hda" ]
BACKUP_CONFIG=[
ACTIVE_FLATTEN="NO",
BACKUP_VOLATILE="YES",
FS_FREEZE="AGENT",
INCREMENTAL_BACKUP_ID="65",
INCREMENT_MODE="CBT",
KEEP_LAST="3",
LAST_INCREMENT_ID="3",
MODE="INCREMENT" ]
Checking information from system datastore:
onedatastore show 0
DATASTORE 0 INFORMATION
ID : 0
NAME : system-hdd
USER : oneadmin
GROUP : oneadmin
CLUSTERS : 0,100
TYPE : SYSTEM
DS_MAD : -
TM_MAD : ceph
BASE PATH : /var/lib/one//datastores/0
DISK_TYPE : RBD
STATE : READY
DATASTORE CAPACITY
TOTAL: : 2T
FREE: : 2T
USED: : 2.1G
LIMIT: : 1.7T
PERMISSIONS
OWNER : um-
GROUP : u--
OTHER : ---
DATASTORE TEMPLATE
ALLOW_ORPHANS="mixed"
BRIDGE_LIST="LA-DEV-node1 LA-DEV-node2 LA-DEV-node3"
CEPH_HOST="LA-DEV-node1 LA-DEV-node2 LA-DEV-node3"
CEPH_SECRET="88235c94-0864-4074-92bb-42f99b7f282e"
CEPH_USER="libvirt"
DATASTORE_CAPACITY_CHECK="yes"
DISK_TYPE="RBD"
DS_MIGRATE="NO"
LIMIT_MB="1809632.15"
NAME="system-hdd"
POOL_NAME="hcx_pool1"
SHARED="YES"
TM_MAD="ceph"
TYPE="SYSTEM_DS"
IMAGES
Cheking information from images datastore:
DATASTORE 1 INFORMATION
ID : 1
NAME : images-hdd
USER : oneadmin
GROUP : oneadmin
CLUSTERS : 0,100
TYPE : IMAGE
DS_MAD : ceph
TM_MAD : ceph
BASE PATH : /var/lib/one//datastores/1
DISK_TYPE : RBD
STATE : READY
DATASTORE CAPACITY
TOTAL: : 2T
FREE: : 2T
USED: : 2.1G
LIMIT: : 1.7T
PERMISSIONS
OWNER : um-
GROUP : u--
OTHER : ---
DATASTORE TEMPLATE
ALLOW_ORPHANS="mixed"
BRIDGE_LIST="LA-DEV-node1 LA-DEV-node2 LA-DEV-node3"
CEPH_HOST="LA-DEV-node1 LA-DEV-node2 LA-DEV-node3"
CEPH_SECRET="88235c94-0864-4074-92bb-42f99b7f282e"
CEPH_USER="libvirt"
CLONE_TARGET="SELF"
CLONE_TARGET_SHARED="SELF"
CLONE_TARGET_SSH="SYSTEM"
COMPATIBLE_SYS_DS="0"
DATASTORE_CAPACITY_CHECK="yes"
DISK_TYPE="RBD"
DISK_TYPE_SHARED="RBD"
DISK_TYPE_SSH="FILE"
DRIVER="raw"
DS_MAD="ceph"
LIMIT_MB="1809632.15"
LN_TARGET="NONE"
LN_TARGET_SHARED="NONE"
LN_TARGET_SSH="SYSTEM"
NAME="images-hdd"
POOL_NAME="hcx_pool1"
SAFE_DIR="/var/tmp"
TM_MAD="ceph"
TM_MAD_SYSTEM="ssh,shared"
TYPE="IMAGE_DS"
IMAGES
57
63
Entire VM information:
onevm show 28
VIRTUAL MACHINE 28 INFORMATION
ID : 28
NAME : test-backup-rsync-ceph
USER : oneadmin
GROUP : oneadmin
STATE : ACTIVE
LCM_STATE : RUNNING
LOCK : None
RESCHED : No
HOST : LA-DEV-node1-kvm
CLUSTER ID : 100
CLUSTER : KVM
START TIME : 01/18 15:33:59
END TIME : -
DEPLOY ID : 27c3321c-7ba3-4fe9-9bfe-6ad253b03c9f
VIRTUAL MACHINE MONITORING
CPU : 0.0
MEMORY : 1018.9M
NETTX : 0K
NETRX : 0K
DISKRDBYTES : 1020193838
DISKRDIOPS : 37100
DISKWRBYTES : 345371136
DISKWRIOPS : 6029
ID : 28
TIMESTAMP : 1737251048
VM_QEMU_PING : QEMU Guest Agent monitoring disabled
PERMISSIONS
OWNER : um-
GROUP : ---
OTHER : ---
VM DISKS
ID DATASTORE TARGET IMAGE SIZE TYPE SAVE
0 images-hdd vda Ubuntu 22.04 (Virtalus) Ceph DS -/10G rbd NO
2 images-hdd vdb empty_disk_image_ceph -/5G rbd NO
1 - hda CONTEXT -/- - -
VIRTUAL MACHINE HISTORY
SEQ UID REQ HOST ACTION DS START TIME PROLOG
0 0 5504 LA- disk-attac 0 01/18 15:34:00 0d 00h01m 0h00m04s
1 0 8544 LA- backup 0 01/18 15:35:50 0d 00h10m 0h00m00s
2 0 9456 LA- backup 0 01/18 15:46:10 0d 00h07m 0h00m00s
3 0 4592 LA- backup 0 01/18 15:53:26 0d 00h01m 0h00m00s
4 0 9344 LA- backup 0 01/18 15:54:31 0d 00h01m 0h00m00s
5 0 9232 LA- backup 0 01/18 15:55:35 0d 00h11m 0h00m00s
6 0 3408 LA- backup 0 01/18 16:06:42 0d 00h02m 0h00m00s
7 0 2816 LA- backup 0 01/18 16:09:13 0d 00h00m 0h00m00s
8 0 1424 LA- backup 0 01/18 16:10:01 0d 00h00m 0h00m00s
9 0 3072 LA- disk-detac 0 01/18 16:10:55 0d 00h45m 0h00m00s
10 0 3920 LA- disk-attac 0 01/18 16:56:52 0d 00h00m 0h00m00s
11 0 3888 LA- disk-detac 0 01/18 16:57:04 0d 00h00m 0h00m00s
12 0 6672 LA- disk-attac 0 01/18 16:57:26 0d 00h02m 0h00m00s
13 0 3280 LA- disk-detac 0 01/18 17:00:22 0d 00h00m 0h00m00s
14 0 9968 LA- disk-attac 0 01/18 17:00:45 0d 00h00m 0h00m00s
15 0 5952 LA- backup 0 01/18 17:01:00 0d 00h08m 0h00m00s
16 0 9024 LA- backup 0 01/18 17:09:42 0d 00h01m 0h00m00s
17 0 1296 LA- backup 0 01/18 17:11:00 0d 00h00m 0h00m00s
18 0 832 LA- backup 0 01/18 17:11:59 0d 00h01m 0h00m00s
19 0 9520 LA- disk-detac 0 01/18 17:13:15 0d 00h07m 0h00m00s
20 0 9536 LA- disk-attac 0 01/18 17:20:24 0d 00h05m 0h00m00s
21 0 5760 LA- backup 0 01/18 17:25:47 0d 00h03m 0h00m00s
22 0 736 LA- backup 0 01/18 17:29:37 0d 00h01m 0h00m00s
23 0 3312 LA- backup 0 01/18 17:30:47 0d 00h01m 0h00m00s
24 0 6880 LA- backup 0 01/18 17:31:53 0d 00h00m 0h00m00s
25 0 6960 LA- backup 0 01/18 17:32:42 0d 00h00m 0h00m00s
26 - - LA- none 0 01/18 17:33:26 0d 00h10m 0h00m00s
BACKUP CONFIGURATION
ACTIVE_FLATTEN="NO"
BACKUP_VOLATILE="YES"
FS_FREEZE="AGENT"
INCREMENTAL_BACKUP_ID="65"
INCREMENT_MODE="CBT"
KEEP_LAST="3"
LAST_INCREMENT_ID="3"
MODE="INCREMENT"
VM BACKUPS
IMAGE IDS: 65
USER TEMPLATE
HYPERVISOR="kvm"
INPUTS_ORDER="ROOT_PASSWORD"
LOGO="images/logos/ubuntu.png"
MEMORY_UNIT_COST="MB"
SUNSTONE=[
NETWORK_ALIAS="yes",
NETWORK_AUTO="no",
NETWORK_RDP="no",
NETWORK_SSH="yes" ]
USER_INPUTS=[
ROOT_PASSWORD="O|password|Optional - Password for user root." ]
VIRTUAL MACHINE TEMPLATE
AUTOMATIC_DS_REQUIREMENTS="(\"CLUSTERS/ID\" @> 0 | \"CLUSTERS/ID\" @> 100) & (\"ID\" @> 0)"
AUTOMATIC_NIC_REQUIREMENTS="(\"CLUSTERS/ID\" @> 0 | \"CLUSTERS/ID\" @> 100)"
AUTOMATIC_REQUIREMENTS="(CLUSTER_ID = 0 | CLUSTER_ID = 100) & !(PUBLIC_CLOUD = YES) & !(PIN_POLICY = PINNED)"
CONTEXT=[
DISK_ID="1",
NETWORK="YES",
PASSWORD="qjASm5JBKqzAzZ6d1aJ25Q==",
ROOT_PASSWORD="123",
SET_HOSTNAME="test-backup-rsync-ceph",
SSH_PUBLIC_KEY="",
TARGET="hda" ]
CPU="1"
FEATURES=[
ACPI="yes" ]
GRAPHICS=[
LISTEN="0.0.0.0",
PORT="5928",
TYPE="VNC" ]
MEMORY="4096"
OS=[
ARCH="x86_64",
BOOT="disk0",
UUID="27c3321c-7ba3-4fe9-9bfe-6ad253b03c9f" ]
TEMPLATE_ID="26"
TM_MAD_SYSTEM="ceph"
VCPU="4"
VMID="28"
Ceph version running in the storage nodes:
ceph version
ceph version 18.2.2 (531c0d11a1c5d39fbfe6aa8a521f023abf3bf3e2) reef (stable)
Expected behavior
The flattening should be working and a 4th backup should have been succeed.
Details
- Affected Component: [Storage]
- Hypervisor: [KVM]
- Version: [6.10.2]
Additional context
Add any other context about the problem here.
Progress Status
- Code committed
- Testing - QA
- Documentation (Release notes - resolved issues, compatibility, known issues)