core: ensure memcached Seek operation is properly cancelled

PR #2495 is not enought, the problem is reproduced during dump restore
with the stacktrace attached down below.

The reason is that SeekAsync starts goroutine that performs Seek
operation over private MemCachedStore. The goroutine iterates over
MemCachedStore's map without holding the lock (it's OK, because it's
private), whereas the main thread continues invocation and
performs writes to the same map. To fix that ic.Exec() needs to
wait until all goroutines are properly exited.

```
2022-05-17T08:34:50.430+0300	INFO	persisted to disk	{"blocks": 632, "keys": 16546, "headerHeight": 54091, "blockHeight": 54091, "took": "57.904387ms"}
fatal error: concurrent map iteration and map write

goroutine 218853 [running]:
runtime.throw({0xf56a31, 0x614968})
	runtime/panic.go:1198 +0x71 fp=0xc0000ceae0 sp=0xc0000ceab0 pc=0x4357b1
runtime.mapiternext(0x0)
	runtime/map.go:858 +0x4eb fp=0xc0000ceb50 sp=0xc0000ceae0 pc=0x40f82b
runtime.mapiterinit(0xc0000cec18, 0xc00359ca40, 0x1a)
	runtime/map.go:848 +0x236 fp=0xc0000ceb70 sp=0xc0000ceb50 pc=0x40f2f6
github.com/nspcc-dev/neo-go/pkg/core/storage.(*MemCachedStore).prepareSeekMemSnapshot(0xc005315680, {{0xc00359ca40, 0x1a, 0x1a}, {0x0, 0x0, 0x0}, 0x0})
	github.com/nspcc-dev/neo-go/pkg/core/storage/memcached_store.go:209 +0x24a fp=0xc0000ced88 sp=0xc0000ceb70 pc=0x823fca
github.com/nspcc-dev/neo-go/pkg/core/storage.(*MemCachedStore).Seek(0xd94ac0, {{0xc00359ca40, 0x1a, 0x1a}, {0x0, 0x0, 0x0}, 0x0}, 0x20)
	github.com/nspcc-dev/neo-go/pkg/core/storage/memcached_store.go:156 +0x9b fp=0xc0000cee20 sp=0xc0000ced88 pc=0x82369b
github.com/nspcc-dev/neo-go/pkg/core/storage.performSeek({0x11c3330, 0xc002240dc0}, {0x11cb258, 0xc005315680}, {0x0, 0x0, 0x1}, {{0xc00359ca40, 0x1a, 0x1a}, ...}, ...)
	github.com/nspcc-dev/neo-go/pkg/core/storage/memcached_store.go:304 +0x4b7 fp=0xc0000cef00 sp=0xc0000cee20 pc=0x824a37
github.com/nspcc-dev/neo-go/pkg/core/storage.(*MemCachedStore).SeekAsync.func1()
	github.com/nspcc-dev/neo-go/pkg/core/storage/memcached_store.go:176 +0x16c fp=0xc0000cefe0 sp=0xc0000cef00 pc=0x823b8c
runtime.goexit()
	runtime/asm_amd64.s:1581 +0x1 fp=0xc0000cefe8 sp=0xc0000cefe0 pc=0x468a41
created by github.com/nspcc-dev/neo-go/pkg/core/storage.(*MemCachedStore).SeekAsync
	github.com/nspcc-dev/neo-go/pkg/core/storage/memcached_store.go:175 +0x1f6

goroutine 1 [runnable]:
github.com/nspcc-dev/neo-go/pkg/core/mpt.MapToMPTBatch.func1(0x4, 0x0)
	github.com/nspcc-dev/neo-go/pkg/core/mpt/batch.go:28 +0x95
sort.doPivot_func({0xc000457878, 0xc003305bc0}, 0x0, 0x1a)
	sort/zfuncversion.go:121 +0x46a
sort.quickSort_func({0xc000457878, 0xc003305bc0}, 0xc001014d20, 0x0, 0xc003304ff0)
	sort/zfuncversion.go:143 +0x85
sort.Slice({0xd94800, 0xc001014d20}, 0x1a)
	sort/slice.go:20 +0x9f
github.com/nspcc-dev/neo-go/pkg/core/mpt.MapToMPTBatch(0xc003304ff0)
	github.com/nspcc-dev/neo-go/pkg/core/mpt/batch.go:28 +0x2e7
github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).storeBlock(0xc000400280, 0xc000f178c0, 0xc005a04370)
	github.com/nspcc-dev/neo-go/pkg/core/blockchain.go:1136 +0xfef
github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).AddBlock(0xc000400280, 0xc000f178c0)
	github.com/nspcc-dev/neo-go/pkg/core/blockchain.go:893 +0x755
github.com/nspcc-dev/neo-go/pkg/core/chaindump.Restore({0x11c3528, 0xc000400280}, 0xc350, 0x0, 0x4c221, 0xc000458710)
	github.com/nspcc-dev/neo-go/pkg/core/chaindump/dump.go:73 +0x2ca
github.com/nspcc-dev/neo-go/cli/server.restoreDB(0xc000410000)
	github.com/nspcc-dev/neo-go/cli/server/server.go:381 +0xcfa
github.com/urfave/cli.HandleAction({0xdbbfa0, 0x10a1078}, 0x7)
	github.com/urfave/cli@v1.22.5/app.go:524 +0xa8
github.com/urfave/cli.Command.Run({{0xf32b10, 0x7}, {0x0, 0x0}, {0x0, 0x0, 0x0}, {0xf4a41d, 0x1c}, {0x0, ...}, ...}, ...)
	github.com/urfave/cli@v1.22.5/command.go:173 +0x652
github.com/urfave/cli.(*App).RunAsSubcommand(0xc0001f7880, 0xc0001adce0)
	github.com/urfave/cli@v1.22.5/app.go:405 +0x9ec
github.com/urfave/cli.Command.startApp({{0xf2e982, 0x2}, {0x0, 0x0}, {0x0, 0x0, 0x0}, {0xf41af9, 0x16}, {0x0, ...}, ...}, ...)
	github.com/urfave/cli@v1.22.5/command.go:372 +0x6e9
github.com/urfave/cli.Command.Run({{0xf2e982, 0x2}, {0x0, 0x0}, {0x0, 0x0, 0x0}, {0xf41af9, 0x16}, {0x0, ...}, ...}, ...)
	github.com/urfave/cli@v1.22.5/command.go:102 +0x808
github.com/urfave/cli.(*App).Run(0xc0001f76c0, {0xc00012e000, 0x8, 0x8})
	github.com/urfave/cli@v1.22.5/app.go:277 +0x705
main.main()
	./main.go:19 +0x33

goroutine 66 [select]:
github.com/syndtr/goleveldb/leveldb/util.(*BufferPool).drain(0xc00027e1c0)
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/util/buffer_pool.go:209 +0xcd
created by github.com/syndtr/goleveldb/leveldb/util.NewBufferPool
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/util/buffer_pool.go:240 +0x19b

goroutine 67 [select]:
github.com/syndtr/goleveldb/leveldb.(*session).refLoop(0xc0002441e0)
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/session_util.go:189 +0x5bb
created by github.com/syndtr/goleveldb/leveldb.newSession
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/session.go:93 +0x2de

goroutine 85 [select]:
github.com/syndtr/goleveldb/leveldb.(*DB).compactionError(0xc0001f7a40)
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/db_compaction.go:91 +0x15e
created by github.com/syndtr/goleveldb/leveldb.openDB
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/db.go:148 +0x4ef

goroutine 86 [select]:
github.com/syndtr/goleveldb/leveldb.(*DB).mpoolDrain(0xc0001f7a40)
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/db_state.go:101 +0xae
created by github.com/syndtr/goleveldb/leveldb.openDB
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/db.go:149 +0x531

goroutine 87 [runnable]:
github.com/syndtr/goleveldb/leveldb.(*compaction).shouldStopBefore(0xc001787440, {0xc001890720, 0x29, 0x30})
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/session_compaction.go:272 +0x10a
github.com/syndtr/goleveldb/leveldb.(*tableCompactionBuilder).run(0xc0001ca140, 0xc002039638)
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/db_compaction.go:461 +0x565
github.com/syndtr/goleveldb/leveldb.(*DB).compactionTransact(0xc0001f7a40, {0xf369f0, 0xb}, {0x11b9b60, 0xc0001ca140})
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/db_compaction.go:186 +0x22f
github.com/syndtr/goleveldb/leveldb.(*DB).tableCompaction(0xc0001f7a40, 0xc001787440, 0x0)
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/db_compaction.go:580 +0xa30
github.com/syndtr/goleveldb/leveldb.(*DB).tableAutoCompaction(0xc0001f7a40)
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/db_compaction.go:644 +0x39
github.com/syndtr/goleveldb/leveldb.(*DB).tCompaction(0xc0001f7a40)
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/db_compaction.go:863 +0x43b
created by github.com/syndtr/goleveldb/leveldb.openDB
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/db.go:155 +0x5a7

goroutine 88 [select]:
github.com/syndtr/goleveldb/leveldb.(*DB).mCompaction(0xc0001f7a40)
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/db_compaction.go:773 +0x119
created by github.com/syndtr/goleveldb/leveldb.openDB
	github.com/syndtr/goleveldb@v1.0.1-0.20210305035536-64b5b1c73954/leveldb/db.go:156 +0x5e9

goroutine 78 [select]:
github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).Run(0xc000400280)
	github.com/nspcc-dev/neo-go/pkg/core/blockchain.go:615 +0x185
created by github.com/nspcc-dev/neo-go/cli/server.initBCWithMetrics
	github.com/nspcc-dev/neo-go/cli/server/server.go:217 +0x23d

goroutine 79 [IO wait]:
internal/poll.runtime_pollWait(0x7ffb00b2aad8, 0x72)
	runtime/netpoll.go:229 +0x89
internal/poll.(*pollDesc).wait(0xc00012e180, 0x4, 0x0)
	internal/poll/fd_poll_runtime.go:84 +0x32
internal/poll.(*pollDesc).waitRead(...)
	internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Accept(0xc00012e180)
	internal/poll/fd_unix.go:402 +0x22c
net.(*netFD).accept(0xc00012e180)
	net/fd_unix.go:173 +0x35
net.(*TCPListener).accept(0xc000280090)
	net/tcpsock_posix.go:140 +0x28
net.(*TCPListener).Accept(0xc000280090)
	net/tcpsock.go:262 +0x3d
net/http.(*Server).Serve(0xc00027e380, {0x11bd4a8, 0xc000280090})
	net/http/server.go:3001 +0x394
net/http.(*Server).ListenAndServe(0xc00027e380)
	net/http/server.go:2930 +0x7d
github.com/nspcc-dev/neo-go/pkg/network/metrics.(*Service).Start(0xc000097d10)
	github.com/nspcc-dev/neo-go/pkg/network/metrics/metrics.go:29 +0x115
created by github.com/nspcc-dev/neo-go/cli/server.initBCWithMetrics
	github.com/nspcc-dev/neo-go/cli/server/server.go:218 +0x285

goroutine 9 [syscall]:
os/signal.signal_recv()
	runtime/sigqueue.go:169 +0x98
os/signal.loop()
	os/signal/signal_unix.go:24 +0x19
created by os/signal.Notify.func1.1
	os/signal/signal.go:151 +0x2c

goroutine 8 [select]:
github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).notificationDispatcher(0xc000400280)
	github.com/nspcc-dev/neo-go/pkg/core/blockchain.go:739 +0x2e7
created by github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).Run
	github.com/nspcc-dev/neo-go/pkg/core/blockchain.go:612 +0xe5

goroutine 10 [chan receive]:
github.com/nspcc-dev/neo-go/cli/server.newGraceContext.func1()
	github.com/nspcc-dev/neo-go/cli/server/server.go:117 +0x28
created by github.com/nspcc-dev/neo-go/cli/server.newGraceContext
	github.com/nspcc-dev/neo-go/cli/server/server.go:116 +0xde
```
This commit is contained in:
Anna Shaleva 2022-05-17 08:59:48 +03:00 committed by Anna Shaleva
parent 15e4d2a4ef
commit b66f666267
2 changed files with 13 additions and 2 deletions

View file

@ -195,7 +195,14 @@ func storageFind(ic *interop.Context) error {
seekres := ic.DAO.SeekAsync(ctx, stc.ID, storage.SeekRange{Prefix: prefix})
item := istorage.NewIterator(seekres, prefix, opts)
ic.VM.Estack().PushItem(stackitem.NewInterop(item))
ic.RegisterCancelFunc(cancel)
ic.RegisterCancelFunc(func() {
cancel()
// Underlying persistent store is likely to be a private MemCachedStore. Thus,
// to avoid concurrent map iteration and map write we need to wait until internal
// seek goroutine is finished, because it can access underlying persistent store.
for range seekres {
}
})
return nil
}

View file

@ -969,7 +969,11 @@ func (n *NEO) getAllCandidatesCall(ic *interop.Context, _ []stackitem.Item) stac
opts := istorage.FindRemovePrefix | istorage.FindDeserialize | istorage.FindPick1
item := istorage.NewIterator(filteredRes, prefix, int64(opts))
ic.RegisterCancelFunc(cancel)
ic.RegisterCancelFunc(func() {
cancel()
for range seekres {
}
})
return stackitem.NewInterop(item)
}