UrBackup stopped working for one Ubuntu client but not the other client or my windows machines

Server
1

I had UrBackup up and running for a few days on Ubuntu 22.04 (both client and server on same machine) and it was successfully making full file backups and incremental file backups regularly. I was looking at green boxes for two windows 11 PCs and two Ubuntu 22.04 machines. Then today it just stopped making any backups on the same machine I use as the server.

Here’s today’s content from my client log:
2024-04-08 18:10:54: WARNING: Shutting down (Signal 15)
2024-04-08 18:14:45: WARNING: Shutting down (Signal 15)
2024-04-08 21:11:39: ERROR: Creating shadowcopy of “mpender” failed.
2024-04-08 21:11:39: ERROR: Error stating file “/home/mpender/Music” to get file tokens. Errno: 40
2024-04-08 21:11:39: ERROR: Error stating file “/home/mpender/Pictures” to get file tokens. Errno: 40
2024-04-08 21:11:39: ERROR: Error stating file “/home/mpender/Public” to get file tokens. Errno: 40
2024-04-08 21:11:39: ERROR: Error stating file “/home/mpender/Templates” to get file tokens. Errno: 40
2024-04-08 21:11:39: ERROR: Error stating file “/home/mpender/Videos” to get file tokens. Errno: 40
2024-04-08 21:14:34: WARNING: Shutting down (Signal 15)
2024-04-08 21:28:59: WARNING: Shutting down (Signal 15)

