Folder "Folder_name" isn't making progress

Support
1

I am getting an error on a previously working share/folder (on Win7):

23:57:58: Folder “Folder_name” isn’t making progress - check logs for possible root cause. Pausing puller for 1m0s.

I am not sure where is the log file it is talking about.

There is AppData\Local\Syncthing\index\LOG file. Here’s few last lines from it:

00:23:00.996695 mem@flush N·15714 S·3MiB
00:23:01.169706 mem@flush created L1@9656 N·15714 S·878KiB "\x00..g,v40308540":"\x01..f,v40324253"
00:23:01.194707 mem@flush committed F·1 T·198.0127ms
00:23:01.197707 journal@remove removed @9651
00:23:01.344717 table@compaction L1·1 -> L2·2 S·3MiB Q·40296249
00:23:01.725741 table@build created L2@9657 N·16615 S·2MiB "\x00..C,v40296492":"\x00..f,v15281983"
00:23:02.149769 table@build created L2@9658 N·44682 S·1MiB "\x00..f,v15281377":"\x1e..\x80,v40296249"
00:23:02.172770 table@compaction committed F-1 S-56KiB D·0 T·828.0532ms
00:23:12.713447 table@remove removed @9652
00:23:12.714447 table@remove removed @9649
00:23:12.715447 table@remove removed @9650
00:23:12.715447 table@remove removed @9656
00:23:12.716447 table@remove removed @9653
00:23:12.717447 table@remove removed @9654

There is also 009640.log in the same folder. But it looks like a binary file.

Anybody has an idea what it all means?

2

The same log where it prints the first message.

3

That’s probably from the web interface. The log in question is printed on the console, which may not be visible depending on how you run syncthing.

(Maybe this should be changed, at least on Windows. :/)

4

Well, what I am seeing in the console window is the same exact message I see in webui:

23:57:58: Folder “Folder_name” isn’t making progress - check logs for possible root cause. Pausing puller for 1m0s.

But what does it mean? What the real issue here?

One of my drives started behaving flaky as of late, and the physical share in question is located on that drive. At some point during the last boot that drive/partition just became invisible in Win, like it does not exist. After I rebooted, everything seems to work, except now I see this message from syncthing.

What should I do in this situation?

5

There ought to be messages prior to that one mentioning one or more errors…

6

Here’s the entire log file in case you’d like to look at it: http://preciseinfo.org/logs/LOG

7

This is the database log, not Syncthing log.

Syncthing logs to stdout… unless you redirect it.

8

I run synthing via shortcut to an executable, and so it behaves as if I started it from the command box. No stdout is redirected.

Well, what I get in the command box is all normal messages, such as establishing connections, recognizing nodes, and then the same exact warning message as I see in webui, and it keeps retrying and displaying the same message every minute.

But what does it mean “isn’t making progress”? Progress doing what?

9

That’s odd. Screenshot?

10

Here’s the screenshot:

http://preciseinfo.org/logs/Folder_not_making_progress.jpg

11

One of the things I notice is that on Win7 side (r/o) webui says there is 1 item out of sync. But on the master side (r/w, Linux) it says 6 items out of sync. When I click on that message, I get these files. What seems to be strange that some of them seem to be scheduled for DOWNLOAD to the r/w side from r/o side because I see these circles with down arrows for those files:

Here’s the image:

http://preciseinfo.org/logs/Out_of_sync.jpg

The strange thing about this is that otherwise both nodes look OK on webui without any errors.

12

Are you pointing syncthing and BTSync at the same folder?

13

Yes, I am. BTsync feeds the hot feed (live side) from Win7 to Linux. Then Syncthing feeds that folder back to Win7, only to a different folder, “not too hot” in terms of frequency of updates. Then BTSync serves that 2nd folder to all the r/o nodes. This way, if we have too frequent of the updates, we can temporarily disconnect the Synching channel and so other users do not get overwhelmed be frequent updates.

Update 1:

Actually, I did remove some files and subfolders in the .stversions subfolder (the r/o side for syncthing) because I would not like these things served to other nodes, even though I have them in the ignore file. (That means that I removed some files in the r/o side (of synchthing), but only in the .stversions subfolder.

But I thought that you can remove anything you want in the .stversions subfolder.

14

Indeed, that’s odd. Mind doing a set STTRACE=model in a terminal window, starting syncthing from that same terminal window, and redoing the screenshot? There should be a bit more debugging crap between the “not making progress” warnings to help narrow down wtf is going on.

15

Well, there seems to be quite a lot of output with STTRACE=model and I have no idea what you’d be interested in. So, here is the text after running it for a few minutes from the very start:

http://preciseinfo.org/logs/x1.txt

The share that is having problems is AntiMatrix_Live

Update 1:

I’d appreciate you post here when you got what you need. I’d prefer not to keep this public.

16

Got it, thanks. What is the exact config of that folder, in terms of versioning, ignoring permissions, etc?

17

Folder Master - no Ignore Permissions - no Simple File Versioning Keep Versions -3

Update 1:

I just tried to set Ignore Permissions - yes. But that did not help. Still the same error.

Update 2:

This share worked fine before that drive which contains this share became non-existent to O/S, if that tells you something. At least these things correlate. But the strange thing about it is that I had the same situation a few days ago when the same drive just disappeared from the O/S. But that time everything worked fine after I rebooted and that drive started working again.

18

Right, so the only code path that doesn’t emit anything useful here (which will be fixed) looks like the case where it’s a directory, and it should be deleted, but the delete fails. The most common reason for that is that there are files in it, possibly covered by an .stignore. Does that make sense, at least so long that the .SyncArchive/.../..._Docs directory (I forget the exact name) ought to be deleted?

The build v0.10.0+9 or newer from http://build.syncthing.net/job/syncthing/ should hopefully print something about the root cause - can you try that?

19

Yep, this is probably what’s happening here. When I deleted some files/folders in.stignore, it did have some subfolders in it and, possibly, just files on the top level. Unfortunately, I no longer have those files cause I emptied the garbage bin.

The .stignore did have .SyncArchive dir with subfolders in it. So, you’d have to traverse the entire tree to properly handle that case, as far as I can see.

Would it be too much of a pain to just handle this case instead of just printing a better looking message?

Yep, I’ll try that. Not sure what you mean by build 0+9.

Also, it is too bad that you seem to be so against a more detailed logging. The debug level trace isn’t that informative to the users and might be way to detailed to see the details of some operation and higher level calls. Also, I’d rather push some button and see the log window where it tells me exactly what is going on, which file is being transferred, it full path, and to which node and what is the higher level operation has initiated is, such as “sending/receiving folder/file xxx with node yyy”, or “doing periodic maintenance”, “rebuilding the index” and operational things like that.

Also, it would be very useful to the users to see the dynamics of transfers. There might be several nodes active at the same time with different state of completeness. I find it very useful to see the progress of things, percentage done, and things like that. Because simply seeing the total network speed and not knowing which exact files are transferred and to/from where makes one wonder or even doubt: is everything going on OK? How much do I have left with this share? What is the total size done by now? At what speed I am transferring the file and so on.

As I mentioned before, a detailed automatic logging to a session log file has helped me to find some pretty esoteric issues in a couple of minutes.

I’d really love to see a more detailed and more precise logging. But hey, life is life and your mind could be busy with all sorts of other things you think are more significant. Not a problem, I can wait. I’d just like to start bringing some people and serving exclusively via Syncthing and totally forgetting about BTSync. Because there is no day passing when I do not see some weirdest issues that should have never happened.

Update 1:

Meanwhile, what do I do now? Should I just remove that share and re-add it again in case you don’t need any more info on this? And, this may happen in the future, and if the same thing happens again, what’d be weird. Why not just handle this case properly and set the correct state for the files that are missing in the file system but are present in the database/index?

The same essential case happens when you restore some previously deleted file. In that case, the “physically present on disk” flag tells you if that file, when last seen, did or did not exist. If it did not exist, that means the file is being restored. So, you just mark it as “updatable” and “propagatable” and “phiscally present on disk” - true.

The same thing happens when you rename some files, and, possibly, decide to rename them back. I have gone through the entire update logic quite extensively and looked at every conceivable case, more or less, and it looks to me that there is a solution to the consistency issue if you apply much stricter rules as to updating the other nodes.

Update 2:

If you decide this case just “slide” and limit the handling to merely displaying the more informative message, I hope it will contain the instructions on what exactly one needs to do to fix this share, even if the message is too long and wraps around. It seems to me that more detailed information is more valuable than just merely being cryptic trying to fit it all on one text line, especially if you do not know the length of that line on different screens.

20

So, erh, not sure where I gave the impression that I’m against logging, or that what you’re seeing is not an issue that should be solved… The steps so far have been to just figure out what the issue is, exactly.

Practically, in this specific case, if the directory should be removed and syncthing can’t do that, you can probably resolve it by removing the directory yourself.