Full backup linux client with LVM snapshots

Hi,

I’m having troubles when backuping a whole drive with linux clients. Estimated size reported on server is bad and as a result backup failed with errors :

2020-01-21 13:37:00: ERROR: FATAL: Backup failed because of disk problems (see previous messages)
2020-01-21 13:37:01: ERROR: Backup failed

Checked server but server is not out of space …

GUI during backup : LVM lv is about 38Gb but size reported is 228 GB !!!

Client log :

2020-01-22 11:01:11: Async index 20fe855f7850f483943c271a7cee81b0
2020-01-22 11:01:11: Removing VSS log data…
2020-01-22 11:01:11: rc=0 hasError=true state=0
2020-01-22 11:01:11: ClientService cmd: #IyxwZGwRPtEtC0nhx2LKp#WAIT FOR INDEX async_id=20fe855f7850f483943c271a7cee81b0#token=R9Z1xkiPdr1t4tqqad8t
2020-01-22 11:01:11: Wait for async index 20fe855f7850f483943c271a7cee81b0
2020-01-22 11:01:11: Final path: /
2020-01-22 11:01:11: Script list at “/usr/local/etc/urbackup/scripts/list” does not exist. Skipping.
2020-01-22 11:01:11: Deleting files… doing full index…
2020-01-22 11:01:11: Script “/usr/local/etc/urbackup/prefilebackup” does not exist
2020-01-22 11:01:11: Final path: /
2020-01-22 11:01:11: Creating shadowcopy of “rootfs” in indexDirs()
2020-01-22 11:01:12: Logical volume “urbackup_snap_646706acc2f40ec9ea90207dc9986555e544d7f6d9d86639” created.
2020-01-22 11:01:12: Shadowcopy path: /mnt/urbackup_snaps/646706acc2f40ec9ea90207dc9986555e544d7f6d9d86639
2020-01-22 11:01:12: done.
2020-01-22 11:01:12: Indexing “rootfs”…
2020-01-22 11:01:12: Not following symlink “/etc/mtab” because symlink target at “/proc/6837/mounts” is excluded
2020-01-22 11:01:12: Not following symlink “/etc/resolv.conf” because symlink target at “/run/resolvconf/resolv.conf” is excluded
2020-01-22 11:01:12: Not following symlink “/etc/resolvconf/run” because symlink target at “/run/resolvconf” is excluded
2020-01-22 11:01:12: Not following symlink “/etc/resolvconf/resolv.conf.d/original” because symlink target at “/run/NetworkManager/resolv.conf” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/alsa-utils.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/bootlogd.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/bootlogs.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/bootmisc.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/checkfs.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/checkroot-bootclean.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/checkroot.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/cryptdisks-early.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/cryptdisks.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/halt.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/hostname.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/hwclock.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/killprocs.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/lvm2.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/motd.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/mountall-bootclean.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/mountall.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/mountdevsubfs.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/mountkernfs.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/mountnfs-bootclean.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/mountnfs.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/rc.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/rcS.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/reboot.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/rmnologin.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/saned.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/sendsigs.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/single.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/stop-bootlogd-single.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/stop-bootlogd.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/sudo.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/umountfs.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/umountnfs.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/umountroot.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:18: Not following symlink “/lib/systemd/system/x11-common.service” because symlink target at “/dev/null” is excluded
2020-01-22 11:01:21: ClientService cmd: #IyxwZGwRPtEtC0nhx2LKp#2PING RUNNING pc_done=&status_id=1&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=R9Z1xkiPdr1t4tqqad8t
2020-01-22 11:01:31: ClientService cmd: #IyxwZGwRPtEtC0nhx2LKp#2PING RUNNING pc_done=&status_id=1&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=R9Z1xkiPdr1t4tqqad8t
2020-01-22 11:01:41: ClientService cmd: #IyxwZGwRPtEtC0nhx2LKp#2PING RUNNING pc_done=&status_id=1&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=R9Z1xkiPdr1t4tqqad8t
2020-01-22 11:01:51: ClientService cmd: #IyxwZGwRPtEtC0nhx2LKp#2PING RUNNING pc_done=&status_id=1&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=R9Z1xkiPdr1t4tqqad8t
2020-01-22 11:01:57: Not following symlink “/var/lock” because symlink target at “/run/lock” is excluded
2020-01-22 11:01:57: Indexing of “rootfs” done. 22781 filesystem lookups 0 db lookups and 0 db updates
2020-01-22 11:01:57: Script “/usr/local/etc/urbackup/postfileindex” does not exist
2020-01-22 11:01:57: Async index 20fe855f7850f483943c271a7cee81b0 finished with “done”
2020-01-22 11:01:57: ClientService cmd: #IyxwZGwRPtEtC0nhx2LKp#GET VSSLOG
2020-01-22 11:01:57: VSS logdata - 211 bytes
[…]
0-1579687317-Logical volume “urbackup_snap_646706acc2f40ec9ea90207dc9986555e544d7f6d9d86639” created.
0-1579687317-Indexing of “rootfs” done. 22781 filesystem lookups 0 db lookups and 0 db updates
0-1579687317-srv-d10-rdc1.lan.local: Loading file list…
0-1579687318-srv-d10-rdc1.lan.local: Started loading files…
0-1579687997-Waiting for file transfers…
0-1579688019-Waiting for file hashing and copying threads…
1-1579688265-HT: No free space available deleting backups…
2-1579688268-HT: FATAL: Error freeing space
1-1579688280-Metadata file and “/media/urbackup/backups/srv-d10-rdc1.lan.local/200122-1101/rootfs/var/log/lastlog” (id=319109) do not exist. Skipping applying metdata for this file. (force start)
1-1579688280-Not all folder metadata could be applied. Metadata was inconsistent.
0-1579688280-Writing new file list…
0-1579688283-All metadata was present
0-1579688283-Transferred 9.0913 GB - Average speed: 111.345 MBit/s
2-1579688291-FATAL: Backup failed because of disk problems (see previous messages)
0-1579688291-Time taken for backing up client srv-d10-rdc1.lan.local: 17m
2-1579688291-Backup failed

