Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Log output related to initial config loading is misleading #4431

Closed
vn971 opened this issue Oct 18, 2017 · 7 comments

Comments

Projects
None yet
4 participants
@vn971
Copy link

commented Oct 18, 2017

What I did:

  • I have a Windows7 computer. (It's not exactly mine, but for simplicity let's call it mine.)
  • I downloaded syncthing from here: https://github.com/syncthing/syncthing/releases . The precise version is this: https://github.com/syncthing/syncthing/releases/download/v0.14.39/syncthing-windows-amd64-v0.14.39.zip
  • I've unzipped the file
  • I ran syncthing.exe

At the last step, it feels like syncthing is trying to just launch normally. It shows "my ID" and such things in the logs. But it always dies later, and after 4 attempts stopps working at all. Here is the produced log:

C:\Users\TN\Downloads\vasya\syncthing-windows-amd64-v0.14.39>syncthing.exe
[monitor] 15:23:10 INFO: Log output saved to file "C:\Users\TN\AppData\Local\Syn
cthing\syncthing.log"
[monitor] 15:23:10 INFO: Starting syncthing
[JAVL5] 15:23:10 INFO: syncthing v0.14.39 "Dysprosium Dragonfly" (go1.9 windows-
amd64) teamcity@build.syncthing.net 2017-09-25 06:05:21 UTC
[JAVL5] 15:23:10 INFO: My ID: JAVL5EL-VV6LZ2H-2SONYVV-AZDNWVT-ZPOJ4Z2-IQJHTXJ-YR
UO3Q3-A7KUZQU
[JAVL5] 15:23:11 INFO: Single thread SHA256 performance is 318 MB/s using minio/
sha256-simd (215 MB/s using crypto/sha256).
[JAVL5] 15:23:11 INFO: Default folder created and/or linked to new config
[JAVL5] 15:23:11 FATAL: Config: EOF
[monitor] 15:23:11 INFO: Syncthing exited: exit status 1
[monitor] 15:23:12 INFO: Starting syncthing
[JAVL5] 15:23:12 INFO: syncthing v0.14.39 "Dysprosium Dragonfly" (go1.9 windows-
amd64) teamcity@build.syncthing.net 2017-09-25 06:05:21 UTC
[JAVL5] 15:23:12 INFO: My ID: JAVL5EL-VV6LZ2H-2SONYVV-AZDNWVT-ZPOJ4Z2-IQJHTXJ-YR
UO3Q3-A7KUZQU
[JAVL5] 15:23:13 INFO: Single thread SHA256 performance is 312 MB/s using minio/
sha256-simd (211 MB/s using crypto/sha256).
[JAVL5] 15:23:13 INFO: Default folder created and/or linked to new config
[JAVL5] 15:23:13 FATAL: Config: EOF
[monitor] 15:23:13 INFO: Syncthing exited: exit status 1
[monitor] 15:23:14 INFO: Starting syncthing
[JAVL5] 15:23:14 INFO: syncthing v0.14.39 "Dysprosium Dragonfly" (go1.9 windows-
amd64) teamcity@build.syncthing.net 2017-09-25 06:05:21 UTC
[JAVL5] 15:23:14 INFO: My ID: JAVL5EL-VV6LZ2H-2SONYVV-AZDNWVT-ZPOJ4Z2-IQJHTXJ-YR
UO3Q3-A7KUZQU
[JAVL5] 15:23:15 INFO: Single thread SHA256 performance is 315 MB/s using minio/
sha256-simd (213 MB/s using crypto/sha256).
[JAVL5] 15:23:15 INFO: Default folder created and/or linked to new config
[JAVL5] 15:23:15 FATAL: Config: EOF
[monitor] 15:23:15 INFO: Syncthing exited: exit status 1
[monitor] 15:23:16 INFO: Starting syncthing
[JAVL5] 15:23:16 INFO: syncthing v0.14.39 "Dysprosium Dragonfly" (go1.9 windows-
amd64) teamcity@build.syncthing.net 2017-09-25 06:05:21 UTC
[JAVL5] 15:23:16 INFO: My ID: JAVL5EL-VV6LZ2H-2SONYVV-AZDNWVT-ZPOJ4Z2-IQJHTXJ-YR
UO3Q3-A7KUZQU
[JAVL5] 15:23:17 INFO: Single thread SHA256 performance is 313 MB/s using minio/
sha256-simd (212 MB/s using crypto/sha256).
[JAVL5] 15:23:17 INFO: Default folder created and/or linked to new config
[JAVL5] 15:23:17 FATAL: Config: EOF
[monitor] 15:23:17 INFO: Syncthing exited: exit status 1
[monitor] 15:23:18 WARNING: 4 restarts in 7.9464545s; not retrying further

