Very weird data leakage error

This really needs more detail so it’s unfortunate the evidence is destroyed by the reset. :confused: It sounds like (potentially large?) files from folder A were offered to multiple other devices as belonging to folder B? Did any of it sync? Any recent config changes?

It’s obviously not clear how this would happen, and my imagination is failing me. If the database was bad on disk you should get checksum errors reading it. If it passed nonetheless and lied about the folder contents the scanner should get the same data and flag the files as deleted (because they don’t actually exist in this folder), yet that didn’t happen. If the database is fine and there’s an odd bug or race condition in sending the index data it’s incredibly unlikely this would happen for multiple devices at the same time. In other words, I don’t understand.

Of course, if there’s a CPU or RAM failure all bets are off, but then I’d also expect lots of odd crashes. See any of those? In my experience NASes are often the oddest and shoddiest machines hardware wise, but if syncthing is running fine normally I would think it’s mostly fine.

1 Like

Hi @lkwg82 ,

Do you have any symlinks in the directories B,C,D,E?

I assumed, but no.

1 Like

It is not destroyed. I copied the database for that.

All folders were offered to multiple devices. At least three out of >20 folders showed this behaviour. Not only large files, all kind, small files and folders were shared.

Recent config changes? Im not sure, will take a look into the backups.

I do have the old database and systemd logs.

This evening I dig deeper. Yesterday was repairing (parts).

1 Like

Excellent. I’d be interested in seeing the database + config, plus any crashes, with some note on at least some file that went awry.

This is the second instance of some kind of “data passing through Syncthing folder boundaries”: Huge issue with Syncthing data scrambling

First insight:

Got some panic, with panicing on reaching open file limit

Hint: I start syncthing with nice and ionice.