Client fs during backup (we can see the snapshot) :

df -h
Sys. de fichiers Taille Utilisé Dispo Uti% Monté sur
udev 2,0G 0 2,0G 0% /dev
tmpfs 395M 46M 350M 12% /run
/dev/mapper/srv–d9–template–vg-root 38G 9,7G 27G 27% /
tmpfs 2,0G 0 2,0G 0% /dev/shm
tmpfs 5,0M 0 5,0M 0% /run/lock
tmpfs 2,0G 0 2,0G 0% /sys/fs/cgroup
/dev/sda1 236M 105M 119M 48% /boot
tmpfs 395M 4,0K 395M 1% /run/user/112
tmpfs 395M 0 395M 0% /run/user/0
/dev/dm-4 38G 9,6G 27G 27% /mnt/urbackup_snaps/646706acc2f40ec9ea90207dc9986555e544d7f6d9d86639

Client config file :

cat /usr/local/var/urbackup/data/settings.cfg
update_freq_incr=-2160
update_freq_incr_def=-2160
update_freq_full=-172800
update_freq_full_def=-172800
update_freq_image_full=-5184000
update_freq_image_full_def=-5184000
update_freq_image_incr=-604800
update_freq_image_incr_def=-604800
max_file_incr=5
max_file_incr_def=5
min_file_incr=5
min_file_incr_def=5
max_file_full=4
max_file_full_def=4
min_file_full=4
min_file_full_def=4
min_image_incr=5
min_image_incr_def=5
max_image_incr=5
max_image_incr_def=5
min_image_full=2
min_image_full_def=2
max_image_full=2
max_image_full_def=2
startup_backup_delay=300
startup_backup_delay_def=300
backup_window_incr_file=1-5/22-24
backup_window_incr_file_def=1-5/22-24
backup_window_full_file=1-5/22-24
backup_window_full_file_def=1-5/22-24
backup_window_incr_image=1-5/22-24
backup_window_incr_image_def=1-5/22-24
backup_window_full_image=1-5/22-24
backup_window_full_image_def=1-5/22-24
exclude_files=/proc/;/run/;/dev/;/media/;/mnt/;/sys/
exclude_files_def=/proc/;/run/;/dev/;/media/;/mnt/;/sys/
include_files=
include_files_def=
default_dirs=/
default_dirs_def=/
allow_config_paths=false
allow_config_paths_def=false
allow_starting_full_file_backups=true
allow_starting_full_file_backups_def=true
allow_starting_incr_file_backups=true
allow_starting_incr_file_backups_def=true
allow_starting_full_image_backups=false
allow_starting_full_image_backups_def=false
allow_starting_incr_image_backups=false
allow_starting_incr_image_backups_def=false
allow_pause=true
allow_pause_def=true
allow_log_view=true
allow_log_view_def=true
allow_overwrite=false
allow_overwrite_def=false
allow_tray_exit=false
allow_tray_exit_def=false
image_letters=ALL_NONUSB
image_letters_def=ALL_NONUSB
internet_server=mybackupserver.mydomain.fr
internet_server_def=mybackupserver.mydomain.fr
internet_server_port=55415
internet_server_port_def=55415
internet_server_proxy=
internet_server_proxy_def=
internet_authkey=wuBgnWyZNo
internet_authkey_def=wuBgnWyZNo
internet_speed=0
internet_speed_def=0
local_speed=0
local_speed_def=0
internet_image_backups=true
internet_image_backups_def=true
internet_full_file_backups=true
internet_full_file_backups_def=true
internet_encrypt=true
internet_encrypt_def=true
internet_compress=true
internet_compress_def=true
internet_mode_enabled=true
internet_mode_enabled_def=true
silent_update=true
silent_update_def=true
client_quota=
client_quota_def=
local_full_file_transfer_mode=hashed
local_full_file_transfer_mode_def=hashed
internet_full_file_transfer_mode=hashed
internet_full_file_transfer_mode_def=hashed
local_incr_file_transfer_mode=hashed
local_incr_file_transfer_mode_def=hashed
internet_incr_file_transfer_mode=blockhash
internet_incr_file_transfer_mode_def=blockhash
local_image_transfer_mode=hashed
local_image_transfer_mode_def=hashed
internet_image_transfer_mode=hashed
internet_image_transfer_mode_def=hashed
end_to_end_file_backup_verification=false
end_to_end_file_backup_verification_def=false
internet_calculate_filehashes_on_client=true
internet_calculate_filehashes_on_client_def=true
internet_parallel_file_hashing=false
internet_parallel_file_hashing_def=false
image_file_format=cowraw
image_file_format_def=cowraw
internet_connect_always=false
internet_connect_always_def=false
server_url=http://mybackupserver.mydomain.fr:55414/
server_url_def=http://mybackupserver.mydomain.fr:55414/
verify_using_client_hashes=false
verify_using_client_hashes_def=false
internet_readd_file_entries=true
internet_readd_file_entries_def=true
background_backups=true
background_backups_def=true
local_incr_image_style=to-full
local_incr_image_style_def=to-full
local_full_image_style=synthetic
local_full_image_style_def=synthetic
internet_incr_image_style=to-full
internet_incr_image_style_def=to-full
internet_full_image_style=synthetic
internet_full_image_style_def=synthetic
create_linked_user_views=false
create_linked_user_views_def=false
max_running_jobs_per_client=3
max_running_jobs_per_client_def=3
cbt_volumes=ALL
cbt_volumes_def=ALL
cbt_crash_persistent_volumes=-
cbt_crash_persistent_volumes_def=-
ignore_disk_errors=false
ignore_disk_errors_def=false
vss_select_components=default=1
vss_select_components_def=default=1
allow_file_restore=false
allow_file_restore_def=false
allow_component_restore=false
allow_component_restore_def=false
allow_component_config=false
allow_component_config_def=false
file_snapshot_groups=ALL
file_snapshot_groups_def=ALL
image_snapshot_groups=ALL
image_snapshot_groups_def=ALL
internet_file_dataplan_limit=5242880000
internet_file_dataplan_limit_def=5242880000
internet_image_dataplan_limit=20971520000
internet_image_dataplan_limit_def=20971520000
alert_script=1
alert_script_def=1
alert_params=
alert_params_def=

