Urbackup doesn't seem to complete any backups

Hello!

I’m running Urbackup on a Debian based virtual machine within Proxmox.
I’m using the docker version of Urbackup, docker compose will be included below.

I have a single 6TB Western Digital Blue drive formatted as btrfs for the backup location. This is temporary, I wanted to get the backups working before I buy more drives to expand this out properly with a RAID like setup.

The whole SATA controller is accessible to the urbackup VM, so it has basically direct access to the drive. I’m not doing a HDD pass through, instead I’m doing a PCIE pass through of the sata controller.

The rest of the hardware is server grade, supermicro motherboard, 2x 6 core Xeon CPUs, 64GB of DDR3 ECC ram. I did a memtest using the built in memtest in proxmox and found no issues with the RAM or CPU.

I have the urbackup client installed on my windows desktop, and a Open Media Vault VM on another proxmox machine. My goal is to backup files from both of these locations to a single place, which then I will backup offsite.

Everything is on the same physical LAN, 1Gb/s between everything verified using iPerf3.

On the windows client I have it doing a daily file backup of a handful of folders, mainly things like documents and places I like to save my code. Every week I have it do a image backup of the C drive only.

On the OMV client I have it doing a daily file backup of a handful of folders, but the size here is much larger, total storage is around 3TB.

I have all three systems, the server and two clients running 24/7. I usually turn off my desktop at the end of the day, but for the sake of the initial backup I turned off all the sleep functions.

The backups never seem to complete. I’ll keep an eye on the progress over a day, I’ll see it move to around 20 - 40%, and then when I check again the same day progress is down to 2%. When I go to the “backups” tab and select any of the clients there are no backups, but if I check the drive I’m backing up to there’s data there and “df” is saying I’m using up around 42% of the 6TB drive.

I even tried formatting the backup drive to start fresh, also tried dumping the whole urbackup container and config and starting new, but same problem.

I’ve done a full read/write test of the HDD using badblocks and it didn’t find any errors. According to SMART there are no errors either, and I have it scheduled to run a short smart test every day and a long test every week.

Docker compose ---------------------------------------------------------------------------------------------------------------

version: '3'
services:
  urbackup:
    image: uroni/urbackup-server:latest
    container_name: urbackup
    restart: unless-stopped
    environment:
      - PUID=1000 # Enter the UID of the user who should own the files here
      - PGID=100  # Enter the GID of the user who should own the files here
      - TZ=America/New_York # Enter your timezone
    volumes:
      - /opt/urbackup/config:/var/urbackup
      - /mnt/backup:/backups
      # Uncomment the next line if you want to bind-mount the www-folder
      #- /path/to/wwwfolder:/usr/share/urbackup
    network_mode: "host"
    # Uncomment the following two lines if you're using BTRFS support
    #cap_add:
    #  - SYS_ADMIN
    # Uncomment the following two lines if you're using ZFS support
    #devices:
    #  - /dev/zfs:/dev/zfs

result of ‘df -h’ ------------------------------------------------------------------------------------------------------------------------

Filesystem      Size  Used Avail Use% Mounted on
udev            1.9G     0  1.9G   0% /dev
tmpfs           388M   36M  353M  10% /run
/dev/sda2        32G  6.2G   24G  21% /
tmpfs           1.9G  200K  1.9G   1% /dev/shm
tmpfs           5.0M     0  5.0M   0% /run/lock
tmpfs           1.9G     0  1.9G   0% /tmp
tmpfs            50M   40K   50M   1% /var/log
/dev/sda1        63M   12M   52M  19% /boot/efi
/dev/sdb1       5.5T  2.3T  3.3T  42% /mnt/backup

Snippet of logs from the server

