Same with RC-1, but now installed RC-3 without that issue. But such things never happen before.
Everything else was still in the folder, all the logs etc and all the full indexes. I restored the config v29 file and got back up and running. The config.xml had been fully recreated as if day one rather than was corrupt or unreadable
What happened is that on automatic upgrade the database not closed panic occurred. The logs before upgrade look normal up until the missing terminations lines and instead the panic happens. Then the startup after upgrade creates the new config:
[start] 15:39:38 INFO: syncthing v1.4.0-rc.3 "Fermium Flea" (go1.13.7 windows-amd64) firstname.lastname@example.org 2020-02-12 11:00:17 UTC [start] 15:39:38 INFO: Default folder created and/or linked to new config [start] 15:39:38 INFO: Default config saved. Edit ... to taste (with Syncthing stopped) or use the GUI
This is entirely misterious to me: If the panic somehow corrupted the config that would result in an error on subsequent start. So the panic has to entirely wipe the config and I don’t see why that should happen. Also the config version update seems like a good candidate for creating the problem, but that’s neither happening from rc 2 to 3 nor should it be influenced by a panic in the previous version.
I believe https://github.com/syncthing/syncthing/pull/6329 would address this panic, as the following goroutine points at the connections service stalling:
goroutine 58 [select]: net/http.(*Transport).getConn(0xc000114dc0, 0xc00e40dbc0, 0x0, 0xc000f4f180, 0x5, 0xc0085aca80, 0x1b, 0x0, 0x0, 0x0, ...) C:/Go/src/net/http/transport.go:1234 +0x55a net/http.(*Transport).roundTrip(0xc000114dc0, 0xc0000d8e00, 0xc00e40db90, 0xc00b17f2dc, 0xc00b17f2d0) C:/Go/src/net/http/transport.go:522 +0x60a net/http.(*Transport).RoundTrip(0xc000114dc0, 0xc0000d8e00, 0xc000114dc0, 0xbf8924e8c3506448, 0x141a121a6249) C:/Go/src/net/http/roundtrip.go:17 +0x3c net/http.send(0xc0000d8800, 0x10f3380, 0xc000114dc0, 0xbf8924e8c3506448, 0x141a121a6249, 0x16e24a0, 0xc0000e9a18, 0xbf8924e8c3506448, 0x1, 0x0) C:/Go/src/net/http/client.go:250 +0x44a net/http.(*Client).send(0xc000413530, 0xc0000d8800, 0xbf8924e8c3506448, 0x141a121a6249, 0x16e24a0, 0xc0000e9a18, 0x0, 0x1, 0xe061c0) C:/Go/src/net/http/client.go:174 +0x101 net/http.(*Client).do(0xc000413530, 0xc0000d8800, 0x0, 0x0, 0x0) C:/Go/src/net/http/client.go:641 +0x3d5 net/http.(*Client).Do(...) C:/Go/src/net/http/client.go:509 net/http.(*Client).Get(0xc000413530, 0xc000f4f180, 0x6a, 0xc0002a4998, 0xc000f4f180, 0x6a) C:/Go/src/net/http/client.go:398 +0xc2 github.com/syncthing/syncthing/lib/discover.(*idCheckingHTTPClient).Get(0xc000413560, 0xc000f4f180, 0x6a, 0x6, 0xc0003d6ce8, 0x3f) C:/BuildAgent/work/174e136266f8a219/lib/discover/global.go:366 +0x52 github.com/syncthing/syncthing/lib/discover.(*globalClient).Lookup(0xc0000fe680, 0x72fa3f2cb158931d, 0xeb3ba4104dd4cc3e, 0x817028ecce60a7ef, 0xfcf82b85d4332171, 0x0, 0x0, 0x4, 0xbf890f58e6cf48d0, 0x51598b615) C:/BuildAgent/work/174e136266f8a219/lib/discover/global.go:159 +0x1b2 github.com/syncthing/syncthing/lib/discover.(*cachingMux).Lookup(0xc0001f92c0, 0x72fa3f2cb158931d, 0xeb3ba4104dd4cc3e, 0x817028ecce60a7ef, 0xfcf82b85d4332171, 0x0, 0x0, 0x0, 0x1, 0xc00250fcd0) C:/BuildAgent/work/174e136266f8a219/lib/discover/cache.go:102 +0x925 github.com/syncthing/syncthing/lib/connections.(*service).connect(0xc0004005a0, 0x1106600, 0xc00005f100) C:/BuildAgent/work/174e136266f8a219/lib/connections/service.go:383 +0x1fea github.com/syncthing/syncthing/lib/util.AsService.func1(0x1106600, 0xc00005f100, 0xc0003bc8a0, 0xc00035ff88) C:/BuildAgent/work/174e136266f8a219/lib/util/utils.go:183 +0x40 github.com/syncthing/syncthing/lib/util.(*service).Serve(0xc0003c8a20) C:/BuildAgent/work/174e136266f8a219/lib/util/utils.go:247 +0x149 github.com/thejerf/suture.(*Supervisor).runService.func1(0xc0004003c0, 0x1, 0x2c0c0e8, 0xc0003c8a20) C:/BuildAgentemail@example.com+incompatible/supervisor.go:600 +0x57 created by github.com/thejerf/suture.(*Supervisor).runService C:/BuildAgentfirstname.lastname@example.org+incompatible/supervisor.go:588 +0x62
As a thought, in both cases where my configs were wiped, they both ran under synctrazor. I wonder if maybe the wrapper is having a detrimental affect?
Synctrazor has nothing to do with it. I never use that on my clients, but it still happened to me.
It has to happen in a certain situation. Because on the Windows 10 computer on which this occurred for the first time with v1.4.0-rc1, an automatic update was carried out today without incidents. It also makes no difference to the manually triggered update if a notice label appears at the top that a newer version is available and can be updated.
It could be that a sync process is currently in progress and the software wants to start the update, so that some timing may not fit.
I’ve never had that in all the versions. The question is, what has changed from v1.3.4 to v1.4.0, what can trigger that.
@Andy Please check any old logs or panic logs for occurrences of
panic: database is closed. If that also occurs for you when the config is wiped, then it’s at the very least likely that the panic is connected/the cause.
I think, all the log before of the update is deleted. In the currently log after the update I didn’t find anything with “panic: database is closed” or “panic” or “database” or such words.
I doesn´t found any file named config v29, whats about this file?
What I found related to database issues was in the “syncthing.0.log”
[5FX6E] 08:55:55 WARNING: Database failed to stop within 10s
[5FX6E] 13:27:38 WARNING: Database failed to stop within 10s
[5FX6E] 13:41:13 WARNING: Database failed to stop within 10s
[5FX6E] 17:06:07 WARNING: Database failed to stop within 10s
and was with the today running syncthing v1.4.0-rc.2
The upgrade comes:
[5FX6E] 17:04:51 INFO: Automatic upgrade (current “v1.4.0-rc.2” < latest “v1.4.0-rc.3”)
[5FX6E] 17:04:57 WARNING: Automatically upgraded to version “v1.4.0-rc.3”. Restarting in 1 minute.
Windows doesn’t have atomic renames, so config update there is three step: write to temp file, delete old config file, rename new config in place. When the config format updates (such as in 1.4.0) we also save a copy as config.xml.something, where something is currently v29. With exceptional bad luck a crash precisely between the delete and rename could lose the config (on Windows). It’s a rather small window of time, but I guess with a database panic that also happens precisely during startup and this happening repeatedly it’s possible. The config would still be there but in a hidden temp file.
Shouldn’t a goroutine writing the config then appear in the panic trace? I looked for that in @terry’s panic trace and couldn’t find it.
Probably? I didn’t look closer and have no better ideas.
Pitty, I hoped there is some reason why it wouldn’t show. Would have been a plausible and fixable reason.
I grepped the crash reports for
wrapper.Save, there aren’t any. No idea.
Are all issues maybe database related? As you mentioned, you modify the structur or others at the database.
Where exactly? I’ll see if I can find it, which seems like it would confirm at least part of that theory…
Same place as the config, named
*number* is a random 10 digit number.
However there’s improvements for shutdowns in the newer RCs, so I hope the config clearing was related and thus just won’t come up anymore.
Any results or problems would be good to message to
to have a closed overview.
Thanks for letting us know it works - it’s nice to also hear the positive outcomes
I’d actually appreciate if updates regarding this problem (or not having this problem with new versions) could stay in here, otherwise it clutters the forum front page a bit. I’ll merge those threads.
Two automatic updates and one manual startet update to v1.4.0-rc.4 on 3 Windows 10 computers without problem.
All updates to v1.4.0-rc.5 on 3 Windows 10 computers without problem.