And here is the content from the server log:
2024-04-08 18:10:54: WARNING: Shutting down (Signal 15)
2024-04-08 18:14:45: WARNING: Shutting down (Signal 15)
2024-04-08 21:11:39: ERROR: Creating shadowcopy of “mpender” failed.
2024-04-08 21:11:39: ERROR: Error stating file “/home/mpender/Music” to get file tokens. Errno: 40
2024-04-08 21:11:39: ERROR: Error stating file “/home/mpender/Pictures” to get file tokens. Errno: 40
2024-04-08 21:11:39: ERROR: Error stating file “/home/mpender/Public” to get file tokens. Errno: 40
2024-04-08 21:11:39: ERROR: Error stating file “/home/mpender/Templates” to get file tokens. Errno: 40
2024-04-08 21:11:39: ERROR: Error stating file “/home/mpender/Videos” to get file tokens. Errno: 40
2024-04-08 21:14:34: WARNING: Shutting down (Signal 15)
2024-04-08 21:28:59: WARNING: Shutting down (Signal 15)
root@scarlet:/var/log# cat urbackup.log
2024-04-08 22:01:07: Starting HTTP-Server on port 55414
2024-04-08 22:01:07: HTTP: Server started up successfully!
2024-04-08 22:01:07: SQLite: recovered 3587 frames from WAL file /var/urbackup/backup_server.db-wal code: 283
2024-04-08 22:01:07: SQLite: recovered 149724 frames from WAL file /var/urbackup/backup_server_files.db-wal code: 283
2024-04-08 22:01:07: SQLite: recovered 5008 frames from WAL file /var/urbackup/backup_server_link_journal.db-wal code: 283
2024-04-08 22:01:07: SQLite: recovered 39189 frames from WAL file /var/urbackup/backup_server_links.db-wal code: 283
2024-04-08 22:01:07: SQLite: recovered 53 frames from WAL file /var/urbackup/backup_server_settings.db-wal code: 283
2024-04-08 22:01:07: SQLite: recovered 3587 frames from WAL file /var/urbackup/backup_server.db-wal code: 283
2024-04-08 22:01:07: SQLite: recovered 53 frames from WAL file /var/urbackup/backup_server_settings.db-wal code: 283
2024-04-08 22:01:07: SQLite: recovered 149724 frames from WAL file /var/urbackup/backup_server_files.db-wal code: 283
2024-04-08 22:01:07: SQLite: recovered 39189 frames from WAL file /var/urbackup/backup_server_links.db-wal code: 283
2024-04-08 22:01:07: SQLite: recovered 5008 frames from WAL file /var/urbackup/backup_server_link_journal.db-wal code: 283
2024-04-08 22:01:07: Started UrBackup…
2024-04-08 22:01:07: Removing temporary files…
2024-04-08 22:01:07: Recreating temporary folder…
2024-04-08 22:01:07: Image mounting disabled: TEST FAILED: guestmount is missing (libguestfs-tools)
2024-04-08 22:01:07: Testing if backup destination can handle subvolumes and snapshots…
2024-04-08 22:01:07: Backup destination cannot handle subvolumes and snapshots. Snapshots disabled.
2024-04-08 22:01:07: Testing if backup destination can handle filesystem transactions…
2024-04-08 22:01:07: Testing for hardlinks in backup destination…
2024-04-08 22:01:07: Could create hardlink at backup destination. Hardlinks enabled.
2024-04-08 22:01:07: Testing for reflinks in backup destination…
2024-04-08 22:01:07: Reflink ioctl failed. errno=95
2024-04-08 22:01:07: Could not create reflink at backup destination. Reflinks disabled. Operation not supported (code: 95)
2024-04-08 22:01:07: Binding to interface eno1 (ipv4) for broadcasting…
2024-04-08 22:01:07: Broadcasting on ipv4 interface eno1 addr 192.168.1.50
2024-04-08 22:01:07: Binding to interface eno1 (ipv6) for broadcasting…
2024-04-08 22:01:07: Broadcasting on ipv6 interface eno1 addr fe80::df99:f5bc:cd78:6026
2024-04-08 22:01:08: InternetService: Server started up successfully!
2024-04-08 22:01:08: UrBackup Server start up complete.
2024-04-08 22:01:08: Looking for old Sessions… 0 sessions
2024-04-08 22:01:08: Server started up successfully!
2024-04-08 22:01:09: Downloading server version info…
2024-04-08 22:01:09: Downloading dataplan database…
2024-04-08 22:01:17: InternetService: No available slots… starting new Worker
2024-04-08 22:01:17: Authentication failed in InternetServiceConnector::ReceivePackets: Token not found (token authentication)
2024-04-08 22:01:17: Authed+capa for client ‘Cookie’ (encrypted-v2, compressed-zstd) - 1 spare connections
2024-04-08 22:01:18: New Backupclient: Scarlet
2024-04-08 22:01:18: New Backupclient: Cookie
2024-04-08 22:01:18: Sending Identity to client “Scarlet” failed. Retrying soon…
2024-04-08 22:01:18: Connecting to target service…
2024-04-08 22:01:18: Established internet connection. Service=0
2024-04-08 22:01:18: InternetService: No available slots… starting new Worker
2024-04-08 22:01:18: Sending Identity to client “Cookie” failed. Retrying soon…
2024-04-08 22:01:18: Authed+capa for client ‘Cookie’ (encrypted-v2, compressed-zstd, token auth) - 1 spare connections
2024-04-08 22:01:18: Connecting to target service…
2024-04-08 22:01:18: Established internet connection. Service=0
2024-04-08 22:01:18: Authed+capa for client ‘Cookie’ (encrypted-v2, compressed-zstd, token auth) - 1 spare connections
2024-04-08 22:01:18: Connecting to target service…
2024-04-08 22:01:18: Established internet connection. Service=0
2024-04-08 22:01:18: Authed+capa for client ‘Cookie’ (encrypted-v2, compressed-zstd, token auth) - 1 spare connections
2024-04-08 22:01:18: Client doesn’t have IMAGE capability
2024-04-08 22:01:18: Forcing offline client “Scarlet”
2024-04-08 22:01:18: Connecting to target service…
2024-04-08 22:01:18: Established internet connection. Service=0
2024-04-08 22:01:18: Authed+capa for client ‘Cookie’ (encrypted-v2, compressed-zstd, token auth) - 1 spare connections
2024-04-08 22:01:19: Getting client settings…
2024-04-08 22:01:19: Connecting to target service…
2024-04-08 22:01:19: Established internet connection. Service=0
2024-04-08 22:01:19: Channel message: STARTUP timestamp=1712575078
2024-04-08 22:01:19: Authed+capa for client ‘Cookie’ (encrypted-v2, compressed-zstd, token auth) - 1 spare connections
2024-04-08 22:01:19: Connecting to target service…
2024-04-08 22:01:19: Established internet connection. Service=1
2024-04-08 22:01:19: Flushing FileClient…
2024-04-08 22:01:19: Authed+capa for client ‘Cookie’ (encrypted-v2, compressed-zstd, token auth) - 1 spare connections
2024-04-08 22:01:19: Connecting to target service…
2024-04-08 22:01:19: Established internet connection. Service=0
2024-04-08 22:01:19: Channel message: UPDATE SETTINGS
2024-04-08 22:01:19: Authed+capa for client ‘Cookie’ (encrypted-v2, compressed-zstd, token auth) - 1 spare connections
2024-04-08 22:01:19: Sending backup incr interval…
2024-04-08 22:01:19: Connecting to target service…
2024-04-08 22:01:19: Established internet connection. Service=0
2024-04-08 22:01:19: Authed+capa for client ‘Cookie’ (encrypted-v2, compressed-zstd, token auth) - 1 spare connections
2024-04-08 22:01:19: Connecting to target service…
2024-04-08 22:01:19: Established internet connection. Service=0
2024-04-08 22:01:19: msg=UPDATE SETTINGS
2024-04-08 22:01:19: Getting client settings…
2024-04-08 22:01:19: Authed+capa for client ‘Cookie’ (encrypted-v2, compressed-zstd, token auth) - 1 spare connections
2024-04-08 22:01:19: Connecting to target service…
2024-04-08 22:01:19: Established internet connection. Service=1
2024-04-08 22:01:19: Flushing FileClient…
2024-04-08 22:01:19: Authed+capa for client ‘Cookie’ (encrypted-v2, compressed-zstd, token auth) - 1 spare connections
2024-04-08 22:03:11: HTTP: No available slots… starting new Worker
2024-04-08 22:03:11: HTTP: No available slots… starting new Worker
2024-04-08 22:03:11: Sending file “/usr/share/urbackup/www”
2024-04-08 22:03:11: Sending file: /usr/share/urbackup/www/index.htm
2024-04-08 22:03:11: Sending file: /usr/share/urbackup/www/index.htm done
2024-04-08 22:03:11: Sending file “/usr/share/urbackup/www/images/urbackup.png”
2024-04-08 22:03:11: Sending file: /usr/share/urbackup/www/images/urbackup.png
2024-04-08 22:03:11: Sending file: /usr/share/urbackup/www/images/urbackup.png done
2024-04-08 22:03:12: Sending file “/usr/share/urbackup/www/fonts/glyphicons-halflings-regular.woff2”
2024-04-08 22:03:12: Sending file: /usr/share/urbackup/www/fonts/glyphicons-halflings-regular.woff2
2024-04-08 22:03:12: Sending file: /usr/share/urbackup/www/fonts/glyphicons-halflings-regular.woff2 done
2024-04-08 22:05:59: Client exited: Scarlet
2024-04-08 22:06:49: Client finished: Scarlet
2024-04-08 22:06:49: Client was forced offline: Scarlet
2024-04-08 22:07:39: New Backupclient: Scarlet
2024-04-08 22:07:39: Sending Identity to client “Scarlet” failed. Retrying soon…
2024-04-08 22:07:40: Client doesn’t have IMAGE capability
2024-04-08 22:07:40: Forcing offline client “Scarlet”
2024-04-08 22:12:42: Client exited: Scarlet
2024-04-08 22:13:32: Client finished: Scarlet
2024-04-08 22:13:32: Client was forced offline: Scarlet
2024-04-08 22:14:01: Sending file “/usr/share/urbackup/www”
2024-04-08 22:14:01: Sending file: /usr/share/urbackup/www/index.htm
2024-04-08 22:14:01: Sending file: /usr/share/urbackup/www/index.htm done
2024-04-08 22:14:01: Sending file “/usr/share/urbackup/www/images/urbackup.png”
2024-04-08 22:14:01: Sending file: /usr/share/urbackup/www/images/urbackup.png
2024-04-08 22:14:01: Sending file: /usr/share/urbackup/www/images/urbackup.png done
2024-04-08 22:14:02: Sending file “/usr/share/urbackup/www/fonts/glyphicons-halflings-regular.woff2”
2024-04-08 22:14:02: Sending file: /usr/share/urbackup/www/fonts/glyphicons-halflings-regular.woff2
2024-04-08 22:14:02: Sending file: /usr/share/urbackup/www/fonts/glyphicons-halflings-regular.woff2 done
2024-04-08 22:14:22: New Backupclient: Scarlet
2024-04-08 22:14:22: Sending Identity to client “Scarlet” failed. Retrying soon…
2024-04-08 22:14:23: Client doesn’t have IMAGE capability
2024-04-08 22:14:23: Forcing offline client “Scarlet”
2024-04-08 22:19:25: Client exited: Scarlet
2024-04-08 22:20:15: Client finished: Scarlet
2024-04-08 22:20:15: Client was forced offline: Scarlet
2024-04-08 22:21:05: New Backupclient: Scarlet
2024-04-08 22:21:05: Sending Identity to client “Scarlet” failed. Retrying soon…
2024-04-08 22:21:05: Client doesn’t have IMAGE capability
2024-04-08 22:21:05: Forcing offline client “Scarlet”
2024-04-08 22:22:29: Sending file “/usr/share/urbackup/www”
2024-04-08 22:22:29: Sending file: /usr/share/urbackup/www/index.htm
2024-04-08 22:22:29: Sending file: /usr/share/urbackup/www/index.htm done
2024-04-08 22:22:29: Sending file “/usr/share/urbackup/www/images/urbackup.png”
2024-04-08 22:22:29: Sending file: /usr/share/urbackup/www/images/urbackup.png
2024-04-08 22:22:29: Sending file: /usr/share/urbackup/www/images/urbackup.png done
2024-04-08 22:22:29: Sending file “/usr/share/urbackup/www/fonts/glyphicons-halflings-regular.woff2”
2024-04-08 22:22:29: Sending file: /usr/share/urbackup/www/fonts/glyphicons-halflings-regular.woff2
2024-04-08 22:22:29: Sending file: /usr/share/urbackup/www/fonts/glyphicons-halflings-regular.woff2 done
2024-04-08 22:26:07: Client exited: Scarlet
2024-04-08 22:26:57: Client finished: Scarlet
2024-04-08 22:26:57: Client was forced offline: Scarlet
2024-04-08 22:27:47: New Backupclient: Scarlet
2024-04-08 22:27:47: Sending Identity to client “Scarlet” failed. Retrying soon…
2024-04-08 22:27:48: Client doesn’t have IMAGE capability
2024-04-08 22:27:48: Forcing offline client “Scarlet”

