Continuous disk activity?

Support
1

I’ve set up Syncthing to sync a bunch of folders every 28,800 seconds. I would have assumed that by setting an eight-hour sync interval on both ends of a connection I could make Syncthing go dormant in between syncs, but it doesn’t. It keeps cycling through the shared folders in two-second intervals, doing the following (says Process Monitor):

QueryOpen (folder)
QueryOpen (folder\.stfolder)
CreateFile
QueryFullSizeInformationVolume
CloseFile

What is going on and how do I stop it? I’d like to be able to set an even longer sync interval and allow my drives to spin down when there’s no activity on the shared folders on either end.

2

Did you close the GUI?

3

Also, is itnactually in sync and have you restarted for the settings to apply?

4

Yep, closed the GUI.

5

And yes, folders are definitely in sync. And it’s after several reboots, so I assume all the settings have been applied.

Perhaps it’s worth mentioning that the disks are on a hardware RAID controller (RR 2720 SGL). So it might be that these queries wouldn’t prevent a drive from spinning down under different circumstances. It’s not reading actual file contents so I imagine whatever information it’s polling ends up being cached by the OS, allowing the drives to idle and eventually sleep. In fact come to think of it it’s possible that messing with some driver settings or third-party caching utility could solve my problem, too. But either way it’s odd that Syncthing has to keep accessing the file system like that. If it detects any changes it still wouldn’t react to them before it’s time to sync, anyway. Right?

6

So it should stay idle if nothing is happening and no scan is going on. The thing you are seeing is the healthchecks of the folder, but as far as I know we only query these when updating database, downloading a file, or scanning, so something must be happening.

You can run with envvar STTRACE=all to see more details.

7

Ok, there’s some log output below. This is what it ends up doing repeatedly after I let it initalise for a few minutes. I can confirm that no other processes are accessing the volume that holds the synced folders.

