Yeah, it doesn’t seem user-specific. Removing -vss is just a workaround if you don’t want to be without backups until this is addressed.
I’m not sure why it would be slower. If anything, now duplicacy shouldn’t have to wait for files with exclusive locks (though might not be able to backup such files without -vss).
Reference: backup command details, -vss
It looks like adding the .local suffix should fix it, but I haven’t upgraded to Catalina so can’t really test the fix. Can anyone check if this fix works?
There is also the problem of how to detect the macOS version in order to decide whether or not to add the .local suffix.
The “right” approach would be to query the system profiler or ioregistry, but you can also run sw_vers and parse output, or read kern.osversion from sysctl — the 19 followed by letter and build number is Catalina.
However I’m wondering if there is better way to do the right thing without changing behavior based on version
However I’m wondering if there is better way to do the right thing without changing behavior based on version
I imagine one way of doing it would be to run
$ tmutil listlocalsnapshots /
Snapshots for volume group containing disk /:
com.apple.TimeMachine.2019-10-14-180021.local
and grep for the date we want (although I have no idea how portable that would be).
@gchen I can definitely test, and implement a version check using one of the methods suggested by saspus or timnn.
Do you have a preference?
I created a PR that uses tmutil listlocalsnapshots: Bugfix: allow -vss usage on Mac OS Catalina by gboudreau · Pull Request #578 · gilbertchen/duplicacy · GitHub
Can easily be changed to another technique to detect the correct snapshot name to use.
I think there is a bigger issue here.
Right now Duplicacy is for some reason asking Time Machine to create snapshots for it. Format and naming of these snapshots are Time Machine implementation details. Duplicacy shall not rely on that. Instead, it shall create snapshots using filesystem API directly – see man fs_snapshot_create
If I remember correctly, the issue with using fs_snapshot_create directly is that it requires a special entitlement from Apple. This can be requested from Apple, but it also requires additional review.
Excellent point. @gchen should reach out to Apple. From what I understand from quick googling it seems the entitlement is being granted to backup applications that can demonstrate that they won’t clog up the drive with snapshots over time. Duplicacy creates a snapshot for a duration of a backup and should delete it afterwards – in this case it should be easy to get an approval; (Weren’t Carbon copy cloner and super duper granted one?)
It looks like this has recurred again, with the recent MacOS Update (10.15.4) 
I finally updated to Catalina some weeks ago and all was fine with Duplicacy (duplicacy-web 1.2.1 + duplicacy_osx_x64_2.4.1), including the -VSS. A MacOS update came through the other day (27-Mar) and my -VSS backups have been failing ever since.
Brian
Works for me.
me@obsidian ~ % duplicacy backup -vss
Running script /Users/alex/.duplicacy/scripts/pre-backup
Storage set to sftp://me@redacted//Backups/duplicacy
Last backup at revision 1676 found
Shadow copy created and mounted at /tmp/snp_043824422
...
Backup for /Users/me at revision 1677 completed
4 files were not included due to access errors
Shadow copy unmounted and deleted at /tmp/snp_043824422
What errors are you seeing? Anything in the console?
The log when it was failing (one of many - it was like this for some days):
Running backup command from /Users/brian/.duplicacy-web/repositories/localhost/11 to back up /Users
Options: [-log backup -storage MacBook-Duplicacy-4T -vss -vss-timeout 200 -stats]
2020-04-03 00:30:01.080 INFO REPOSITORY_SET Repository set to /Users
2020-04-03 00:30:01.081 INFO STORAGE_SET Storage set to /Volumes/Duplicacy-4TB/Duplicacy
2020-04-03 00:30:02.045 INFO BACKUP_START Last backup at revision 138 found
2020-04-03 00:30:02.612 ERROR VSS_CREATE Error while mounting snapshot: exit status 77
Error while mounting snapshot: exit status 77
After I removed the VSS option:
Running backup command from /Users/brian/.duplicacy-web/repositories/localhost/11 to back up /Users
Options: [-log backup -storage MacBook-Duplicacy-4T -stats]
2020-04-03 00:30:56.681 INFO REPOSITORY_SET Repository set to /Users
2020-04-03 00:30:56.681 INFO STORAGE_SET Storage set to /Volumes/Duplicacy-4TB/Duplicacy
2020-04-03 00:30:57.053 INFO BACKUP_START Last backup at revision 138 found
2020-04-03 00:30:57.053 INFO BACKUP_INDEXING Indexing /Users
2020-04-03 00:30:57.053 INFO SNAPSHOT_FILTER Parsing filter file /Users/brian/.duplicacy-web/repositories/localhost/11/.duplicacy/filters
2020-04-03 00:30:57.054 INFO SNAPSHOT_FILTER Loaded 43 include/exclude pattern(s)
… and so on
A couple of points:
-vss-timeout option set and that you’re running directly from the command line (I’m using the web edition). I’ll try both those tomorrow morning when I’m more awake.I’ve just tried with duplciacy-web, same story, works fine.
Duplicacy simply calls mount on a snapshot it just created; I’m not sure what does error code 77 mean
// Mount snapshot as readonly and hide from GUI i.e. Finder
_, err = CommandWithTimeout(timeoutInSeconds,
"/sbin/mount", "-t", "apfs", "-o", "nobrowse,-r,-s="+snapshotName, "/", snapshotPath)
if err != nil {
LOG_ERROR("VSS_CREATE", "Error while mounting snapshot: %v", err)
return top
}
Check the following:
tmutil snapshot. Does it succeed? It would return timestamp for the snapshot.tmutil listlocalsnapshots /. Do you see your snapshot from above there?mkdir /tmp/test
mount -t apfs -o "nobrowse,-r,-s=com.apple.TimeMachine.2020-04-03-201431.local" / /tmp/test. Substitute correct date from above. Does it succeed or you get the same error 77?umount /tmp/test
tmutil deletelocalsnapshots 2020-04-03-215916 – put whatever date tmutil snapshot returned above command returned.Where does it fail?
As a prophylactic I would boot into recovery partition and run first aid on a partition, then on a APFS container and then on a volume. If still fails – I would nuke all local time machine snapshots and try again.
Thanks for such a comprehensive and useful reply. It sent me down a very informative path.
I haven’t solved the issue, but I have a lot more information.
For ease of reading, I’ll summarise what I’ve found here and explain how I got there below that:
mount attempt is to /private/tmp/snp_nnnnnnn, whereas when run from the command line, the mount occurs on /tmp/snp_nnnnnnn.What I did to come to those conclusions:
I started out following your suggestions.
deletelocalsnapshots /” thing. This removed all but one of the snapshots and allowed me to remove the final one separately.None of that changed things. It still failed with Error 77. Not only that, but, when it fails, it leaves behind the directory of the form /tmp/snp_nnnnnnn in which it fails to mount the snapshot.
Then I tried running from the command line. I did this initially because I wanted to see whether the previous version of Duplicacy, duplicacy_osx_x64_2.4.0 would fail. It didn’t.
Nor did the current version, duplicacy_osx_x64_2.4.1, either. Both ran with -vss as arguments and did the right thing.
So I went back and verified: the Web Edition still fails, on exactly the same backup.
At this point I started digging in the MacOS Console Log (which seems to be more comprehensive than the syslog), re-running Duplicacy with -verbose and even -debug and then comparing the timestamped records in the Console Log with those in the Duplicacy output.
What I observed was:
In a successful run, the (significant) Console log entries look like this:
default 14:16:27.604863+1000 kernel fs_insert_snapshot_metadata:254: snap_name='com.apple.TimeMachine.2020-04-05-141627.local' snap_xid 8057969 extentref oid 917407 sblock oid 915526
default 14:16:27.670779+1000 kernel handle_snapshot_mount:490: mounting snapshot w/snap_xid 8057966 and sblock oid 0xde67a
default 14:16:27.670804+1000 kernel handle_mount:329: vol-uuid: 023BA78F-896D-465B-93FC-174A1E95FE94 block size: 4096 block count: 122086923 (unencrypted; flags: 0x1; features: 1.0.12)
default 14:16:27.671188+1000 kernel apfs_vfsop_mount:1489: mounted volume: Macintosh HD
whereas in a failing one, they look like:
default 14:43:31.180979+1000 kernel fs_insert_snapshot_metadata:254: snap_name='com.apple.TimeMachine.2020-04-05-144331.local' snap_xid 8059163 extentref oid 911201 sblock oid 1115909
error 14:43:31.304968+1000 kernel Sandbox: mount_apfs(6531) System Policy: deny(1) fs-snapshot-mount /private/tmp/snp_021295157
default 14:43:31.304981+1000 kernel apfs_vfsop_mount:1406: handle_*_mount failed, err: 1
default 14:43:31.304985+1000 kernel apfs_vfsop_mount:1460: apfs_vfsop_mount failed, err: 1
Sometimes, but not every time, the failing one also tries to create a snapshot on volume /Volumes/Recovery, but that fails with the message error: Error Domain=NSPOSIXErrorDomain Code=45 "Operation not supported". I don’t know whether that’s significant or not.
Similarly, there is a lot of snapshot cleaning up and filecoordinationd does a lot of arbitration, but I think that’s all just secondary to snapshot creation.
What may be more significant is that the Duplicacy output of the successful runs shows that the snapshot is mounted in /tmp/snp_nnnnnnn, where the Console log of the failures shows an attempt to mount in /private/tmp/snp_nnnnnnn.
/tmp is symlinked to /private/tmp) it’s possible that something at a deeper level treats them separately.I also observed that the VSS Snapshot is actually created (it’s still there afterwards). The error occurs when Duplicacy attempts to mount the snapshot in the temporary directory.
The report of Sandbox and System Policy being invoked sent me looking at extended attributes and into the Sandbox directory (/System/Library/Sandbox). While I don’t pretend to understand the semantics of the *.sb files, what I did observe was that:
Profiles sub-directory (such as system.sb and application.sb) were updated in that directory on 27th March at 9:50am.2020-03-27 09:15 (that particular schedule runs hourly).I can supply logs if you’d like to look deeper.
Brian
Fascinating!
First – it just occurred to me that the fact that it works for me is another indirect confirmation of what you suspect: that it may indeed have to do with permissions/policies/security/sandboxing: I have both secure boot and SIP disabled… since forever, and I completely forgot about that.
So, this is our culprit:
Sandbox: mount_apfs(6531) System Policy: deny(1) fs-snapshot-mount /private/tmp/snp_021295157
I diffed the whole Profiles folder with what I had on another Mac with 10.15.1 and did not see any relevant changes at a first glance.
I have a few ideas to try (will try in the evening)
the duplicacy_web is signed, while the duplicacy CLI is not signed at all. I’m not sure, but maybe it inherits restrictions of a parent process when launched as such:
me@obsidian ~ % codesign --verify --verbose ~/.duplicacy-web/bin/duplicacy_osx_x64_2.4.1
/Users/me/.duplicacy-web/bin/duplicacy_osx_x64_2.4.1: code object is not signed at all
In architecture: x86_64
me@obsidian ~ % codesign --verify --verbose /Applications/Duplicacy\ Web\ Edition.app/
/Applications/Duplicacy Web Edition.app/: valid on disk
/Applications/Duplicacy Web Edition.app/: satisfies its Designated Requirement
Wondering what will happen if we sign the Duplicacy command line with default entitlements – will it start failing? (I can try that tomorrow only – I cannot turn back security on my Mac to test this, I’ll need to find another one or configure VM). If that is the case gchen will need to adjust entitlements.
Assuming the issue is with restrictions on access to filesystem snapshots (and it is indeed quite sensitive from security perspective access): Will the behavior change if you add Duplicacy Web to System Preferences -> Security and Privacy -> Full Disk Access?
In case the issue with the mount point (as opposed to access to the snaphot in the first place – Instead of using /private/tmp/ or /tmp why not do it right and use mktemp to generate temp file path (it will end up in /var/folders/ and should be fully accessible`). (If I find a place to run macOS with full security on I’ll try that later – or you can try that. But I suspect the item 2 above should help)
Brilliant!! That fixed it 
A simple change to the Doco, or, in the longer term, a change to the installer to prompt the Preferences change (if that is possible).
What’s the process to initiate those?
That’s the problem with “temporarily” lifting security constraints - we forget that we’ve done it 
.
Thanks again!
Brian
Awesome!
Summoning @gchen for that
Yea… except in my case the lift was intentionally permanent (I mess with .kexts a lot) and its not that I forgot to revert it back – I forgot that my config is special in any way… I’t my “normal”. It’s like herd immunity – if majority of users keep it enabled malware can’t spread so those like me who have to have it disabled are also protected 
I’m having this same issue but with CLI 2.5.0 on macOS Catalina 10.15.4. I’m able to do backups fine without VSS but when I use it I similarly get an Error 77. I also get the same information in the logs that @pdp8user is seeing.
Is there something I can do I my end to get it working?
Some additional information:
When I first launched the application I received a message saying that the application can’t be opened because Apple cannot check it for malicious software. This software needs to be updated. Contact the developer for more information. I was able to open it after going to the Security control panel and clicking allow after reading that the app was blocked because “it is not from an identified developer”.
When I run the codesign command, I get a “valid on disk” and “satisfies it’s Designated Requirement” message.
I have both the Web Edition and the CLI version on my Mac.
Did you read this topic? This specifically:
I did do that but with the CLI 2.5.0 executable:
I confirmed that SIP is turned on and secure boot is enabled to allow full security.
I was also able to make and list Time Machine snapshots by doing the following:
This is the command I’m running and output I’m seeing:
White:Test2 indoracer$ duplicacy -log backup -vss
2020-04-12 03:21:58.478 INFO STORAGE_SET Storage set to gcd://Backups/Duplicacy
2020-04-12 03:22:06.323 INFO BACKUP_START Last backup at revision 1 found
2020-04-12 03:22:06.912 ERROR VSS_CREATE Error while mounting snapshot: exit status 77
Try it with giving full disk access to the Web Edition:
You may have to do it with both the Web & CLI editions.
I’m certainly running with SIP turned on. Mine was working on the CLI without setting Full Disk Access for it, but that was before the update to 2.5.0 . It will be interesting to see whether I have to add that when the update comes through. The Web edition normally updates itself automatically, so I’ll keep a close eye on things.
