Error flattening backup increments when using Ceph and rsync backup driver

[Franco-Sparrow]

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)