Hi, I installed the mac client (2.4.12-2), but the backup never finish. At the moment I get the following error messages:
2022-03-07 14:07:33(info): Starting scheduled incremental file backup…
2022-03-07 14:08:05(info): Backing up “Desktop” without snapshot.
2022-03-07 14:08:05(info): Following symbolic link at “/Users/username/Desktop/Neu zugewiesene Objekte.nosync” to “/Users/Shared/Relocated Items” confirms symlink backup target “.symlink_Relocated Items” to “/Users/Shared/Relocated Items”
2022-03-07 14:08:05(info): Indexing of “Desktop” done. 7826 filesystem lookups 0 db lookups and 0 db updates
2022-03-07 14:08:05(info): Backing up “.symlink_Relocated Items” without snapshot.
2022-03-07 14:08:06(info): My Client: Loading file list…
2022-03-07 14:40:10(error): Error getting filelist of My Client. Errorcode: TIMEOUT (2)
2022-03-07 14:40:10(error): Backup had an early error. Deleting partial backup.
The message “Errorcode Timeout (2) and Backup had an early error. Deleting partial backup.” is repeating over the last days. The full backup is about 190 GB, approx. 60 GB where transferred, since this moment, I get error messages each time the client tries to transfer more files to the server.
I am not sure what cause this problems? Maybe someone could help me with this?
Do you have any other clients attached to the same Urbackup server? If you do, and they’re running ok, can you say if they’ve got similarly large backup sets?
yes we have also other clients attached to the same server, some with even larger backup sets, all are working fine. But they are all windows clients. This is the first mac client that we connected to the server. And there this messages appear, and the backup still never finish, because the client stop the transfer of the files.
Here are the latest log files from the server:
2022-03-08 18:32:06: WARNING: Connecting to ClientService of "My Client" failed: Sending logdata to client failed
2022-03-08 20:46:35: ERROR: Error getting file metadata. Errorcode: TIMEOUT (2)
2022-03-08 20:46:42: ERROR: Error getting file patch for "NwrluONa5kIBJdpAzTF7|Desktop/Lukas Backup/Youtube/aufnahmen/New Gen gamez/Call of Duty Black Ops 3 08.29.2015 - 00.13.53.09.DVR.mp4" from My Client. Errorcode: TIMEOUT (2)
2022-03-08 20:46:42: ERROR: Client My Client went offline.
2022-03-08 20:46:44: WARNING: File "/urbackup/My Client/220308-1930/.hashes/Desktop/Lukas Backup/Youtube/aufnahmen/New Gen gamez/Call of Duty Black Ops 3 08.29.2015 - 00.13.53.09.DVR.mp4" has wrong size. Should=993992 is=993988. Error writing metadata to file. -1
2022-03-08 20:46:44: ERROR: Writing metadata to /urbackup/My Client/220308-1930/.hashes/Desktop/Lukas Backup/Youtube/aufnahmen/New Gen gamez/Call of Duty Black Ops 3 08.29.2015 - 00.13.53.09.DVR.mp4 failed
2022-03-08 20:47:02: ERROR: Connecting to ClientService of "My Client" failed: Sending status (BACKUP FAILED) to client failed
2022-03-08 20:47:35: WARNING: Error reading current metadata
2022-03-08 20:47:35: WARNING: File "/urbackup/My Client/220308-1930/.hashes/Desktop/Lukas Backup/Youtube/aufnahmen/New Gen gamez/Call of Duty Black Ops 3 08.29.2015 - 00.13.53.09.DVR.mp4" has wrong size. Should=993996 is=993988. Error writing metadata to file. -2
2022-03-08 20:47:35: ERROR: Error saving metadata. Cannot write common metadata.
2022-03-08 20:47:36: ERROR: Fatal error during backup. Backup not completed
2022-03-08 20:47:37: ERROR: FATAL: Backup failed because of disk problems (see previous messages)
2022-03-08 20:47:37: ERROR: Backup failed
2022-03-08 20:47:39: WARNING: Connecting to ClientService of "My Client" failed: Sending logdata to client failed
2022-03-08 20:52:49: ERROR: Connecting to ClientService of "My Client" failed - CONNECT error during filelist construction
2022-03-08 20:52:59: ERROR: Backup had an early error. Deleting partial backup.
2022-03-08 20:53:00: WARNING: Exponential backoff: Waiting at least 40m before next file backup
2022-03-08 20:53:00: WARNING: Connecting to ClientService of "My Client" failed: Sending logdata to client failed
2022-03-08 21:19:21: ERROR: Connecting to ClientService of "My Client" failed - CONNECT error during filelist construction (2)
2022-03-08 21:19:27: ERROR: Backup had an early error. Deleting partial backup.
2022-03-08 21:19:28: WARNING: Connecting to ClientService of "My Client" failed: Sending logdata to client failed
2022-03-09 00:02:47: ERROR: Connecting to ClientService of "My Client" failed - CONNECT error during filelist construction (2)
2022-03-09 00:02:52: ERROR: Backup had an early error. Deleting partial backup.
2022-03-09 00:02:54: WARNING: Connecting to ClientService of "My Client" failed: Sending logdata to client failed
2022-03-09 02:03:19: ERROR: Connecting to ClientService of "My Client" failed - CONNECT error during filelist construction (2)
2022-03-09 02:03:25: ERROR: Backup had an early error. Deleting partial backup.
2022-03-09 02:03:30: WARNING: Connecting to ClientService of "My Client" failed: Sending logdata to client failed
2022-03-09 04:04:22: ERROR: Connecting to ClientService of "My Client" failed - CONNECT error during filelist construction (2)
2022-03-09 04:04:27: ERROR: Backup had an early error. Deleting partial backup.
2022-03-09 04:04:29: WARNING: Connecting to ClientService of "My Client" failed: Sending logdata to client failed
2022-03-09 16:15:02: ERROR: Connecting to ClientService of "My Client" failed: Querying client capabilities failed
2022-03-09 16:15:02: ERROR: Could not get client capabilities
Sorry for the delay in responding. I don’t understand why this isn’t working for you at present.
Is it viable to uninstall the Urbackup Client from the Mac, and delete /Library/Application Support/Urbackup Client from the machine, before then reinstalling and re-configuring it?
sorry for my late reply. I uninstalled the client and reinstalled. Also deleted the Library Folder first. The backup started quite good after the installation (76 GB transferred). But the backup still never finishes and these are the latest server logs for this client.
2022-03-28 03:58:57: ERROR: Connecting to ClientService of "My Client" failed - CONNECT error during filelist construction (2)
2022-03-28 03:59:07: ERROR: Backup had an early error. Deleting partial backup.
2022-03-28 04:04:08: ERROR: Connecting to ClientService of "My Client" failed - CONNECT error during filelist construction
2022-03-28 04:04:18: ERROR: Backup had an early error. Deleting partial backup.
2022-03-28 04:04:19: WARNING: Exponential backoff: Waiting at least 40m before next file backup
2022-03-28 06:10:10: ERROR: Connecting to ClientService of "My Client" failed - CONNECT error during filelist construction (2)
2022-03-28 06:10:16: ERROR: Backup had an early error. Deleting partial backup.
2022-03-28 06:10:18: WARNING: Connecting to ClientService of "My Client" failed: Sending logdata to client failed
2022-03-28 08:58:25: ERROR: Connecting to ClientService of "My Client" failed - CONNECT error during filelist construction (2)
2022-03-28 08:58:31: ERROR: Backup had an early error. Deleting partial backup.
2022-03-28 08:58:33: WARNING: Connecting to ClientService of "My Client" failed: Sending logdata to client failed
2022-03-28 09:26:57: ERROR: Connecting to ClientService of "My Client" failed - CONNECT error during filelist construction (2)
2022-03-28 09:27:04: ERROR: Backup had an early error. Deleting partial backup.
2022-03-28 09:27:06: WARNING: Connecting to ClientService of "My Client" failed: Sending logdata to client failed
The backup is immediately interrupted after it startet.
No problem for the delay in replying. Is there anything new and informative in the client’s local log file, in /Library/Logs/urbackup_client_backend.log?
here are again log files from server and client. The client is transferring data to the server, we are now at about 84GB (last post 76GB). But still error messages and still a lot of data that should be transferred.
# Client Logs
2022-03-31 12:22:25: rc=0 hasError=true state=0
2022-03-31 12:22:25: SERVICE_COMMANDS finished
2022-03-31 12:22:25: Started connection to SERVICE_COMMANDS
2022-03-31 12:22:25: ClientService cmd: #I767VM8KYTwjkIgn43R11#INCRINTERVALL "259203"
2022-03-31 12:22:25: rc=0 hasError=true state=0
2022-03-31 12:22:25: SERVICE_COMMANDS finished
2022-03-31 12:22:25: Started connection to SERVICE_COMMANDS
2022-03-31 12:22:25: ClientService cmd: #I767VM8KYTwjkIgn43R11#VERSION 224
2022-03-31 12:22:25: Not down-grading from current client version 253 to server version 224
2022-03-31 12:22:26: rc=0 hasError=true state=0
2022-03-31 12:22:26: SERVICE_COMMANDS finished
2022-03-31 12:22:26: Started connection to SERVICE_COMMANDS
2022-03-31 12:22:26: ClientService cmd: #I767VM8KYTwjkIgn43R11#2LOGDATA 1648720226 0-1648719106-Starting scheduled incremental file backup...
2-1648720224-Connecting to ClientService of "My Client" failed - CONNECT error during filelist construction (2)
2-1648720226-Backup had an early error. Deleting partial backup.
2022-03-31 12:22:26: rc=0 hasError=true state=0
2022-03-31 12:22:26: SERVICE_COMMANDS finished
2022-03-31 12:22:26: Started connection to SERVICE_COMMANDS
2022-03-31 12:22:26: ClientService cmd: #I767VM8KYTwjkIgn43R11#2PING RUNNING pc_done=&status_id=308&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=NwrluONa5kIBJdpAzTF7
2022-03-31 12:22:26: Started connection to SERVICE_COMMANDS
2022-03-31 12:22:26: ClientService cmd: #I767VM8KYTwjkIgn43R11#3START BACKUP group=0&running_jobs=1&resume=incr&sha=528&with_permissions=1&with_scripts=1&with_orig_path=1&with_sequence=1&with_proper_symlinks=1&status_id=308&async=1#token=NwrluONa5kIBJdpAzTF7
2022-03-31 12:22:26: Removing running process (timeout) id 18 server_id 304 token NwrluONa5kIBJdpAzTF7 action 5
2022-03-31 12:22:26: Removing running process (timeout) id 19 server_id 305 token NwrluONa5kIBJdpAzTF7 action 5
2022-03-31 12:22:26: rc=0 hasError=true state=0
2022-03-31 12:22:26: SERVICE_COMMANDS finished
2022-03-31 12:22:27: Started connection to SERVICE_COMMANDS
2022-03-31 12:22:27: ClientService cmd: #I767VM8KYTwjkIgn43R11#WAIT FOR INDEX async_id=28893a94b8f7459cb8e3948ae7c7e8bd#token=NwrluONa5kIBJdpAzTF7
2022-03-31 12:22:27: Wait for async index 28893a94b8f7459cb8e3948ae7c7e8bd
2022-03-31 12:22:27: ClientService cmd: STATUS#pw=XxG9FcLxMmVRVh4VuUUPHoXTtBkXWf
2022-03-31 12:22:28: ClientService cmd: STATUS#pw=XxG9FcLxMmVRVh4VuUUPHoXTtBkXWf
2022-03-31 12:22:30: Client timeout in ClientConnector::Run
2022-03-31 12:22:30: SERVICE_COMMANDS finished
2022-03-31 12:22:36: ClientService cmd: #I767VM8KYTwjkIgn43R11#2PING RUNNING pc_done=&eta_ms=77641&status_id=308&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=NwrluONa5kIBJdpAzTF7
2022-03-31 12:22:37: Following symbolic link at "/Applications/Safari.app/Contents/MacOS/SafariForWebKitDevelopment" to "/Library/Application Support/Apple/Safari/SafariForWebKitDevelopment" confirms symlink backup target ".symlink_SafariForWebKitDevelopment" to "/Library/Application Support/Apple/Safari/SafariForWebKitDevelopment"
2022-03-31 12:22:46: ClientService cmd: #I767VM8KYTwjkIgn43R11#2PING RUNNING pc_done=&eta_ms=67587&status_id=308&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=NwrluONa5kIBJdpAzTF7
# Server Logs
2022-03-31 01:15:52(info): Starting scheduled incremental file backup...
2022-03-31 01:21:24(info): Backing up "Desktop" without snapshot.
2022-03-31 01:21:24(info): Following symbolic link at "/Users/huber/Desktop/Neu zugewiesene Objekte.nosync" to "/Users/Shared/Relocated Items" confirms symlink backup target ".symlink_Relocated Items" to "/Users/Shared/Relocated Items"
2022-03-31 01:21:24(info): Indexing of "Desktop" done. 6841 filesystem lookups 0 db lookups and 0 db updates
2022-03-31 01:21:24(info): Backing up "Documents" without snapshot.
2022-03-31 01:21:24(info): Indexing of "Documents" done. 270 filesystem lookups 0 db lookups and 0 db updates
2022-03-31 01:21:24(info): Backing up "Pictures" without snapshot.
2022-03-31 01:21:24(info): Indexing of "Pictures" done. 333 filesystem lookups 0 db lookups and 0 db updates
2022-03-31 01:21:24(info): Backing up "Applications" without snapshot.
2022-03-31 01:21:24(info): Following symbolic link at "/Applications/Safari.app/Contents/MacOS/SafariForWebKitDevelopment" to "/Library/Application Support/Apple/Safari/SafariForWebKitDevelopment" confirms symlink backup target ".symlink_SafariForWebKitDevelopment" to "/Library/Application Support/Apple/Safari/SafariForWebKitDevelopment"
2022-03-31 01:21:24(info): Indexing of "Applications" done. 27686 filesystem lookups 0 db lookups and 0 db updates
2022-03-31 01:21:24(info): Backing up ".symlink_Relocated Items" without snapshot.
2022-03-31 01:21:24(info): Backing up ".symlink_SafariForWebKitDevelopment" without snapshot.
2022-03-31 01:21:24(info): My Client: Loading file list...
2022-03-31 01:22:41(info): My Client: Calculating file tree differences...
2022-03-31 01:22:42(info): My Client: Indexing file entries from last backup...
2022-03-31 01:22:45(info): My Client: Calculating tree difference size...
2022-03-31 01:22:46(info): My Client: Linking unchanged and loading new files...
2022-03-31 01:22:46(info): Referencing snapshot on "My Client" for path "Desktop" failed: FAILED
2022-03-31 01:22:48(info): Referencing snapshot on "My Client" for path "Documents" failed: FAILED
2022-03-31 01:22:49(info): Referencing snapshot on "My Client" for path "Pictures" failed: FAILED
2022-03-31 01:57:00(error): Error getting file metadata. Errorcode: TIMEOUT (2)
2022-03-31 01:57:05(error): Error getting complete file "NwrluONa5kIBJdpAzTF7|Pictures/Photos Library.photoslibrary/originals/E/EC78B009-34B4-4D8F-A59A-7D72844252BF.heic" from My Client. Errorcode: TIMEOUT (2)
2022-03-31 01:57:05(info): Saving incomplete file.
2022-03-31 01:57:05(error): Client My Client went offline.
2022-03-31 01:57:35(info): Waiting for file transfers...
2022-03-31 01:57:58(info): Client had timeout. Retrying backup soon...
2022-03-31 01:57:58(info): Waiting for file hashing and copying threads...
2022-03-31 01:57:59(info): Writing new file list...
2022-03-31 01:58:00(info): Number of copied file entries from last backup is 11942
2022-03-31 02:00:20(info): Transferred 89.5273 MB - Average speed: 350.784 KBit/s
2022-03-31 02:00:20(info): (Before compression: 124.246 MB ratio: 1.3878)
2022-03-31 02:00:20(info): 8.5793 GB of files were already present on the server and did not need to be transferred
2022-03-31 02:00:20(info): Time taken for backing up client My Client: 44m 27s
2022-03-31 02:00:20(error): Backup failed
Sorry - I’m really not sure what’s going on with your issue - assuming it’s not something silly like the client machine going to sleep?..
Have you yet tried simplifying your backup set - e.g. just backup ~/Desktop, and ensure this repeatedly succeeds, before adding other folders into the mix?