C:\Users\TN\Downloads\vasya\syncthing-windows-amd64-v0.14.39>

I tried to access syncthing settings then (C:\Users\TN\AppData\Local\syncthing). This directory contains 5 files: cert.pem, config.xml, key.pem, syncthing.exe (?!, but anyway), syncthing.log. The config.xml file is empty. Other files are not empty. Running syncthing.exe from this exact directory doesn't change anything, same error.

Version Information

Syncthing Version: v0.14.39
OS Version: Windows 7 (amd64 architecture)
Browser Version: N.A.

@AudriusButkevicius

This comment has been minimized.

Copy link
Member

commented Oct 18, 2017

Can you set env var STTRACE=config and run again?

@vn971

This comment has been minimized.

Copy link
Author

commented Oct 18, 2017

@AudriusButkevicius Thanks for the answer. Done:

Microsoft Windows [Version 6.1.7601]
(c) Корпорация Майкрософт (Microsoft Corp.), 2009. Все права защищены.

C:\Users\TN\AppData\Local\syncthing>set STTRACE=config

C:\Users\TN\AppData\Local\syncthing>syncthing.exe
[monitor] 2017/10/18 16:04:40.066442 monitor.go:58: INFO: Log output saved to fi
le "C:\Users\TN\AppData\Local\Syncthing\syncthing.log"
[monitor] 2017/10/18 16:04:40.109445 monitor.go:95: INFO: Starting syncthing
[JAVL5] 2017/10/18 16:04:40.140447 main.go:651: INFO: syncthing v0.14.39 "Dyspro
sium Dragonfly" (go1.9 windows-amd64) teamcity@build.syncthing.net 2017-09-25 06
:05:21 UTC
[JAVL5] 2017/10/18 16:04:40.180449 main.go:652: INFO: My ID: JAVL5EL-VV6LZ2H-2SO
NYVV-AZDNWVT-ZPOJ4Z2-IQJHTXJ-YRUO3Q3-A7KUZQU
[JAVL5] 2017/10/18 16:04:41.084501 sha256.go:92: INFO: Single thread SHA256 perf
ormance is 314 MB/s using minio/sha256-simd (214 MB/s using crypto/sha256).
[JAVL5] 2017/10/18 16:04:41.084501 main.go:1104: INFO: Default folder created an
d/or linked to new config
[JAVL5] 2017/10/18 16:04:41.086501 main.go:997: FATAL: Config: EOF
[monitor] 2017/10/18 16:04:41.093501 monitor.go:159: INFO: Syncthing exited: exi
t status 1
[monitor] 2017/10/18 16:04:42.093558 monitor.go:95: INFO: Starting syncthing
[JAVL5] 2017/10/18 16:04:42.130560 main.go:651: INFO: syncthing v0.14.39 "Dyspro
sium Dragonfly" (go1.9 windows-amd64) teamcity@build.syncthing.net 2017-09-25 06
:05:21 UTC
[JAVL5] 2017/10/18 16:04:42.170563 main.go:652: INFO: My ID: JAVL5EL-VV6LZ2H-2SO
NYVV-AZDNWVT-ZPOJ4Z2-IQJHTXJ-YRUO3Q3-A7KUZQU
[JAVL5] 2017/10/18 16:04:43.074614 sha256.go:92: INFO: Single thread SHA256 perf
ormance is 314 MB/s using minio/sha256-simd (214 MB/s using crypto/sha256).
[JAVL5] 2017/10/18 16:04:43.074614 main.go:1104: INFO: Default folder created an
d/or linked to new config
[JAVL5] 2017/10/18 16:04:43.076615 main.go:997: FATAL: Config: EOF
[monitor] 2017/10/18 16:04:43.083615 monitor.go:159: INFO: Syncthing exited: exi
t status 1
[monitor] 2017/10/18 16:04:44.083672 monitor.go:95: INFO: Starting syncthing
[JAVL5] 2017/10/18 16:04:44.136675 main.go:651: INFO: syncthing v0.14.39 "Dyspro
sium Dragonfly" (go1.9 windows-amd64) teamcity@build.syncthing.net 2017-09-25 06
:05:21 UTC
[JAVL5] 2017/10/18 16:04:44.183678 main.go:652: INFO: My ID: JAVL5EL-VV6LZ2H-2SO
NYVV-AZDNWVT-ZPOJ4Z2-IQJHTXJ-YRUO3Q3-A7KUZQU
[JAVL5] 2017/10/18 16:04:45.087730 sha256.go:92: INFO: Single thread SHA256 perf
ormance is 313 MB/s using minio/sha256-simd (214 MB/s using crypto/sha256).
[JAVL5] 2017/10/18 16:04:45.087730 main.go:1104: INFO: Default folder created an
d/or linked to new config
[JAVL5] 2017/10/18 16:04:45.089730 main.go:997: FATAL: Config: EOF
[monitor] 2017/10/18 16:04:45.096730 monitor.go:159: INFO: Syncthing exited: exi
t status 1
[monitor] 2017/10/18 16:04:46.096787 monitor.go:95: INFO: Starting syncthing
[JAVL5] 2017/10/18 16:04:46.145790 main.go:651: INFO: syncthing v0.14.39 "Dyspro
sium Dragonfly" (go1.9 windows-amd64) teamcity@build.syncthing.net 2017-09-25 06
:05:21 UTC
[JAVL5] 2017/10/18 16:04:46.191793 main.go:652: INFO: My ID: JAVL5EL-VV6LZ2H-2SO
NYVV-AZDNWVT-ZPOJ4Z2-IQJHTXJ-YRUO3Q3-A7KUZQU
[JAVL5] 2017/10/18 16:04:47.095844 sha256.go:92: INFO: Single thread SHA256 perf
ormance is 315 MB/s using minio/sha256-simd (214 MB/s using crypto/sha256).
[JAVL5] 2017/10/18 16:04:47.095844 main.go:1104: INFO: Default folder created an
d/or linked to new config
[JAVL5] 2017/10/18 16:04:47.097845 main.go:997: FATAL: Config: EOF
[monitor] 2017/10/18 16:04:47.104845 monitor.go:159: INFO: Syncthing exited: exi
t status 1
[monitor] 2017/10/18 16:04:48.104902 monitor.go:75: WARNING: 4 restarts in 7.995
4573s; not retrying further