[DS2GJ] 2015/10/03 18:34:01.085937 client_udp.go:106: DEBUG: discover udp6://announce-v6.syncthing.net:22026: broadcast resolve: GetAddrInfoW: No such host is known.; trying again in 1m0s
[DS2GJ] 2015/10/03 18:34:02.968750 rwfolder.go:239: DEBUG: rwFolder/FSP_Sync@0xc082545320 skip (curVer == prevVer) 207638 true
[DS2GJ] 2015/10/03 18:34:03.015625 rwfolder.go:239: DEBUG: rwFolder/FSP_MP3@0xc08247a480 skip (curVer == prevVer) 207336 true
[DS2GJ] 2015/10/03 18:34:03.310546 rwfolder.go:239: DEBUG: rwFolder/FSP_Camera@0xc0821f86c0 skip (curVer == prevVer) 194236 true
[DS2GJ] 2015/10/03 18:34:03.522460 rwfolder.go:239: DEBUG: rwFolder/FSP_SCGFX@0xc0835c7b00 skip (curVer == prevVer) 207639 true
[DS2GJ] 2015/10/03 18:34:12.969726 rwfolder.go:239: DEBUG: rwFolder/FSP_Sync@0xc082545320 skip (curVer == prevVer) 207638 true
[DS2GJ] 2015/10/03 18:34:13.016601 rwfolder.go:239: DEBUG: rwFolder/FSP_MP3@0xc08247a480 skip (curVer == prevVer) 207336 true
[DS2GJ] 2015/10/03 18:34:13.310546 rwfolder.go:239: DEBUG: rwFolder/FSP_Camera@0xc0821f86c0 skip (curVer == prevVer) 194236 true
[DS2GJ] 2015/10/03 18:34:13.523437 rwfolder.go:239: DEBUG: rwFolder/FSP_SCGFX@0xc0835c7b00 skip (curVer == prevVer) 207639 true
[DS2GJ] 2015/10/03 18:34:21.075195 multicast.go:93: DEBUG: sent 56 bytes to [ff32::5222]:21026 on {EDC51DD2-DE5E-4B4D-91E6-ECE0D8D88C41}
[DS2GJ] 2015/10/03 18:34:21.076171 broadcast.go:114: DEBUG: addresses: [255.255.255.255]
[DS2GJ] 2015/10/03 18:34:21.076171 broadcast.go:192: DEBUG: recv 56 bytes from 192.168.1.10:58928
[DS2GJ] 2015/10/03 18:34:21.076171 broadcast.go:140: DEBUG: sent 56 bytes to 255.255.255.255:21025
[DS2GJ] 2015/10/03 18:34:21.076171 discover.go:320: DEBUG: discover: Received local announcement from 192.168.1.10:58928 for DS2GJZG-BZP7IHB-7YOWHO2-D44YF2B-QOUPWC6-JAI3QGG-7Q5OVV5-KMUOOAX
[DS2GJ] 2015/10/03 18:34:21.076171 beacon.go:34: DEBUG: recv 56 bytes from [fe80::d42b:acc1:5567:ea06%{EDC51DD2-DE5E-4B4D-91E6-ECE0D8D88C41}]:21026
[DS2GJ] 2015/10/03 18:34:21.076171 discover.go:320: DEBUG: discover: Received local announcement from [fe80::d42b:acc1:5567:ea06%{EDC51DD2-DE5E-4B4D-91E6-ECE0D8D88C41}]:21026 for DS2GJZG-BZP7IHB-7YOWHO2-D44YF2B-QOUPWC6-JAI3QGG-7Q5OVV5-KMUOOAX
[DS2GJ] 2015/10/03 18:34:21.410156 protocol.go:387: DEBUG: read header {0 13 4 false} (msglen=0)
[DS2GJ] 2015/10/03 18:34:21.410156 protocol.go:411: DEBUG: read 0 bytes
[DS2GJ] 2015/10/03 18:34:21.410156 protocol.go:431: DEBUG: message data:
[DS2GJ] 2015/10/03 18:34:21.410156 protocol.go:673: DEBUG: write uncompressed message; {0 13 5 false} (len=0)
[DS2GJ] 2015/10/03 18:34:21.410156 protocol.go:690: DEBUG: wrote 8 bytes on the wire
[DS2GJ] 2015/10/03 18:34:21.427734 protocol.go:740: DEBUG: GZMGZFV-P6KK7FZ-WKLRGX2-J7VMQ5T-BDJMQQQ-7R5DKCT-FW4E76Z-IURTCAX ping skipped after rd 17.5781ms
[DS2GJ] 2015/10/03 18:34:22.970703 rwfolder.go:239: DEBUG: rwFolder/FSP_Sync@0xc082545320 skip (curVer == prevVer) 207638 true
[DS2GJ] 2015/10/03 18:34:23.016601 rwfolder.go:239: DEBUG: rwFolder/FSP_MP3@0xc08247a480 skip (curVer == prevVer) 207336 true
[DS2GJ] 2015/10/03 18:34:23.311523 rwfolder.go:239: DEBUG: rwFolder/FSP_Camera@0xc0821f86c0 skip (curVer == prevVer) 194236 true
[DS2GJ] 2015/10/03 18:34:23.524414 rwfolder.go:239: DEBUG: rwFolder/FSP_SCGFX@0xc0835c7b00 skip (curVer == prevVer) 207639 true
[DS2GJ] 2015/10/03 18:34:32.970703 rwfolder.go:239: DEBUG: rwFolder/FSP_Sync@0xc082545320 skip (curVer == prevVer) 207638 true
[DS2GJ] 2015/10/03 18:34:33.017578 rwfolder.go:239: DEBUG: rwFolder/FSP_MP3@0xc08247a480 skip (curVer == prevVer) 207336 true
[DS2GJ] 2015/10/03 18:34:33.311523 rwfolder.go:239: DEBUG: rwFolder/FSP_Camera@0xc0821f86c0 skip (curVer == prevVer) 194236 true
[DS2GJ] 2015/10/03 18:34:33.525390 rwfolder.go:239: DEBUG: rwFolder/FSP_SCGFX@0xc0835c7b00 skip (curVer == prevVer) 207639 true

Here is some of the corresponding output from Process Monitor (filtered to show all activity on the E: volume):

