Since updating to 2.3, I’ve been unable to complete a backup because Duplicati silently quits. (Potentially crashes, but there aren’t any crash logs that I can find.) What I see is that the backup will progress for some time, then all Duplicati processes disappear and I get a “reconnecting” dialog on the web client.
I can restart Duplicati and re-initiate the backup, but it invariably quits/crashes in the same way later. There’s “No crash log found” under the Crash log tab.
I ran a backup with verbose logging, and just before the crash I saw messages like “New file /Users/joe/Pictures/Photos Library.photoslibrary/dup_backup/2D9EA445-22…”, so Duplicati was clearly processing my photos library. (dup_backup in the path is a bit interesting; I wonder if this left-over from a previous aborted backup?)
Anyways, does anyone have any suggestions on how to further isolate what’s actually happening? I genuinely have nothing to go on right now other than what I’ve posted.
That usually means a hard crash. The process is killed and is not allowed to write anything, making it really hard to diagnose.
That is a new feature in 2.3, and might be related to the crash. With 2.3, Duplicati will backup the Photos in iCloud if you have the photos folder included in the backup. Previous versions would only backup whatever was in the on-disk Photos.library folder. In 2.3, Duplicati will talk to MacOS and if it gets permissions, it will make a backup of all photos, even if they are stored in iCloud and are not on-disk.
Use the option --photos-handling and set it to one of:
LibraryOnly: Don’t attempt to communicate with MacOS Photos and treat the folder as a regular folder (how it was in 2.2 and earlier)
PhotosOnly: Don’t read the local Photos.sqlite and other files in there. Instead ask MacOS to list all Photos, and then make backups of the actual Photos.
PhotosAndLibrary: Default; Get both the photos and the local files.
I would recommend either excluding the Photos folder or using PhotosOnly, as there is no value in having a backup of the internal database that Photos is using, because it will simply be rebuilt automatically if missing. We keep it on to avoid breaking changes for people who expect the previous way.
The dup_backup is a virtual path added by Duplicati so the photos do not clash with actual files in the Photos.library folder.
I would suggest trying to set --photos-handling=Library to see if that makes the problem go away. If it does, then go to sources and exclude the Photos folder from the backup.
If you want a backup of the photos, then you can try to add a --log-file=/path/to/log + --log-file-log-level=profiling to the backup in the advanced settings. This will track as much as possible up to the actual crash and maybe we can get a glimpse of what is happening.
You can also look in the MacOS app Console and look at “Crash Reports” to see if there is anything recorded there.
Btw, the Photos library should work on x64 + Arm, but it was only tested on Arm (M3). Do you happen to have an x64 Mac?
It was a 2.2-series canary, I believe; this has been the case for a couple of months (my last successful backup was at the end of April), so I might have the timeline wrong.
A genuinely awesome feature. Thank you!
(Should be easy for Duplicati in my own setup, because I tell macOS to keep all photos on disk for backup purposes; the library is gigantic, though, so if I don’t have to any more with this feature, double thank you.)
I’ll give this a try if all else fails!
I’ve got the log, but there’s no smoking gun in it; Duplicati is going through my photo library and doing various transactions, and then stops. HOWEVER, Console is a little more instructive, I think. No crashes, but it looks like the kernel’s OOM killer decided Duplicati needed reaping:
default 15:06:51.036381-0400 duplicati [0xa7f83d400] Re-initialization successful; calling out to event handler with XPC_ERROR_CONNECTION_INTERRUPTED
default 15:06:51.036974-0400 duplicati [0xa7f83d180] Re-initialization successful; calling out to event handler with XPC_ERROR_CONNECTION_INTERRUPTED
default 15:06:51.049581-0400 duplicati [0xa7f83d2c0] Re-initialization successful; calling out to event handler with XPC_ERROR_CONNECTION_INTERRUPTED
default 15:06:51.051791-0400 duplicati [0xa4b7ce940] Re-initialization successful; calling out to event handler with XPC_ERROR_CONNECTION_INTERRUPTED
error 15:06:51.051841-0400 duplicati Connection to assetsd was interrupted - photolibraryd exited, died, or closed the photo library
default 15:06:51.063086-0400 duplicati Client connection interrupted for URL <private>, resetting bind state (previous result: <private>)
default 15:06:51.066376-0400 duplicati [0xa4b7cca00] Re-initialization successful; calling out to event handler with XPC_ERROR_CONNECTION_INTERRUPTED
default 15:06:51.111517-0400 duplicati Process Instance Registry XPC connection has been interrupted
default 15:06:51.138441-0400 duplicati [0xa4b7ce440] Re-initialization successful; calling out to event handler with XPC_ERROR_CONNECTION_INTERRUPTED
default 15:06:51.187832-0400 duplicati [0xa4b7cdcc0] Re-initialization successful; calling out to event handler with XPC_ERROR_CONNECTION_INTERRUPTED
default 15:06:51.191500-0400 kernel memorystatus: killing largest compressed process duplicati [9887] 41699 MB
Nothing particularly smoking-gun-ish in photolibraryd console logs at that time, though:
default 15:06:11.748374-0400 photolibraryd [0x864c72440] Re-initialization successful; calling out to event handler with XPC_ERROR_CONNECTION_INTERRUPTED
default 15:06:11.748374-0400 photolibraryd [0x864c72e40] Re-initialization successful; calling out to event handler with XPC_ERROR_CONNECTION_INTERRUPTED
default 15:06:11.749099-0400 photolibraryd [0x865719f40] Re-initialization successful; calling out to event handler with XPC_ERROR_CONNECTION_INTERRUPTED
default 15:06:11.749524-0400 photolibraryd [0x864c4d900] Re-initialization successful; calling out to event handler with XPC_ERROR_CONNECTION_INTERRUPTED
default 15:06:11.750328-0400 photolibraryd ### Connection error 0x8492b21c0 Connection interrupted for com.apple.managedcorespotlightd
default 15:06:11.750385-0400 photolibraryd ### Connection error 0x8492b0280 Connection interrupted for com.apple.managedcorespotlightd
default 15:06:11.750417-0400 photolibraryd ### Connection error 0x8597ce900 Connection interrupted for com.apple.managedcorespotlightd
default 15:06:11.750430-0400 photolibraryd ### Connection error 0x8492b31c0 Connection interrupted for com.apple.managedcorespotlightd
default 15:06:45.981708-0400 photolibraryd [0x86137d7c0] Re-initialization successful; calling out to event handler with XPC_ERROR_CONNECTION_INTERRUPTED
error 15:06:45.985528-0400 photolibraryd <private>: connection with com.apple.cloudphotod was interrupted
default 15:06:45.987807-0400 photolibraryd Failing 0 upload tasks
default 15:06:45.987819-0400 photolibraryd Failing 0 force sync tasks
default 15:06:51.035511-0400 WindowServer 0[outside of RPC]: Process death: 0x0-0x100100 (photolibraryd) connectionID: C0DC3 pid: 1058 in session 0x101
default 15:06:51.035558-0400 WindowServer <BSCompoundAssertion:0xc7300d540> ([FocusManager:257]-deferringPolicyEvaluationSuppression) acquire for reason:process death - 0x0-0x100100 (photolibraryd) acq:0xc743bfe40 count:1
default 15:06:51.036124-0400 WindowServer 0[outside of RPC]: [FocusManager:257] update to deferring policy requested for reason: permitted list updated - 0x0-0x100100 removed - but we are suppressing evaluation for reasons: {(
"process death - 0x0-0x100100 (photolibraryd)"
)}
error 15:06:51.039819-0400 Spotlight Connection to assetsd was interrupted - photolibraryd exited, died, or closed the photo library
error 15:06:51.040290-0400 Spotlight Connection to assetsd was interrupted - photolibraryd exited, died, or closed the photo library
default 15:06:51.040765-0400 WindowServer 0[outside of RPC]: [FocusManager:257] update to deferring policy requested for reason: permitted list updated - 0x1-0x422 removed - but we are suppressing evaluation for reasons: {(
"process death - 0x0-0x100100 (photolibraryd)"
)}
error 15:06:51.044217-0400 photoanalysisd Connection to assetsd was interrupted - photolibraryd exited, died, or closed the photo library
default 15:06:51.045957-0400 filecoordinationd Received state update for 1058 (osservice<com.apple.photolibraryd(501)>, running-NotVisible
default 15:06:51.046791-0400 runningboardd XPC connection invalidated: [osservice<com.apple.photolibraryd(501)>:1058]
error 15:06:51.051841-0400 duplicati Connection to assetsd was interrupted - photolibraryd exited, died, or closed the photo library
Not knowing much about the APIs you’re using, my theory is that Duplicati memory usage is the smoking gun here.
That is the exact reason. Duplicati has taken up 42GB of memory and the kernel is just hard-terminating it to avoid out-of-memory errors.
It is most likely a memory leak somewhere in the bridge code that talks to the PhotosLibrary.
I think what is happening is that the photo library is being downloaded faster than Duplicati can process it, and at some point the buffer is just too big and the process gets killed.
Upload cache is filled, blocking further processing files
Readers are blocked from sending more data
PhotoKit keeps streaming data, but none is processed
This works fine if we are talking pictures of a few mb, so 4x10mb = 40mb.
But if one or more of these are high-res videos, we can get 4x20gb or so.
Follow up questions:
What is the (appx) size of the library?
What size are the largest files in there (assuming some are videos)?
Does my theory sound plausible given your data?
