Hi, I"m having this same error show up. Backups stopped accumulating November 2 (so about 8 weeks ago) not sure if this is a problem with one of the updates
What I see if I try to run the backup manually, it starts of, it gets past preparing, then I see updates saying “transferring…” it gets to 7 or so % and then errors out.
Is there a way to diagnose what is going wrong here?
Maybe a stupid response, but are you sure your backup disk has enough space available?
Rugby
(aka Daniel or Big Dan)
January 3, 2023, 8:31pm
4
Where are you backing up to? An external disk, a network share? If an external disk, as Dirk mentioned, is there enough space, and you might run some disk checking software.
noris
January 4, 2023, 6:06pm
7
Hi @john_schneider ,
It looks like you are backing up to a NAS location. Can you please confirm if backups to a USB drive also have the same failure? Or is the NAS the only location impacted?
@Dirk_De_Taey and @Rugby - thanks yes, there is about 7T of space available
@noris - it’s a NAS, yes. an SMB mount running off of a TruNAS server. the most recent build that had a successful backup is build-1133. I went digging into the logs and it’s failing to copy the file (see below) I got into Emacs to follow the directory links from the root of the file path and in the directory I was able to create and save a file, so access isn’t the issue.
Any pointers on what I might try?
LOGS LOGS LOGS LOGS
01/05 15:08:49 Trace: [broker/backups] doing backup now
01/05 15:08:49 Warn: AddTopLevel: capturelayer(1960)
01/05 15:08:49 Trace: [broker/backups] computing list of files to back up
01/05 15:08:49 Warn: AddTopLevel: dialog_manual_backups(2983)
01/05 15:08:49 Debug: [broker/backups] preparing sync on FileBrowser.Entry: \\freenas.local, Roon : \RoonBackups
01/05 15:08:49 Debug: [broker/filebrowser/volumeshare] Use volume, user: broker/backups/startbackup, id: \\freenas.local\Roon
01/05 15:08:49 Trace: [backup] preparing backup on dir AttachedDir:/Users/mlcondit/Library/RoonMounts/RoonStorage_c4ef7bfa2da2a20479e3d5c69fb3fe294df94007/RoonBackups
01/05 15:08:49 Info: [stats] 38792mb Virtual, 796mb Physical, 472mb Managed
01/05 15:08:50 Trace: [backup] getbackupdirs, rootdir: AttachedDir:/Users/mlcondit/Library/RoonMounts/RoonStorage_c4ef7bfa2da2a20479e3d5c69fb3fe294df94007/RoonBackups, machineid: e89963b3-33cd-e775-232c-848cea3f7e65
01/05 15:08:50 Debug: [broker/backups] successful sync prepare on FileBrowser.Entry: \\freenas.local, Roon : \RoonBackups
01/05 15:08:50 Info: [loadstatus] IsBackupInProgress False => True
01/05 15:08:50 Trace: [broker/backups] [a7c7a6a2-491c-4fe8-a515-cb011a76834b] paused media thread
01/05 15:08:50 Trace: [zone AppleTV] Suspend
01/05 15:08:50 Info: [zone AppleTV] Canceling Pending Sleep
01/05 15:08:50 Trace: [zone Fly Tying] Suspend
01/05 15:08:50 Info: [zone Fly Tying] Canceling Pending Sleep
01/05 15:08:50 Trace: [zone bluenode airplay] Suspend
01/05 15:08:50 Info: [zone bluenode airplay] Canceling Pending Sleep
01/05 15:08:50 Trace: [zone denon] Suspend
01/05 15:08:50 Info: [zone denon] Canceling Pending Sleep
01/05 15:08:50 Trace: [zone Richy] Suspend
01/05 15:08:50 Info: [zone Richy] Canceling Pending Sleep
01/05 15:08:50 Trace: [zone bluestream roon] Suspend
01/05 15:08:50 Info: [zone bluestream roon] Canceling Pending Sleep
01/05 15:08:50 Trace: [zone Bedroom speaker] Suspend
01/05 15:08:50 Info: [zone Bedroom speaker] Canceling Pending Sleep
01/05 15:08:50 Trace: [leveldb] closing /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/transport/zone_1601bffd7c92ee900f9f82f8ce255c94235d.db temporarily
01/05 15:08:50 Trace: [leveldb] closing /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/transport/zone_16012cdd53bd8d7275eb3fda9f718fb0e1ad.db temporarily
01/05 15:08:50 Trace: [leveldb] closing /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/transport/zone_160195828476e09cbae2311aa13af66757b4.db temporarily
01/05 15:08:50 Trace: [leveldb] closing /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/transport/zone_16019d2e5e84c6c2295db623cbad7281cc28.db temporarily
01/05 15:08:50 Trace: [leveldb] closing /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/transport/zone_1601d7186075ebbc9005f46be5bedcb3223d.db temporarily
01/05 15:08:50 Trace: [leveldb] closing /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/transport/zone_1601623c28e89da7fb83da7cf73bbe52556c.db temporarily
01/05 15:08:50 Trace: [leveldb] closing /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/transport/zone_1601b13d80f41dcebb3cfbfa4aded160881b.db temporarily
01/05 15:08:50 Trace: [broker/backups] [a7c7a6a2-491c-4fe8-a515-cb011a76834b] paused transport thread
01/05 15:08:50 Trace: [leveldb] closing /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/broker_4.db temporarily
01/05 15:08:50 Info: [broker/database/vacuum] ==================================================================================================
01/05 15:08:50 Info: [broker/database/vacuum] ===[ Validating Database ]========================================================================
01/05 15:08:50 Info: [broker/database/vacuum] ==================================================================================================
01/05 15:08:50 Info: [broker/database/vacuum] Validating /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/broker_4.db
01/05 15:08:50 Warn: AddTopLevel: win_backup_in_progress(23)
01/05 15:08:50 Info: [broker/database/vacuum] processed 11 playlist entries
01/05 15:08:50 Info: [broker/database/vacuum] processed 3277 profile entries (skipped 0 entries)
01/05 15:08:50 Info: [broker/database/vacuum] processed 534 radio entries
01/05 15:08:51 Warn: [mobile] /hello => ServiceUnavailable
01/05 15:08:51 Debug: [easyhttp] [4201] POST to https://roonmobile.roonlabs.net/1/cores/announce returned after 888 ms, status code: 200
01/05 15:08:52 Info: [broker/database/vacuum] processed 527567 music entries
01/05 15:08:53 Info: [broker/database/vacuum] validated tinysooid db in 640ms, visited 932873 entries
01/05 15:08:53 Info: [broker/database/vacuum] processed 177205 image entries
01/05 15:08:53 Info: [broker/database/vacuum] finished validation in 3002ms
01/05 15:08:53 Info: [broker/database/vacuum] ==================================================================================================
01/05 15:08:53 Info: [broker/database/vacuum] ==================================================================================================
01/05 15:08:53 Info: [broker/database/vacuum] ==================================================================================================
01/05 15:08:53 Trace: [leveldb] closing /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/clientdata.db temporarily
01/05 15:08:53 Trace: [broker/backups] [a7c7a6a2-491c-4fe8-a515-cb011a76834b] paused misc thread
01/05 15:08:56 Trace: [leveldb] re-opening /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/broker_4.db
01/05 15:08:56 Trace: [leveldb] re-opening /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/clientdata.db
01/05 15:08:56 Trace: [leveldb] re-opening /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/transport/zone_1601bffd7c92ee900f9f82f8ce255c94235d.db
01/05 15:08:56 Trace: [leveldb] re-opening /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/transport/zone_16012cdd53bd8d7275eb3fda9f718fb0e1ad.db
01/05 15:08:56 Trace: [leveldb] re-opening /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/transport/zone_160195828476e09cbae2311aa13af66757b4.db
01/05 15:08:56 Trace: [leveldb] re-opening /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/transport/zone_16019d2e5e84c6c2295db623cbad7281cc28.db
01/05 15:08:56 Trace: [leveldb] re-opening /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/transport/zone_1601d7186075ebbc9005f46be5bedcb3223d.db
01/05 15:08:56 Trace: [leveldb] re-opening /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/transport/zone_1601623c28e89da7fb83da7cf73bbe52556c.db
01/05 15:08:56 Trace: [leveldb] re-opening /Users/mlcondit/Library/Roon/Database/Core/bb7bc5a59d57421dbb718b063ddd86bb/transport/zone_1601b13d80f41dcebb3cfbfa4aded160881b.db
01/05 15:08:56 Info: [loadstatus] IsBackupInProgress True => False
01/05 15:08:58 Info: [mobile] GOT HTTP API /hello
01/05 15:08:58 Trace: [mobile] Got Hello Request body={"coreId":"356aa34a-fdb8-4c41-8499-1b728ae0d5df"}
01/05 15:08:58 Debug: [easyhttp] [4202] POST to https://roonmobile.roonlabs.net/1/cores/announce returned after 2169 ms, status code: 200
01/05 15:08:59 Trace: [broker/backups] [a7c7a6a2-491c-4fe8-a515-cb011a76834b] checked 634 files, planning to upload 252 files
01/05 15:08:59 Debug: [broker/backups] syncing on FileBrowser.Entry: \\freenas.local, Roon : \RoonBackups - 249 files to upload, 634 manifest entries
01/05 15:08:59 Trace: [backup] uploading files. bytes transferred: 0/237867664 (0%)
01/05 15:08:59 Trace: [backup] uploading files. bytes transferred: 33/237867664 (0%)
01/05 15:08:59 Trace: [backup] uploading files. bytes transferred: 607/237867664 (0%)
01/05 15:08:59 Trace: [backup] uploading files. bytes transferred: 2835469/237867664 (1%)
01/05 15:08:59 Trace: [backup] uploading files. bytes transferred: 5670737/237867664 (2%)
01/05 15:08:59 Trace: [backup] uploading files. bytes transferred: 5692316/237867664 (2%)
01/05 15:09:01 Trace: [backup] uploading files. bytes transferred: 6711268/237867664 (2%)
01/05 15:09:03 Trace: [backup] uploading files. bytes transferred: 8827835/237867664 (3%)
01/05 15:09:04 Warn: [backup] failed to sync: putfile hash: AttachedDir:/Users/mlcondit/Library/RoonMounts/RoonStorage_c4ef7bfa2da2a20479e3d5c69fb3fe294df94007/RoonBackups/e89963b3-33cd-e775-232c-848cea3f7e65/8e/1c/8e1c64c0e9327e71d053c1942a781caf71ced89b69dae3b6b433853d70dfee4d: Result[Status=UnexpectedError, ErrorText=System.IO.IOException: file move failed: -1 errno=5
at Base.IO.LongPathFile.Move(String srcpath, String dstpath)
at Roon.FileSystem.AttachedFileSystem.<>c__DisplayClass15_0.<PutFile>b__0()
at System.Threading.Tasks.Task`1.InnerInvoke()
at System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(Thread threadPoolThread, ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location ---
at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread)
--- End of stack trace from previous location ---
at Roon.FileSystem.AttachedFileSystem.PutFile(Stream srcfile, IFileSystemDir parent_, String destname, Boolean overwrite, CancellationToken canceltoken)]
01/05 15:09:04 Warn: [broker/backups] failed sync on FileBrowser.Entry: \\freenas.local, Roon : \RoonBackups: Result[Status=UnexpectedError]
01/05 15:09:04 Debug: [broker/backups] on done, auto: False
01/05 15:09:04 Debug: [broker/filebrowser/volumeshare] Use dispose, id: \\freenas.local\Roon
noris
January 9, 2023, 9:39pm
9
Hi @john_schneider ,
Can you please confirm if a local storage option (USB/local HDD) also exhibits this behavior?
Sorry for delay, I was traveling.
I hooked up a USB drive to my iMAC and the backup succeeded.
So I would suspect there is some kind issue that arose due to a system update.
The MacOS has been updated but I don’t recall if it was November or later
I have a workaround. I can backup locally and copy it over to the NAS
It would be nice to know why this just stopped working though
Thanks
noris
January 19, 2023, 6:05pm
11
Are you able to back up directly to your iMac if you create a shared folder there? To create the folder, you can use similar instructions to this:
system
(system)
Closed
March 5, 2023, 6:06pm
12
This topic was automatically closed 45 days after the last reply. New replies are no longer allowed.