Are there any known problems with ZFS ?

I have three different MacOS machines of various ages all with home folders on “Send Only” and a FreeBSD 12.2 machine with a syncthing dataset and three corresponding folders set to “Receive Only” and “Ignore Permissions”. I also have “Watch for Changes” unchecked everywhere and a rescan interval of a few hours because I want regular backups not frantic resource wastage with constant I/O which syncthing seems good at.

Everything is on v1.18.1 with the FreeBSD one installed from ports. The only oddity is that I only run the FreeBSD sever every few days and yes it is always shut down gracefully.

Despite various experiments including removing the database (the index-v0.14.0.db directory) obviously not under the thing’s feet, using -reset-database. I reliably get tens of thousands of apparently locally modified files. If I press Revert they turn into Out of Sync files then during “Pepare for Sync” they reduce themselves down to near zero at an I/O limiting rate. Then fewer local modifications may be dreamt up after sync.

If I inspect the list of supposedly modified files there are plenty I am absolutely confident have not changed in ten years. There is nothing demanding (such as characters that may not be availble in some filesystems) in the filenames.

I also have simple file versioning on and am seeing if things behave better without it on one of the three since I can rely on ZFS snapshots to retrieve old versions.

The synching/transfer phase itself seems to work efficiently enough.

Any ideas what may have gone catastrophically wrong, known issues with ZFS or how to debug it ?

Thank you,

Jon

I run a few macOS boxes myself, with a storage server on FreeBSD 12.2 with ZFS, roughly the same setup as you in fact. I’m not seeing any issues and it’s been running like this for quite a few years. Though I’m using our FreeBSD binaries rather than the port, not that I think it should make much of a difference… So yeah, no good ideas about what you’re seeing unfortunately.

I’ve focussed on one particular file that is “changed” and searched the log for it. It’s a photo obviously taken some years back and backed up using Samsung’s SmartSwitch software. But I do not understand what the log is telling me. Can you have a look please.

Is this enough debug ?