Client backupdirs :

urbackupclientctl list-backupdirs
PATH NAME FLAGS


/ rootfs follow_symlinks,symlinks_optional,share_hashes

Any help would be appreciated …

Regards,

You probably have a large sparse file somewhere. While UrBackup supports sparse files and will only store and transfer the used bits it uses the full size for size estimation (and cleanup). If you look at the server debug log before No free space available deleting backups… you’ll probably see the file.

Or run a find / -size +20G on the client.

You’re right guy, thanks ! :sunglasses:

root@srv-d10-rdc1:/usr/local# find / -size +20G
/var/log/lastlog
find: ‘/run/user/112/gvfs’: Permission non accordée
/proc/kcore
find: ‘/proc/7515/task/7515/fd/6’: Aucun fichier ou dossier de ce type
find: ‘/proc/7515/task/7515/fdinfo/6’: Aucun fichier ou dossier de ce type
find: ‘/proc/7515/fd/5’: Aucun fichier ou dossier de ce type
find: ‘/proc/7515/fdinfo/5’: Aucun fichier ou dossier de ce type

/var/log/lastlog is the culprit

root@srv-d10-rdc1:/usr/local# ll -hs /var/log/lastlog
24K -rw-rw-r-- 1 root utmp 220G janv. 21 23:20 /var/log/lastlog
root@srv-d10-rdc1:/usr/local#

Is there a way to modify this behaviour or getting around this problem ?

Thx

Of course i could exclude /var/log/lastlog from backups but if there are any other files like this how could we exclude them systematically ?

I guess it should just take the sparse extents into account when checking if the file fits on backup storage.

Yes, it should just take the “allocated size” in account instead of the file size itself …