C:\Users\TN\AppData\Local\syncthing>

// Please check that I've set up the environment variable correctly. I don't really know how to do that in Windows, just searched it up on the internet.

@vn971

This comment has been minimized.

Copy link
Author

commented Oct 18, 2017

Hm!
I've tried to delete this empty config.xml, and syncthing started working! So I guess it's all about how syncthing behaves with a broken config.xml, now that we know it.

@calmh

This comment has been minimized.

Copy link
Member

commented Oct 18, 2017

I think it's expected that it fails to start with an existing but broken config. The FATAL: Config: EOF implies that it was empty, but in a non-untuitive way. The INFO: Default folder created and/or linked to new config looks like it tried to fix it, but apparently unsuccessfully. That should probably be improved.

@vn971

This comment has been minimized.

Copy link
Author

commented Oct 18, 2017

@calmh yes, seems so. So how do you think, should syncthing ask to remove (or just move to a backup dir) current config.xml and replace it with a new one if it thinks that the old one is broken? If yes, I can leave the issue open. If not, I close it, right?

@AudriusButkevicius

This comment has been minimized.

Copy link
Member

commented Oct 18, 2017

So probably no, corrupt config is not something that should be handled automatically, as having no folders no devices silently would be quite a surprise. The right thing in this case is to fix it manually.

@vn971

This comment has been minimized.

Copy link
Author

commented Oct 18, 2017

@AudriusButkevicius actually yes, I agree. I guess logging could be a bit bitter (what exactly went wrong?). But other than that, it's correct as it is.

@vn971 vn971 closed this Oct 18, 2017

imsodin added a commit to imsodin/syncthing that referenced this issue Oct 19, 2017

st-review pushed a commit that referenced this issue Oct 21, 2017

@calmh calmh changed the title syncthing fails to start on Windows, empty `config.xml` Log output related to initial config loading is misleading Dec 3, 2017

@calmh calmh added the bug label Dec 3, 2017

@calmh calmh added this to the v0.14.40 milestone Dec 3, 2017

@syncthing syncthing locked and limited conversation to collaborators Oct 19, 2018

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
You can’t perform that action at this time.