[TROML] 2021/09/21 15:46:24.815481 walkfs.go:84: DEBUG: walk: path=Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg
[TROML] 2021/09/21 15:46:24.815527 set.go:254: DEBUG: mfniu-t64dk Get(Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg)
[TROML] 2021/09/21 15:46:24.815674 walk.go:402: DEBUG: walker/mfniu-t64dk@0xc0001a1540 rescan: File{Name:"Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg", Sequence:280479, Permissions:0644, ModTime:2021-03-15 13:07:14 +0000 GMT, Version:{[{MVMLQFC 1615813946}]}, VersionHash:, Length:3006754, Deleted:false, Invalid:false, LocalFlags:0x0, NoPermissions:false, BlockSize:131072, Blocks:[Block{0/131072/2115929828/65ad1fbc1bc19899f9d3e7a2c16b4f09fb2e5d0f090ab8a5f6afd1983f4d53b0} Block{131072/131072/1033398823/d63f7fb9c5735d6c654448693cbf779f88105851c3acdbb0dff7f5aac6dfb4b7} Block{262144/131072/3158092449/f7aa6c09be7feb0aaa7f66f12b2c98a3a41881bf272f87917a55a445699f8d07} Block{393216/131072/3320693630/ba931ee4ce5e33f55fe810779991e7c27aba3de8814ad3b5c77838e224194775} Block{524288/131072/686964201/44445ca13c602783dcf1f3636cc8ef25c0b5af999b923e4ae002d6b76769da08} Block{655360/131072/1637471061/fd314aac59cd9d37faff2d3a42e68b4571ad3f75d53d560ec75a6a5e9b361dd4} Block{786432/131072/2486000142/315f1b204caaf8141dbbc6da7c5aa79b4e367fcfaf4b2b124b50e1848e0ca444} Block{917504/131072/2067219156/adc463a0cc352736a6a3d7a698da062579d212fcbe780244d525a30775c7ee9c} Block{1048576/131072/1119780218/5bab8d15157dfa68b5e26d606ba75fed101c9e02fa243a7f64001c90b304fd2f} Block{1179648/131072/2453296733/de88f47cabd2ee484c58ebce89cdc7575cc799cfd58dac37397e035bbfbaa4e0} Block{1310720/131072/3794434983/95b677cc430bc6525cad768038b46322eb4b062fe5debd4c7c0f3bee185160aa} Block{1441792/131072/169482838/6070d53794b0b8717743d2f4c1ae1406be867545094969600cd6368ce7296aa3} Block{1572864/131072/2011672782/d465d9774a154532ddcc8987dabeb7531087bd255bf0da62d3aa20d07a937232} Block{1703936/131072/1808597933/c4ab050871f9853f70fef2ce20f5c68828e84cc59cd557e2c3273d0e803235e8} Block{1835008/131072/2409618092/8b44ac7ab0785c63f72e71bb023880c3717ec163eaf6112f7036c396cb7dafac} Block{1966080/131072/618123602/28b1348d47fb4b6b8c0cb7fb76288e16fd0f55798b91b4227eff7b42d23f54a7} Block{2097152/131072/2452103538/49f12f3e529afa32847d312a5f563faf475be649a40cf89e807b7f7f6c064d64} Block{2228224/131072/3061757876/e053524dca98ffc3ba02afc6a7a5b9ebaaeff461bdee0c6191af7c5f69478a29} Block{2359296/131072/2967152474/eb2c655c80797bb57871af6bc9505e05d0e2ab1f1fc22336f77ec4b86a7447c6} Block{2490368/131072/3799665560/a46b237c4ff21da0a784eb2039040c10fc4ee968bf286043117530d1de4a36d6} Block{2621440/131072/3650524807/688c0c17e98928ba06322bbb1033cad16513d2256c0e1b206003643d652dc65d} Block{2752512/131072/1091107116/e0d636783c33853f4a993bdb911b2854da57636b4e7844023fc3e6ff65777cce} Block{2883584/123170/3365077896/8f385e07981305edf8386de4049748ffedf3f92265d3921d9593a3020a9d7b44}], BlocksHash:87f3bbed4859a07dfbb62cc281847f0ea88b3f4b85fb2dd10d2b21344d3e033d} 1514398633 -rw-r--r--
[TROML] 2021/09/21 15:46:24.815731 walk.go:405: DEBUG: walker/mfniu-t64dk@0xc0001a1540 to hash: Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg File{Name:"Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg", Sequence:0, Permissions:0644, ModTime:2017-12-27 18:17:13 +0000 GMT, Version:{[{MVMLQFC 1615813946} {TROML5F 1632235584}]}, VersionHash:, Length:3006754, Deleted:false, Invalid:false, LocalFlags:0x8, NoPermissions:true, BlockSize:131072, Blocks:[], BlocksHash:}
[TROML] 2021/09/21 15:47:52.585468 walk.go:187: DEBUG: walker/mfniu-t64dk@0xc0001a1540 real to hash: Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg
[TROML] 2021/09/21 15:47:52.681360 logfs.go:79: DEBUG: blockqueue.go:20 basic /pool/syncthing/mum-imac-home Open Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg {{0xc00c7b9d68 Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg} 0xc000231920} <nil>
[TROML] 2021/09/21 15:47:52.768927 set.go:267: DEBUG: mfniu-t64dk GetGlobal(Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg)
[TROML] 2021/09/21 15:48:13.009164 lowlevel.go:256: DEBUG: removing sequence; folder="mfniu-t64dk" sequence=280479 Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg
[TROML] 2021/09/21 15:48:13.009225 lowlevel.go:266: DEBUG: insert (local); folder="mfniu-t64dk" File{Name:"Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg", Sequence:345778, Permissions:0644, ModTime:2017-12-27 18:17:13 +0000 GMT, Version:{[{MVMLQFC 1615813946} {TROML5F 1632235584}]}, VersionHash:, Length:3006754, Deleted:false, Invalid:false, LocalFlags:0x8, NoPermissions:true, BlockSize:131072, Blocks:[Block{0/131072/2115929828/65ad1fbc1bc19899f9d3e7a2c16b4f09fb2e5d0f090ab8a5f6afd1983f4d53b0} Block{131072/131072/1033398823/d63f7fb9c5735d6c654448693cbf779f88105851c3acdbb0dff7f5aac6dfb4b7} Block{262144/131072/3158092449/f7aa6c09be7feb0aaa7f66f12b2c98a3a41881bf272f87917a55a445699f8d07} Block{393216/131072/3320693630/ba931ee4ce5e33f55fe810779991e7c27aba3de8814ad3b5c77838e224194775} Block{524288/131072/686964201/44445ca13c602783dcf1f3636cc8ef25c0b5af999b923e4ae002d6b76769da08} Block{655360/131072/1637471061/fd314aac59cd9d37faff2d3a42e68b4571ad3f75d53d560ec75a6a5e9b361dd4} Block{786432/131072/2486000142/315f1b204caaf8141dbbc6da7c5aa79b4e367fcfaf4b2b124b50e1848e0ca444} Block{917504/131072/2067219156/adc463a0cc352736a6a3d7a698da062579d212fcbe780244d525a30775c7ee9c} Block{1048576/131072/1119780218/5bab8d15157dfa68b5e26d606ba75fed101c9e02fa243a7f64001c90b304fd2f} Block{1179648/131072/2453296733/de88f47cabd2ee484c58ebce89cdc7575cc799cfd58dac37397e035bbfbaa4e0} Block{1310720/131072/3794434983/95b677cc430bc6525cad768038b46322eb4b062fe5debd4c7c0f3bee185160aa} Block{1441792/131072/169482838/6070d53794b0b8717743d2f4c1ae1406be867545094969600cd6368ce7296aa3} Block{1572864/131072/2011672782/d465d9774a154532ddcc8987dabeb7531087bd255bf0da62d3aa20d07a937232} Block{1703936/131072/1808597933/c4ab050871f9853f70fef2ce20f5c68828e84cc59cd557e2c3273d0e803235e8} Block{1835008/131072/2409618092/8b44ac7ab0785c63f72e71bb023880c3717ec163eaf6112f7036c396cb7dafac} Block{1966080/131072/618123602/28b1348d47fb4b6b8c0cb7fb76288e16fd0f55798b91b4227eff7b42d23f54a7} Block{2097152/131072/2452103538/49f12f3e529afa32847d312a5f563faf475be649a40cf89e807b7f7f6c064d64} Block{2228224/131072/3061757876/e053524dca98ffc3ba02afc6a7a5b9ebaaeff461bdee0c6191af7c5f69478a29} Block{2359296/131072/2967152474/eb2c655c80797bb57871af6bc9505e05d0e2ab1f1fc22336f77ec4b86a7447c6} Block{2490368/131072/3799665560/a46b237c4ff21da0a784eb2039040c10fc4ee968bf286043117530d1de4a36d6} Block{2621440/131072/3650524807/688c0c17e98928ba06322bbb1033cad16513d2256c0e1b206003643d652dc65d} Block{2752512/131072/1091107116/e0d636783c33853f4a993bdb911b2854da57636b4e7844023fc3e6ff65777cce} Block{2883584/123170/3365077896/8f385e07981305edf8386de4049748ffedf3f92265d3921d9593a3020a9d7b44}], BlocksHash:87f3bbed4859a07dfbb62cc281847f0ea88b3f4b85fb2dd10d2b21344d3e033d}
[TROML] 2021/09/21 15:48:13.009270 transactions.go:635: DEBUG: update global; folder="mfniu-t64dk" device=7777777-777777N-7777777-777777N-7777777-777777N-7777777-77777Q4 file="Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg" version={[{MVMLQFC 1615813946} {TROML5F 1632235584}]} invalid=true
[TROML] 2021/09/21 15:48:13.009304 transactions.go:649: DEBUG: new global for "Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg" after update: {{Version:{[{MVMLQFC 1615813946} {TROML5F 1632235584}]}, Deleted:false, Devices:{}, Invalid:{7777777}}, {Version:{[{MVMLQFC 1615813946}]}, Deleted:false, Devices:{MVMLQFC}, Invalid:{}}}
[TROML] 2021/09/21 15:48:13.009316 lowlevel.go:287: DEBUG: adding sequence; folder="mfniu-t64dk" sequence=345778 Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg
[TROML] 2021/09/21 15:51:46.084088 logfs.go:61: DEBUG: osutil.go:134 basic /pool/syncthing/mum-imac-home Lstat Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg {0xc01475e6c0} <nil>

