Since upgrading one of my Macs to Ventura 13.0, my folder will no longer sync (getting stuck on a piece of undocumented metadata called com.apple.provenance
I have tried removing the xattr with sudo xattr -d com.apple.provenance /path/to/file but that isn’t working either.
Google has nothing about this really… anyone else running into this? Using syncthing-macos 1.22.0-1
related posts: AskDifferent and syncthing-macos
@calmh not sure yet this is caused by the application bundle or the golang daemon. If there is no documentation then we have to wait till google or stackoverflows has a working solution.
What does that mean concretely? What do you see when “it gets stuck” - is that part of an error message, and if so: where is that error message displayed and what does it say in full?
What I mean by “it gets stuck” is that the folder never completes syncing, it just continues looping over the same set of files and says Out of Sync in the GUI.
I think what it’s trying to do is write the com.apple.provenance metadata to the macOS 12.6 computer which seems to not recognize it (think it was added in Ventura).
Here’s a little snippet from the log file:
Setxattr "com.apple.provenance": permission denied
2022-11-05 17:56:46 Puller (folder "Sync" (xxxxx-xxxxx), item "Development/wgfix/.git/objects/7a/05770eb8ce93f0358ffc52054fd4ae0a82e355"): syncing: shortcut file (setting xattrs): set xattrs /Users/luke/Sync/Development/wgfix/.git/objects/7a/05770eb8ce93f0358ffc52054fd4ae0a82e355: Setxattr "com.apple.provenance": permission denied
2022-11-05 17:56:46 Puller (folder "Sync" (xxxxx-xxxxx), item "Development/wgfix/.git/objects/80/22c63e3a07a7e8af11fdd17b8b027eb7934db0"): syncing: shortcut file (setting xattrs): set xattrs /Users/luke/Sync/Development/wgfix/.git/objects/80/22c63e3a07a7e8af11fdd17b8b027eb7934db0: Setxattr "com.apple.provenance": permission denied
2022-11-05 17:56:46 Puller (folder "Sync" (xxxxx-xxxxx), item "Development/wgfix/.git/objects/88/1c396f37a853b386178f02b1b959efb357c6f4"): syncing: shortcut file (setting xattrs): set xattrs /Users/luke/Sync/Development/wgfix/.git/objects/88/1c396f37a853b386178f02b1b959efb357c6f4: Setxattr "com.apple.provenance": permission denied
2022-11-05 17:56:46 "Sync" (xxxxx-xxxxx): Failed to sync 6 items
2022-11-05 17:56:46 Folder "Sync" (xxxxx-xxxxx) isn't making sync progress - retrying in 1m0s.
2022-11-05 17:56:55 Puller (folder "Sync" (xxxxx-xxxxx), item "Development/obsidian-plugin-downloader/.git/objects/d1/5fe2dd523e430d1063e670aad71d1ec85c8ea6"): syncing: shortcut file (setting xattrs): set xattrs /Users/luke/Sync/Development/obsidian-plugin-downloader/.git/objects/d1/5fe2dd523e430d1063e670aad71d1ec85c8ea6: Setxattr "com.apple.provenance": permission denied
2022-11-05 17:56:55 Puller (folder "Sync" (xxxxx-xxxxx), item "Development/obsidian-plugin-downloader/.git/objects/da/f4478ff5aa46f587566ae9bfcc409d67d5ff24"): syncing: shortcut file (setting xattrs): set xattrs /Users/luke/Sync/Development/obsidian-plugin-downloader/.git/objects/da/f4478ff5aa46f587566ae9bfcc409d67d5ff24: Setxattr "com.apple.provenance": permission denied
2022-11-05 17:56:55 Puller (folder "Sync" (xxxxx-xxxxx), item "Development/wgfix/.git/objects/7a/05770eb8ce93f0358ffc52054fd4ae0a82e355"): syncing: shortcut file (setting xattrs): set xattrs /Users/luke/Sync/Development/wgfix/.git/objects/7a/05770eb8ce93f0358ffc52054fd4ae0a82e355: Setxattr "com.apple.provenance": permission denied
2022-11-05 17:56:55 Puller (folder "Sync" (xxxxx-xxxxx), item "Development/wgfix/.git/objects/80/22c63e3a07a7e8af11fdd17b8b027eb7934db0"): syncing: shortcut file (setting xattrs): set xattrs /Users/luke/Sync/Development/wgfix/.git/objects/80/22c63e3a07a7e8af11fdd17b8b027eb7934db0: Setxattr "com.apple.provenance": permission denied
2022-11-05 17:56:55 Puller (folder "Sync" (xxxxx-xxxxx), item "Development/wgfix/.git/objects/88/1c396f37a853b386178f02b1b959efb357c6f4"): syncing: shortcut file (setting xattrs): set xattrs /Users/luke/Sync/Development/wgfix/.git/objects/88/1c396f37a853b386178f02b1b959efb357c6f4: Setxattr "com.apple.provenance": permission denied
2022-11-05 17:56:55 Puller (folder "Sync" (xxxxx-xxxxx), item "Development/obsidian-plugin-downloader/.git/objects/0d/abf678d9990da367c3f4c76c73347577675beb"): syncing: shortcut file (setting xattrs): set xattrs /Users/luke/Sync/Development/obsidian-plugin-downloader/.git/objects/0d/abf678d9990da367c3f4c76c73347577675beb: Setxattr "com.apple.provenance": permission denied
2022-11-05 17:56:55 "Sync" (xxxxx-xxxxx): Failed to sync 6 items
2022-11-05 17:56:55 Folder "Sync" (xxxxx-xxxxx) isn't making sync progress - retrying in 1m0s.
So you have enabled syncing xattrs, right? So apparently the user syncthing is run as (yours on macos I think) doesn’t have permissions to sync those attributes.
Yes @imsodin I have enabled syncing xattr’s. It’s been working well (for other attributes). There’s something “special” about com.apple.provenance apparently. It would be nice if, at least as a workaround, this particular xattr could be ignored by Syncthing.
I think we are in the right direction, the new com.apple.provenance xattr should could be simply ignored. If this xattr is undocumented then don’t know what we are doing, but at least from a Syncthing perspective the files must sync and not fail.
A possible solution could be if syncthing detects this xattr in a sync between two macOS devices a (>=13.0) and b (<13.0). It gives a popup that the device is in a special mode and the user agrees this particular xattr is not synced and attached to the device. In addition to the xattr sync flags. But not sure how this works internaly.
You can ignore that attribute, you just can’t do it from the GUI config editor at the moment. Add entries to the xattr filter for that folder in the config.xml:
<folder id="..." ...>
<xattrFilter>
...
<entry match="com.apple.provenance" permit="false"/>
<entry match="*" permit="true"/>
</xattrFilter>
</folder>
Thanks to you all for resolving this I have reopened this to add to the documentation. See macOS Ventura 13.0 sync fails due to com.apple.provenance metadata · Issue #185 · syncthing/syncthing-macos · GitHub
Totally off topic, but every time I see people syncing git repos, I want to scream at them.
You’ll get it corrupted.
Thanks @calmh - didn’t know about this and that’s a great solution. I expect we’ll learn a little more about this mysterious attribute as time rolls on.
And thanks @AudriusButkevicius for the warning about syncing git repos. It’s not something I do with much intention, just happens to be that a few git repos are sitting in my larger “Sync” folder. I’ve never had any problems before, but I’ll look into adding these to my ignorelist and maybe automating some git pulls to keep them synced.
Just noting here that after editing the config.xml by hand and inserting that section, it seems that ST changes it slightly (adding </entry> closing tags). My config looks like this now:
<xattrFilter>
<entry match="com.apple.provenance" permit="false"></entry>
<entry match="*" permit="true"></entry>
<maxSingleEntrySize>0</maxSingleEntrySize>
<maxTotalSize>0</maxTotalSize>
</xattrFilter>
Problem is, I still can’t get the Sync to complete. It just keeps alternating between “Up to date”, “Preparing to Sync”, “Scanning (NN%)”, “Out of sync” and back again. The Out of sync items appear to be random, and range from 1 to a few hundred. My global state appears to match (# of items, size) on both Macs. I have also tried a full database reset on both sides using this method, and letting it re-sync overnight. No luck. I never had any sync issues before, and been using ST3 for years.
Here’s a screenshot
Looking at logs and in the gui, why are they out of sync and why doesn’t it sync?
There isn’t much in the logs, here’s a section:
2022-11-07 09:13:09 My ID: XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX
2022-11-07 09:13:10 Single thread SHA256 performance is 978 MB/s using minio/sha256-simd (977 MB/s using crypto/sha256).
2022-11-07 09:13:11 Hashing performance is 405.34 MB/s
2022-11-07 09:13:11 Overall send rate is unlimited, receive rate is unlimited
2022-11-07 09:13:11 Using discovery mechanism: global discovery server https://discovery.syncthing.net/v2/?noannounce&id=XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX
2022-11-07 09:13:11 Using discovery mechanism: global discovery server https://discovery-v4.syncthing.net/v2/?nolookup&id=XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX
2022-11-07 09:13:11 Using discovery mechanism: global discovery server https://discovery-v6.syncthing.net/v2/?nolookup&id=XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX
2022-11-07 09:13:11 Using discovery mechanism: IPv4 local broadcast discovery on port 21027
2022-11-07 09:13:11 Using discovery mechanism: IPv6 local multicast discovery on address [ff12::8384]:21027
2022-11-07 09:13:11 TCP listener ([::]:22000) starting
2022-11-07 09:13:11 ...
2022-11-07 09:13:11 Relay listener (dynamic+https://relays.syncthing.net/endpoint) starting
2022-11-07 09:13:11 QUIC listener ([::]:22000) starting
2022-11-07 09:13:11 GUI and API listening on 127.0.0.1:8384
2022-11-07 09:13:11 Access the GUI via the following URL: http://127.0.0.1:8384/
2022-11-07 09:13:11 My name is "mini.ldh.me"
2022-11-07 09:13:11 Device XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX is "air" at [dynamic]
2022-11-07 09:13:11 Ready to synchronize "Sync" (XXXXX-XXXXX) (sendreceive)
2022-11-07 09:13:20 quic://0.0.0.0:22000 detected NAT type: Symmetric NAT
2022-11-07 09:13:21 Detected 0 NAT services
2022-11-07 09:13:26 Established secure connection to XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX at 192.168.20.40:22000-192.168.20.42:22000/tcp-server/TLS1.3-TLS_AES_128_GCM_SHA256
2022-11-07 09:13:26 Device XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX client is "syncthing v1.22.1" named "air" at 192.168.20.40:22000-192.168.20.42:22000/tcp-server/TLS1.3-TLS_AES_128_GCM_SHA256
2022-11-07 09:13:26 Connection from XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX-XXXXXXX at [2600:4041:xxxx:590]:22000 (tcp-server) rejected: already connected to this device
2022-11-07 09:13:58 Joined relay relay://204.144.201.226:22067
2022-11-07 09:14:31 Completed initial scan of sendreceive folder "Sync" (XXXXX-XXXXX)
2022-11-07 09:14:53 Folder "Sync" (XXXXX-XXXXX) isn't making sync progress - retrying in 1m22s.
The only interesting bit I see there is isn't making sync progress - retrying in 1m22s. — Do I need to enable some of the Debugging Facilities options?
I changed the xattrFilter in my config slightly, since I figured there were a few other attributes that I did not want or care about syncing, and that might be causing problems. Here’s what I’ve got now:
<xattrFilter>
<entry match="com.apple.provenance" permit="false"></entry>
<entry match="com.apple.quarantine" permit="false"></entry>
<entry match="com.apple.macl" permit="false"></entry>
<entry match="com.apple.lastuseddate#PS" permit="false"></entry>
<entry match="*" permit="true"></entry>
<maxSingleEntrySize>0</maxSingleEntrySize>
<maxTotalSize>0</maxTotalSize>
</xattrFilter>
Still no luck getting the Sync loop to quiesce. I was having trouble following the log stream since the macOS bundle doesn’t make running with custom CLI options easy. I created this small helper script that streams from the REST API.
When running this, I note now that the same set of 40-50 folders keep detecting “changes”. When I inspect these, the modification dates are not recent at all, they are months or years old, so not sure what’s causing this detection. I think I need some extra debug logging…
@calmh Any other logs or debug options I can check to help get to the root of this?
Enable tracing for scanner and see what it says. A couple of passes that shows a given file changing repeatedly should be useful.
Thanks @calmh
The logs were huge and rotating out too quickly so I had to first figure out how to add --log-max-size=52428800 args to the syncthing process using the macOS bundle (solution here btw)
After doing this and enabling the scanner debugging, I can see the following lines repeating for those out of sync dirs:
[27XXY] 2022/11/08 08:06:17.929607 walk.go:447: DEBUG: walker/9buzz-pod9e@0xc00077f760 checking: Directory{Name:"Settings/Alfred/Alfred.alfredpreferences/workflows/user.workflow.5E30867B-CE27-40A7-AEC6-19A351E530C2", Sequence:0, Permissions:0755, ModTime:2022-10-14 21:56:39.016903472 -0400 EDT, Version:{[{27XXY22 1667912777} {67NVZZX 1667912757}]}, VersionHash:, Deleted:false, Invalid:false, LocalFlags:0x0, NoPermissions:false, Platform:{<nil> <nil> <nil> <nil> <nil>}, InodeChangeTime:1969-12-31 19:00:00 -0500 EST}
[27XXY] 2022/11/08 08:06:17.929659 walk.go:469: DEBUG: walker/9buzz-pod9e@0xc00077f760 rescan: Directory{Name:"Settings/Alfred/Alfred.alfredpreferences/workflows/user.workflow.5E30867B-CE27-40A7-AEC6-19A351E530C2", Sequence:242422, Permissions:0755, ModTime:2022-02-17 20:36:13.978905006 -0500 EST, Version:{[{27XXY22 1667912777} {67NVZZX 1667912757}]}, VersionHash:, Deleted:false, Invalid:false, LocalFlags:0x0, NoPermissions:false, Platform:{<nil> <nil> <nil> xattrs:<name:"com.apple.metadata:kMDItemFinderComment" value:"bplist00_\020\026Workflow Object Finder\010\000\000\000\000\000\000\001\001\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000!" > <nil> <nil>}, InodeChangeTime:2022-11-08 08:05:58.918794184 -0500 EST}
[27XXY] 2022/11/08 08:06:17.929720 walk.go:472: DEBUG: walker/9buzz-pod9e@0xc00077f760 dir: Settings/Alfred/Alfred.alfredpreferences/workflows/user.workflow.5E30867B-CE27-40A7-AEC6-19A351E530C2 Directory{Name:"Settings/Alfred/Alfred.alfredpreferences/workflows/user.workflow.5E30867B-CE27-40A7-AEC6-19A351E530C2", Sequence:0, Permissions:0755, ModTime:2022-10-14 21:56:39.016903472 -0400 EDT, Version:{[{27XXY22 1667912777} {67NVZZX 1667912757}]}, VersionHash:, Deleted:false, Invalid:false, LocalFlags:0x0, NoPermissions:false, Platform:{<nil> <nil> <nil> <nil> <nil>}, InodeChangeTime:1969-12-31 19:00:00 -0500 EST}
I redacted the IDs a bit but if you want the full 100MB logfile I sent you the link privately.
I note the seemingly invalid time in InodeChangeTime:1969-12-31
That part is actually fine, but there’s another suspicious part to it. I’ll look into it.