weird errors and crash, new folders dont sync on new simple setup.

~ is a shorthand for home directory, so make sure you are looking in the right place. I suggest you post the logs + screenshots from both sides as your own descriptions are not showing the full picture

FYI, I am a unix sys admin, so I know where ~ is. just for clarity, on the mac it is /Users/myname. Any idea where to find the logs on the mac?

Could it be that when I reinstalled syncthing after removing the old syncthing and its config, it has generated the same device ID, and it has started syncing old folders which are not in the new installs config, so crashes? I found a whole load of "panic-xxxx.log files. Looking through the file, there is nothing obvious. Note, the first folder I created was simply “test”. This worked fine, and test appeared on all 3 devices without errors.

The logs show this:

[JGHGH] 14:19:37 WARNING: Error on folder “folder1” (folder1): folder path missing

There seems to be bug where the folder was not created, which explains why this folder is not on the local device. However, it has not caused the crash. This comes later:

[JGHGH] 14:19:37 INFO: Failed initial scan of readwrite folder “folder1” (folder1) [JGHGH] 14:19:37 INFO: Completed initial scan of readwrite folder “Default Folder” (default) [JGHGH] 14:19:37 INFO: Completed initial scan of readwrite folder “test” (test)

[JGHGH] 14:19:39 INFO: Adding folder “test” (test) Panic at 2018-06-15T14:19:39+02:00 panic: cannot start already running folder test

What does this mean? I created a folder test once, and it was synced correctly to all 3 devices. I cant remember which device I created test on, probably server1.

The cannot start already running folder error should never happen. Please share screenshots and logs (not excerpts), so we can analyze what might be wrong here. Otherwise it’s just guessing.

It cannot have generated the same device id, but if the old id/config was still in place, it has used them again.

Here are the symptoms as much as I can ascertain:

  1. client either deleted, or didnt create, the test folder, and wont start. Test folder was created on the server and auto share folders was on.
  2. client started syncing files from a different share name, from a different device ID, from a previous install where the config was deleted (verified the config only contains the new devices and files)
  3. one of the two servers is stuck with “out of sync” when syncing two empty directories.

Uploading screenshots and logs will take some time as I have to remove every occurence of the share names etc. as they are confidential company products, but will do it.

With regards to problem one, the test dir and crashing syncthing.

I tried deleting the empty test dir in ~, then starting syncthing. it creates a new copy of the test folder, then dies. Attached are my local device logs.panic-20180615-141939.log (93.3 KB)

Perhaps there is a bug creating and syncing a new emty folder, or a bug which cant handle a folder called test?

Attached are screen shots of the two servers. One is stuck, the other says its ok. The “folder1” directory is empty in both servers, but it wont sync.

Any idea how to fix this?

You need to nuke everything and start fresh. Something is clearly screwed, potentially old database, with new config etc. Run syncthing -paths to see where stuff is located.

Something is really weird here.

[JGHGH] 14:19:37 INFO: Ready to synchronize "folder1" (folder1) (readwrite)
[JGHGH] 14:19:37 INFO: Ready to synchronize "test" (test) (readwrite)
[JGHGH] 14:19:37 INFO: Ready to synchronize "Default Folder" (default) (readwrite)

So far so good, starting up up some folders.

[JGHGH] 14:19:37 WARNING: Error on folder "folder1" (folder1): folder path missing
[JGHGH] 14:19:37 INFO: Failed initial scan of readwrite folder "folder1" (folder1)

OK, that thing doesn’t exist, but no biggie.

[JGHGH] 14:19:37 INFO: Completed initial scan of readwrite folder "test" (test)

The “test” folder is fine. :+1:

[JGHGH] 14:19:39 INFO: Established secure connection to OGDJTJX-DVOE24J-3MNM2AQ-7EHB55U-IOFXZDG-W4ZJPMU-LWQHFZM-Z53DNAC at 192.168.1.39:51822-139.162.8.193:22000/tcp-client (TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305)
[JGHGH] 14:19:39 INFO: Device OGDJTJX-DVOE24J-3MNM2AQ-7EHB55U-IOFXZDG-W4ZJPMU-LWQHFZM-Z53DNAC client is "syncthing v0.14.48" named "syncthing1" at 192.168.1.39:51822-139.162.8.193:22000/tcp-client
[JGHGH] 14:19:39 INFO: Adding folder "test" (test)

We connected to a new device, presumably with the introducer or auto accept folders option set, and it’s announcing the folder “test”. For some reason I don’t understand we decide that we should add it again.

panic: cannot start already running folder test

Clearly, because it already exists.

There were some changes lately to how we check for folder presence and sharing. @imsodin, ideas?

“You need to nuke everything and start fresh.” Unfortunately, this is exactly what I did!
The two servers were build 2 days ago from scratch. They are completely new installs On my client, I did the paths, found that syncthing was storing its config in ~/Library/Application Support/Syncthing/, I deleted this directory and the syncthing binaries.

If I started again now, I would get exactly the same result - servers that wont sync an empty directory with each other, and a client that wont start because of the test folder, and spurious files which came from an old device id with a completely different folder name.

Attached is the config.xml found in ~/Library/Application Support/Syncthing/

It only has the new stuff in it.

config.xml (6.2 KB)

That’s in the RC and from the logs this is .48.

1 Like

I’d try setting up all 3 machined from scratch.

Are all devices running .48?

The two servers are running 0.14.48. All 3 were installed by me a few days ago from scratch. If I follow the same steps I did, I will get the same result.

I need to figure out

  1. how to start my local syncthing. It dies right after it creates the test folder.
  2. how to fix the stuck server which says that the empty folder is “out of sync” with the other server.

I had a thought about the test folder. It was working until I introduce the second server (i.e. 3rd device)