[TROML] 2021/09/21 15:46:24.815674 ...
 rescan: File{Name:"Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg",
 Sequence:280479, Permissions:0644, ModTime:2021-03-15 13:07:14 +0000 GMT, 

It rescans a file because a change is detected. The “old” version, which is announced by the other side and which supposedly should have been the file on disk, is the thing it talks about here after rescan:. Modification time is from march.

[TROML] 2021/09/21 15:46:24.815731 ...
 to hash: ... 
 File{Name:"Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg",
 Sequence:0, Permissions:0644, ModTime:2017-12-27 18:17:13 +0000 GMT, 

That’s the metadata of the file as it exists on disk today. Note that the modification time on disk is quite different from what we thought it should be. This is the change that caused the scan, and then the “locally modified” warning.

Let’s have a look at that file. It was modified in 2017. Now I can see more “Locally Changed” files with 2012 in their names.

root@hewlett:/pool/syncthing/mum-imac-home/Samsung/SmartSwitch/Backup # stat -x /pool/syncthing/mum-imac-home/Samsung/SmartSwitch/Backup/SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg
  File: "SM-G950F_20210315125618/Photo/_EXTERNAL_/DCIM/Camera/20161214_201624.jpg"
  Size: 3006754      FileType: Regular File
  Mode: (0644/-rw-r--r--)         Uid: ( 2000/syncthing)  Gid: ( 2000/syncthing)
Device: 1026736422,18446744072312782897   Inode: 176052    Links: 2
Access: Wed Dec 27 18:17:13 2017
Modify: Wed Dec 27 18:17:13 2017
Change: Tue Sep 21 13:51:05 2021

So if this is what normally goes wrong I need to try to work out where these odd dates come from.

There’s another hard link to that file? That’s interesting, and could cause confusion. Changing the modtime of the one will alter the other as well, so if they are both seen by Syncthing and map to different files on the other side …

Ah. Because of earlier problems of endless extra copies of things (in .stversions) I did a couple of things.

  1. I ran a file de-deduplicator to hard link duplicates. I see how that could cause problems and will now get rid of (remove or unlink somehow) such files.

  2. I have since activated dedup which makes a lot of sense since many files exist on two of the remote machines.

Is there an ignore-timestamps option so I can avoid doing this ? For example where I have emailed a file the de-duplicator has spotted this and linked the extra copies though activating dedup instead might have been a better idea.

Mystery solved…

There’s no option to ignore modtimes. There is however a modtime window setting, which is generally used to get an allowed drift of up to 2s to compensate for FAT not having more precision in time stamps. It’s an int32. You could in principle set this to for example 788400000s to allow 25 years of timestamp drift. It’s not precisely a scenario we test for, though.

My problem is not explained by hard links since they number a fraction of the “Locally Changed Items” that keep popping up. I shall endeavour to find an example with logging switched on.

May I ask if you have ever tried a whole MacOS home directory (with some exclusions like Trash, Cache, Caches) ?

Correction: I hadn’t done a pass since breaking the last hard links. Things are somewhat better now.

It would be nice if warnings were issued against multiply-linked files. Even nicer if modtimes could be ignored for them for those that want to use them to save space. I now have ZFS dedup doing its stuff. It works really well since the two remote machines have a lot of the same content such as emails and photos.

Thank you for spotting that my hard linking was the cause.

2 Likes