please log file operations by default

Feature
1

In this post I was worried that syncthing destroyed my files:

Now I’m more confident that it didn’t happen, but I still find myself in the position of trying to figure out what the heck syncthing is doing sometimes. The GUIs help: I can see if a folder is out of sync, by how much, and even the file transfer progress (to a certain extent). But that’s when I have the GUI and that doesn’t provide me with an history of changes.

In the above post, I was told to use the audit commandline flags but that prove to actually be quite difficult to use. It outputs JSON which is nice for programmers and admins (like me) but really not that nice for more novice users (who might not know how to parse JSON).

We output a lot of logs by default, for example I frequently see things like this:

jan 14 09:30:27 angela syncthing[6435]: [72RXH] INFO: Connected to myself ([REDACTED]) at 172.17.0.1:22000-192.168.0.117:22000/tcp-server/TLS1.3-TLS_AES_128_GCM_SHA256 - should not happen 
jan 14 09:30:33 angela syncthing[6435]: [72RXH] INFO: Connection to [REDACTED] at 192.168.0.117:22000-192.168.0.153:22000/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: read timeout

which is… interesting, but not necessarily everything I want to know. (I’ll also note this contains PII which we should generally be careful about, but I guess that’s expected…)

So what I would like syncthing to do, by default, is say things like this:

  • transferred file foo.txt from remote X
  • transferred file bar.txt to remote X
  • deleted file bar.txt to sync with remote X

… basically. I know that it could mean a lot of output on first syncs, but maybe the output could be rate-limited?

This is important to deal with situations like the thread above, but it’s also helpful in other cases. I just setup syncthing on my Kobo ebook reader (!) which is really awesome (!!) and it kind of works. One problem I often have is the CPU is somewhat slow on there, so sometimes it looks like syncthing is not doing anything. I opened a logfile (which has already grown to 56MB, btw, something for another thread), but it doesn’t really tell me much. I could tell it started scanning a folder, which took several minutes, so that might be what happened. But it didn’t tell me when it transfered that ONE file I wanted to have on that thing. I just had to hit refresh in the file browser repeatedly, which was a frustrating user experience.

Having file transfer updates would also help me see what’s going on in my desktop, since there I run syncthing in the background. Then I could just tail the journalctl logs to see what’s going on.

Thanks!

1 Like
2

So, --verbose? (--audit is a raw event log, --verbose translates most events into humanese.)

It doesn’t log transferring files to other devices, but that’s because that’s not really a thing. Syncthing transfers blocks with hashes, and doesn’t really know on the sending side where that block will be used.

3 Likes
3

i guess the question is: how verbose is --verbose anyways? :slight_smile:

1 Like
4

the anser is: a lot.

jan 14 20:15:26 angela syncthing[14602]: [72RXH] VERBOSE: Device [REDACTED] sent an index update for "default" with 1 items 
jan 14 20:15:26 angela syncthing[14602]: [72RXH] VERBOSE: Folder "default" is now sync-waiting 
jan 14 20:15:26 angela syncthing[14602]: [72RXH] VERBOSE: Folder "default" is now sync-preparing 
jan 14 20:15:26 angela syncthing[14602]: [72RXH] VERBOSE: Started syncing "default" / "test" (delete file) 
jan 14 20:15:26 angela syncthing[14602]: [72RXH] VERBOSE: Finished syncing "default" / "test" (delete file): Success 
jan 14 20:15:26 angela syncthing[14602]: [72RXH] VERBOSE: Remote change detected in folder "default": deleted file test 
jan 14 20:15:26 angela syncthing[14602]: [72RXH] VERBOSE: Folder "default" is now idle 
jan 14 20:15:26 angela syncthing[14602]: [72RXH] VERBOSE: Summary for folder "default" is map[errors:0] globalBytes:311340646 globalDeleted:509 globalDirectories:2 globalFiles:52 globalSymlinks:0 globalTotalItems:563 inSyncBytes:311340646 inSyncFiles:52 localBytes:311340646 localDeleted:310 localDirectories:2 localFiles:52 localSymlinks:0 localTotalItems:364 needBytes:0 needDeletes:0 needDirectories:0 needFiles:0 needSymlinks:0 needTotalItems:0 pullErrors:0 sequence:730 state:idle version:730] 
jan 14 20:15:26 angela syncthing[14602]: [72RXH] VERBOSE: Completion for folder "default" on device [REDACTED] is 100% 
jan 14 20:15:26 angela syncthing[14602]: [72RXH] VERBOSE: Completion for folder "default" on device [REDACTED] is 95% 
jan 14 20:15:26 angela syncthing[14602]: [72RXH] VERBOSE: Completion for folder "default" on device [REDACTED] is 95% 
jan 14 20:15:26 angela syncthing[14602]: [72RXH] VERBOSE: Device [REDACTED] sent an index update for "default" with 1 items 
jan 14 20:15:26 angela syncthing[14602]: [72RXH] VERBOSE: Device [REDACTED] sent an index update for "default" with 1 items

ie. 13 lines for a single file deleted. :wink: i guess i was looking for something a little less verbose, like just:

jan 14 20:15:26 angela syncthing[14602]: [72RXH] VERBOSE: Remote change detected in folder "default": deleted file test

but maybe i’m being picky.

thanks for the quick response!

1 Like
5

a week later: this works great, thanks again! :slight_smile:

3 Likes