Dear all,
I searched online but couldn’t find a solution to my issue. In December I suddenly had a corrupted password container file which I synced from my PC via my NAS to my Android. I investigated further but couldn’t find the root cause. I left it be but recently my wife encountered an issue with her synced files which got corrupted as well. Not all files but quite a number of files.
I investigated further and found out:
All files corrupted are filled with zeros according to the hex editor
Files have the same size and names as the original ones
Filetypes random: pdf, jpg, txt, …
only files within syncthing folders got corrupted (scanned my whole NAS folder with awk (find -type f -printf “%S\t%p\n” 2>/dev/null | awk -F"\t" ‘{if ($1 < 1.0) print $2}’
Further information:
my PC: Linux Arch
my phone: Samsung Android
my NAS: readynas 314 with Debian 8 (ReadyNASOS 6.10.10)
deactivated Internetaccess on my router for my NAS because of IT Sec concerns (but tested it also with Internet enabled)
my wife Laptop: Windows 10 / switched recently to PC with Win 11 but not connected to syncthing yet
I can simulate this issue consistenly by putting a text file in the folder which I sync from my PC to the NAS to the Phone. When only the synching between the PC and the NAS happens all is fine. As soon the synching to the phone happens the file is corrupted / filled with zeros on all devices.
It cannot be an issue of the phone alone as it also happens to the files of my wife which I don’t sync to my phone
Do you have any suggestion which I can analyze further?
Many thanks,
Matthias
Log from the Phone:
17:15:57 [HMF4A] INFO: Puller (folder “Matthias-KeepassXC” (nwsyy-oujaq), item “hdd1.txt”): syncing: finishing: pull: no such file
17:15:57 [HMF4A] INFO: “Matthias-KeepassXC” (nwsyy-oujaq): Failed to sync 1 items
17:15:57 [HMF4A] INFO: Folder “Matthias-KeepassXC” (nwsyy-oujaq) isn’t making sync progress - retrying in 1m0s.
Log from my NAS:
2025-02-26 17:15:15 Connection from xxxx at [fe80::1e69:7aff:fead:ca89%eth0]:22000 (quic-server) rejected: device is paused
2025-02-26 17:15:35 Connection from xxxx at [fe80::1e69:7aff:fead:ca89%eth0]:22000 (quic-server) rejected: device is paused
2025-02-26 17:15:40 Connection from xxxx at [fe80::1e69:7aff:fead:ca89%eth0]:22000 (tcp-server) rejected: device is paused
2025-02-26 17:15:40 Connection from xxxx at 192.168.178.12:22000 (tcp-server) rejected: device is paused
2025-02-26 17:15:53 Relay listener (dynamic+https://relays.syncthing.net/endpoint) starting
2025-02-26 17:15:53 Relay listener (dynamic+https://relays.syncthing.net/endpoint) shutting down
2025-02-26 17:15:53 listenerSupervisor@dynamic+https://relays.syncthing.net/endpoint: service dynamic+https://relays.syncthing.net/endpoint failed: Get “https://relays.syncthing.net/endpoint”: dial tcp 51.159.84.17:443: connect: connection refused
2025-02-26 17:15:53 Relay listener (dynamic+https://relays.syncthing.net/endpoint) starting
2025-02-26 17:15:53 Relay listener (dynamic+https://relays.syncthing.net/endpoint) shutting down
2025-02-26 17:15:53 listenerSupervisor@dynamic+https://relays.syncthing.net/endpoint: service dynamic+https://relays.syncthing.net/endpoint failed: Get “https://relays.syncthing.net/endpoint”: dial tcp 51.159.84.17:443: connect: connection refused
2025-02-26 17:15:53 Relay listener (dynamic+https://relays.syncthing.net/endpoint) starting
2025-02-26 17:15:53 Relay listener (dynamic+https://relays.syncthing.net/endpoint) shutting down
2025-02-26 17:15:53 listenerSupervisor@dynamic+https://relays.syncthing.net/endpoint: service dynamic+https://relays.syncthing.net/endpoint failed: Get “https://relays.syncthing.net/endpoint”: dial tcp 51.159.84.17:443: connect: connection refused
My suspicion is that something else is acting on the file on the phone. Syncthing hashes all blocks before writing it, so this would be a very surprising failure mode. Can you reproduce it without that phone involved?
I could share the same folder with the laptop of my wife with the same result and a similiar log. At least it is showing the same error as the phone log. Can I turn on advanced logging for specific facilities? If yes which should I turn on?
[monitor] 2025/02/26 19:53:34 INFO: Log output saved to file "C:\Users\xxx\AppData\Local\Syncthing\syncthing.log"
[start] 2025/02/26 19:53:34 INFO: syncthing v1.29.2 "Gold Grasshopper" (go1.23.4 windows-amd64) builder@github.syncthing.net 2025-01-11 16:38:29 UTC
[GTERX] 2025/02/26 19:53:35 INFO: My ID: GTERXWL
[GTERX] 2025/02/26 19:53:35 INFO: Hashing performance is 241.42 MB/s
[GTERX] 2025/02/26 19:53:35 INFO: Overall send rate is unlimited, receive rate is unlimited
[GTERX] 2025/02/26 19:53:35 INFO: Using discovery mechanism: global discovery server https://discovery-lookup.syncthing.net/v2/?noannounce
[GTERX] 2025/02/26 19:53:35 INFO: Using discovery mechanism: global discovery server https://discovery-announce-v4.syncthing.net/v2/?nolookup
[GTERX] 2025/02/26 19:53:35 INFO: Using discovery mechanism: global discovery server https://discovery-announce-v6.syncthing.net/v2/?nolookup
[GTERX] 2025/02/26 19:53:35 INFO: Using discovery mechanism: IPv4 local broadcast discovery on port 21027
[GTERX] 2025/02/26 19:53:35 INFO: Relay listener (dynamic+https://relays.syncthing.net/endpoint) starting
[GTERX] 2025/02/26 19:53:35 INFO: Using discovery mechanism: IPv6 local multicast discovery on address [ff12::8384]:21027
[GTERX] 2025/02/26 19:53:35 INFO: TCP listener ([::]:22000) starting
[GTERX] 2025/02/26 19:53:35 INFO: QUIC listener ([::]:22000) starting
[GTERX] 2025/02/26 19:53:35 INFO: Support for IPv6 UPnP is currently not available on Windows: listen udp6 [ff05::c]:0: setsockopt: not supported by windows
[GTERX] 2025/02/26 19:53:35 INFO: GUI and API listening on 127.0.0.1:8384
[GTERX] 2025/02/26 19:53:35 INFO: Access the GUI via the following URL: http://localhost:8384/
[GTERX] 2025/02/26 19:53:35 INFO: My name is "DESKTOP-KMTECV2"
[GTERX] 2025/02/26 19:53:35 INFO: Device DHWRYEX is "NAS" at [dynamic]
[GTERX] 2025/02/26 19:53:40 INFO: Established secure connection to DHWRYEX at 192.168.178.21:22000-192.168.178.10:22000/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256/LAN-P10-617QRDKKVVER8E4ACR9G4AJF7Q
[GTERX] 2025/02/26 19:53:40 INFO: Device DHWRYEX client is "syncthing v1.28.0" named "nas-6E-1B-3E" at 192.168.178.21:22000-192.168.178.10:22000/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256/LAN-P10-617QRDKKVVER8E4ACR9G4AJF7Q
[GTERX] 2025/02/26 19:53:42 INFO: Unexpected folder "Matthias-KeepassXC" (nwsyy-oujaq) sent from device "DHWRYEX"; ensure that the folder exists and that this device is selected under "Share With" in the folder configuration.
[GTERX] 2025/02/26 19:53:56 INFO: Failed to acquire [::]:22000/TCP open port on NAT-PMP@192.168.178.1: getting new lease on NAT-PMP@192.168.178.1 (external port 30194 -> internal port 22000): unexpected result size 12, expected 16
[GTERX] 2025/02/26 19:53:56 INFO: Failed to acquire [::]:22000/TCP open port on 75802409-bccb-40e7-9f6c-DC396FAFCD7B/WANDevice - FRITZ!Box 7590/urn:upnp-org:serviceId:WANIPConn1/urn:schemas-upnp-org:service:WANIPConnection:2/http://192.168.178.1:49000/igd2upnp/control/WANIPConn1: getting new lease on 75802409-bccb-40e7-9f6c-DC396FAFCD7B/WANDevice - FRITZ!Box 7590/urn:upnp-org:serviceId:WANIPConn1/urn:schemas-upnp-org:service:WANIPConnection:2/http://192.168.178.1:49000/igd2upnp/control/WANIPConn1 (external port 63194 -> internal port 22000): UPnP Error: Unknown Error Code (606)
[GTERX] 2025/02/26 19:53:57 INFO: Failed to acquire [::]:22000/TCP open port on 75802409-bccb-40e7-8e6c-DC396FAFCD7B/WANDevice - FRITZ!Box 7590/urn:upnp-org:serviceId:WANIPConn1/urn:schemas-upnp-org:service:WANIPConnection:1/http://192.168.178.1:49000/igdupnp/control/WANIPConn1: getting new lease on 75802409-bccb-40e7-8e6c-DC396FAFCD7B/WANDevice - FRITZ!Box 7590/urn:upnp-org:serviceId:WANIPConn1/urn:schemas-upnp-org:service:WANIPConnection:1/http://192.168.178.1:49000/igdupnp/control/WANIPConn1 (external port 49846 -> internal port 22000): UPnP Error: Unknown Error Code (606)
[GTERX] 2025/02/26 19:53:57 INFO: Detected 3 NAT services
[GTERX] 2025/02/26 19:54:47 INFO: Joined relay relay://144.24.174.10:22067
[GTERX] 2025/02/26 19:55:11 INFO: Adding folder "Matthias-KeepassXC" (nwsyy-oujaq)
[GTERX] 2025/02/26 19:55:11 INFO: No stored folder metadata for "nwsyy-oujaq"; recalculating
[GTERX] 2025/02/26 19:55:11 INFO: Ready to synchronize "Matthias-KeepassXC" (nwsyy-oujaq) (sendreceive)
[GTERX] 2025/02/26 19:55:11 INFO: Device DHWRYEX folder "Matthias-KeepassXC" (nwsyy-oujaq) has a new index ID (0x564B35E64342BD9E)
[GTERX] 2025/02/26 19:55:11 INFO: Completed initial scan of sendreceive folder "Matthias-KeepassXC" (nwsyy-oujaq)
[GTERX] 2025/02/26 19:55:48 INFO: Puller (folder "Matthias-KeepassXC" (nwsyy-oujaq), item "hdd1.txt"): syncing: finishing: pull: no such file
[GTERX] 2025/02/26 19:55:48 INFO: "Matthias-KeepassXC" (nwsyy-oujaq): Failed to sync 1 items
[GTERX] 2025/02/26 19:55:48 INFO: Folder "Matthias-KeepassXC" (nwsyy-oujaq) isn't making sync progress - retrying in 1m0s.
So Syncthing synced a file, then when it was going to do the last touch-up of name, permissions and timestamp, the file was no longer there. That’s very odd and I’d look into other things like potential antivirus interference or something.
So it looks like it is an general issue with my NAS and not syncthing related. Only the new files or touched files have showed the issue and that is why I tought it is syncthing but in fact all new files have the issue described above.
NAS is now 15 Years old and without support so I am retiring it and replace it with a new one.
hello
I got exactly same problem with an Asustor NAS 10 years ago because the hard disks I installed where not listed in hardware compatibility list.
that was at least conclusion of Asustor support.