I am not sure how to interpret the logs and could use some help parsing what is meaningful from what is normal.

Thanks, Mike

2

How I would “digest” the logs is to look at Error numbers. Assuming that these are classic Linux “errno.h” error numbers - then 40 is “too many symbolic links”.
If I were to assume that you DO NOT have a lot of symbolic links on your /home/mpender - then I would question the methodology chosen for the shadow/Lvm/snapshots/whatever.
In my experience - LVM snapshots sometimes go awry and that which is supposed to be the non-writable-snapshot to backup seems to be “swapped” with the one that IS writable but has very little space allocated to it. Naturally, the way it’s supposed to work is that a small LVM is created for writing only the changes/additions whilst the backup is occurring. SO - That’s 1.
Another could be if you used the kernel module who’s name I forget …er “doupp”? its choice 4 I think when you install the client. That’s another method of snapshot that gets confused on Root with separate /boot and Efi mounts.
Last - there is rsync - which does use symbolic links. If IT WERE a contributing culprit - then I would look at the size and type of filesystem of my /home.
BUT WAIT!! - WHat if you don’t have a separate FS for /home? Then, I’d be looking elsewhere.

Server Log — hmmm. Not using BTRFS FS, not using a FS capable of reflinks???
Is this a Linux or Windows server?
Windows - Sorry - dunno.
Linux - what Filesystem are you using for your Urbackup server? Is your Urbackup server a docker image? - If yes - WHERE have you pointed the docker volumes for urbackup data…eg. what filesystem type?

I apologize if my thoughts have lead you on on a wild goose chase. However, geese do need some consideration and can be useful for rumination.
David

3

I don’t think I have a lot of symbolic links in my /home/mpender – I don’t think I have any. And when installing the client on the Linux machines I chose the no-image backups option (choice 5) so I didn’t think I would be generating snapshots.

It is a Linux server – Ubuntu 22.04.3 – and the file system is a LVM install for the operating system, but an ext4 volume for the backup data.

Something weird happened though. I left the system alone for a day and then it made an incremental file backup of the disk. Unfortunately, the problem has not simply gone away. The MacBookPro won’t back up now and immediately gives me the “starting backup failed” message when I try to do a full file backup. The only common factor appears to be that it is the Linux machines that are affected.

4

I think I may have found the root of the problem. I made recent changes to the Ubuntu OS to prepare for the new software coming out later this month. The changes I made seem to cause the computer name to be reported in lower case instead of a mix of upper and lower case, like Scarlet and MacBookPro. I’ve tried using this command on the client:
urbackupclientctl set-settings -k computername -v MacBookPro

And the backups started again. Unfortunately, I did several other things as well, like moving the old backups off the backup disk so I would not accidentally erase them, so I don’t know if setting the computer name on the client would have solved the problem all by itself.

  • Mike
