Repository: syncthing/syncthing (language: go)

Issue:
Deduplicated files on Windows aren't treated as regular files any more (Go 1.21)
I do have multiple servers where Deduplication is enabled (NTFS). And since 1.24.0 files can't be pulled from those servers. In GUI and CLI the meassage "syncing: finishing: pull: no such file" is shown. 

It does work when i do starting V 1.23.7 on the server. (before it was finished syncing i switched back to 1.24.0 and it stopped working again)

It also does work when undedup the volume and using V1.24.0

EDIT: Indexer also affected


Discussion / hints:
Interesting. I think the main difference between the two is that we build 1.24.0 with Go 1.21 and the older one with Go 1.20. Full logs from the failure with STTRACE=model,fs might be enlightening.
is this sufficient?

```
[QP7B2] 2023/09/21 15:43:58.970866 logfs.go:61: DEBUG: traversessymlink.go:51 basic D:\SEC Lstat temp {0xc00efbd5e0} <nil>
[QP7B2] 2023/09/21 15:43:58.970866 model.go:1937: DEBUG: model@0xc000355040 REQ(in) failed stating file (<nil>): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile.csv" o=1835008 s=131072
[QP7B2] 2023/09/21 15:43:58.971379 model.go:1875: DEBUG: model@0xc000355040 REQ(in): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile.csv" o=2490368 s=131072 t=false
[QP7B2] 2023/09/21 15:43:58.971390 model.go:1875: DEBUG: model@0xc000355040 REQ(in): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile.csv" o=2883584 s=131072 t=false
[QP7B2] 2023/09/21 15:43:58.971390 logfs.go:61: DEBUG: model.go:1934 basic D:\SEC Lstat temp\somefile.csv {0xc00ee8d880} <nil>
[QP7B2] 2023/09/21 15:43:58.980749 model.go:1937: DEBUG: model@0xc000355040 REQ(in) failed stating file (<nil>): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile.csv" o=1703936 s=131072
[QP7B2] 2023/09/21 15:43:58.980749 logfs.go:61: DEBUG: model.go:1934 basic D:\SEC Lstat temp\somefile.csv {0xc00f22e540} <nil>
[QP7B2] 2023/09/21 15:43:58.980749 logfs.go:61: DEBUG: model.go:1934 basic D:\SEC Lstat temp\somefile.csv {0xc00f0d9e30} <nil>
[QP7B2] 2023/09/21 15:43:58.980749 logfs.go:61: DEBUG: model.go:1934 basic D:\SEC Lstat temp\somefile.csv {0xc00f22e460} <nil>
[QP7B2] 2023/09/21 15:43:58.981283 logfs.go:61: DEBUG: model.go:1934 basic D:\SEC Lstat temp\somefile.csv {0xc00f31c0e0} <nil>
[QP7B2] 2023/09/21 15:43:58.981283 model.go:1937: DEBUG: model@0xc000355040 REQ(in) failed stating file (<nil>): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile.csv" o=2228224 s=131072
[QP7B2] 2023/09/21 15:43:58.981283 logfs.go:61: DEBUG: traversessymlink.go:51 basic D:\SEC Lstat temp {0xc00f0d9f10} <nil>
[QP7B2] 2023/09/21 15:43:58.981283 logfs.go:61: DEBUG: model.go:1934 basic D:\SEC Lstat temp\somefile.csv {0xc00f0f2620} <nil>
[QP7B2] 2023/09/21 15:43:58.981283 logfs.go:61: DEBUG: traversessymlink.go:51 basic D:\SEC Lstat temp {0xc00f400f50} <nil>
[QP7B2] 2023/09/21 15:43:58.981283 logfs.go:61: DEBUG: model.go:1934 basic D:\SEC Lstat temp\somefile.csv {0xc00f400e00} <nil>
[QP7B2] 2023/09/21 15:43:58.981283 model.go:1937: DEBUG: model@0xc000355040 REQ(in) failed stating file (<nil>): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile.csv" o=2359296 s=131072
[QP7B2] 2023/09/21 15:43:58.981283 model.go:1875: DEBUG: model@0xc000355040 REQ(in): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile.csv" o=2621440 s=131072 t=false
[QP7B2] 2023/09/21 15:43:58.981283 model.go:1937: DEBUG: model@0xc000355040 REQ(in) failed stating file (<nil>): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile.csv" o=1441792 s=131072
[QP7B2] 2023/09/21 15:43:58.981283 logfs.go:61: DEBUG: model.go:1934 basic D:\SEC Lstat temp\somefile.csv {0xc00ef65340} <nil>
[QP7B2] 2023/09/21 15:43:58.981283 logfs.go:61: DEBUG: model.go:1934 basic D:\SEC Lstat temp\somefile.csv {0xc00f401030} <nil>
[QP7B2] 2023/09/21 15:43:58.981819 model.go:1937: DEBUG: model@0xc000355040 REQ(in) failed stating file (<nil>): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile.csv" o=2490368 s=131072
[QP7B2] 2023/09/21 15:43:58.981819 model.go:1937: DEBUG: model@0xc000355040 REQ(in) failed stating file (<nil>): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile.csv" o=1572864 s=131072
[QP7B2] 2023/09/21 15:43:58.981819 model.go:1937: DEBUG: model@0xc000355040 REQ(in) failed stating file (<nil>): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile.csv" o=1966080 s=131072
[QP7B2] 2023/09/21 15:43:58.981819 model.go:1937: DEBUG: model@0xc000355040 REQ(in) failed stating file (<nil>): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile.csv" o=2097152 s=131072
[QP7B2] 2023/09/21 15:43:58.982994 logfs.go:61: DEBUG: traversessymlink.go:51 basic D:\SEC Lstat temp {0xc00f2e0000} <nil>
[QP7B2] 2023/09/21 15:43:58.982994 model.go:1937: DEBUG: model@0xc000355040 REQ(in) failed stating file (<nil>): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile.csv" o=2883584 s=131072
[QP7B2] 2023/09/21 15:43:58.982994 logfs.go:61: DEBUG: model.go:1934 basic D:\SEC Lstat temp\somefile.csv {0xc00ef65490} <nil>
[QP7B2] 2023/09/21 15:43:58.982994 model.go:1937: DEBUG: model@0xc000355040 REQ(in) failed stating file (<nil>): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile.csv" o=2621440 s=131072
[QP7B2] 2023/09/21 15:43:59.109211 model.go:1875: DEBUG: model@0xc000355040 REQ(in): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile2.csv.csv" o=8126464 s=131072 t=false
[QP7B2] 2023/09/21 15:43:59.118763 logfs.go:61: DEBUG: traversessymlink.go:51 basic D:\SEC Lstat temp {0xc00ef656c0} <nil>
[QP7B2] 2023/09/21 15:43:59.118763 model.go:1875: DEBUG: model@0xc000355040 REQ(in): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile2.csv.csv" o=8388608 s=131072 t=false
[QP7B2] 2023/09/21 15:43:59.118763 model.go:1875: DEBUG: model@0xc000355040 REQ(in): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile2.csv.csv" o=8257536 s=131072 t=false
[QP7B2] 2023/09/21 15:43:59.118763 model.go:1875: DEBUG: model@0xc000355040 REQ(in): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile2.csv.csv" o=8781824 s=131072 t=false
[QP7B2] 2023/09/21 15:43:59.119306 logfs.go:61: DEBUG: traversessymlink.go:51 basic D:\SEC Lstat temp {0xc00f4011f0} <nil>
[QP7B2] 2023/09/21 15:43:59.119306 logfs.go:61: DEBUG: model.go:1934 basic D:\SEC Lstat temp\somefile2.csv.csv {0xc00ef657a0} <nil>
[QP7B2] 2023/09/21 15:43:59.119306 model.go:1937: DEBUG: model@0xc000355040 REQ(in) failed stating file (<nil>): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile2.csv.csv" o=8126464 s=131072
[QP7B2] 2023/09/21 15:43:59.119306 logfs.go:61: DEBUG: traversessymlink.go:51 basic D:\SEC Lstat temp {0xc00f2e00e0} <nil>
[QP7B2] 2023/09/21 15:43:59.119306 model.go:1875: DEBUG: model@0xc000355040 REQ(in): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile2.csv.csv" o=8519680 s=131072 t=false
[QP7B2] 2023/09/21 15:43:59.119306 model.go:1875: DEBUG: model@0xc000355040 REQ(in): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile2.csv.csv" o=8912896 s=131072 t=false
[QP7B2] 2023/09/21 15:43:59.119306 logfs.go:61: DEBUG: traversessymlink.go:51 basic D:\SEC Lstat temp {0xc00f137c00} <nil>
[QP7B2] 2023/09/21 15:43:59.119306 logfs.go:61: DEBUG: traversessymlink.go:51 basic D:\SEC Lstat temp {0xc00f401420} <nil>
[QP7B2] 2023/09/21 15:43:59.119815 model.go:1875: DEBUG: model@0xc000355040 REQ(in): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile2.csv.csv" o=8650752 s=131072 t=false
[QP7B2] 2023/09/21 15:43:59.119847 logfs.go:61: DEBUG: traversessymlink.go:51 basic D:\SEC Lstat temp {0xc00f0f29a0} <nil>
[QP7B2] 2023/09/21 15:43:59.119847 model.go:1875: DEBUG: model@0xc000355040 REQ(in): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile2.csv.csv" o=9175040 s=131072 t=false
[QP7B2] 2023/09/21 15:43:59.119847 logfs.go:61: DEBUG: traversessymlink.go:51 basic D:\SEC Lstat temp {0xc00efbd6c0} <nil>
[QP7B2] 2023/09/21 15:43:59.119847 model.go:1875: DEBUG: model@0xc000355040 REQ(in): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile2.csv.csv" o=9043968 s=131072 t=false
[QP7B2] 2023/09/21 15:43:59.119847 logfs.go:61: DEBUG: model.go:1934 basic D:\SEC Lstat temp\somefile2.csv.csv {0xc00ef658f0} <nil>
[QP7B2] 2023/09/21 15:43:59.119847 model.go:1937: DEBUG: model@0xc000355040 REQ(in) failed stating file (<nil>): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile2.csv.csv" o=8388608 s=131072
[QP7B2] 2023/09/21 15:43:59.119847 model.go:1875: DEBUG: model@0xc000355040 REQ(in): 4IXYROE-A4TLOX2-L46XRLN-AJ266NV-KWLJ3OR-UMLZ3UV-RFRPV4P-G4NWBA7: "cdkwq-5hfwx" / "temp\\somefile2.csv.csv" o=9306112 s=131072 t=false
```
Check before that log in model:

> 	if info, err := folderFs.Lstat(name); err != nil || !info.IsRegular() {

Given the error is nil, it apparently thinks this is not a regular file. You did not change anything regarding ntfs/deduplication in parallel with this upgrade, right?

I don't see anything directly related in go1.21 changelogs, but there seems to have been changes in `os` / `io/fs`, so maybe it's a regression.

Can you check that file for any special attributes/types/whatever one can see if one inspects it with standard windows tools please.  
(We should add the `LStat` result to the `/rest/debug/file` endpoint, would be handy for these cases.)
This commit might well be related, as it deals with reparse points and so does ntfs deduplication:

https://github.com/golang/go/commit/3e44b7d07a7b3c6233eb1bf4cf3cb00a0b85adec
https://learn.microsoft.com/en-us/windows-server/storage/data-deduplication/understand

The commit message talks about symlinks and them being rare, seems like they weren't aware of the connection to ntfs deduplication (not that surprising). Posted to golang-nuts: https://groups.google.com/g/golang-nuts/c/YtBDdIgxazY
No Special attributes but as far as I see for now, if the file is pulled before it is duplicated it is just working as expected.
I will try to set up a testing server later. Then I will be able to provide you the full log. (I truncated the file as ~1500 files were missing)
I mean if you can confirm that it works before dedupe, and not after, and that it worked with the previous version and not anymore now, then I think the case is pretty clear already together with the logs you already provided - thanks for that.
Okay i have to correct myself, indexer seems also to have no access to deduped files

Here the full log wiith a non deduped folder and a deduped folder:

```
2023/09/21 21:02:46.941480 filesystem_copy_range.go:26: DEBUG: Registering duplicate_extents copyRange method
2023/09/21 21:02:46.942010 filesystem_copy_range.go:26: DEBUG: Registering all copyRange method
2023/09/21 21:02:46.942010 filesystem_copy_range.go:26: DEBUG: Registering standard copyRange method
2023/09/21 21:02:46.943603 logfs.go:73: DEBUG: utils.go:27 basic D:\SyncThing2 MkdirAll . -rwx------ <nil>
2023/09/21 21:02:46.943603 logfs.go:115: DEBUG: utils.go:32 basic D:\SyncThing2 Stat . {0xc0002a3960} <nil>
2023/09/21 21:02:46.943603 logfs.go:31: DEBUG: utils.go:38 basic D:\SyncThing2 Chmod . -rwx------ <nil>
[start] 2023/09/21 21:02:46.943603 main.go:544: INFO: syncthing v1.24.0 "Fermium Flea" (go1.21.0 windows-amd64) builder@github.syncthing.net 2023-08-23 10:28:48 UTC
[SX4F4] 2023/09/21 21:02:47.218717 syncthing.go:154: INFO: My ID: SX4F4FC-5RVT46Q-QX67UGC-3XAS2NA-XIOY4ZO-XWUTV3W-NJX4AI3-MEUV4QD
[SX4F4] 2023/09/21 21:02:48.120585 sha256.go:88: INFO: Single thread SHA256 performance is 376 MB/s using crypto/sha256 (375 MB/s using minio/sha256-simd).
[SX4F4] 2023/09/21 21:02:48.584594 syncthing.go:186: INFO: Hashing performance is 322.58 MB/s
[SX4F4] 2023/09/21 21:02:48.584753 progressemitter.go:228: DEBUG: progress emitter: updated interval 5s
[SX4F4] 2023/09/21 21:02:48.584753 limiter.go:162: INFO: Overall send rate is unlimited, receive rate is unlimited
[SX4F4] 2023/09/21 21:02:48.584753 relay_listen.go:57: INFO: Relay listener (dynamic+https://relays.syncthing.net/endpoint) starting
[SX4F4] 2023/09/21 21:02:48.584753 manager.go:92: INFO: Using discovery mechanism: global discovery server https://discovery.syncthing.net/v2/?noannounce&id=LYXKCHX-VI3NYZR-ALCJBHF-WMZYSPK-QG6QJA3-MPFYMSO-U56GTUK-NA2MIAW
[SX4F4] 2023/09/21 21:02:48.584753 manager.go:92: INFO: Using discovery mechanism: global discovery server https://discovery-v4.syncthing.net/v2/?nolookup&id=LYXKCHX-VI3NYZR-ALCJBHF-WMZYSPK-QG6QJA3-MPFYMSO-U56GTUK-NA2MIAW
[SX4F4] 2023/09/21 21:02:48.584753 manager.go:92: INFO: Using discovery mechanism: global discovery server https://discovery-v6.syncthing.net/v2/?nolookup&id=LYXKCHX-VI3NYZR-ALCJBHF-WMZYSPK-QG6QJA3-MPFYMSO-U56GTUK-NA2MIAW
[SX4F4] 2023/09/21 21:02:48.585276 manager.go:92: INFO: Using discovery mechanism: IPv4 local broadcast discovery on port 21027
[SX4F4] 2023/09/21 21:02:48.585276 manager.go:92: INFO: Using discovery mechanism: IPv6 local multicast discovery on address [ff12::8384]:21027
[SX4F4] 2023/09/21 21:02:48.585276 logfs.go:79: DEBUG: ignore.go:383 basic F:\Deduped Open .stignore <nil> open \\?\F:\Deduped\.stignore: The system cannot find the file specified.
[SX4F4] 2023/09/21 21:02:48.585276 logfs.go:115: DEBUG: folderconfiguration.go:161 basic F:\Deduped Stat . {0xc0000b4230} <nil>
[SX4F4] 2023/09/21 21:02:48.585276 logfs.go:115: DEBUG: folderconfiguration.go:120 basic F:\Deduped Stat . {0xc0000b4310} <nil>
[SX4F4] 2023/09/21 21:02:48.585796 progressemitter.go:79: DEBUG: progress emitter: timer - looking after 0
[SX4F4] 2023/09/21 21:02:48.585796 progressemitter.go:98: DEBUG: progress emitter: nothing new
[SX4F4] 2023/09/21 21:02:48.586280 logfs.go:115: DEBUG: folderconfiguration.go:138 basic F:\Deduped Stat .stfolder {0xc0000b43f0} <nil>
[SX4F4] 2023/09/21 21:02:48.586280 logfs.go:145: DEBUG: model.go:402 basic F:\Deduped Hide .stfolder <nil>
[SX4F4] 2023/09/21 21:02:48.586280 logfs.go:145: DEBUG: model.go:403 basic F:\Deduped Hide .stversions The system cannot find the file specified.
[SX4F4] 2023/09/21 21:02:48.586280 logfs.go:145: DEBUG: model.go:404 basic F:\Deduped Hide .stignore The system cannot find the file specified.
[SX4F4] 2023/09/21 21:02:48.586280 model.go:424: INFO: Ready to synchronize "DedupData" (6qfz6-aatus) (sendreceive)
[SX4F4] 2023/09/21 21:02:48.586800 folder.go:153: DEBUG: sendreceive/6qfz6-aatus@0xc000182400 starting
[SX4F4] 2023/09/21 21:02:48.586800 logfs.go:115: DEBUG: folderconfiguration.go:120 basic F:\Deduped Stat . {0xc000226310} <nil>
[SX4F4] 2023/09/21 21:02:48.586800 logfs.go:115: DEBUG: folderconfiguration.go:138 basic F:\Deduped Stat .stfolder {0xc0002263f0} <nil>
[SX4F4] 2023/09/21 21:02:48.586800 logfs.go:79: DEBUG: ignore.go:383 basic F:\ControlData Open .stignore <nil> open \\?\F:\ControlData\.stignore: The system cannot find the file specified.
[SX4F4] 2023/09/21 21:02:48.586800 logfs.go:163: DEBUG: folder.go:338 basic D:\SyncThing2\index-v0.14.0.db Usage . {3482379812864 4000768262144} <nil>
[SX4F4] 2023/09/21 21:02:48.586800 logfs.go:79: DEBUG: ignore.go:383 basic F:\Deduped Open .stignore <nil> open \\?\F:\Deduped\.stignore: The system cannot find the file specified.
[SX4F4] 2023/09/21 21:02:48.587326 folder.go:204: DEBUG: sendreceive/6qfz6-aatus@0xc000182400 Scanning due to timer
[SX4F4] 2023/09/21 21:02:48.587326 folder.go:437: DEBUG: sendreceive/6qfz6-aatus@0xc000182400 scanning
[SX4F4] 2023/09/21 21:02:48.587326 logfs.go:115: DEBUG: folderconfiguration.go:120 basic F:\Deduped Stat . {0xc0002265b0} <nil>
[SX4F4] 2023/09/21 21:02:48.587326 logfs.go:115: DEBUG: folderconfiguration.go:138 basic F:\Deduped Stat .stfolder {0xc000226690} <nil>
[SX4F4] 2023/09/21 21:02:48.587326 api.go:403: INFO: GUI and API listening on 127.0.0.1:8384
[SX4F4] 2023/09/21 21:02:48.587326 api.go:404: INFO: Access the GUI via the following URL: http://127.0.0.1:8384/
[SX4F4] 2023/09/21 21:02:48.587326 logfs.go:163: DEBUG: folder.go:338 basic D:\SyncThing2\index-v0.14.0.db Usage . {3482379812864 4000768262144} <nil>
[SX4F4] 2023/09/21 21:02:48.587326 syncthing.go:321: INFO: My name is "TESTSERVER"
[SX4F4] 2023/09/21 21:02:48.587326 syncthing.go:324: INFO: Device IUUIKA4-EGUU3MX-DQT4LQA-QD75I5X-NH6OCRO-4U44TFK-WX7ZDBZ-6ZCC7QA is "UPC" at [dynamic]
[SX4F4] 2023/09/21 21:02:48.587797 logfs.go:79: DEBUG: ignore.go:383 basic F:\Deduped Open .stignore <nil> open \\?\F:\Deduped\.stignore: The system cannot find the file specified.
[SX4F4] 2023/09/21 21:02:48.587797 logfs.go:145: DEBUG: model.go:402 basic F:\ControlData Hide .stfolder <nil>
[SX4F4] 2023/09/21 21:02:48.587797 logfs.go:145: DEBUG: model.go:403 basic F:\ControlData Hide .stversions The system cannot find the file specified.
[SX4F4] 2023/09/21 21:02:48.587797 logfs.go:133: DEBUG: folder.go:1024 basic F:\Deduped Watch . Matcher/[]@0xc0002b8090 false <nil>
[SX4F4] 2023/09/21 21:02:48.587797 folder.go:1038: DEBUG: Started filesystem watcher for folder "DedupData" (6qfz6-aatus)
[SX4F4] 2023/09/21 21:02:48.587797 logfs.go:145: DEBUG: model.go:404 basic F:\ControlData Hide .stignore The system cannot find the file specified.
[SX4F4] 2023/09/21 21:02:48.587797 logfs.go:151: DEBUG: main.go:881 basic D:\SyncThing2 Glob panic-*.log [] <nil>
[SX4F4] 2023/09/21 21:02:48.587797 model.go:424: INFO: Ready to synchronize "ControlData" (zzofn-dcjut) (sendreceive)
[SX4F4] 2023/09/21 21:02:48.587797 folder.go:153: DEBUG: sendreceive/zzofn-dcjut@0xc001489000 starting
[SX4F4] 2023/09/21 21:02:48.587797 logfs.go:115: DEBUG: folderconfiguration.go:120 basic F:\ControlData Stat . {0xc0001970a0} <nil>
[SX4F4] 2023/09/21 21:02:48.587797 logfs.go:115: DEBUG: folderconfiguration.go:138 basic F:\ControlData Stat .stfolder {0xc000197180} <nil>
[SX4F4] 2023/09/21 21:02:48.588308 logfs.go:163: DEBUG: folder.go:338 basic D:\SyncThing2\index-v0.14.0.db Usage . {3482379812864 4000768262144} <nil>
[SX4F4] 2023/09/21 21:02:48.591569 walkfs.go:84: DEBUG: walk: path=.
[SX4F4] 2023/09/21 21:02:48.591569 logfs.go:151: DEBUG: main.go:881 basic D:\SyncThing2 Glob index [] <nil>
[SX4F4] 2023/09/21 21:02:48.591569 logfs.go:79: DEBUG: ignore.go:383 basic F:\ControlData Open .stignore <nil> open \\?\F:\ControlData\.stignore: The system cannot find the file specified.
[SX4F4] 2023/09/21 21:02:48.591569 folder.go:204: DEBUG: sendreceive/zzofn-dcjut@0xc001489000 Scanning due to timer
[SX4F4] 2023/09/21 21:02:48.591569 folder.go:437: DEBUG: sendreceive/zzofn-dcjut@0xc001489000 scanning
[SX4F4] 2023/09/21 21:02:48.592107 walkfs.go:84: DEBUG: walk: path=.stfolder
[SX4F4] 2023/09/21 21:02:48.592107 logfs.go:115: DEBUG: folderconfiguration.go:120 basic F:\ControlData Stat . {0xc000197340} <nil>
[SX4F4] 2023/09/21 21:02:48.592107 logfs.go:115: DEBUG: folderconfiguration.go:138 basic F:\ControlData Stat .stfolder {0xc000197420} <nil>
[SX4F4] 2023/09/21 21:02:48.592107 logfs.go:151: DEBUG: main.go:881 basic D:\SyncThing2 Glob index*.converted [] <nil>
[SX4F4] 2023/09/21 21:02:48.592107 logfs.go:163: DEBUG: folder.go:338 basic D:\SyncThing2\index-v0.14.0.db Usage . {3482379812864 4000768262144} <nil>
[SX4F4] 2023/09/21 21:02:48.592107 walkfs.go:84: DEBUG: walk: path=Test-1.txt
[SX4F4] 2023/09/21 21:02:48.592107 logfs.go:151: DEBUG: main.go:881 basic D:\SyncThing2 Glob config.xml.v* [config.xml.v0] <nil>
[SX4F4] 2023/09/21 21:02:48.592107 logfs.go:79: DEBUG: ignore.go:383 basic F:\ControlData Open .stignore <nil> open \\?\F:\ControlData\.stignore: The system cannot find the file specified.
[SX4F4] 2023/09/21 21:02:48.592107 walkfs.go:84: DEBUG: walk: path=Test-10.txt
[SX4F4] 2023/09/21 21:02:48.592107 logfs.go:133: DEBUG: folder.go:1024 basic F:\ControlData Watch . Matcher/[]@0xc0000e85a0 false <nil>
[SX4F4] 2023/09/21 21:02:48.592107 folder.go:1038: DEBUG: Started filesystem watcher for folder "ControlData" (zzofn-dcjut)
[SX4F4] 2023/09/21 21:02:48.592107 logfs.go:61: DEBUG: main.go:888 basic D:\SyncThing2 Lstat config.xml.v0 {0xc000a9e3f0} <nil>
[SX4F4] 2023/09/21 21:02:48.592638 walkfs.go:84: DEBUG: walk: path=Test-2.txt
[SX4F4] 2023/09/21 21:02:48.592638 logfs.go:151: DEBUG: main.go:881 basic D:\SyncThing2 Glob support-bundle-* [] <nil>
[SX4F4] 2023/09/21 21:02:48.592638 walkfs.go:84: DEBUG: walk: path=.
[SX4F4] 2023/09/21 21:02:48.592638 logfs.go:151: DEBUG: main.go:881 basic D:\SyncThing2 Glob tmp-index-sorter.* [] <nil>
[SX4F4] 2023/09/21 21:02:48.592638 walkfs.go:84: DEBUG: walk: path=Test-3.txt
[SX4F4] 2023/09/21 21:02:48.592638 logfs.go:151: DEBUG: main.go:881 basic D:\SyncThing2 Glob audit-*.log [] <nil>
[SX4F4] 2023/09/21 21:02:48.592638 walkfs.go:84: DEBUG: walk: path=.stfolder
[SX4F4] 2023/09/21 21:02:48.592638 walkfs.go:84: DEBUG: walk: path=Test-1.txt
[SX4F4] 2023/09/21 21:02:48.592638 walkfs.go:84: DEBUG: walk: path=Test-4.txt
[SX4F4] 2023/09/21 21:02:48.592638 logfs.go:151: DEBUG: main.go:881 basic D:\SyncThing2 Glob index-v0.11.0.db [] <nil>
[SX4F4] 2023/09/21 21:02:48.592638 logfs.go:151: DEBUG: main.go:881 basic D:\SyncThing2 Glob index-v0.13.0.db [] <nil>
[SX4F4] 2023/09/21 21:02:48.592638 walkfs.go:84: DEBUG: walk: path=Test-5.txt
[SX4F4] 2023/09/21 21:02:48.592638 logfs.go:151: DEBUG: main.go:881 basic D:\SyncThing2 Glob *.idx.gz [] <nil>
[SX4F4] 2023/09/21 21:02:48.592638 walkfs.go:84: DEBUG: walk: path=Test-10.txt
[SX4F4] 2023/09/21 21:02:48.593173 logfs.go:151: DEBUG: main.go:881 basic D:\SyncThing2 Glob backup-of-v0.8 [] <nil>
[SX4F4] 2023/09/21 21:02:48.593173 walkfs.go:84: DEBUG: walk: path=Test-6.txt
[SX4F4] 2023/09/21 21:02:48.593173 walkfs.go:84: DEBUG: walk: path=Test-2.txt
[SX4F4] 2023/09/21 21:02:48.593173 walkfs.go:84: DEBUG: walk: path=Test-3.txt
[SX4F4] 2023/09/21 21:02:48.593173 walkfs.go:84: DEBUG: walk: path=Test-7.txt
[SX4F4] 2023/09/21 21:02:48.593173 walkfs.go:84: DEBUG: walk: path=Test-4.txt
[SX4F4] 2023/09/21 21:02:48.593173 walkfs.go:84: DEBUG: walk: path=Test-5.txt
[SX4F4] 2023/09/21 21:02:48.593173 walkfs.go:84: DEBUG: walk: path=Test-8.txt
[SX4F4] 2023/09/21 21:02:48.608376 walkfs.go:84: DEBUG: walk: path=Test-6.txt
[SX4F4] 2023/09/21 21:02:48.608916 quic_listen.go:123: INFO: QUIC listener ([::]:22000) starting
[SX4F4] 2023/09/21 21:02:48.608916 tcp_listen.go:77: INFO: TCP listener ([::]:22000) starting
[SX4F4] 2023/09/21 21:02:48.608916 walkfs.go:84: DEBUG: walk: path=Test-9.txt
[SX4F4] 2023/09/21 21:02:48.608916 logfs.go:127: DEBUG: walk.go:235 basic F:\Deduped Walk . 0x14a7020 <nil>
[SX4F4] 2023/09/21 21:02:48.608916 walkfs.go:84: DEBUG: walk: path=Test-7.txt
[SX4F4] 2023/09/21 21:02:48.608916 folder.go:506: DEBUG: sendreceive/6qfz6-aatus@0xc000182400 finished scanning, detected 0 changes
[SX4F4] 2023/09/21 21:02:48.608916 walkfs.go:84: DEBUG: walk: path=Test-8.txt
[SX4F4] 2023/09/21 21:02:48.608916 folder.go:925: INFO: Completed initial scan of sendreceive folder "DedupData" (6qfz6-aatus)
[SX4F4] 2023/09/21 21:02:48.608916 folder.go:312: DEBUG: sendreceive/6qfz6-aatus@0xc000182400 next rescan in 1h9m55.054759709s
[SX4F4] 2023/09/21 21:02:48.609442 walkfs.go:84: DEBUG: walk: path=Test-9.txt
[SX4F4] 2023/09/21 21:02:48.609458 logfs.go:127: DEBUG: walk.go:235 basic F:\ControlData Walk . 0x14a7020 <nil>
[SX4F4] 2023/09/21 21:02:48.609458 logfs.go:61: DEBUG: osutil.go:134 basic F:\ControlData Lstat Test-1.txt {0xc000142540} <nil>
[SX4F4] 2023/09/21 21:02:48.609458 logfs.go:61: DEBUG: osutil.go:134 basic F:\ControlData Lstat Test-10.txt {0xc000142690} <nil>
[SX4F4] 2023/09/21 21:02:48.609458 logfs.go:61: DEBUG: osutil.go:134 basic F:\ControlData Lstat Test-2.txt {0xc000142770} <nil>
[SX4F4] 2023/09/21 21:02:48.609458 logfs.go:61: DEBUG: osutil.go:134 basic F:\ControlData Lstat Test-3.txt {0xc000142850} <nil>
[SX4F4] 2023/09/21 21:02:48.609458 logfs.go:61: DEBUG: osutil.go:134 basic F:\ControlData Lstat Test-4.txt {0xc0001429a0} <nil>
[SX4F4] 2023/09/21 21:02:48.609458 logfs.go:61: DEBUG: osutil.go:134 basic F:\ControlData Lstat Test-5.txt {0xc000142b60} <nil>
[SX4F4] 2023/09/21 21:02:48.609458 logfs.go:61: DEBUG: osutil.go:134 basic F:\ControlData Lstat Test-6.txt {0xc000142cb0} <nil>
[SX4F4] 2023/09/21 21:02:48.609458 logfs.go:61: DEBUG: osutil.go:134 basic F:\ControlData Lstat Test-7.txt {0xc000142d90} <nil>
[SX4F4] 2023/09/21 21:02:48.609989 logfs.go:61: DEBUG: osutil.go:134 basic F:\ControlData Lstat Test-8.txt {0xc000142e70} <nil>
[SX4F4] 2023/09/21 21:02:48.609989 logfs.go:61: DEBUG: osutil.go:134 basic F:\ControlData Lstat Test-9.txt {0xc000142f50} <nil>
[SX4F4] 2023/09/21 21:02:48.609989 folder.go:506: DEBUG: sendreceive/zzofn-dcjut@0xc001489000 finished scanning, detected 0 changes
[SX4F4] 2023/09/21 21:02:48.609989 folder.go:925: INFO: Completed initial scan of sendreceive folder "ControlData" (zzofn-dcjut)
[SX4F4] 2023/09/21 21:02:48.609989 folder.go:312: DEBUG: sendreceive/zzofn-dcjut@0xc001489000 next rescan in 52m1.46765327s
[SX4F4] 2023/09/21 21:02:48.825865 service.go:427: INFO: Established secure connection to IUUIKA4-EGUU3MX-DQT4LQA-QD75I5X-NH6OCRO-4U44TFK-WX7ZDBZ-6ZCC7QA at 192.168.10.4:22000-192.168.10.30:22000/tcp-client/TLS1.3-TLS_AES_128_GCM_SHA256/LAN-P10
[SX4F4] 2023/09/21 21:02:48.825865 indexhandler.go:448: DEBUG: Removing index handler for device IUUIKA4 and folder 6qfz6-aatus
[SX4F4] 2023/09/21 21:02:48.825865 indexhandler.go:451: DEBUG: Removed index handler for device IUUIKA4 and folder 6qfz6-aatus
[SX4F4] 2023/09/21 21:02:48.825865 indexhandler.go:448: DEBUG: Removing index handler for device IUUIKA4 and folder zzofn-dcjut
[SX4F4] 2023/09/21 21:02:48.825865 indexhandler.go:451: DEBUG: Removed index handler for device IUUIKA4 and folder zzofn-dcjut
[SX4F4] 2023/09/21 21:02:48.826374 model.go:2286: INFO: Device IUUIKA4-EGUU3MX-DQT4LQA-QD75I5X-NH6OCRO-4U44TFK-WX7ZDBZ-6ZCC7QA client is "syncthing v1.24.0" named "UPC" at 192.168.10.4:22000-192.168.10.30:22000/tcp-client/TLS1.3-TLS_AES_128_GCM_SHA256/LAN-P10
[SX4F4] 2023/09/21 21:02:48.826935 model.go:1171: DEBUG: Handling ClusterConfig from IUUIKA4
[SX4F4] 2023/09/21 21:02:49.316505 progressemitter.go:285: DEBUG: progress emitter: bytes completed for 6qfz6-aatus: 0
[SX4F4] 2023/09/21 21:02:49.316505 model.go:929: DEBUG: model@0xc00020bd40 Completion(7777777-777777N-7777777-777777N-7777777-777777N-7777777-77777Q4, "6qfz6-aatus"): map[completion:100 globalBytes:0 globalItems:0 needBytes:0 needDeletes:0 needItems:0 remoteState:unknown sequence:0]
[SX4F4] 2023/09/21 21:02:49.317560 progressemitter.go:285: DEBUG: progress emitter: bytes completed for zzofn-dcjut: 0
[SX4F4] 2023/09/21 21:02:49.318622 model.go:929: DEBUG: model@0xc00020bd40 Completion(7777777-777777N-7777777-777777N-7777777-777777N-7777777-77777Q4, "zzofn-dcjut"): map[completion:100 globalBytes:104857600 globalItems:10 needBytes:0 needDeletes:0 needItems:0 remoteState:unknown sequence:10]
[SX4F4] 2023/09/21 21:02:49.962510 progressemitter.go:285: DEBUG: progress emitter: bytes completed for 6qfz6-aatus: 0
[SX4F4] 2023/09/21 21:02:49.963058 progressemitter.go:285: DEBUG: progress emitter: bytes completed for zzofn-dcjut: 0
[SX4F4] 2023/09/21 21:02:52.645308 service.go:277: INFO: Connection from IUUIKA4-EGUU3MX-DQT4LQA-QD75I5X-NH6OCRO-4U44TFK-WX7ZDBZ-6ZCC7QA at 192.168.10.30:22000 (quic-server) rejected: already connected to this device
[SX4F4] 2023/09/21 21:02:58.444916 quic_listen.go:58: INFO: quic://0.0.0.0:22000 detected NAT type: Symmetric NAT
[SX4F4] 2023/09/21 21:02:58.882685 service.go:103: INFO: Detected 0 NAT services
[SX4F4] 2023/09/21 21:03:17.753594 service.go:371: INFO: Failed to exchange Hello messages with IUUIKA4-EGUU3MX-DQT4LQA-QD75I5X-NH6OCRO-4U44TFK-WX7ZDBZ-6ZCC7QA at 192.168.10.4:22000-192.168.10.30:59109/tcp-server/TLS1.3-TLS_AES_128_GCM_SHA256/LAN-P10: write tcp 192.168.10.4:22000->192.168.10.30:59109: wsasend: An existing connection was forcibly closed by the remote host.
[SX4F4] 2023/09/21 21:03:19.999186 progressemitter.go:75: DEBUG: progress emitter: stopping
[SX4F4] 2023/09/21 21:03:19.999186 folder.go:182: DEBUG: sendreceive/zzofn-dcjut@0xc001489000 exiting
[SX4F4] 2023/09/21 21:03:19.999186 basicfs_watch.go:112: DEBUG: basic F:\ControlData Watch: Stopped
[SX4F4] 2023/09/21 21:03:19.999186 basicfs_watch.go:112: DEBUG: basic F:\Deduped Watch: Stopped
[SX4F4] 2023/09/21 21:03:19.999186 quic_listen.go:147: INFO: QUIC listener ([::]:22000) shutting down
[SX4F4] 2023/09/21 21:03:19.999186 folder.go:182: DEBUG: sendreceive/6qfz6-aatus@0xc000182400 exiting
[SX4F4] 2023/09/21 21:03:20.003467 relay_listen.go:65: INFO: Relay listener (dynamic+https://relays.syncthing.net/endpoint) shutting down
[SX4F4] 2023/09/21 21:03:20.003467 model.go:1802: INFO: Connection to IUUIKA4-EGUU3MX-DQT4LQA-QD75I5X-NH6OCRO-4U44TFK-WX7ZDBZ-6ZCC7QA at 192.168.10.4:22000-192.168.10.30:22000/tcp-client/TLS1.3-TLS_AES_128_GCM_SHA256/LAN-P10 closed: Syncthing is being stopped
[SX4F4] 2023/09/21 21:03:20.755833 tcp_listen.go:112: INFO: TCP listener ([::]:22000) shutting down
[SX4F4] 2023/09/21 21:03:20.756388 syncthing.go:360: INFO: Exiting

```

Also if you have the posibility to try yourself. the script below creates a virtual disk, formats it, enables dedup, creates Testdata in 2 folders, one will be deduped one not. Windows Server needed (>= 2016) and the dedup feature added

```
$VHD   = New-VHD -Path D:\DedupTest.vhdx -SizeBytes 1GB
$mount = $VHD | Mount-VHD -Passthru
$mount | Initialize-Disk -PartitionStyle GPT
$part  = New-Partition -DiskNumber $mount.DiskNumber -UseMaximumSize -AssignDriveLetter
$Vol   = $part | Format-Volume -FileSystem NTFS -NewFileSystemLabel "TestDedup"
Enable-DedupVolume -Volume ($part.DriveLetter + ":") -UsageType Default
New-Item -Path ($part.DriveLetter + ":\ControlData") -ItemType Directory | Out-Null
Set-DedupVolume -Volume ($part.DriveLetter + ":") -MinimumFileAgeDays 0 -ExcludeFolder ($part.DriveLetter + ":\ControlData")
$count = 0
do{
$count++
    $out = New-Object byte[] 10MB; 
    (New-Object Random).NextBytes($out); 
    [IO.File]::WriteAllBytes(($part.DriveLetter + ":\ControlData\Test-$count.txt"), $out)
}until($count -eq 10)
Copy-Item ($part.DriveLetter + ":\ControlData") -Destination ($part.DriveLetter + ":\Deduped\") -Recurse
Start-DedupJob -Volume ($part.DriveLetter + ":") -Priority High -Type Optimization
do{Start-Sleep -Seconds 1}until($null -eq (Get-DedupJob))
Get-DedupStatus
```

Fix patch:
diff --git a/lib/fs/basicfs_lstat_windows.go b/lib/fs/basicfs_lstat_windows.go
index ec0e8038dfa..5a0024c71a3 100644
--- a/lib/fs/basicfs_lstat_windows.go
+++ b/lib/fs/basicfs_lstat_windows.go
@@ -18,15 +18,17 @@ import (
 	"golang.org/x/sys/windows"
 )
 
-func isDirectoryJunction(path string) (bool, error) {
+const IO_REPARSE_TAG_DEDUP = 0x80000013
+
+func readReparseTag(path string) (uint32, error) {
 	namep, err := syscall.UTF16PtrFromString(path)
 	if err != nil {
-		return false, fmt.Errorf("syscall.UTF16PtrFromString failed with: %s", err)
+		return 0, fmt.Errorf("syscall.UTF16PtrFromString failed with: %s", err)
 	}
 	attrs := uint32(syscall.FILE_FLAG_BACKUP_SEMANTICS | syscall.FILE_FLAG_OPEN_REPARSE_POINT)
 	h, err := syscall.CreateFile(namep, 0, 0, nil, syscall.OPEN_EXISTING, attrs, 0)
 	if err != nil {
-		return false, fmt.Errorf("syscall.CreateFile failed with: %s", err)
+		return 0, fmt.Errorf("syscall.CreateFile failed with: %s", err)
 	}
 	defer syscall.CloseHandle(h)
 
@@ -47,10 +49,19 @@ func isDirectoryJunction(path string) (bool, error) {
 			// instance to indicate no symlinks are possible.
 			ti.ReparseTag = 0
 		} else {
-			return false, fmt.Errorf("windows.GetFileInformationByHandleEx failed with: %s", err)
+			return 0, fmt.Errorf("windows.GetFileInformationByHandleEx failed with: %s", err)
 		}
 	}
-	return ti.ReparseTag == windows.IO_REPARSE_TAG_MOUNT_POINT, nil
+
+	return ti.ReparseTag, nil
+}
+
+func isDirectoryJunction(reparseTag uint32) bool {
+	return reparseTag == windows.IO_REPARSE_TAG_MOUNT_POINT
+}
+
+func isDeduplicatedFile(reparseTag uint32) bool {
+	return reparseTag == IO_REPARSE_TAG_DEDUP
 }
 
 type dirJunctFileInfo struct {
@@ -67,17 +78,38 @@ func (fi *dirJunctFileInfo) IsDir() bool {
 	return true
 }
 
+type dedupFileInfo struct {
+	os.FileInfo
+}
+
+func (fi *dedupFileInfo) Mode() os.FileMode {
+	// A deduplicated file should be treated as a regular file and not an
+	// irregular file.
+	return fi.FileInfo.Mode() &^ os.ModeIrregular
+}
+
 func (f *BasicFilesystem) underlyingLstat(name string) (os.FileInfo, error) {
 	var fi, err = os.Lstat(name)
 
-	// NTFS directory junctions can be treated as ordinary directories,
-	// see https://forum.syncthing.net/t/option-to-follow-directory-junctions-symbolic-links/14750
-	if err == nil && f.junctionsAsDirs && fi.Mode()&os.ModeSymlink != 0 {
-		var isJunct bool
-		isJunct, err = isDirectoryJunction(name)
-		if err == nil && isJunct {
-			return &dirJunctFileInfo{fi}, nil
+	// There are cases where files are tagged as symlink, but they end up being
+	// something else. Make sure we properly handle those types.
+	if err == nil {
+		// NTFS directory junctions can be treated as ordinary directories,
+		// see https://forum.syncthing.net/t/option-to-follow-directory-junctions-symbolic-links/14750
+		if fi.Mode()&os.ModeSymlink != 0 && f.junctionsAsDirs {
+			if reparseTag, reparseErr := readReparseTag(name); reparseErr == nil && isDirectoryJunction(reparseTag) {
+				return &dirJunctFileInfo{fi}, nil
+			}
+		}
+
+		// Workaround for #9120 till golang properly handles deduplicated files by
+		// considering them regular files.
+		if fi.Mode()&os.ModeIrregular != 0 {
+			if reparseTag, reparseErr := readReparseTag(name); reparseErr == nil && isDeduplicatedFile(reparseTag) {
+				return &dedupFileInfo{fi}, nil
+			}
 		}
 	}
+
 	return fi, err
 }


Test patch: