search

streamingfast / substreams-sink-kv

Substreams KV sink
Apache License 2.0
2 stars 5 forks source link

Data race on cursor #27

Open YaroShkvorets opened 1 year ago

YaroShkvorets commented 1 year ago

Looks like there is a potential data race scenario that could result in the sink writing incorrect cursor to the database. Hard to recreate but race detecter sees it:

go run -race . inject -e mainnet.eth.streamingfast.io:443 "badger3://$(pwd)/badger_data.db" ../../examples/wasm-query-service/substreams.yaml
==================
WARNING: DATA RACE
Read at 0x00c003bcf600 by goroutine 412:
  github.com/streamingfast/substreams-sink-kv/db.cursorToBytes()
      /Users/shkvo/github/Pinax/StreamingFast/substreams-sink-kv/db/cursor.go:38 +0xbe
  github.com/streamingfast/substreams-sink-kv/db.(*DB).WriteCursor()
      /Users/shkvo/github/Pinax/StreamingFast/substreams-sink-kv/db/cursor.go:30 +0x64
  github.com/streamingfast/substreams-sink-kv/sinker.(*KVSinker).Stop()
      /Users/shkvo/github/Pinax/StreamingFast/substreams-sink-kv/sinker/sinker.go:117 +0x11d
  github.com/streamingfast/substreams-sink-kv/sinker.New.func1()
      /Users/shkvo/github/Pinax/StreamingFast/substreams-sink-kv/sinker/sinker.go:74 +0xa0
  github.com/streamingfast/shutter.(*Shutter).Shutdown()
      /Users/shkvo/go/pkg/mod/github.com/streamingfast/shutter@v1.5.0/shutter.go:111 +0x174
  main.injectRunE.func1()
      /Users/shkvo/github/Pinax/StreamingFast/substreams-sink-kv/cmd/substreams-sink-kv/inject.go:142 +0x87
  github.com/streamingfast/shutter.(*Shutter).Shutdown()
      /Users/shkvo/go/pkg/mod/github.com/streamingfast/shutter@v1.5.0/shutter.go:111 +0x174
  main.injectRunE.func5()
      /Users/shkvo/github/Pinax/StreamingFast/substreams-sink-kv/cmd/substreams-sink-kv/inject.go:180 +0x3d

Previous write at 0x00c003bcf600 by goroutine 88:
  github.com/streamingfast/substreams-sink.NewCursor()
      /Users/shkvo/go/pkg/mod/github.com/streamingfast/substreams-sink@v0.0.0-20230403140748-db3b0d195289/types.go:18 +0x1065
  github.com/streamingfast/substreams-sink.(*Sinker).doRequest()
      /Users/shkvo/go/pkg/mod/github.com/streamingfast/substreams-sink@v0.0.0-20230403140748-db3b0d195289/sinker.go:268 +0xff8
  github.com/streamingfast/substreams-sink.(*Sinker).run()
      /Users/shkvo/go/pkg/mod/github.com/streamingfast/substreams-sink@v0.0.0-20230403140748-db3b0d195289/sinker.go:164 +0xbc4
  github.com/streamingfast/substreams-sink.(*Sinker).Start()
      /Users/shkvo/go/pkg/mod/github.com/streamingfast/substreams-sink@v0.0.0-20230403140748-db3b0d195289/sinker.go:114 +0x266
  github.com/streamingfast/substreams-sink-kv/sinker.(*KVSinker).Run()
      /Users/shkvo/github/Pinax/StreamingFast/substreams-sink-kv/sinker/sinker.go:147 +0x6aa
  github.com/streamingfast/substreams-sink-kv/sinker.(*KVSinker).Start()
      /Users/shkvo/github/Pinax/StreamingFast/substreams-sink-kv/sinker/sinker.go:109 +0x5c4
  main.injectRunE.func2()
      /Users/shkvo/github/Pinax/StreamingFast/substreams-sink-kv/cmd/substreams-sink-kv/inject.go:146 +0x64
maoueh commented 1 year ago

This seems to happen at shutdown of the whole stack, so I'll take a closer look.

The code around shutdown has been heavily refactored in v2 bump, I'll run again with race detection to see if it stills report the problem.

maoueh commented 1 year ago

Ok it actually finds other also now. I'll try to take time next week to dig deeper.