Multiple volume image backup issue on Server 2.5.22

Description: I’m trying to backup 2 volumes via Linux image backup: both of them take part in boot process:
/dev/sda1 - partition that contains grub and /boot
/dev/sdb - device with main OS (Centos 7)

Steps to reproduce:

  1. Setup Urbackup client with dattobd.
  2. Setup Image Backup for client specifying volumes: /mountpoint/for/sda1;C (minor issue, if I specify “/” volume for backup - it tries to make snapshot from “/:” and fails, so I have to use capital “c”)
  3. Run Full Image Backup.

Expected behavior:
Both partitions successfully backed up.

Actual behavior:

  • /dev/sda1 - backed up partially? Out of 12Gbs used - only around 500 Mbs backed up and during backup seems like CBT is used, however no full backup present. (ext4)
  • /dev/sdb fails to backup. (ext3)

Error logs:

Feb 10 12:19:16 URBACKUP_CLIENT urbackupclientbackend[32428]: Started connection to SERVICE_COMMANDS
Feb 10 12:19:16 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#FULL IMAGE letter=/mnt/for_swap&token=tMvcsnR8c4ReFTm6QnWI&bitmap=1&status_id=62&running_jobs=1&zero_skipped=1
Feb 10 12:19:16 URBACKUP_CLIENT su[3830]: (to zimbra) root on none
Feb 10 12:19:16 URBACKUP_CLIENT su[3830]: pam_unix(su-l:session): session opened for user zimbra by (uid=0)
Feb 10 12:19:19 URBACKUP_CLIENT kernel: EXT4-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null)
Feb 10 12:19:19 URBACKUP_CLIENT urbackupclientbackend[32428]: Snapshotting device /dev/sda1 via dattobd...
Feb 10 12:19:19 URBACKUP_CLIENT urbackupclientbackend[32428]: Using /dev/datto0...
Feb 10 12:19:19 URBACKUP_CLIENT urbackupclientbackend[32428]: Mounting /dev/mapper/wsnap-7f543c1dcc765251b4b0f1fd7a3a37acfdd21c719a519193...
Feb 10 12:19:19 URBACKUP_CLIENT urbackupclientbackend[32428]: Shadowcopy path: /mnt/urbackup_snaps/7f543c1dcc765251b4b0f1fd7a3a37acfdd21c719a519193
Feb 10 12:19:19 URBACKUP_CLIENT urbackupclientbackend[32428]: Resetting CBT information
Feb 10 12:19:19 URBACKUP_CLIENT urbackupclientbackend[32428]: done.
Feb 10 12:19:19 URBACKUP_CLIENT urbackupclientbackend[32428]: Detected fs type ext4
Feb 10 12:19:19 URBACKUP_CLIENT urbackupclientbackend[32428]: Partclone v0.3.18 http://partclone.org
Feb 10 12:19:19 URBACKUP_CLIENT urbackupclientbackend[32428]: Starting to clone device (/dev/datto0) to image (-)
Feb 10 12:19:19 URBACKUP_CLIENT urbackupclientbackend[32428]: Reading Super Block
Feb 10 12:19:19 URBACKUP_CLIENT urbackupclientbackend[32428]: Calculating bitmap... Please wait...
Feb 10 12:19:20 URBACKUP_CLIENT urbackupclientbackend[32428]: [198B blob data]
Feb 10 12:19:20 URBACKUP_CLIENT urbackupclientbackend[32428]: Total Time: 00:00:01, 100.00% completed!
Feb 10 12:19:20 URBACKUP_CLIENT urbackupclientbackend[32428]: done!
Feb 10 12:19:20 URBACKUP_CLIENT urbackupclientbackend[32428]: File system:  EXTFS
Feb 10 12:19:20 URBACKUP_CLIENT urbackupclientbackend[32428]: Device size:   41.0 GB = 10000123 Blocks
Feb 10 12:19:20 URBACKUP_CLIENT urbackupclientbackend[32428]: Space in use:  12.3 GB = 2998213 Blocks
Feb 10 12:19:20 URBACKUP_CLIENT urbackupclientbackend[32428]: Free Space:    28.7 GB = 7001910 Blocks
Feb 10 12:19:20 URBACKUP_CLIENT urbackupclientbackend[32428]: Block size:   4096 Byte
Feb 10 12:19:20 URBACKUP_CLIENT urbackupclientbackend[32428]: Elapsed: 00:00:01, Remaining: 00:01:39, Completed:   1.00%,   0.00byte/min,
Feb 10 12:19:20 URBACKUP_CLIENT urbackupclientbackend[32428]: [102B blob data]
Feb 10 12:19:22 URBACKUP_CLIENT urbackupclientbackend[32428]: Elapsed: 00:00:02, Remaining: 00:03:18, Completed:   1.00%,   0.00byte/min,
Feb 10 12:19:23 URBACKUP_CLIENT urbackupclientbackend[32428]: [126B blob data]
Feb 10 12:19:23 URBACKUP_CLIENT urbackupclientbackend[32428]: FSINFO: blocksize=4096 size=40960503808 has_error=false used_space=12277084160 type=ext4
Feb 10 12:19:23 URBACKUP_CLIENT urbackupclientbackend[32428]: Trying to exclude contents of file /mnt/urbackup_snaps/7f543c1dcc765251b4b0f1fd7a3a37acfdd21c719a519193//swapfile_for_tango from backup...
Feb 10 12:19:23 URBACKUP_CLIENT urbackupclientbackend[32428]: Trying to exclude contents of file /mnt/urbackup_snaps/7f543c1dcc765251b4b0f1fd7a3a37acfdd21c719a519193/.datto_3d41c58e-6724-4d47-8981-11c766a08a24_7f543c1dcc765251b4b0f1fd7a3a37acfdd21c719a519193 from backup...
Feb 10 12:19:26 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2PING RUNNING pc_done=4&status_id=62&speed_bpms=0&total_bytes=1889574912&done_bytes=70119424&paused_fb=1#token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:19:36 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2PING RUNNING pc_done=13&status_id=62&speed_bpms=0&total_bytes=1889574912&done_bytes=241750016&paused_fb=1#token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:19:40 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: PONG
Feb 10 12:19:40 URBACKUP_CLIENT urbackupclientbackend[32428]: rc=0 hasError=true state=3
Feb 10 12:19:40 URBACKUP_CLIENT urbackupclientbackend[32428]: SERVICE_COMMANDS finished
Feb 10 12:19:40 URBACKUP_CLIENT urbackupclientbackend[32428]: Started connection to SERVICE_COMMANDS
Feb 10 12:19:40 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#1CHANNEL capa=0&token=tMvcsnR8c4ReFTm6QnWI&restore_version=1&startup=1&virtual_client=
Feb 10 12:19:40 URBACKUP_CLIENT urbackupclientbackend[32428]: New channel: Number of Channels: 1
Feb 10 12:19:46 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2PING RUNNING pc_done=22&status_id=62&speed_bpms=5136.49&total_bytes=1889574912&done_bytes=420061184&paused_fb=1#token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:19:56 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2PING RUNNING pc_done=32&status_id=62&speed_bpms=4519.21&total_bytes=1889574912&done_bytes=607776768&paused_fb=1#token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:20:06 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2PING RUNNING pc_done=42&status_id=62&speed_bpms=4987.73&total_bytes=1889574912&done_bytes=788434944&paused_fb=1#token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:20:16 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2PING RUNNING pc_done=50&status_id=62&speed_bpms=5926.15&total_bytes=1889574912&done_bytes=949018624&paused_fb=1#token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:20:26 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2PING RUNNING pc_done=58&status_id=62&speed_bpms=6459.6&total_bytes=1889574912&done_bytes=1097289728&paused_fb=1#token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:20:36 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2PING RUNNING pc_done=72&status_id=62&speed_bpms=6406.49&total_bytes=1889574912&done_bytes=1361145856&paused_fb=1#token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:20:39 URBACKUP_CLIENT urbackupclientbackend[32428]: Sending full image done
Feb 10 12:20:39 URBACKUP_CLIENT urbackupclientbackend[32428]: Deleting shadowcopy for path "/mnt/urbackup_snaps/7f543c1dcc765251b4b0f1fd7a3a37acfdd21c719a519193" -2
Feb 10 12:20:39 URBACKUP_CLIENT urbackupclientbackend[32428]: Unmounting /dev/datto0 at /mnt/urbackup_snaps/7f543c1dcc765251b4b0f1fd7a3a37acfdd21c719a519193...
Feb 10 12:20:39 URBACKUP_CLIENT urbackupclientbackend[32428]: Removing devicemapper snapshot...
Feb 10 12:20:39 URBACKUP_CLIENT urbackupclientbackend[32428]: Transitioning dattobd snapshot /dev/datto0 to incremental...
Feb 10 12:20:39 URBACKUP_CLIENT urbackupclientbackend[32428]: Deleting Shadowcopy for dir "/mnt/for_swap"
Feb 10 12:20:39 URBACKUP_CLIENT urbackupclientbackend[32428]: Removing running process (1) id 7 server_id 62 token tMvcsnR8c4ReFTm6QnWI action 3
Feb 10 12:20:39 URBACKUP_CLIENT urbackupclientbackend[32428]: Service finished. Transferred 381.977 MB
Feb 10 12:20:39 URBACKUP_CLIENT urbackupclientbackend[32428]: SERVICE_COMMANDS finished
Feb 10 12:20:45 URBACKUP_CLIENT urbackupclientbackend[32428]: Done.
Feb 10 12:20:46 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2PING RUNNING pc_done=90&status_id=62&speed_bpms=4768.84&total_bytes=1889574912&done_bytes=1701298176&paused_fb=1#token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: Starting zmconfigd...Started connection to SERVICE_COMMANDS
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2LOGDATA 1644492089 0-1644491992-Starting unscheduled full image backup of volume "/mnt/for_swap"...
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: 0-1644491992-Basing image backup on last incremental or full image backup
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: 1-1644491992-Error retrieving last image backup. Doing full image backup instead.
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: 0-1644492089-Transferred 381.977 MB - Average speed: 33.424 MBit/s
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: 0-1644492089-(Before compression: 1.76435 GB ratio: 4.72984)
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: 0-1644492089-Time taken for backing up client Tango: 1m 36s
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: 0-1644492089-Backup succeeded
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: rc=0 hasError=true state=0
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: SERVICE_COMMANDS finished
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: Started connection to SERVICE_COMMANDS
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#MBR driveletter=SYSVOL&disk_path=SYSVOL&image_full=1&running_jobs=1&token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: rc=0 hasError=true state=0
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: SERVICE_COMMANDS finished
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: Started connection to SERVICE_COMMANDS
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#FULL IMAGE letter=SYSVOL&token=tMvcsnR8c4ReFTm6QnWI&bitmap=1&status_id=64&running_jobs=1&zero_skipped=1
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: Not found
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: rc=0 hasError=true state=0
Feb 10 12:20:53 URBACKUP_CLIENT urbackupclientbackend[32428]: SERVICE_COMMANDS finished
Feb 10 12:20:54 URBACKUP_CLIENT urbackupclientbackend[32428]: Started connection to SERVICE_COMMANDS
Feb 10 12:20:54 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2PING RUNNING pc_done=0&status_id=64&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:20:54 URBACKUP_CLIENT urbackupclientbackend[32428]: Started connection to SERVICE_COMMANDS
Feb 10 12:20:54 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#MBR driveletter=ESP&disk_path=ESP&image_full=1&running_jobs=1&token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:20:54 URBACKUP_CLIENT urbackupclientbackend[32428]: rc=0 hasError=true state=0
Feb 10 12:20:54 URBACKUP_CLIENT urbackupclientbackend[32428]: SERVICE_COMMANDS finished
Feb 10 12:20:54 URBACKUP_CLIENT urbackupclientbackend[32428]: Started connection to SERVICE_COMMANDS
Feb 10 12:20:54 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#FULL IMAGE letter=ESP&token=tMvcsnR8c4ReFTm6QnWI&bitmap=1&status_id=65&running_jobs=1&zero_skipped=1
Feb 10 12:20:54 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: Not found
Feb 10 12:20:54 URBACKUP_CLIENT urbackupclientbackend[32428]: rc=0 hasError=true state=0
Feb 10 12:20:54 URBACKUP_CLIENT urbackupclientbackend[32428]: SERVICE_COMMANDS finished
Feb 10 12:20:55 URBACKUP_CLIENT urbackupclientbackend[32428]: Started connection to SERVICE_COMMANDS
Feb 10 12:20:55 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2PING RUNNING pc_done=0&status_id=65&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:20:55 URBACKUP_CLIENT urbackupclientbackend[32428]: Started connection to SERVICE_COMMANDS
Feb 10 12:20:55 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2PING RUNNING pc_done=0&status_id=63&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:20:55 URBACKUP_CLIENT urbackupclientbackend[32428]: Started connection to SERVICE_COMMANDS
Feb 10 12:20:55 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#MBR driveletter=C&disk_path=C:&image_full=1&running_jobs=1&token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:20:55 URBACKUP_CLIENT urbackupclientbackend[32428]: dl_devnum=b
Feb 10 12:20:55 URBACKUP_CLIENT urbackupclientbackend[32428]: rc=0 hasError=true state=0
Feb 10 12:20:55 URBACKUP_CLIENT urbackupclientbackend[32428]: SERVICE_COMMANDS finished
Feb 10 12:20:56 URBACKUP_CLIENT urbackupclientbackend[32428]: Started connection to SERVICE_COMMANDS
Feb 10 12:20:56 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#FULL IMAGE letter=C:&token=tMvcsnR8c4ReFTm6QnWI&bitmap=1&status_id=63&running_jobs=1&zero_skipped=1
Feb 10 12:20:56 URBACKUP_CLIENT su[4827]: (to zimbra) root on none
Feb 10 12:20:56 URBACKUP_CLIENT su[4827]: pam_unix(su-l:session): session opened for user zimbra by (uid=0)
Feb 10 12:20:56 URBACKUP_CLIENT urbackupclientbackend[32428]: rc=0 hasError=true state=0
Feb 10 12:20:56 URBACKUP_CLIENT urbackupclientbackend[32428]: SERVICE_COMMANDS finished
Feb 10 12:21:04 URBACKUP_CLIENT urbackupclientbackend[32428]: rc=0 hasError=true state=0
Feb 10 12:21:04 URBACKUP_CLIENT urbackupclientbackend[32428]: SERVICE_COMMANDS finished
Feb 10 12:21:05 URBACKUP_CLIENT urbackupclientbackend[32428]: rc=0 hasError=true state=0
Feb 10 12:21:05 URBACKUP_CLIENT urbackupclientbackend[32428]: SERVICE_COMMANDS finished
Feb 10 12:21:05 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2PING RUNNING pc_done=0&status_id=63&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:21:07 URBACKUP_CLIENT urbackupclientbackend[32428]: WARNING: Could not open snapshot at "/mnt/urbackup_snaps/ed76ed75ed43f82a645287e7be01c04e71ac1671bbd0dfbf"
Feb 10 12:21:07 URBACKUP_CLIENT urbackupclientbackend[32428]: WARNING: Removing reference because shadowcopy could not be openend
Feb 10 12:21:07 URBACKUP_CLIENT urbackupclientbackend[32428]: WARNING: Restarting shadow copy of / because it was started by this server
Feb 10 12:21:07 URBACKUP_CLIENT urbackupclientbackend[32428]: Releasing /dev/sdb orig_target=/dev/sdb target=/mnt/urbackup_snaps/ed76ed75ed43f82a645287e7be01c04e71ac1671bbd0dfbf
Feb 10 12:21:07 URBACKUP_CLIENT urbackupclientbackend[32428]: Deleting shadowcopy for path "/mnt/urbackup_snaps/ed76ed75ed43f82a645287e7be01c04e71ac1671bbd0dfbf" -2
Feb 10 12:21:07 URBACKUP_CLIENT urbackupclientbackend[32428]: Snapshot at /mnt/urbackup_snaps/ed76ed75ed43f82a645287e7be01c04e71ac1671bbd0dfbf was already removed
Feb 10 12:21:07 URBACKUP_CLIENT urbackupclientbackend[32428]: Deleting Shadowcopy for dir "/"
Feb 10 12:21:07 URBACKUP_CLIENT kernel: datto: fallocate is not supported for '/.datto_3d41c58e-6724-4d47-8981-11c766a08a24_4c6ab9ef88739f9e85e12372f24ee57936f6cf1e41e07085', falling back on writing zeros
Feb 10 12:21:15 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2PING RUNNING pc_done=0&status_id=63&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=tMvcsnR8c4ReFTm6QnWI
Feb 10 12:21:19 URBACKUP_CLIENT kernel: datto: '//.datto_3d41c58e-6724-4d47-8981-11c766a08a24_4c6ab9ef88739f9e85e12372f24ee57936f6cf1e41e07085' is not on 'sda1': -22
Feb 10 12:21:19 URBACKUP_CLIENT kernel: datto: error setting up cow manager: -22
Feb 10 12:21:19 URBACKUP_CLIENT kernel: datto: error transitioning tracer to snapshot mode: -22
Feb 10 12:21:19 URBACKUP_CLIENT kernel: datto: error during transition to snapshot ioctl handler: -22
Feb 10 12:21:21 URBACKUP_CLIENT kernel: datto: device specified already exists: -16
Feb 10 12:21:21 URBACKUP_CLIENT kernel: datto: error during setup ioctl handler: -16
Feb 10 12:21:21 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: Creating snapshot of "/dev/sdb" failed
Feb 10 12:21:21 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: Snapshotting device /dev/sdb via dattobd...
Feb 10 12:21:21 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: Trying to transition /dev/datto0 to snapshot...
Feb 10 12:21:21 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: dbdctl transition-to-snapshot '//.datto_3d41c58e-6724-4d47-8981-11c766a08a24_4c6ab9ef88739f9e85e12372f24ee57936f6cf1e41e07085' 0
Feb 10 12:21:21 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: driver returned an error performing specified action. check dmesg for more info: Invalid argument
Feb 10 12:21:21 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: Using /dev/datto0...
Feb 10 12:21:21 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: CBT=type=datto&reset=1
Feb 10 12:21:21 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: driver returned an error performing specified action. check dmesg for more info: Device or resource busy
Feb 10 12:21:21 URBACKUP_CLIENT urbackupclientbackend[32428]: Disabling CBT on volume "/dev/sdb"
Feb 10 12:21:21 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: Getting shadowcopy of "/dev/sdb" failed.
Feb 10 12:21:21 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: Creating shadow copy failed. See client log file for details.
Feb 10 12:21:21 URBACKUP_CLIENT urbackupclientbackend[32428]: Sending full image done
Feb 10 12:21:21 URBACKUP_CLIENT urbackupclientbackend[32428]: Removing running process (1) id 8 server_id 63 token tMvcsnR8c4ReFTm6QnWI action 3
Feb 10 12:21:21 URBACKUP_CLIENT urbackupclientbackend[32428]: SERVICE_COMMANDS finished
Feb 10 12:21:22 URBACKUP_CLIENT urbackupclientbackend[32428]: Started connection to SERVICE_COMMANDS
Feb 10 12:21:22 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: #I5vBaB3Q7U8e5PFSv2WI5#2LOGDATA 1644492118 0-1644492090-Starting unscheduled full image backup of volume "C:"...
Feb 10 12:21:22 URBACKUP_CLIENT urbackupclientbackend[32428]: 0-1644492092-Basing image backup on last incremental or full image backup
Feb 10 12:21:22 URBACKUP_CLIENT urbackupclientbackend[32428]: 1-1644492092-Error retrieving last image backup. Doing full image backup instead.
Feb 10 12:21:22 URBACKUP_CLIENT urbackupclientbackend[32428]: 2-1644492118-Request of image backup failed. Reason: Creating shadow copy failed. See client log file for details.
Feb 10 12:21:22 URBACKUP_CLIENT urbackupclientbackend[32428]: 0-1644492118-Transferred 858 bytes - Average speed: 264 Bit/s
Feb 10 12:21:22 URBACKUP_CLIENT urbackupclientbackend[32428]: 0-1644492118-Time taken for backing up client Tango: 27s
Feb 10 12:21:22 URBACKUP_CLIENT urbackupclientbackend[32428]: 2-1644492118-Backup failed
Feb 10 12:21:22 URBACKUP_CLIENT urbackupclientbackend[32428]: rc=0 hasError=true state=0
Feb 10 12:21:22 URBACKUP_CLIENT urbackupclientbackend[32428]: SERVICE_COMMANDS finished
Feb 10 12:21:25 URBACKUP_CLIENT urbackupclientbackend[32428]: rc=0 hasError=true state=0
Feb 10 12:21:25 URBACKUP_CLIENT urbackupclientbackend[32428]: SERVICE_COMMANDS finished
Feb 10 12:21:40 URBACKUP_CLIENT urbackupclientbackend[32428]: ClientService cmd: PONG
Feb 10 12:22:21 URBACKUP_CLIENT urbackupclientbackend[32428]: Done.