Sep 13 23:17:09 nas nice[2080]: panic: open /home/syncthing/.config/syncthing/index-v0.14.0.db/121148.ldb: too many open files
Sep 13 23:17:09 nas nice[2080]:         panic: open /home/syncthing/.config/syncthing/index-v0.14.0.db/121148.ldb: too many open files
Sep 13 23:17:09 nas nice[2080]: goroutine 1 [running]:
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/syncthing/lib/db.(*batch).flush(...)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/db/lowlevel.go:260
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/syncthing/lib/db.readWriteTransaction.close(0x1045880, 0xc017c5e190, 0x1052b80, 0xc0061daf00, 0xc017c5e1a0)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/db/transactions.go:97 +0xda
Sep 13 23:17:09 nas nice[2080]: panic(0xc81720, 0xc0045262a0)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/runtime/panic.go:522 +0x1b5
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/syncthing/lib/db.(*batch).flush(...)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/db/lowlevel.go:260
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/syncthing/lib/db.(*batch).checkFlush(0xc017c5e1a0)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/db/lowlevel.go:253 +0xf6
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/syncthing/lib/db.(*instance).dropDeviceFolder(0xc01c07e1a0, 0xc00010b3c0, 0x20, 0x20, 0xc0053f65b0, 0xb, 0x10, 0xc00efbce00)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/db/instance.go:438 +0x47c
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/syncthing/lib/db.(*FileSet).Drop(0xc00efbcdc0, 0x87f4a0c81f46d128, 0xd56fca663c7f6a98, 0x45274760b9779423, 0xe3da48b18280d0ea)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/db/set.go:113 +0x232
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/syncthing/lib/model.(*model).startFolderLocked(0xc001323340, 0xc000035710, 0xb, 0xc000035730, 0x10, 0x0, 0xc00023a660, 0x27, 0x2, 0xc004a80840, ...)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/model/model.go:272 +0xdd5
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/syncthing/lib/model.(*model).StartFolder(0xc001323340, 0xc000035710, 0xb)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/model/model.go:244 +0x14a
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/syncthing/lib/syncthing.(*App).startup(0xc0000da000, 0x42c30f, 0xc0025f8430)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/syncthing/syncthing.go:246 +0x1158
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/syncthing/lib/syncthing.(*App).Start.func1()
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/syncthing/syncthing.go:103 +0x33
Sep 13 23:17:09 nas nice[2080]: sync.(*Once).Do(0xc0000da100, 0xc002680fa0)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/sync/once.go:44 +0xb3
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/syncthing/lib/syncthing.(*App).Start(0xc0000da000)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/syncthing/syncthing.go:102 +0x56
Sep 13 23:17:09 nas nice[2080]: main.syncthingMain(0xc00003a2d0, 0x25, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/cmd/syncthing/main.go:646 +0x8ae
Sep 13 23:17:09 nas nice[2080]: main.main()
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/cmd/syncthing/main.go:390 +0x406
Sep 13 23:17:09 nas nice[2080]: goroutine 6 [syscall]:
Sep 13 23:17:09 nas nice[2080]: os/signal.signal_recv(0x0)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/runtime/sigqueue.go:139 +0x9c
Sep 13 23:17:09 nas nice[2080]: os/signal.loop()
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/os/signal/signal_unix.go:23 +0x22
Sep 13 23:17:09 nas nice[2080]: created by os/signal.init.0
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/os/signal/signal_unix.go:29 +0x41
Sep 13 23:17:09 nas nice[2080]: goroutine 7 [chan receive]:
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/notify.(*nonrecursiveTree).dispatch(0xc000070600, 0xc000070540)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syncthing/notify@v0.0.0-20190709140112-69c7a957d3e2/tree_nonrecursive.go:36 +0xb6
Sep 13 23:17:09 nas nice[2080]: created by github.com/syncthing/notify.newNonrecursiveTree
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syncthing/notify@v0.0.0-20190709140112-69c7a957d3e2/tree_nonrecursive.go:29 +0xdd
Sep 13 23:17:09 nas nice[2080]: goroutine 8 [chan receive]:
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/notify.(*nonrecursiveTree).internal(0xc000070600, 0xc0000705a0)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syncthing/notify@v0.0.0-20190709140112-69c7a957d3e2/tree_nonrecursive.go:81 +0x58
Sep 13 23:17:09 nas nice[2080]: created by github.com/syncthing/notify.newNonrecursiveTree
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syncthing/notify@v0.0.0-20190709140112-69c7a957d3e2/tree_nonrecursive.go:30 +0x109
Sep 13 23:17:09 nas nice[2080]: goroutine 11 [select]:
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/syncthing/lib/events.(*Logger).Serve(0xc0000707e0)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/events/events.go:260 +0x126
Sep 13 23:17:09 nas nice[2080]: created by github.com/syncthing/syncthing/lib/events.init.1
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/events/events.go:234 +0x5b
Sep 13 23:17:09 nas nice[2080]: goroutine 14 [select]:
Sep 13 23:17:09 nas nice[2080]: github.com/syndtr/goleveldb/leveldb/util.(*BufferPool).drain(0xc00018e0e0)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/util/buffer_pool.go:206 +0x121
Sep 13 23:17:09 nas nice[2080]: created by github.com/syndtr/goleveldb/leveldb/util.NewBufferPool
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/util/buffer_pool.go:237 +0x176
Sep 13 23:17:09 nas nice[2080]: goroutine 15 [select]:
Sep 13 23:17:09 nas nice[2080]: github.com/syndtr/goleveldb/leveldb.(*session).refLoop(0xc000264ff0)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/session_util.go:189 +0x5e3
Sep 13 23:17:09 nas nice[2080]: created by github.com/syndtr/goleveldb/leveldb.newSession
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/session.go:93 +0x2b5
Sep 13 23:17:09 nas nice[2080]: goroutine 51 [runnable]:
Sep 13 23:17:09 nas nice[2080]: github.com/syndtr/goleveldb/leveldb.(*DB).compactionError(0xc00024a1a0)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:106 +0x212
Sep 13 23:17:09 nas nice[2080]: created by github.com/syndtr/goleveldb/leveldb.openDB
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:142 +0x40f
Sep 13 23:17:09 nas nice[2080]: goroutine 52 [select]:
Sep 13 23:17:09 nas nice[2080]: github.com/syndtr/goleveldb/leveldb.(*DB).mpoolDrain(0xc00024a1a0)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_state.go:101 +0xf6
Sep 13 23:17:09 nas nice[2080]: created by github.com/syndtr/goleveldb/leveldb.openDB
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:143 +0x431
Sep 13 23:17:09 nas nice[2080]: goroutine 53 [runnable]:
Sep 13 23:17:09 nas nice[2080]: github.com/syndtr/goleveldb/leveldb.(*iComparer).Compare(0xc0001129a0, 0xc006025770, 0x48, 0x50, 0xc01b7ae380, 0x6a, 0xe0, 0x1)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/comparer.go:37 +0x1b5
Sep 13 23:17:09 nas nice[2080]: github.com/syndtr/goleveldb/leveldb/iterator.(*mergedIterator).next(0xc0003b8000, 0xc013fd8680)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/iterator/merged_iter.go:134 +0x16c
Sep 13 23:17:09 nas nice[2080]: github.com/syndtr/goleveldb/leveldb/iterator.(*mergedIterator).Next(0xc0003b8000, 0xc00044fb00)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/iterator/merged_iter.go:176 +0x15d
Sep 13 23:17:09 nas nice[2080]: github.com/syndtr/goleveldb/leveldb.(*tableCompactionBuilder).run(0xc0000ae8c0, 0xc0001011d8, 0x0, 0x0)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:439 +0x2e7
Sep 13 23:17:09 nas nice[2080]: github.com/syndtr/goleveldb/leveldb.(*DB).compactionTransact(0xc00024a1a0, 0xd75514, 0xb, 0x103bd00, 0xc0000ae8c0)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:185 +0x161
Sep 13 23:17:09 nas nice[2080]: github.com/syndtr/goleveldb/leveldb.(*DB).tableCompaction(0xc00024a1a0, 0xc000378000, 0xc0001f2400)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:577 +0x62b
Sep 13 23:17:09 nas nice[2080]: github.com/syndtr/goleveldb/leveldb.(*DB).tableAutoCompaction(0xc00024a1a0)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:633 +0x54
Sep 13 23:17:09 nas nice[2080]: github.com/syndtr/goleveldb/leveldb.(*DB).tCompaction(0xc00024a1a0)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:852 +0x2cc
Sep 13 23:17:09 nas nice[2080]: created by github.com/syndtr/goleveldb/leveldb.openDB
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:149 +0x585
Sep 13 23:17:09 nas nice[2080]: goroutine 54 [select]:
Sep 13 23:17:09 nas nice[2080]: github.com/syndtr/goleveldb/leveldb.(*DB).mCompaction(0xc00024a1a0)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:762 +0x12e
Sep 13 23:17:09 nas nice[2080]: created by github.com/syndtr/goleveldb/leveldb.openDB
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:150 +0x5a7
Sep 13 23:17:09 nas nice[2080]: goroutine 66 [chan receive]:
Sep 13 23:17:09 nas nice[2080]: main.setupSignalHandling.func1(0xc005249c80, 0xc0000da000)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/cmd/syncthing/main.go:672 +0x34
Sep 13 23:17:09 nas nice[2080]: created by main.setupSignalHandling
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/cmd/syncthing/main.go:671 +0xbf
Sep 13 23:17:09 nas nice[2080]: goroutine 67 [chan receive]:
Sep 13 23:17:09 nas nice[2080]: main.setupSignalHandling.func2(0xc00453bc20, 0xc0000da000)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/cmd/syncthing/main.go:682 +0x34
Sep 13 23:17:09 nas nice[2080]: created by main.setupSignalHandling
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/cmd/syncthing/main.go:681 +0x17a
Sep 13 23:17:09 nas nice[2080]: goroutine 68 [sleep]:
Sep 13 23:17:09 nas nice[2080]: runtime.goparkunlock(...)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/runtime/proc.go:307
Sep 13 23:17:09 nas nice[2080]: time.Sleep(0x2540be400)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/runtime/time.go:105 +0x159
Sep 13 23:17:09 nas nice[2080]: main.standbyMonitor(0xc0000da000)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/cmd/syncthing/main.go:761 +0x6b
Sep 13 23:17:09 nas nice[2080]: created by main.syncthingMain
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/cmd/syncthing/main.go:618 +0xb5a
Sep 13 23:17:09 nas nice[2080]: goroutine 69 [select]:
Sep 13 23:17:09 nas nice[2080]: main.autoUpgrade(0x10565e0, 0xc0003f6400, 0xc0000da000)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/cmd/syncthing/main.go:781 +0x135
Sep 13 23:17:09 nas nice[2080]: created by main.syncthingMain
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/cmd/syncthing/main.go:642 +0x9ef
Sep 13 23:17:09 nas nice[2080]: goroutine 70 [select]:
Sep 13 23:17:09 nas nice[2080]: github.com/thejerf/suture.(*Supervisor).Serve(0xc00480de00)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/thejerf/suture@v3.0.2+incompatible/supervisor.go:454 +0x350
Sep 13 23:17:09 nas nice[2080]: created by github.com/thejerf/suture.(*Supervisor).ServeBackground
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/pkg/mod/github.com/thejerf/suture@v3.0.2+incompatible/supervisor.go:407 +0x3f
Sep 13 23:17:09 nas nice[2080]: goroutine 71 [chan receive]:
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/syncthing/lib/events.(*bufferedSubscription).pollingLoop(0xc00025a1e0)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/events/events.go:441 +0x8d
Sep 13 23:17:09 nas nice[2080]: created by github.com/syncthing/syncthing/lib/events.NewBufferedSubscription
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/events/events.go:436 +0x157
Sep 13 23:17:09 nas nice[2080]: goroutine 72 [chan receive]:
Sep 13 23:17:09 nas nice[2080]: github.com/syncthing/syncthing/lib/events.(*bufferedSubscription).pollingLoop(0xc00025a280)
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/events/events.go:441 +0x8d
Sep 13 23:17:09 nas nice[2080]: created by github.com/syncthing/syncthing/lib/events.NewBufferedSubscription
Sep 13 23:17:09 nas nice[2080]:         /opt/tcagent/syncthing-1-work/174e136266f8a219/lib/events/events.go:436 +0x157
Sep 13 23:17:09 nas nice[2080]: goroutine 81 [IO wait]:
Sep 13 23:17:09 nas nice[2080]: internal/poll.runtime_pollWait(0x7ff502914f08, 0x72, 0xffffffffffffffff)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/runtime/netpoll.go:182 +0x56
Sep 13 23:17:09 nas nice[2080]: internal/poll.(*pollDesc).wait(0xc000119a18, 0x72, 0xe00, 0xe4e, 0xffffffffffffffff)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x9b
Sep 13 23:17:09 nas nice[2080]: internal/poll.(*pollDesc).waitRead(...)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/internal/poll/fd_poll_runtime.go:92
Sep 13 23:17:09 nas nice[2080]: internal/poll.(*FD).Read(0xc000119a00, 0xc00012e000, 0xe4e, 0xe4e, 0x0, 0x0, 0x0)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/internal/poll/fd_unix.go:169 +0x19b
Sep 13 23:17:09 nas nice[2080]: net.(*netFD).Read(0xc000119a00, 0xc00012e000, 0xe4e, 0xe4e, 0x203000, 0x7ff50291b588, 0xbf)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/net/fd_unix.go:202 +0x4f
Sep 13 23:17:09 nas nice[2080]: net.(*conn).Read(0xc0052c6668, 0xc00012e000, 0xe4e, 0xe4e, 0x0, 0x0, 0x0)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/net/net.go:177 +0x69
Sep 13 23:17:09 nas nice[2080]: crypto/tls.(*atLeastReader).Read(0xc0004577e0, 0xc00012e000, 0xe4e, 0xe4e, 0x67ed3598, 0x7, 0xc0000a5938)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/crypto/tls/conn.go:761 +0x60
Sep 13 23:17:09 nas nice[2080]: bytes.(*Buffer).ReadFrom(0xc0001df758, 0x10322a0, 0xc0004577e0, 0x409cf5, 0xc870e0, 0xd3ade0)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/bytes/buffer.go:207 +0xbd
Sep 13 23:17:09 nas nice[2080]: crypto/tls.(*Conn).readFromUntil(0xc0001df500, 0x1032e80, 0xc0052c6668, 0x5, 0xc0052c6668, 0x203000)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/crypto/tls/conn.go:783 +0xf8
Sep 13 23:17:09 nas nice[2080]: crypto/tls.(*Conn).readRecordOrCCS(0xc0001df500, 0xf3a400, 0xc0001df638, 0xc0000a5b88)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/crypto/tls/conn.go:590 +0x125
Sep 13 23:17:09 nas nice[2080]: crypto/tls.(*Conn).readRecord(...)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/crypto/tls/conn.go:558
Sep 13 23:17:09 nas nice[2080]: crypto/tls.(*Conn).Read(0xc0001df500, 0xc0053bc000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/crypto/tls/conn.go:1236 +0x137
Sep 13 23:17:09 nas nice[2080]: net/http.(*persistConn).Read(0xc000246120, 0xc0053bc000, 0x1000, 0x1000, 0xc0000a5c88, 0x404de5, 0xc005d77f20)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/net/http/transport.go:1526 +0x7b
Sep 13 23:17:09 nas nice[2080]: bufio.(*Reader).fill(0xc001476060)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/bufio/bufio.go:100 +0x10f
Sep 13 23:17:09 nas nice[2080]: bufio.(*Reader).Peek(0xc001476060, 0x1, 0x0, 0x0, 0x1, 0xc005520300, 0x0)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/bufio/bufio.go:138 +0x4f
Sep 13 23:17:09 nas nice[2080]: net/http.(*persistConn).readLoop(0xc000246120)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/net/http/transport.go:1679 +0x1a3
Sep 13 23:17:09 nas nice[2080]: created by net/http.(*Transport).dialConn
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/net/http/transport.go:1359 +0xae8
Sep 13 23:17:09 nas nice[2080]: goroutine 82 [select]:
Sep 13 23:17:09 nas nice[2080]: net/http.(*persistConn).writeLoop(0xc000246120)
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/net/http/transport.go:1978 +0x113
Sep 13 23:17:09 nas nice[2080]: created by net/http.(*Transport).dialConn
Sep 13 23:17:09 nas nice[2080]:         /usr/local/go/src/net/http/transport.go:1360 +0xb0d
Sep 13 23:17:09 nas systemd[1]: syncthing@syncthing.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Sep 13 23:17:09 nas systemd[1]: syncthing@syncthing.service: Failed with result 'exit-code'.
Sep 13 23:17:09 nas systemd[1]: syncthing@syncthing.service: Service hold-off time over, scheduling restart.
Sep 13 23:17:09 nas systemd[1]: syncthing@syncthing.service: Scheduled restart job, restart counter is at 2.
Sep 13 23:17:09 nas systemd[1]: Stopped Syncthing - Open Source Continuous File Synchronization for syncthing.
Sep 13 23:17:09 nas systemd[1]: Started Syncthing - Open Source Continuous File Synchronization for syncthing.

numbers of database files

# ll ~syncthing/.config/syncthing/index-v0.14.0.db.bogus/ | wc -l
1379

Could it be, that scanning the folders and upgrading the database led to a massive spike in filehandles which later crashed the process?

folders and numbers for each

df823f515b5027d47af7b69614a31a01  size=19G   files=2213    dirs=31
edb8e7456f0b4807476b5a1ff575842d  size=106G  files=2943    dirs=8
a0ddaa8d4cba5c2b4d6a43053ea5b4e6  size=4,5K  files=1       dirs=0
aca897a8bf2fbe9ca415e565ef64d600  size=34K   files=0       dirs=3
6adf1310436cde9eee0cc538193c0cff  size=2,3G  files=2609    dirs=277
da08d2c776e1379b73e564e551ef5094  size=207G  files=42898   dirs=1428
04db88a8c7ca9a2e6f8565c88f620547  size=12G   files=1346    dirs=4
ca6148ac266c3cb7ac712a0a319426ce  size=101M  files=1       dirs=2
f1e1eda79d38477b1781344b4fc7cf04  size=20G   files=305529  dirs=35339
4510183fe8c5aed45cd2229dee505ba6  size=11G   files=807     dirs=44
dc4b3e5c028afbb03da448031cddf08b  size=18G   files=3106    dirs=5251
86ea8dd474a84dd6044ff5d8eaf683e3  size=56G   files=2648    dirs=241
d0071f9ca8a7b8d7aa56ad1605955bc3  size=25K   files=0       dirs=1
6100f486988f56ca0507f7c3eb0349c8  size=25K   files=0       dirs=2
fde04fe7ff20e46d7ddedbb9800516ad  size=1,0K  files=0       dirs=2
8001120ab7ffcb399e6df53461982ec6  size=2,5G  files=2320    dirs=262
fdffec305ea73b97f2f9bd6458fe9122  size=17G   files=11347   dirs=482
7c132db0e600c97463ddf5168023190a  size=7,6G  files=2729    dirs=111
3c95dc0d5a455b3ae46a652029b163b6  size=486G  files=6898    dirs=11
dc06430607fbf593a7e400083b428d51  size=72M   files=26      dirs=7
279afc0b69fa094286567bcfb955855e  size=3,1G  files=408     dirs=4
87bfb8b249524fe5615e18b560a43206  size=694K  files=3       dirs=8
c045e42ba0713ed16a62980109ae0c4a  size=695K  files=0       dirs=443
d655ba4c3ad131917a6327bbaf32a422  size=427G  files=64284   dirs=2744
0978db7dea14d67b7b294680c0216731  size=163G  files=63919   dirs=8000
5b150b6b30996e5049c33a0ca3339a57  size=2,6G  files=94      dirs=13
4baf5da73b84b5bb0e00cacf9315368d  size=11G   files=6634    dirs=922
9286ed3bf89758277763a1fac945963f  size=41K   files=6       dirs=4
19758b7abc05a4238fed94d29a484d30  size=1,1G  files=160     dirs=8
0cb1a02082a8f0921f644fbe03f773e0  size=7,7G  files=2317    dirs=3415
ebcc05f8cc0dd8d3ddcf6bc61bbff11f  size=12G   files=7738    dirs=178
e47c4977e255c6ad00170805cdcd4768  size=68G   files=10753   dirs=5
fd501c4765cb5dde7958886f21adb458  size=14G   files=34959   dirs=6732
f8c91f571f399bcb2a65d7bff1c1b1cd  size=7,6G  files=9348    dirs=4016
2b807080d2d0b4840a944b2c8982ff33  size=34G   files=8309    dirs=4

I added a script anonymize.pl to anonymize the log output with the help of the config.xml.

(It maps internally and replaces with e.g. folder-id-12)

Panics aren’t optimal, clearly, but also shouldn’t cause what you’re describing. To debug this I really need to see the undoctored config and database.

The same panic occurred in connection with the other issue I linked above. Maybe it’s just a secondary effect of the underlying problem, but it seems connected (ok, n=2 isn’t particularly significant, but still).

Hopefully we’ll soon have two sets of dbs, configs and logs to see whether there’s any (the same) anomalies.

Same-ish, yes, as in out of fd:s. This one is apparently part of a reconfiguration (removing devices from a folder), other one was during normal operations. Of course panics when writing to the database isn’t great, but I’d hope it wouldn’t result in correct-seeming but wrong data…

Sure, should have added a modifier to the “same” - what I meant is that both time the database panic during writes. And yes, I agree that what ensues after is totally unexpected…

How can I send u the config confidentially?

And the database is around 2,5GB.

Absolutely. Do you have someplace you can upload it and pass a link in PM or so?

Make that the third time. In Epic mixup of files after disk restoration, I experienced something similar too (i.e. files from one share leaked into another).

Will there be an issue in the tracker for that?

Is there an explanation on how to reproduce this so that this can be expressed as an issue and fixed?

I’m not sure if @calmh will try to investigate. I shared with him the logs, database and the config.

I can try to reproduce there are some hints and like to coordinate the effort with an issue.