I.e had server 1 setup, and the local device connected with non-introducer, and auto accept shares set to true. Then I created the second server, and connected it to server 1 with introducer true and auto accept shares to true. At some point after this, my local device would not start. I cant remember if I had to manually add my local device to server 2 (or visa versa). I remember a popup in the app asking if I wanted to accept the second server. So perpas the issue is with 3 devices: two servers auto accepting each others shares, and the device accepting servers shares.

COULD IT BE THAT SERVER 1 AND SERVER 2 ARE TRYING TO ADD THE “TEST” SHARE TO THE DEVICE?

It should be ok, as they have the same ID. I suggest you disable these auto-introduction stuff, and add folders manually.

Do we think that the “Auto Accept” feature is broken in a 3 device scenario? It would have been ideal for us.

The difficulty will be educating our users that they should not tick this box (which will break the client and is difficult for users to fix), but instead manually share each folder.

This what I did on the server.

I cant show the client UI as I cant start it, but on the client I ticked auto accept. also, I did auto-accept between server 1 and server 2, so that adding a folder to server 1 would automatically put it on the back up server 2.

Well try undoing it and see if it makes it better. Perhaps there is a bug, but until we know whats the cause.

@jvlittle If you can reproduce the crash for which you posted logs above I’d be very interesting to see logs with model and config debug facilities enabled.

The panic definitely originates from auto accepting folders, but I don’t (yet?) have any idea how/why.

Panic at 2018-06-15T14:19:39+02:00
panic: cannot start already running folder test

goroutine 218 [running]:
github.com/syncthing/syncthing/lib/model.(*Model).startFolderLocked(0xc4200b2480, 0xc420538f38, 0x4, 0x4)
	/Users/jb/buildAgent-syncthing/work/src/github.com/syncthing/syncthing/lib/model/model.go:201 +0xe35
github.com/syncthing/syncthing/lib/model.(*Model).StartFolder(0xc4200b2480, 0xc420538f38, 0x4)
	/Users/jb/buildAgent-syncthing/work/src/github.com/syncthing/syncthing/lib/model/model.go:189 +0x9d
github.com/syncthing/syncthing/lib/model.(*Model).CommitConfiguration(0xc4200b2480, 0x1c, 0xc420528c00, 0x3, 0x3, 0xc420404000, 0x2, 0x2, 0x1, 0xc4205395f0, ...)
	/Users/jb/buildAgent-syncthing/work/src/github.com/syncthing/syncthing/lib/model/model.go:2655 +0x4a7
github.com/syncthing/syncthing/lib/config.(*Wrapper).notifyListener(0xc4200e2380, 0x47e9d40, 0xc4200b2480, 0x1c, 0xc420528c00, 0x3, 0x3, 0xc420404000, 0x2, 0x2, ...)
	/Users/jb/buildAgent-syncthing/work/src/github.com/syncthing/syncthing/lib/config/wrapper.go:184 +0x141
github.com/syncthing/syncthing/lib/config.(*Wrapper).notifyListeners.func1(0xc4200e2380, 0xc4203d4300, 0xc4203d4600, 0x47eb140, 0xc420510b50, 0x47e9d40, 0xc4200b2480)
	/Users/jb/buildAgent-syncthing/work/src/github.com/syncthing/syncthing/lib/config/wrapper.go:175 +0x134
created by github.com/syncthing/syncthing/lib/config.(*Wrapper).notifyListeners
	/Users/jb/buildAgent-syncthing/work/src/github.com/syncthing/syncthing/lib/config/wrapper.go:174 +0x187

goroutine 213 [semacquire]:
sync.runtime_Semacquire(0xc420510b5c)
	/usr/local/go/src/runtime/sema.go:56 +0x39
sync.(*WaitGroup).Wait(0xc420510b50)
	/usr/local/go/src/sync/waitgroup.go:129 +0x72
github.com/syncthing/syncthing/lib/model.(*Model).handleAutoAccepts(0xc4200b2480, 0xae89abe3a6998671, 0xefe1900f81668d6d, 0xbd94b93523dfe250, 0xdad83db35c0eb48b, 0xc420539416, 0xa, 0xc420063c80, 0x1, 0x1, ...)
	/Users/jb/buildAgent-syncthing/work/src/github.com/syncthing/syncthing/lib/model/model.go:1210 +0x7fc
github.com/syncthing/syncthing/lib/model.(*Model).ClusterConfig(0xc4200b2480, 0xae89abe3a6998671, 0xefe1900f81668d6d, 0xbd94b93523dfe250, 0xdad83db35c0eb48b, 0xc420b24600, 0x3, 0x4)
	/Users/jb/buildAgent-syncthing/work/src/github.com/syncthing/syncthing/lib/model/model.go:930 +0x3b4
github.com/syncthing/syncthing/lib/protocol.(*rawConnection).readerLoop(0xc4206840c0, 0x0, 0x0)
	/Users/jb/buildAgent-syncthing/work/src/github.com/syncthing/syncthing/lib/protocol/protocol.go:346 +0xed0
created by github.com/syncthing/syncthing/lib/protocol.(*rawConnection).Start
	/Users/jb/buildAgent-syncthing/work/src/github.com/syncthing/syncthing/lib/protocol/protocol.go:210 +0x43

That’s not yet in v0.14.48. Potentially those changes might even improve the situation - that’s pure speculation though.

1 Like

Attached is the config from server1 if it helps. As I said, the auto folder stuff worked for the test folder until I added server2.

server1_config.xml (8.0 KB)

Actually, looking at my local config, the second server is not in the list yet, as when it popped up with the dialog to accept the invite from server 2 , I didnt hit yes nor no, and the popup never came back.

Hi, how do I enable model and debug facilities? Its easy to reproduce - I just try to start syncthing. Currently, it crashes every time I try to start it.