In some cases dattobd reports:

Feb 10 12:50:30 URBACKUP_CLIENT kernel: datto: device specified already exists: -16
Feb 10 12:50:30 URBACKUP_CLIENT kernel: datto: error during setup ioctl handler: -16
Feb 10 12:50:30 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: Creating snapshot of "/dev/sdb" failed
Feb 10 12:50:30 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: Snapshotting device /dev/sdb via dattobd...
Feb 10 12:50:30 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: Using /dev/datto0...
Feb 10 12:50:30 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: CBT=type=datto&reset=1
Feb 10 12:50:30 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: driver returned an error performing specified action. check dmesg for more info: Device or resource busy
Feb 10 12:50:30 URBACKUP_CLIENT urbackupclientbackend[32428]: Disabling CBT on volume "/dev/sdb"
Feb 10 12:50:30 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: Getting shadowcopy of "/dev/sdb" failed.
Feb 10 12:50:30 URBACKUP_CLIENT urbackupclientbackend[32428]: ERROR: Creating shadow copy failed. See client log file for details.

With single volume in the list - issue is not present.

Could be compression or the exclusion of swap file. If you want to verify image contents, there is a testing procedure described at Server 2.5.23/Client 2.5.17 ( Testing (image backup + file backup with CBT))

Maybe because it’s not a partition. Will have to run some tests…

