Well… Since it doesn’t work in 2.5, I’d though I try to see if it’s the version or the database itself. I’m getting a bit desperate to get it working, at least, so I can do some risky drive cleaning.
I’ll try downgrading it, and I hope it will be fixed/can update without issues
After downgrading, doing a backup (Which worked perfectly), then updating, it again crashes on startup
2022-08-30 21:39:33: Starting HTTP-Server on port 55414
2022-08-30 21:39:33: HTTP: Server started up successfully!
2022-08-30 21:39:33: SQLite: recovered 8331 frames from WAL file /var/urbackup/backup_server.db-wal code: 283
2022-08-30 21:39:33: SQLite: recovered 75082 frames from WAL file /var/urbackup/backup_server_files.db-wal code: 283
2022-08-30 21:39:33: SQLite: recovered 245 frames from WAL file /var/urbackup/backup_server_link_journal.db-wal code: 283
2022-08-30 21:39:34: SQLite: recovered 121514 frames from WAL file /var/urbackup/backup_server_links.db-wal code: 283
2022-08-30 21:39:34: SQLite: recovered 36 frames from WAL file /var/urbackup/backup_server_settings.db-wal code: 283
2022-08-30 21:39:34: SQLite: recovered 8331 frames from WAL file /var/urbackup/backup_server.db-wal code: 283
2022-08-30 21:39:34: SQLite: recovered 36 frames from WAL file /var/urbackup/backup_server_settings.db-wal code: 283
2022-08-30 21:39:34: SQLite: recovered 75082 frames from WAL file /var/urbackup/backup_server_files.db-wal code: 283
2022-08-30 21:39:34: SQLite: recovered 121514 frames from WAL file /var/urbackup/backup_server_links.db-wal code: 283
2022-08-30 21:39:34: SQLite: recovered 245 frames from WAL file /var/urbackup/backup_server_link_journal.db-wal code: 283
2022-08-30 21:39:34: Started UrBackup...
2022-08-30 21:39:34: Removing temporary files...
2022-08-30 21:39:34: Recreating temporary folder...
2022-08-30 21:39:34: Testing if backup destination can handle subvolumes and snapshots...
2022-08-30 21:39:34: Backup destination cannot handle subvolumes and snapshots. Snapshots disabled.
2022-08-30 21:39:34: Testing if backup destination can handle filesystem transactions...
2022-08-30 21:39:34: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:39:34: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:39:35: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:39:35: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:39:35: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:39:35: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:39:36: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:39:36: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:39:36: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:39:36: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:39:37: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:39:37: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:39:37: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:39:37: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:39:38: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:39:38: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:39:38: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:39:38: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:39:39: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:39:39: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:39:39: HTTP: No available slots... starting new Worker
2022-08-30 21:39:39: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:39:39: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client
2022-08-30 21:42:11: Starting HTTP-Server on port 55414
2022-08-30 21:42:11: HTTP: Server started up successfully!
2022-08-30 21:42:18: SQLite: recovered 8331 frames from WAL file /var/urbackup/backup_server.db-wal code: 283
2022-08-30 21:43:21: SQLite: recovered 75082 frames from WAL file /var/urbackup/backup_server_files.db-wal code: 283
2022-08-30 21:43:21: SQLite: recovered 246 frames from WAL file /var/urbackup/backup_server_link_journal.db-wal code: 283
2022-08-30 21:43:34: SQLite: recovered 121514 frames from WAL file /var/urbackup/backup_server_links.db-wal code: 283
2022-08-30 21:43:34: SQLite: recovered 36 frames from WAL file /var/urbackup/backup_server_settings.db-wal code: 283
2022-08-30 21:43:34: SQLite: recovered 8331 frames from WAL file /var/urbackup/backup_server.db-wal code: 283
2022-08-30 21:43:34: SQLite: recovered 36 frames from WAL file /var/urbackup/backup_server_settings.db-wal code: 283
2022-08-30 21:43:34: SQLite: recovered 75082 frames from WAL file /var/urbackup/backup_server_files.db-wal code: 283
2022-08-30 21:43:35: SQLite: recovered 121514 frames from WAL file /var/urbackup/backup_server_links.db-wal code: 283
2022-08-30 21:43:35: SQLite: recovered 246 frames from WAL file /var/urbackup/backup_server_link_journal.db-wal code: 283
2022-08-30 21:43:35: Started UrBackup...
2022-08-30 21:43:35: Removing temporary files...
2022-08-30 21:43:35: Recreating temporary folder...
2022-08-30 21:43:35: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:43:35: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:43:36: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:43:36: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:43:36: Testing if backup destination can handle subvolumes and snapshots...
2022-08-30 21:43:37: Backup destination cannot handle subvolumes and snapshots. Snapshots disabled.
2022-08-30 21:43:37: Testing if backup destination can handle filesystem transactions...
2022-08-30 21:43:37: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:43:37: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:43:37: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:43:37: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:43:38: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:43:38: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:43:38: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:43:38: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:43:39: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:43:39: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:43:39: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:43:39: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:43:40: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:43:40: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client. Retrying in 1s...
2022-08-30 21:43:40: WARNING: SQLite: no such column: value_client in "SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?" errorcode: 1
2022-08-30 21:43:40: ERROR: Error preparing Query [SELECT value, value_client, use FROM settings_db.settings WHERE clientid=? AND key=?]: no such column: value_client
I don’t know what else to do apart from staying on 2.4 for now. Thankfully I’m not urgently requesting to update. I’ll just wait until the bug is fixed.
If I can do anything else to help debug it, I can try to help still.
Wow okay. Then stay with 2.4. I check some things today to understand how some things are working to better understand whats going on.
So, I got some new info.
After upgrading the package and start the urbackup service, the database gets the missing column by calling upgrade59_60. This step adds the column, which is missing.
If some upgrade fail, the server clearly outputs Upgrading database failed. Shutting down server..
It should also log an Upgrading database to version 65 warning. the first time
If you have some time: Could you again:
Could you post the log from the 1st startup after upgrading?
The log above is a first time startup of 2.5 (Then a second time). A search for “Upgrading” or “Upgrade” in the whole log file doesn’t return anything related either.
I can make another log, but I can’t do it on the original hardware for now. Some clients need full backups to be done and that will take some time.
I can try to use a VM for it. I just need to set it up
Houston, we got a problem.
Your db data for the misc table seems kinda corrupt - You are missing the db_version column. Without it, the database would never upgrade (In fact, the urbackupserver can recognize the missing value and try an import of a db file (backup_server.dat, cannot find it anywhere), but I bet this fails as well).
A healthy misc looks like:
But yours looks like:
I dont know how the misc data is stored like that. the many two’s and one’s makes no sense to me. The dates neither.
At this point, maybe uroni has an idea.
Could you try the following with your current working installation? You dont have to upgrade.
Please edit /etc/default/urbackupsrv and set the loglevel to debug (should now be warn). Restart and post the full log here. I bet, there are some database things, because the db_version is missing.
I would say: At this point, the database is in a inconsistent state and not able to run a upgrade without checking the structure first.
That sounds bad.
It also seems to not be the only thing going wrong. After restoring the 2.4 server, backups of the server’s file make the storage disk stop responding after a point and some files on the clients are loaded but moving them produce an error that they don’t exist in the temporary files.
IDK what caused it to break down, but it seems there’s a bigger corruption problem than just updating. Luckily I made urbackup backup its own files when moving it from windows. I can try to dig until I find a version with proper misc table
Here’s the log:
2022-08-31 20:15:08: Starting HTTP-Server on port 55414
2022-08-31 20:15:09: HTTP: Server started up successfully!
2022-08-31 20:15:20: SQLite: recovered 8378 frames from WAL file /var/urbackup/backup_server.db-wal code: 283
2022-08-31 20:16:27: SQLite: recovered 76480 frames from WAL file /var/urbackup/backup_server_files.db-wal code: 283
2022-08-31 20:16:27: SQLite: recovered 247 frames from WAL file /var/urbackup/backup_server_link_journal.db-wal code: 283
2022-08-31 20:16:43: SQLite: recovered 121408 frames from WAL file /var/urbackup/backup_server_links.db-wal code: 283
2022-08-31 20:16:43: SQLite: recovered 36 frames from WAL file /var/urbackup/backup_server_settings.db-wal code: 283
2022-08-31 20:16:43: SQLite: recovered 8378 frames from WAL file /var/urbackup/backup_server.db-wal code: 283
2022-08-31 20:16:43: SQLite: recovered 36 frames from WAL file /var/urbackup/backup_server_settings.db-wal code: 283
2022-08-31 20:16:43: SQLite: recovered 76480 frames from WAL file /var/urbackup/backup_server_files.db-wal code: 283
2022-08-31 20:16:44: SQLite: recovered 121408 frames from WAL file /var/urbackup/backup_server_links.db-wal code: 283
2022-08-31 20:16:44: SQLite: recovered 247 frames from WAL file /var/urbackup/backup_server_link_journal.db-wal code: 283
2022-08-31 20:16:44: Started UrBackup...
2022-08-31 20:16:44: Removing temporary files...
2022-08-31 20:16:44: Recreating temporary folder...
2022-08-31 20:16:45: UrBackup Server start up complete.
2022-08-31 20:16:45: Looking for old Sessions... 0 sessions
2022-08-31 20:16:45: Server started up successfully!
2022-08-31 20:16:46: Downloading version file...
2022-08-31 20:16:46: Testing if backup destination can handle subvolumes and snapshots...
2022-08-31 20:16:46: Downloading version file...
2022-08-31 20:16:46: Downloading server version info...
2022-08-31 20:16:46: Downloading dataplan database...
2022-08-31 20:16:47: Backup destination cannot handle subvolumes and snapshots. Snapshots disabled.
2022-08-31 20:16:47: Testing if backup destination can handle filesystem transactions...
2022-08-31 20:16:47: Testing for hardlinks in backup destination...
2022-08-31 20:16:47: Could not create hardlink at backup destination. Hardlinks disabled. File exists (code: 17)
2022-08-31 20:16:47: Testing for reflinks in backup destination...
2022-08-31 20:16:47: Error opening destination file. errno=17
2022-08-31 20:16:47: Could not create reflink at backup destination. Reflinks disabled. File exists (code: 17)
2022-08-31 20:16:47: Binding to interface enp3s0 (ipv4) for broadcasting...
2022-08-31 20:16:47: Broadcasting on ipv4 interface enp3s0 addr 192.168.0.99
2022-08-31 20:16:47: Binding to interface docker0 (ipv4) for broadcasting...
2022-08-31 20:16:47: Broadcasting on ipv4 interface docker0 addr 172.17.0.1
2022-08-31 20:16:47: Binding to interface enp3s0 (ipv6) for broadcasting...
2022-08-31 20:16:47: Broadcasting on ipv6 interface enp3s0 addr 2a01:e0a:53f:680:7c31:3b87:6918:d242
2022-08-31 20:16:47: Binding to interface enp3s0 (ipv6) for broadcasting...
2022-08-31 20:16:47: Broadcasting on ipv6 interface enp3s0 addr 2a01:e0a:53f:680:b298:615d:bdf3:e434
2022-08-31 20:16:47: Binding to interface enp3s0 (ipv6) for broadcasting...
2022-08-31 20:16:47: Broadcasting on ipv6 interface enp3s0 addr fe80::d396:d20e:e929:c4b7
2022-08-31 20:17:19: New Backupclient: Imaginary-Tree
2022-08-31 20:17:19: Sending Identity to client "Imaginary-Tree" failed. Retrying soon...
2022-08-31 20:17:22: Client doesn't have IMAGE capability
2022-08-31 20:17:22: Getting client settings...
2022-08-31 20:17:23: Sending backup incr interval...
2022-08-31 20:17:23: Client doesn't have IMAGE capability
2022-08-31 20:18:09: New Backupclient: Zephyrus-Duo
2022-08-31 20:18:09: Sending Identity to client "Zephyrus-Duo" failed. Retrying soon...
2022-08-31 20:18:09: Getting client settings...
2022-08-31 20:18:09: Sending backup incr interval...
2022-08-31 20:18:22: Resetting channel to Imaginary-Tree because session identity changed.
Thanks - but still not that, what I expected.
If something is wrong with the db_version, the server would log Importing data... but it does not.
=> https://github.com/uroni/urbackup_backend/blob/2.4.x/urbackupserver/dllmain.cpp#L2090
Dont know why its not logging that line.
How old is your whole urbackup instance? When die you first set it up?
I made it in late june on Windows, then transfered it on a Linux Mint Server the 15 august.
I’ve been looking at the files and it’s corrupted since the 20 at least (I didn’t save it into urbackup before that). I still got my database from before the move, and the misc table is fine. I’ll try to restore that one.
It’s alive and in 2.5!
I did lose a month worth of backups but I won’t cry over it.
I’ll keep an eye out for any other problems, but now it would probably outside the original scope of this thread. I still have the old database, if the devs needs help to debug further
Still, thank you for your help.
It should be okay to move from windows to linux, imho. Dont know whats the issue.
Nice, that it is running now 
Did you ever updatest the installation or is the 2.5 update the first update of the server?
It’s the first update yeah.
So, the database have changed while using urbackup. I dont get how the db_version got lost then 