2023-10-23 23:41:04: Starting HTTP-Server on port 55414
2023-10-23 23:41:04: HTTP: Server started up successfully!
2023-10-23 23:41:04: SQLite: recovered 4088 frames from WAL file /var/urbackup/backup_server.db-wal code: 283
2023-10-23 23:41:04: SQLite: recovered 787 frames from WAL file /var/urbackup/backup_server_files.db-wal code: 283
2023-10-23 23:41:04: SQLite: recovered 37 frames from WAL file /var/urbackup/backup_server_link_journal.db-wal code: 283
2023-10-23 23:41:04: SQLite: recovered 22 frames from WAL file /var/urbackup/backup_server_settings.db-wal code: 283
2023-10-23 23:41:04: WARNING: Error: Unknown action [progress]
2023-10-23 23:41:04: SQLite: recovered 4088 frames from WAL file /var/urbackup/backup_server.db-wal code: 283
2023-10-23 23:41:04: SQLite: recovered 22 frames from WAL file /var/urbackup/backup_server_settings.db-wal code: 283
2023-10-23 23:41:04: SQLite: recovered 787 frames from WAL file /var/urbackup/backup_server_files.db-wal code: 283
2023-10-23 23:41:04: SQLite: recovered 37 frames from WAL file /var/urbackup/backup_server_link_journal.db-wal code: 283
2023-10-23 23:41:04: Started UrBackup...
2023-10-23 23:41:04: Removing temporary files...
2023-10-23 23:41:04: ERROR: No permission to access "/backups/urbackup_tmp_files"
2023-10-23 23:41:04: Recreating temporary folder...
2023-10-23 23:41:04: Image mounting disabled: TEST FAILED: guestmount is missing (libguestfs-tools)
2023-10-23 23:41:05: InternetService: Server started up successfully!
2023-10-23 23:41:05: Backup destination cannot handle subvolumes and snapshots. Snapshots disabled.
2023-10-23 23:41:05: UrBackup Server start up complete.
2023-10-23 23:41:05: Looking for old Sessions... 0 sessions
2023-10-23 23:41:05: Server started up successfully!
.........
2023-10-23 23:42:20: Statistics recalculation done
2023-10-23 23:42:20: Updating statistics...
2023-10-23 23:42:20: Updating image stats...
2023-10-23 23:42:20: Starting unscheduled full file backup...
2023-10-23 23:42:20: Updating file statistics...
2023-10-23 23:42:20: Done updating statistics.
2023-10-23 23:43:54: Backing up "3D" without snapshot.
2023-10-23 23:43:54: Indexing of "3D" done. 175 filesystem lookups 0 db lookups and 0 db updates
2023-10-23 23:43:54: Backing up "Books" without snapshot.
2023-10-23 23:43:54: Indexing of "Books" done. 241 filesystem lookups 0 db lookups and 0 db updates
2023-10-23 23:43:54: Backing up "Code" without snapshot.
2023-10-23 23:43:54: Indexing of "Code" done. 3253 filesystem lookups 0 db lookups and 0 db updates
2023-10-23 23:43:54: Backing up "Design" without snapshot.
2023-10-23 23:43:54: Indexing of "Design" done. 487 filesystem lookups 0 db lookups and 0 db updates
2023-10-23 23:43:54: Backing up "Gravee" without snapshot.
2023-10-23 23:43:54: Indexing of "Gravee" done. 66 filesystem lookups 0 db lookups and 0 db updates
2023-10-23 23:43:54: Backing up "Photography" without snapshot.
2023-10-23 23:43:54: Indexing of "Photography" done. 620 filesystem lookups 0 db lookups and 0 db updates
2023-10-23 23:43:54: Backing up "Photoshop" without snapshot.
2023-10-23 23:43:54: Indexing of "Photoshop" done. 14 filesystem lookups 0 db lookups and 0 db updates
2023-10-23 23:43:54: Backing up "Videos" without snapshot.
2023-10-23 23:43:54: Indexing of "Videos" done. 182 filesystem lookups 0 db lookups and 0 db updates
2023-10-23 23:43:54: omv: Loading file list...
2023-10-23 23:43:54: omv: Started loading files...
2023-10-23 23:43:54: Referencing snapshot on "omv" for path "3D" failed: FAILED
2023-10-23 23:43:55: ERROR: Error opening file "/backups/omv/231023-2342/.b68xO+K9SCOF35cLk4Bf9Q/1" for reading file. File: temp_fn. No such file or directory (code: 2) Target path: "/backups/omv/231023-2342/3D/BMW1M-MikePan.blend1"
2023-10-23 23:43:55: WARNING: HT: Error creating hardlink from "/backups/omv/230919-2007/3D/BMW1M-MikePan.blend" to "/backups/omv/231023-2342/3D/BMW1M-MikePan.blend"
2023-10-23 23:43:55: WARNING: HT: Error creating hardlink from "/backups/omv/230923-1151/3D/Blender/2013/untitled.blend1" to "/backups/omv/231023-2342/3D/Blender/2013/untitled.blend1"
2023-10-23 23:43:55: WARNING: HT: Error creating hardlink from "/backups/omv/230919-2007/3D/Blender/2013/3DIntroTest/3Dintrotest.blend" to "/backups/omv/231023-2342/3D/Blender/2013/3DIntroTest/3Dintrotest.blend"
2023-10-23 23:43:55: ERROR: Error opening file "/backups/omv/231023-2342/.b68xO+K9SCOF35cLk4Bf9Q/2" from pipe for reading ec=2
2023-10-23 23:43:55: WARNING: HT: Error creating hardlink from "/backups/omv/230924-2006/3D/Blender/2013/3DIntroTest/3Dintrotest2.blend" to "/backups/omv/231023-2342/3D/Blender/2013/3DIntroTest/3Dintrotest2.blend"
2023-10-23 23:43:55: ERROR: Error opening file "/backups/omv/231023-2342/.b68xO+K9SCOF35cLk4Bf9Q/3" from pipe for reading ec=2
2023-10-23 23:43:55: ERROR: Error opening file "/backups/omv/231023-2342/.b68xO+K9SCOF35cLk4Bf9Q/4" from pipe for reading ec=2
2023-10-23 23:43:55: ERROR: Error opening file "/backups/omv/231023-2342/.b68xO+K9SCOF35cLk4Bf9Q/5" for reading file. File: temp_fn. No such file or directory (code: 2) Target path: "/backups/omv/231023-2342/3D/Blender/2013/3DIntroTest/3Dintrotest2.blend1"
2023-10-23 23:43:55: ERROR: Error opening file "/backups/omv/231023-2342/.b68xO+K9SCOF35cLk4Bf9Q/6" for reading file. File: temp_fn. No such file or directory (code: 2) Target path: "/backups/omv/231023-2342/3D/Blender/2013/3DIntroTest/3Dintrotest3.blend1"
2023-10-23 23:43:55: ERROR: Error opening file "/backups/omv/231023-2342/.b68xO+K9SCOF35cLk4Bf9Q/7" for reading file. File: temp_fn. No such file or directory (code: 2) Target path: "/backups/omv/231023-2342/3D/Blender/2013/3DIntroTest/3Dintrotest5(269).blend"
2023-10-23 23:44:02: WARNING: HT: Error creating hardlink from "/backups/omv/230928-2138/3D/Blender/2013/3DIntroTest/3Dintrotest5-REALWATER.blend" to "/backups/omv/231023-2342/3D/Blender/2013/3DIntroTest/3Dintrotest5-REALWATER.blend"
2023-10-23 23:44:16: WARNING: HT: Error creating hardlink from "/backups/omv/230922-2247/3D/Blender/2013/3DIntroTest/3Dintrotest5.blend" to "/backups/omv/231023-2342/3D/Blender/2013/3DIntroTest/3Dintrotest5.blend"
2023-10-23 23:44:19: WARNING: HT: More hardlink errors. Skipping... 
2023-10-23 23:44:19: WARNING: HT: Error creating hardlink from "/backups/omv/230919-2007/3D/Blender/2013/3DIntroTest/3Dintrotest8.blend1" to "/backups/omv/231023-2342/3D/Blender/2013/3DIntroTest/3Dintrotest8.blend1"
.........................
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6755" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6756" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6757" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/omv/230919-2007/Code/hexo/gravee/node_modules/stylus/lib/stack/index.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/stylus/lib/stack/index.js"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6758" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6759" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/GRAVEEPC/230922-0948/F/Code/votebroward2022/node_modules/stylus/lib/visitor/deps-resolver.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/stylus/lib/visitor/deps-resolver.js"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6760" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6761" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6762" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/GRAVEEPC/230922-0948/F/Code/gravee/node_modules/prismjs/components/prism-regex.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/prismjs/components/prism-regex.js"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6763" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6764" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/GRAVEEPC/230922-0948/F/Code/gravee/node_modules/stylus/node_modules/source-map/package.json" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/stylus/node_modules/source-map/package.json"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6765" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6766" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/omv/230919-2007/Code/hexo/gravee/node_modules/source-map/lib/mapping-list.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/stylus/node_modules/source-map/lib/mapping-list.js"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6767" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6768" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6769" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/omv/230919-2007/Code/hexo/gravee/node_modules/source-map/lib/source-map-generator.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/stylus/node_modules/source-map/lib/source-map-generator.js"
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/omv/230919-2007/Code/hexo/gravee/node_modules/source-map/lib/util.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/stylus/node_modules/source-map/lib/util.js"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6770" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6771" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6772" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6773" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/omv/230919-2007/Code/hexo/gravee/node_modules/supports-color/readme.md" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/supports-color/readme.md"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6774" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6775" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6776" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6777" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6778" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6779" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/omv/230919-2007/Code/hexo/gravee/node_modules/text-table/index.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/text-table/index.js"
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/omv/230919-2007/Code/hexo/gravee/node_modules/text-table/readme.markdown" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/text-table/readme.markdown"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6780" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6781" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6782" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6783" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6784" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6785" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6786" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6787" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6788" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/GRAVEEPC/230922-0948/F/Code/character-creator/node_modules/through2/README.md" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/through2/README.md"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6789" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6790" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6791" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6792" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6793" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6794" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6795" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/omv/230922-1028/Code/hexo/gravee/node_modules/to-regex-range/index.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/to-regex-range/index.js"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6796" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6797" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6798" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6799" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/GRAVEEPC/230922-0948/F/Code/character-creator/node_modules/tough-cookie/README.md" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/tough-cookie/README.md"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6800" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/GRAVEEPC/230922-2242/F/Code/character-creator/node_modules/tough-cookie/lib/cookie.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/tough-cookie/lib/cookie.js"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6801" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6802" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6803" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/GRAVEEPC/230922-2242/F/Code/character-creator/node_modules/tough-cookie/lib/pathMatch.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/tough-cookie/lib/pathMatch.js"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6804" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/GRAVEEPC/230922-2242/F/Code/character-creator/node_modules/tough-cookie/lib/pubsuffix-psl.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/tough-cookie/lib/pubsuffix-psl.js"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6805" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6806" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/GRAVEEPC/230922-0948/F/Code/character-creator/node_modules/tr46/index.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/tr46/index.js"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6807" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6808" from pipe for reading ec=2
2023-10-23 23:49:54: WARNING: HT: Error creating hardlink from "/backups/GRAVEEPC/230922-0948/F/Code/character-creator/node_modules/tr46/lib/mappingTable.json" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/tr46/lib/mappingTable.json"
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6809" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6810" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6811" from pipe for reading ec=2
2023-10-23 23:49:54: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6812" from pipe for reading ec=2
2023-10-23 23:49:55: WARNING: HT: Error creating hardlink from "/backups/GRAVEEPC/230922-0948/F/Code/gravee/node_modules/tslib/SECURITY.md" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/tslib/SECURITY.md"
2023-10-23 23:49:55: WARNING: HT: Error creating hardlink from "/backups/GRAVEEPC/230922-0948/C/Users/gouth/.vscode/extensions/ryannaddy.laravel-artisan-0.0.31/node_modules/tslib/tslib.d.ts" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/tslib/tslib.d.ts"
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6813" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6814" from pipe for reading ec=2
2023-10-23 23:49:55: WARNING: HT: Error creating hardlink from "/backups/GRAVEEPC/230922-2242/F/Code/character-creator/node_modules/tslib/tslib.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/tslib/tslib.js"
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6815" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6816" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6817" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6818" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6819" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6820" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6821" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6822" from pipe for reading ec=2
2023-10-23 23:49:55: WARNING: HT: Error creating hardlink from "/backups/GRAVEEPC/230922-0948/F/Code/character-creator/node_modules/url-parse/index.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/url-parse/index.js"
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6823" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6824" from pipe for reading ec=2
2023-10-23 23:49:55: WARNING: HT: Error creating hardlink from "/backups/GRAVEEPC/230922-0948/F/Code/votebroward2022/node_modules/url-parse/dist/url-parse.min.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/url-parse/dist/url-parse.min.js"
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6825" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6826" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6827" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6828" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6829" from pipe for reading ec=2
2023-10-23 23:49:55: WARNING: HT: Error creating hardlink from "/backups/omv/230919-2007/Code/hexo/gravee/node_modules/vary/README.md" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/vary/README.md"
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6830" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6831" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6832" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6833" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6834" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6835" from pipe for reading ec=2
2023-10-23 23:49:55: WARNING: HT: Error creating hardlink from "/backups/omv/230919-2007/Code/hexo/gravee/node_modules/warehouse/lib/model.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/warehouse/lib/model.js"
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6836" from pipe for reading ec=2
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6837" from pipe for reading ec=2
2023-10-23 23:49:55: WARNING: HT: Error creating hardlink from "/backups/omv/230919-2007/Code/hexo/gravee/node_modules/warehouse/lib/query.js" to "/backups/GRAVEEPC/231023-2341/F/Code/character-creator/node_modules/warehouse/lib/query.js"
2023-10-23 23:49:55: ERROR: Error opening file "/backups/GRAVEEPC/231023-2341/.b68xO+K9SCOF35cLk4Bf9Q/6838" from pipe for reading ec=2