It might be reusing the datto device used for the other volume, i.e., this bit doesn’t work: https://github.com/uroni/urbackup_backend/blob/dev/linux_snapshot/dattobd_create_snapshot#L58

Edit: I think removing the double quotes might fix it, so:

has_num ()
{
	exists "/mnt/urbackup_snaps/cbt_info/*-snapdev" && grep "$1" /mnt/urbackup_snaps/cbt_info/*-snapdev > /dev/null
}

Could you change this and check?

Making this fix seems to have resolved some strange issues I was hunting for on other Linux systems.

Unfortunately original system based on which this report has been created got migrated and no longer contain 2 volumes, so I cannot verify on 100%, but as mentioned above - I have Linux image backups running more reliably now due to the fix.

And I see that fix already applied for 2.5 branch. Thank you.

Reason for long validation is that I still have datto cow files left on systems that are backed up. I cannot understand sequence of steps which leads to abandoned files. So I thought that this is somehow related. Example on one of the systems:

----------    1 root root 144M Apr 13 04:30 .datto_3d41c58e-6724-4d47-8981-11c766a08a24_1d7e63ca3ab8b56d54ba09d6046d8b8b81961a283dfb6252
----------    1 root root 144M Feb 24 01:48 .datto_3d41c58e-6724-4d47-8981-11c766a08a24_a51a72ebbd546ff91731f249a567ebecc0b7967543d802b3
----------    1 root root 144M May  3 08:56 .datto_3d41c58e-6724-4d47-8981-11c766a08a24_cddca5ba7f7dc69d20f29cd68ca196b7c7b280b9df74dd9b

On this example files are small, but on some other examples they might be 12-20G, which leads to exhausted space on the root drives. Issue is not 100% reproducable. File might not appear for weeks and then I check - they are there.

Will report separately once found. I believe this issue could be closed.