Hi,
I’m running urbackup 2.5.31 in an binhex/arch-urbackup container running on unraid to backup a windows client (among others) with version 2.5.25. The backup is configured to only run file backups once every 20 hours day between 3AM to 11AM:
The local settings mirror that (and client side changing of backups has been disabled):
But the backup seems to ignore both settings and run multiple times a day:
Turning on debug logs gives me detailled logging on the backup process, but doesn’t provide a rationale why backups are being started:
2024-07-12 14:47:47: Looking for old Sessions... 0 sessions
2024-07-12 15:17:48: Looking for old Sessions... 0 sessions
2024-07-12 15:47:49: Looking for old Sessions... 0 sessions
2024-07-12 16:17:50: Looking for old Sessions... 0 sessions
2024-07-12 16:21:03: New Backupclient: cookie
2024-07-12 16:21:03: Sending Identity to client "cookie" failed. Retrying soon...
2024-07-12 16:21:04: Getting client settings...
2024-07-12 16:21:04: Flushing FileClient...
2024-07-12 16:21:04: Channel message: STARTUP timestamp=1720786975
2024-07-12 16:21:04: Sending backup incr interval...
2024-07-12 16:21:04: Starting scheduled incremental file backup...
2024-07-12 16:21:04: cookie: Connecting for filelist...
2024-07-12 16:21:04: cookie: Waiting for filelist
2024-07-12 16:21:04: cookie: Connecting for filelist (async)...
2024-07-12 16:21:54: New Backupclient: cookie[vmdata]
2024-07-12 16:21:54: Sending Identity to client "cookie[vmdata]" failed. Retrying soon...
2024-07-12 16:21:54: Getting client settings...
2024-07-12 16:21:54: Flushing FileClient...
2024-07-12 16:21:54: Channel message: STARTUP timestamp=1720786975
2024-07-12 16:21:54: Sending backup incr interval...
2024-07-12 16:22:22: Scanning for changed hard links on volume of "C:\"...
2024-07-12 16:22:22: Indexing of "vscode" done. 1 filesystem lookups 0 db lookups and 0 db updates
2024-07-12 16:22:22: Indexing of "git config" done. 1 filesystem lookups 0 db lookups and 0 db updates
2024-07-12 16:22:22: Indexing of "Pictures" done. 56 filesystem lookups 0 db lookups and 0 db updates
2024-07-12 16:22:22: Indexing of "Desktop" done. 2 filesystem lookups 0 db lookups and 0 db updates
2024-07-12 16:22:22: Following symbolic link at "C:\ProgramData\Desktop" to "C:\Users\Public\Desktop" confirms symlink backup target ".symlink_Desktop" to "C:\Users\Public\Desktop"
2024-07-12 16:22:22: Following symbolic link at "C:\ProgramData\Documents" to "C:\Users\Public\Documents" confirms symlink backup target ".symlink_Documents" to "C:\Users\Public\Documents"
2024-07-12 16:22:22: Indexing of "ProgramData" done. 3896 filesystem lookups 0 db lookups and 0 db updates
2024-07-12 16:22:22: Indexing of "Music" done. 22 filesystem lookups 8877 db lookups and 21 db updates
2024-07-12 16:22:22: Indexing of "Appdata" done. 10474 filesystem lookups 0 db lookups and 0 db updates
2024-07-12 16:22:22: cookie: Doing backup with hashed transfer...
2024-07-12 16:22:22: cookie: Connecting to client...
2024-07-12 16:22:22: cookie: Loading file list...
2024-07-12 16:22:22: Flushing FileClient...
2024-07-12 16:22:22: cookie Starting incremental backup...
2024-07-12 16:22:22: cookie: Calculating file tree differences...
2024-07-12 16:22:22: Flushing FileClient...
2024-07-12 16:22:22: Flushing FileClient...
2024-07-12 16:22:22: cookie: Calculating tree difference size...
2024-07-12 16:22:23: cookie: Linking unchanged and loading new files...
2024-07-12 16:22:23: WARNING: SQLite: cannot open file at line 36982 of [3bfa9cc97d] errorcode: 14
2024-07-12 16:22:23: WARNING: SQLite: os_unix.c:36982: (40) openDirectory(/var/urbackup) - errorcode: 14
2024-07-12 16:22:23: Loading file "AsusUpdateCheck.idx"
2024-07-12 16:22:23: Flushing FileClient...
2024-07-12 16:22:23: GT: Loaded file "AsusUpdateCheck.idx"
2024-07-12 16:22:23: Loading file "AsusUpdateCheck_05_20240712142255.log"
2024-07-12 16:22:23: PT: Hashing file "AsusUpdateCheck.idx"
2024-07-12 16:22:23: HT: Copying file: "/backups/cookie/240712-1621/ProgramData/ASUS/SCD/AsusUpdateCheck.idx" (id=4058)
2024-07-12 16:22:23: HT: Renaming file to "/backups/cookie/240712-1621/ProgramData/ASUS/SCD/AsusUpdateCheck.idx"
2024-07-12 16:22:23: GT: Loaded file "AsusUpdateCheck_05_20240712142255.log"
2024-07-12 16:22:23: Loading file "bzvolumes.xml"
2024-07-12 16:22:23: PT: Hashing file "AsusUpdateCheck_05_20240712142255.log"
2024-07-12 16:22:23: GT: Loaded file "bzvolumes.xml"
2024-07-12 16:22:23: Loading file "bzfileids.dat"
2024-07-12 16:22:23: PT: Hashing file "bzvolumes.xml"
2024-07-12 16:22:23: HT: Copying file: "/backups/cookie/240712-1621/ProgramData/ASUS/SCD/AsusUpdateCheck_05_20240712142255.log" (id=4063)
2024-07-12 16:22:23: HT: Renaming file to "/backups/cookie/240712-1621/ProgramData/ASUS/SCD/AsusUpdateCheck_05_20240712142255.log"
2024-07-12 16:22:23: HT: Copying file: "/backups/cookie/240712-1621/ProgramData/Backblaze/bzdata/bzvolumes.xml" (id=4079)
2024-07-12 16:22:23: HT: Renaming file to "/backups/cookie/240712-1621/ProgramData/Backblaze/bzdata/bzvolumes.xml"
2024-07-12 16:22:23: Flushing FileClient...
2024-07-12 16:22:23: Flushing FileClient...
2024-07-12 16:22:23: Flushing FileClient...
[Files are being backed up]
2024-07-12 16:23:10: Syncing file system...
2024-07-12 16:23:11: WARNING: SQLite: cannot open file at line 36982 of [3bfa9cc97d] errorcode: 14
2024-07-12 16:23:11: WARNING: SQLite: os_unix.c:36982: (40) openDirectory(/var/urbackup) - errorcode: 14
2024-07-12 16:23:11: Creating symbolic links. -1
2024-07-12 16:23:11: Creating symbolic links. -2
2024-07-12 16:23:11: Symbolic links created.
2024-07-12 16:23:11: Transferred 1.68055 GB - Average speed: 344.933 MBit/s
2024-07-12 16:23:11: Script does not exist urbackup/post_incr_filebackup
2024-07-12 16:23:14: Time taken for backing up client cookie: 2m 10s
2024-07-12 16:23:14: Backup succeeded
2024-07-12 16:23:14: Updating statistics...
2024-07-12 16:23:14: Updating image stats...
2024-07-12 16:23:14: Updating file statistics...
2024-07-12 16:23:14: Done updating statistics.
2024-07-12 16:23:15: msg=WAKEUP
2024-07-12 16:23:15: server_prepare_hash Thread finished (exit)
2024-07-12 16:23:15: server_hash Thread finished - normal
Is there some setting I’m missing or something I misunderstand about the configuration?