I’ll attach the full log file too.

I see messages like the one below in dmesg

[121978.023566] INFO: task kworker/u8:2:994163 blocked for more than 120 seconds.
[121978.023610]       Not tainted 6.1.0-13-amd64 #1 Debian 6.1.55-1
[121978.023628] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[121978.023645] task:kworker/u8:2    state:D stack:0     pid:994163 ppid:2      flags:0x00004000
[121978.023650] Workqueue: btrfs-endio-write btrfs_work_helper [btrfs]
[121978.023706] Call Trace:
[121978.023708]  <TASK>
[121978.023710]  __schedule+0x351/0xa20
[121978.023716]  schedule+0x5d/0xe0
[121978.023719]  wait_current_trans+0xf0/0x160 [btrfs]
[121978.023769]  ? cpuusage_read+0x10/0x10
[121978.023773]  start_transaction+0x332/0x610 [btrfs]
[121978.023824]  btrfs_finish_ordered_io+0x378/0x860 [btrfs]
[121978.023876]  ? _raw_spin_lock+0x13/0x40
[121978.023879]  ? psi_group_change+0x145/0x360
[121978.023883]  btrfs_work_helper+0xe4/0x380 [btrfs]
[121978.023941]  process_one_work+0x1c7/0x380
[121978.023946]  worker_thread+0x4d/0x380
[121978.023949]  ? _raw_spin_lock_irqsave+0x23/0x50
[121978.023953]  ? rescuer_thread+0x3a0/0x3a0
[121978.023957]  kthread+0xe9/0x110
[121978.023960]  ? kthread_complete_and_exit+0x20/0x20
[121978.023963]  ret_from_fork+0x22/0x30
[121978.023970]  </TASK>