18:34:02,9685790	syncthing.exe	3692	QueryOpen	E:\Sync	SUCCESS	CreationTime: 30-09-2015 23:08:28, LastAccessTime: 30-09-2015 23:08:31, LastWriteTime: 30-09-2015 23:08:31, ChangeTime: 03-10-2015 00:09:33, AllocationSize: 12.288, EndOfFile: 12.288, FileAttributes: D
18:34:02,9687232	syncthing.exe	3692	QueryOpen	E:\Sync\.stfolder	SUCCESS	CreationTime: 09-09-2015 22:18:05, LastAccessTime: 09-09-2015 22:18:05, LastWriteTime: 09-09-2015 22:18:05, ChangeTime: 03-10-2015 00:09:01, AllocationSize: 0, EndOfFile: 0, FileAttributes: HA
18:34:02,9688494	syncthing.exe	3692	CreateFile	E:\Sync	SUCCESS	Desired Access: Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Open For Free Space Query, Attributes: n/a, ShareMode: None, AllocationSize: n/a, OpenResult: Opened
18:34:02,9688936	syncthing.exe	3692	QueryFullSizeInformationVolume	E:\Sync	SUCCESS	TotalAllocationUnits: 2.197.601.791, CallerAvailableAllocationUnits: 1.445.506.158, ActualAvailableAllocationUnits: 1.445.506.158, SectorsPerAllocationUnit: 8, BytesPerSector: 512
18:34:02,9689210	syncthing.exe	3692	CloseFile	E:\Sync	SUCCESS	
18:34:03,0144986	syncthing.exe	3692	QueryOpen	E:\Musik\MP3	SUCCESS	CreationTime: 24-02-2014 00:42:42, LastAccessTime: 02-10-2015 23:45:20, LastWriteTime: 02-10-2015 23:45:20, ChangeTime: 03-10-2015 00:30:10, AllocationSize: 81.920, EndOfFile: 81.920, FileAttributes: DNCI
18:34:03,0146418	syncthing.exe	3692	QueryOpen	E:\Musik\MP3\.stfolder	SUCCESS	CreationTime: 09-09-2015 22:27:45, LastAccessTime: 09-09-2015 22:27:45, LastWriteTime: 09-09-2015 22:27:45, ChangeTime: 27-09-2015 12:45:21, AllocationSize: 0, EndOfFile: 0, FileAttributes: HANCI
18:34:03,0148034	syncthing.exe	3692	CreateFile	E:\Musik\MP3	SUCCESS	Desired Access: Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Open For Free Space Query, Attributes: n/a, ShareMode: None, AllocationSize: n/a, OpenResult: Opened
18:34:03,0148479	syncthing.exe	3692	QueryFullSizeInformationVolume	E:\Musik\MP3	SUCCESS	TotalAllocationUnits: 2.197.601.791, CallerAvailableAllocationUnits: 1.445.506.158, ActualAvailableAllocationUnits: 1.445.506.158, SectorsPerAllocationUnit: 8, BytesPerSector: 512
18:34:03,0148758	syncthing.exe	3692	CloseFile	E:\Musik\MP3	SUCCESS	
18:34:03,3103650	syncthing.exe	3692	QueryOpen	E:\Camera	SUCCESS	CreationTime: 03-10-2015 00:06:08, LastAccessTime: 03-10-2015 00:23:49, LastWriteTime: 03-10-2015 00:23:49, ChangeTime: 03-10-2015 00:23:49, AllocationSize: 196.608, EndOfFile: 196.608, FileAttributes: D
18:34:03,3105106	syncthing.exe	3692	QueryOpen	E:\Camera\.stfolder	SUCCESS	CreationTime: 03-10-2015 00:14:13, LastAccessTime: 03-10-2015 00:14:13, LastWriteTime: 03-10-2015 00:14:13, ChangeTime: 03-10-2015 00:14:13, AllocationSize: 0, EndOfFile: 0, FileAttributes: HA
18:34:03,3106361	syncthing.exe	3692	CreateFile	E:\Camera	SUCCESS	Desired Access: Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Open For Free Space Query, Attributes: n/a, ShareMode: None, AllocationSize: n/a, OpenResult: Opened
18:34:03,3106803	syncthing.exe	3692	QueryFullSizeInformationVolume	E:\Camera	SUCCESS	TotalAllocationUnits: 2.197.601.791, CallerAvailableAllocationUnits: 1.445.506.158, ActualAvailableAllocationUnits: 1.445.506.158, SectorsPerAllocationUnit: 8, BytesPerSector: 512
18:34:03,3107081	syncthing.exe	3692	CloseFile	E:\Camera	SUCCESS	
18:34:03,5213604	syncthing.exe	3692	QueryOpen	E:\_ST\Grafik\Smash Cafe	SUCCESS	CreationTime: 03-10-2015 00:00:18, LastAccessTime: 03-10-2015 00:25:04, LastWriteTime: 03-10-2015 00:25:04, ChangeTime: 03-10-2015 00:25:04, AllocationSize: 12.288, EndOfFile: 12.288, FileAttributes: DNCI
18:34:03,5215057	syncthing.exe	3692	QueryOpen	E:\_ST\Grafik\Smash Cafe\.stfolder	SUCCESS	CreationTime: 03-10-2015 00:13:06, LastAccessTime: 03-10-2015 00:13:06, LastWriteTime: 03-10-2015 00:13:06, ChangeTime: 03-10-2015 00:13:06, AllocationSize: 0, EndOfFile: 0, FileAttributes: HANCI
18:34:03,5217018	syncthing.exe	3692	CreateFile	E:\_ST\Grafik\Smash Cafe	SUCCESS	Desired Access: Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Open For Free Space Query, Attributes: n/a, ShareMode: None, AllocationSize: n/a, OpenResult: Opened
18:34:03,5217463	syncthing.exe	3692	QueryFullSizeInformationVolume	E:\_ST\Grafik\Smash Cafe	SUCCESS	TotalAllocationUnits: 2.197.601.791, CallerAvailableAllocationUnits: 1.445.506.158, ActualAvailableAllocationUnits: 1.445.506.158, SectorsPerAllocationUnit: 8, BytesPerSector: 512
18:34:03,5217741	syncthing.exe	3692	CloseFile	E:\_ST\Grafik\Smash Cafe	SUCCESS	
18:34:12,9696261	syncthing.exe	3692	QueryOpen	E:\Sync	SUCCESS	CreationTime: 30-09-2015 23:08:28, LastAccessTime: 30-09-2015 23:08:31, LastWriteTime: 30-09-2015 23:08:31, ChangeTime: 03-10-2015 00:09:33, AllocationSize: 12.288, EndOfFile: 12.288, FileAttributes: D
18:34:12,9697700	syncthing.exe	3692	QueryOpen	E:\Sync\.stfolder	SUCCESS	CreationTime: 09-09-2015 22:18:05, LastAccessTime: 09-09-2015 22:18:05, LastWriteTime: 09-09-2015 22:18:05, ChangeTime: 03-10-2015 00:09:01, AllocationSize: 0, EndOfFile: 0, FileAttributes: HA
18:34:12,9698958	syncthing.exe	3692	CreateFile	E:\Sync	SUCCESS	Desired Access: Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Open For Free Space Query, Attributes: n/a, ShareMode: None, AllocationSize: n/a, OpenResult: Opened
18:34:12,9699403	syncthing.exe	3692	QueryFullSizeInformationVolume	E:\Sync	SUCCESS	TotalAllocationUnits: 2.197.601.791, CallerAvailableAllocationUnits: 1.445.506.158, ActualAvailableAllocationUnits: 1.445.506.158, SectorsPerAllocationUnit: 8, BytesPerSector: 512
18:34:12,9699685	syncthing.exe	3692	CloseFile	E:\Sync	SUCCESS	
18:34:13,0155502	syncthing.exe	3692	QueryOpen	E:\Musik\MP3	SUCCESS	CreationTime: 24-02-2014 00:42:42, LastAccessTime: 02-10-2015 23:45:20, LastWriteTime: 02-10-2015 23:45:20, ChangeTime: 03-10-2015 00:30:10, AllocationSize: 81.920, EndOfFile: 81.920, FileAttributes: DNCI
18:34:13,0156941	syncthing.exe	3692	QueryOpen	E:\Musik\MP3\.stfolder	SUCCESS	CreationTime: 09-09-2015 22:27:45, LastAccessTime: 09-09-2015 22:27:45, LastWriteTime: 09-09-2015 22:27:45, ChangeTime: 27-09-2015 12:45:21, AllocationSize: 0, EndOfFile: 0, FileAttributes: HANCI
18:34:13,0158561	syncthing.exe	3692	CreateFile	E:\Musik\MP3	SUCCESS	Desired Access: Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Open For Free Space Query, Attributes: n/a, ShareMode: None, AllocationSize: n/a, OpenResult: Opened
18:34:13,0159006	syncthing.exe	3692	QueryFullSizeInformationVolume	E:\Musik\MP3	SUCCESS	TotalAllocationUnits: 2.197.601.791, CallerAvailableAllocationUnits: 1.445.506.158, ActualAvailableAllocationUnits: 1.445.506.158, SectorsPerAllocationUnit: 8, BytesPerSector: 512
18:34:13,0159281	syncthing.exe	3692	CloseFile	E:\Musik\MP3	SUCCESS	
18:34:13,3104046	syncthing.exe	3692	QueryOpen	E:\Camera	SUCCESS	CreationTime: 03-10-2015 00:06:08, LastAccessTime: 03-10-2015 00:23:49, LastWriteTime: 03-10-2015 00:23:49, ChangeTime: 03-10-2015 00:23:49, AllocationSize: 196.608, EndOfFile: 196.608, FileAttributes: D
18:34:13,3105517	syncthing.exe	3692	QueryOpen	E:\Camera\.stfolder	SUCCESS	CreationTime: 03-10-2015 00:14:13, LastAccessTime: 03-10-2015 00:14:13, LastWriteTime: 03-10-2015 00:14:13, ChangeTime: 03-10-2015 00:14:13, AllocationSize: 0, EndOfFile: 0, FileAttributes: HA
18:34:13,3106779	syncthing.exe	3692	CreateFile	E:\Camera	SUCCESS	Desired Access: Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Open For Free Space Query, Attributes: n/a, ShareMode: None, AllocationSize: n/a, OpenResult: Opened
18:34:13,3107217	syncthing.exe	3692	QueryFullSizeInformationVolume	E:\Camera	SUCCESS	TotalAllocationUnits: 2.197.601.791, CallerAvailableAllocationUnits: 1.445.506.158, ActualAvailableAllocationUnits: 1.445.506.158, SectorsPerAllocationUnit: 8, BytesPerSector: 512
18:34:13,3107516	syncthing.exe	3692	CloseFile	E:\Camera	SUCCESS	
18:34:13,5224263	syncthing.exe	3692	QueryOpen	E:\_ST\Grafik\Smash Cafe	SUCCESS	CreationTime: 03-10-2015 00:00:18, LastAccessTime: 03-10-2015 00:25:04, LastWriteTime: 03-10-2015 00:25:04, ChangeTime: 03-10-2015 00:25:04, AllocationSize: 12.288, EndOfFile: 12.288, FileAttributes: DNCI
18:34:13,5225713	syncthing.exe	3692	QueryOpen	E:\_ST\Grafik\Smash Cafe\.stfolder	SUCCESS	CreationTime: 03-10-2015 00:13:06, LastAccessTime: 03-10-2015 00:13:06, LastWriteTime: 03-10-2015 00:13:06, ChangeTime: 03-10-2015 00:13:06, AllocationSize: 0, EndOfFile: 0, FileAttributes: HANCI
18:34:13,5227677	syncthing.exe	3692	CreateFile	E:\_ST\Grafik\Smash Cafe	SUCCESS	Desired Access: Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Open For Free Space Query, Attributes: n/a, ShareMode: None, AllocationSize: n/a, OpenResult: Opened
18:34:13,5228115	syncthing.exe	3692	QueryFullSizeInformationVolume	E:\_ST\Grafik\Smash Cafe	SUCCESS	TotalAllocationUnits: 2.197.601.791, CallerAvailableAllocationUnits: 1.445.506.158, ActualAvailableAllocationUnits: 1.445.506.158, SectorsPerAllocationUnit: 8, BytesPerSector: 512
18:34:13,5228393	syncthing.exe	3692	CloseFile	E:\_ST\Grafik\Smash Cafe	SUCCESS

There’s obviously not a lot going on but it does poll the file system a little bit. I’m thinking there is something wrong with my setup since those polls really should be cached at a high API level in Windows (7 Ultimate SP1, if it matters) and never make it to the device driver. So the drives should still spin down with this amount of activity. But either way it’d be good to know why it’s actually polling like this.

8

So I found where this happens, we basically check if the folder is there every second etc.

You can open a ticket if you want this changed, basically it’s moving the folder health check after detecting a change.

9

Well mystery solved then. Thx.

As a developer I don’t find this behaviour very attractive. In fact it bugs me somewhat. But that’s really not a discussion for a support forum. :slight_smile: And since I suspect my setup is wonky I’ll want to address that anyway before opening a ticket.

10

Well it’s a check which happens before we start downloading stuff. But we seem to do the health check before checking if there is anything to download, so we should just swap them around to avoid hitting the disk.

11

This could explain why my disk started spinning sometimes without something syncing to a folder on that disk. I wonder why it did not spin all the time with that check happening, maybe the info was cached in the RAM and it only happened when something needed RAM and that info was removed from cache…

12

I think that this is what I see with my arm build for Android. My intervals are set to 0 and I still see alot of mount.exfat activity by syncthing

13

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.