5

My understanding of host names is that, despite case used; a DNS lookup should reply by lowercasing prior to lookup. Hence, always finding the correct IP.

However, it MAY be that the conversation between the client and server do not respect this tradition.

Certainly the names used in the urbackup “bk” folder are case significant and correspond to the names in the web admin…which should be identical to the client host-name field.

I would assume that, as it is the server that needs to resolve the client hostname to an IP…it would use standard Linux libraries/resolvers. I therefore conclude that the case name change was not the solution.

I will add that, many years ago, in my Unix days, there was an issue with a hostname of exactly 8 characters length causing problems. Being very old, I adhere to ancient UNIX mysticism and avoid 8 character names.

You say you made some other changes…can you recall in what area even if not specifically?
David

6

The other changes were moving the old backups off of the backup disk to another disk entirely, stopping the client and then removing the client listing from the UrBackup server database and then starting the client again. That created a new full backup.

I tried to recreate the issue this weekend with a virtual machine. I started with an installation of Ubuntu 20.04.6 and upgraded to 22.04.4. The virtual machine was named UbuntuVM. I could not reproduce the problem where the hostname was changed to ubuntuvm. I manually changed the machine name to ubuntuvm and verified that the incremental file backups began failing immediately. However, I found that setting the hostname back to UbuntuVM again did not clear the problem. Nor did using this command: “urbackupclientctl set-settings -k computername -v UbuntuVM” to set the client hostname.

It appears you were right and setting the computername is not a solution. As before, I stopped the client and removed the database entry and backups from the server, then restarted the client and the server began backing up normally again.

I think the problem with the backups failing is triggered by a change in the name of the Ubuntu client hostname, but I have not been able to determine what causes the hostname to change.

  • Michael
7

There’s the Server idents file that specifies the key (handshaking stuff) and IF the server idents on the client is not the same as on the server - then they wont talk.
I can’t recall the detail but, in the manual (somewhere) it talks about server idents - or maybe server_idents.
I know that one can locate the file on the server fairly easily…then all you got to do is plonk it int the correct /usr/local/??? (can’t remember but a
find /usr/local -name “server*idents”
will show you where it is.
If it’s not available in the server web page somewhere (though I think it is) then
you can always connect to the container with a terminal (as user root) and run a /bin/bash which will enable you to do the find too.

7:23am - up all night.trying to attach urbackup server to a specific nic that has 2.5gbps - sigh.
Good luck