bit-team / backintime

Back In Time - An easy-to-use backup tool for GNU Linux using rsync in the back
https://backintime.readthedocs.io
GNU General Public License v2.0
2.05k stars 203 forks source link

Question: What is happening during "Finalizing" and is it OK to interrupt? #1871

Closed CoeJoder closed 1 month ago

CoeJoder commented 1 month ago

First of all, thanks for your time and for the efforts to maintain this great piece of software!

I have a large backup job running (2TB, from a LAN server's NFS-mounted folder to an external USB LUKS2-encrypted ext4 partition). The rsync command completed this morning, but the "Finalizing" step is still going many hours later. The drive enclosure sounds busy, and the backintime process is consuming significant RAM. I'm not sure if the process has hanged, or if it is safe to force-quit it.

I couldn't tell from reading the Python code what is happening during the "Finalize" step (it seems to delegate to a list of "Plugins" as a final step but I couldn't tell what those are without live debugging). I'm hoping someone can advise if this process will eventually complete and if it is normal to take this long, or if it is OK to force-quit it and still have the backup be restorable.

Thanks for your time and advice!

Output of `backintime --diagnostics` { "backintime": { "name": "Back In Time", "version": "1.4.1-1", "latest-config-version": 6, "local-config-file": "/home/UsernameReplaced/.config/backintime/config", "local-config-file-found": true, "global-config-file": "/etc/backintime/config", "global-config-file-found": false, "started-from": "/usr/share/backintime/common", "running-as-root": false, "user-callback": "/home/UsernameReplaced/.config/backintime/user-callback", "keyring-supported": true }, "host-setup": { "platform": "Linux-5.15.0-121-generic-x86_64-with-glibc2.35", "system": "Linux #131-Ubuntu SMP Fri Aug 9 08:29:53 UTC 2024", "OS": { "/etc/os-release": "Linux Mint 21.3", "/etc/lsb-release": "DISTRIB_ID=LinuxMint\nDISTRIB_RELEASE=21.3\nDISTRIB_CODENAME=virginia\nDISTRIB_DESCRIPTION=\"Linux Mint 21.3 Virginia\"\n", "/etc/debian_version": "bookworm/sid\n" }, "display-system": "x11", "locale": "en_US, UTF-8", "PATH": "/home/UsernameReplaced/.n/bin:/home/UsernameReplaced/.npm_global/node_modules/.bin:/home/UsernameReplaced/.local/bin:/home/UsernameReplaced/.n/bin:/home/UsernameReplaced/.npm_global/node_modules/.bin:/home/UsernameReplaced/.local/bin:/home/UsernameReplaced/.n/bin:/home/UsernameReplaced/.npm_global/node_modules/.bin:/home/UsernameReplaced/.local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin:/home/UsernameReplaced/.cabal/bin:/home/UsernameReplaced/.ghcup/bin", "RSYNC_OLD_ARGS": "(not set)", "RSYNC_PROTECT_ARGS": "(not set)" }, "python-setup": { "python": "3.10.12 main Jul 29 2024 16:56:48 CPython GCC 11.4.0", "python-executable": "/usr/bin/python3", "python-executable-symlink": true, "python-executable-resolved": "/usr/bin/python3.10", "sys.path": [ "/usr/share/backintime/qt/plugins", "/usr/share/backintime/common/plugins", "/usr/share/backintime/plugins", "/usr/share/backintime/common", "/usr/lib/python310.zip", "/usr/lib/python3.10", "/usr/lib/python3.10/lib-dynload", "/usr/local/lib/python3.10/dist-packages", "/usr/lib/python3/dist-packages", "/usr/lib/python3.10/dist-packages" ], "qt": { "Version": "PyQt 5.15.6 / Qt 5.15.3", "Theme": "Mint-Y-Sand", "Theme Search Paths": [ "/home/UsernameReplaced/.icons", "/home/UsernameReplaced/.local/share/icons", "/usr/share/cinnamon/icons", "/home/UsernameReplaced/.local/share/flatpak/exports/share/icons", "/var/lib/flatpak/exports/share/icons", "/usr/share/icons", ":/icons" ], "Fallback Theme": "", "Fallback Search Paths": [] } }, "external-programs": { "rsync": { "version": "3.2.7", "protocol": "31.0", "capabilities": { "file_bits": 64, "inum_bits": 64, "timestamp_bits": 64, "long_int_bits": 64, "socketpairs": true, "symlinks": true, "symtimes": true, "hardlinks": true, "hardlink_specials": true, "hardlink_symlinks": true, "IPv6": true, "atimes": true, "batchfiles": true, "inplace": true, "append": true, "ACLs": true, "xattrs": true, "secluded_args": "optional", "iconv": true, "prealloc": true, "stop_at": true, "crtimes": false }, "optimizations": { "SIMD_roll": true, "asm_roll": false, "openssl_crypto": true, "asm_MD5": false }, "checksum_list": [ "xxh128", "xxh3", "xxh64", "md5", "md4", "sha1", "none" ], "compress_list": [ "zstd", "lz4", "zlibx", "zlib", "none" ], "daemon_auth_list": [ "sha512", "sha256", "sha1", "md5", "md4" ] }, "ssh": "OpenSSH_8.9p1 Ubuntu-3ubuntu0.10, OpenSSL 3.0.2 15 Mar 2022", "sshfs": "3.7.1", "encfs": "1.9.5", "shell": "/bin/bash", "shell-version": "GNU bash, version 5.1.16(1)-release (x86_64-pc-linux-gnu)" } }
buhtz commented 1 month ago