The urbackup tmp directory seems to exist, and has correct permissions

drwxr-x--- 1 dietpi users   16 Oct 25 10:27 urbackup_tmp_files
drwxr-xr-x 1 dietpi users  154 Oct 25 10:26 .
drwxr-x--- 1 dietpi users  132 Oct 25 10:26 GRAVEEPC
-rw-r--r-- 1 root   root  137M Oct 25 10:13 urbackup.log
drwxr-x--- 1 dietpi users   44 Oct 25 01:07 omv
drwxr-x--- 1 dietpi users  818 Oct 24 03:53 urbackup
drwxr-x--- 1 dietpi users    0 Oct 23 23:41 clients
drwxr-x--- 1 root   root     4 Oct 23 23:41 testA54hj5luZtlorr494
drwxr-xr-x 7 root   root  4.0K May  4 00:02 ..

contents of urbackup_tmp_files

-rwx------ 1 dietpi users 3.8M Oct 25 10:28 28
-rwx------ 1 dietpi users  26M Oct 25 10:28 18
drwxr-x--- 1 dietpi users   16 Oct 25 10:27 .
-rwx------ 1 dietpi users 3.9M Oct 25 10:27 27
drwxr-xr-x 1 dietpi users  154 Oct 25 10:26 ..
-rwx------ 1 dietpi users 8.4M Oct 25 01:08 17

Solved:

A few things were involved in fixing this.

First I figured I was trying to backup too much at once, so I removed the largest backup task of about 4TB and limited it to only my personal desktop. On this I also stopped the image backup, and only backed up important folder paths such as my Documents folder.

This sort of seemed to work, as the backup task would go further than before. I was still getting file not found errors though. I noticed when the docker container started up the test for BTRFS was failing, that was because I forgot to uncomment the lines in the docker compose that enabled BTRFS support!

D’oh.

Still that didn’t fix everything, with far less files to backup I was able to see the actual end of the backup log and it was still failing with drive errors.

So I went nuclear, wiped the drive completely, re-partitioned, and reformatted it.
I uninstalled the urbackup client from all my systems. I deleted the config folder created by docker container.
Deleted all the container images, and started it up again.

I setup urbackup again, this time starting with my PC as the only client and with only a handful of folders to backup. IT WORKS!!

I added the remaining folders I wanted to backup and this seems to be working well. Next I’m going to start with the large 4TB backup, but again I’m going to start small and move up to the larger backup after a few successful backups.