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

Support
1

I setup two syncthing servers, and added them to each other with introducer and auto share folders set.

I then installed syncthing on my local mac, and added mac to server 1 and 2 (without introducer)

At this point all devices see each other and there are no errors.

Now I create a shared folder “folder1” on server 1. Shortly after, I see this folder automatically appear on server 2 and local device. All 3 see the new folder.

then I add a second folder “folder2” to server 1.

Note, I am the only one with access, and no files or directories have been added to any of the shared folders.

server 2 shows folder 2 up to date, and shows server 1 device as up to date.

Server 1 shows folder 1 as Out of Sync, and shows server 2 as 0% of 612 MiB. When I look at “failed items” on server 1 UI, it shows: “vendor/github.com/stretchr no such file or directory” Where did this come from?

This cannot be, there are no files or directories in either shared folder.

I try to open the UI of my local install, and its dead. the syncthing process has crashed.

Looking on my local machine, I cant find where syncthing has put the folders. They are not under ~. Searching for the dir shows its not present.

Now when I restart the crashed syncthing on my local machine, it shows:

2018-06-15 13:25:57: Error on folder “folder2” (folder22): folder path missing

So when I added the folder on the server, it has tried to add it on the device (as I had auto create folder set), but seems to have failed, in addition to the other issue with the spurious file which I did not add failing.

This was just a simple exercise to share a new empty folder on 3 brand new machines (which have never had syncthing installed). I dont know what I could have done differently

Note, the two servers are ubuntu 18.04 LTS running the linux 64 bit version of syncthing.

The device is a mac running syncthing-macosx 0.14.46.1

Now the local device syncthing has crashed again - “syncing seems to be down, or there is a problem with your internet connection”. There is no problem with the internet connection, and both servers are up.

Any ideas?

I now cant start my local syncthing. The process just dies. I am unable to connect to the UI via browser.

The only thing I can think of is that I used to have syncthing installed. It was the manual install of the mac version direct form the official website. Its a tar.gz file I unzipped into downloads, and ran the exe from there. With this I tried to syc with others peer to peer, but this failed due to too many sync errors. I removed this version by deleting the directory containg the exe, and also removed the directory /Users/me/Library/Application Support/Syncthing. This should have eradicated the old version. Then I installed syncthing again using the nice https://github.com/xor-gate/syncthing-macosx. It seems somehow the new setup has been infected with the old setup. I dont know how, or how to fix/debug.

when I look in /Users/me/Library/Application Support/Syncthing/config.xml

I only see the two new servers, and one of the two shared folders, the one which causes the problem. The path is ~/folder1, but this folder does not exist on my machine.

This also does not shed light on where the mystery files are coming from. The old syncthing was sycing to a folder/share called “folder” without the 1.

It is worth noting that both servers are secure, e.g. FW only permits SSH and 22000, password auth is disabled (only certs), fail2ban installed etc. and UI is access only through ssh tunnel.

I just looked on the server in the folder1 share directory. There was a directory in it called ivan in it. Noone put this there. Searching my machine, I have a directory called ivan under a directory called “folder” - not “folder1”. This is where the old version of syncthing was syncing to. the one I removed but its ghost is haunting me by moving files from old share to new share.

With my local syncthing process not running, I connected to both servers and removed all the spurious files under folder1. folder1 is now empty on both servers. In server2 UI, it shows Everything up to date. On server 1 UI, it shows folder1 as out of sync. “rescan all” did not help. Looking at failed items, its still showing the file which doesnt exist. I just also tried restarting syncthing on server 1, still “out of sync”

I can confirm there is only one copy of syncthing exe on the local machine, and its the one from xor-gate, not the original download one.

2

~ 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

3

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?

4

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.

5

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.

6

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.

7

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?

8

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.

syncthing2
syncthing2.png2412×1590 298 KB
syncthing1_screen
syncthing1_screen.png2368×1598 322 KB

Any idea how to fix this?

9

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.

10

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?

11

“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)

12

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

1 Like
13

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

Are all devices running .48?

14

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?

15

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

16

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.

serveraccept_png
serveraccept_png.png908×797 80.9 KB

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.

17

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

18

@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
19

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

1 Like
20

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.