Hello Coe,

thank you for your question.

I have a large backup job running (2TB, from a LAN server's NFS-mounted folder to an external USB LUKS2-encrypted ext4 partition).

Does this mean Back In Time (BIT) run on one machine, access (download) the LAN-servers data via an NFS mounted volume and transfers that data through an USB-wirte to an extern HDD/Volumen? And it is 2 TeraByte?

That is a lot and will take its time ,because of the amount of data and because of the transferring process (USB might be the slowest part, but also the de/encryption done by CPU). You should interrupt (kill) Back In Time. While "Finalizing" BIT does unmount the volume. Unmounting will force the operating system to "flush" the data to the drive. This need to be done. Especially it is important because you do use an encrypted destination drive. When you interrupt BIT and the unmounting it could lead to corrupt data.

the "Finalizing" step is still going many hours later.

Not sure but depending on the amount of data and the encrypting need to be done I am not surprised much about "many hours". I don't know for sure how LUKS encryption is done when an extern USB drive is involved. But I can say that the CPU on the connected PC need to compute that encryption, it will need RAM for that, this does take time and then it need to transfer the result to the USB drive. It might also be the case that there is much more communication between the PC and the USB drive as simply transferring data.

The drive enclosure sounds busy, and the backintime process is consuming significant RAM.

See?

Keep also in mind that BIT (or rsync in the back) need to check al lfiles on the destination if they are different from the new files to backup. It is not only about transfering new files to the drive, it is also about reading the old files from the drive and comparing them to the new one. And with all this de/encryption need to be computed.

Let BIT and the operating system do its job.

CoeJoder commented 1 month ago

@buhtz thank you for the reply! The backup was complete; I was confused by the language of "Finaling" being used as the final log message (rather than "Done" or some other past participle) in addition to the continued HDD activity & RAM usage. It appears that the RAM usage was due to the very large BiT log file being open, and the HDD activity was due to ext4lazyinit running in the background in a hard-capped %CPU process on a gargantuan partition.

I was able to avoid this annoying HDD behavior on the next drive by formatting it eagerly:

mkfs.ext4 -E lazy_itable_init=0 /dev/xyz1

False alarm... sorry!

buhtz commented 1 month ago

Thank you for the feedback. I will add the "lazy_itable_init" "hack" to our FAQ as a tip. And I will also think about how to improve the status bar output.

EDIT: I checked the man page of mkfs.ext4. I understand why lazy_itable_init=0 speed up the process in your case. But I don't think this is helpful for most of our users. So I wouldn't add this to the FAQ.