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.
I think coordinate the effort with a forum thread, when it’s clear what the issue is, you can open an issue.
1 Like
I’m currently trying to reproduce it.
This is a sample scenario.