core package tests exhibit data race

[piersy]

System information

Geth version:

Geth
Version: 1.9.25-stable
Git Commit: e7872729012a4871397307b12cc3f4772ffcbec6
Architecture: amd64
Protocol Versions: [65 64 63]
Go Version: go1.14.7
Operating System: linux
GOPATH=/home/piersy/go
GOROOT=go

OS & Version: Linux Ubuntu 20.04.2 LTS (Focal Fossa)

Expected behaviour

Tests should not exhibit data races.

Actual behaviour

Tests exhibit data races

Steps to reproduce the behaviour

go test -p 1 -race ./core

Backtrace

go test -p 1 -race ./core
{"pc":0,"op":88,"gas":"0x7148","gasCost":"0x2","memory":"0x","memSize":0,"stack":[],"returnStack":[],"returnData":"0x","depth":1,"refund":0,"opName":"PC","error":""}
{"pc":1,"op":255,"gas":"0x7146","gasCost":"0x1388","memory":"0x","memSize":0,"stack":["0x0"],"returnStack":[],"returnData":"0x","depth":1,"refund":24000,"opName":"SELFDESTRUCT","error":""}
{"output":"","gasUsed":"0x138a","time":13170359}
{"pc":0,"op":116,"gas":"0x13498","gasCost":"0x3","memory":"0x","memSize":0,"stack":[],"returnStack":[],"returnData":"0x","depth":1,"refund":0,"opName":"PUSH21","error":""}
{"pc":22,"op":96,"gas":"0x13495","gasCost":"0x3","memory":"0x","memSize":0,"stack":["0x600360035560046004556158ff6000526002601ef3"],"returnStack":[],"returnData":"0x","depth":1,"refund":0,"opName":"PUSH1","error":""}
{"pc":24,"op":82,"gas":"0x13492","gasCost":"0x6","memory":"0x0000000000000000000000000000000000000000000000000000000000000000","memSize":32,"stack":["0x600360035560046004556158ff6000526002601ef3","0x0"],"returnStack":[],"returnData":"0x","depth":1,"refund":0,"opName":"MSTORE","error":""}
{"pc":25,"op":96,"gas":"0x1348c","gasCost":"0x3","memory":"0x0000000000000000000000600360035560046004556158ff6000526002601ef3","memSize":32,"stack":[],"returnStack":[],"returnData":"0x","depth":1,"refund":0,"opName":"PUSH1","error":""}
{"pc":27,"op":96,"gas":"0x13489","gasCost":"0x3","memory":"0x0000000000000000000000600360035560046004556158ff6000526002601ef3","memSize":32,"stack":["0x0"],"returnStack":[],"returnData":"0x","depth":1,"refund":0,"opName":"PUSH1","error":""}
{"pc":29,"op":96,"gas":"0x13486","gasCost":"0x3","memory":"0x0000000000000000000000600360035560046004556158ff6000526002601ef3","memSize":32,"stack":["0x0","0x15"],"returnStack":[],"returnData":"0x","depth":1,"refund":0,"opName":"PUSH1","error":""}
{"pc":31,"op":96,"gas":"0x13483","gasCost":"0x3","memory":"0x0000000000000000000000600360035560046004556158ff6000526002601ef3","memSize":32,"stack":["0x0","0x15","0xb"],"returnStack":[],"returnData":"0x","depth":1,"refund":0,"opName":"PUSH1","error":""}
{"pc":33,"op":245,"gas":"0x13480","gasCost":"0x7d06","memory":"0x0000000000000000000000600360035560046004556158ff6000526002601ef3","memSize":32,"stack":["0x0","0x15","0xb","0x0"],"returnStack":[],"returnData":"0x","depth":1,"refund":0,"opName":"CREATE2","error":""}
{"pc":0,"op":96,"gas":"0xb49d","gasCost":"0x3","memory":"0x","memSize":0,"stack":[],"returnStack":[],"returnData":"0x","depth":2,"refund":0,"opName":"PUSH1","error":""}
{"pc":2,"op":96,"gas":"0xb49a","gasCost":"0x3","memory":"0x","memSize":0,"stack":["0x3"],"returnStack":[],"returnData":"0x","depth":2,"refund":0,"opName":"PUSH1","error":""}
{"pc":4,"op":85,"gas":"0xb497","gasCost":"0x4e20","memory":"0x","memSize":0,"stack":["0x3","0x3"],"returnStack":[],"returnData":"0x","depth":2,"refund":0,"opName":"SSTORE","error":""}
{"pc":5,"op":96,"gas":"0x6677","gasCost":"0x3","memory":"0x","memSize":0,"stack":[],"returnStack":[],"returnData":"0x","depth":2,"refund":0,"opName":"PUSH1","error":""}
{"pc":7,"op":96,"gas":"0x6674","gasCost":"0x3","memory":"0x","memSize":0,"stack":["0x4"],"returnStack":[],"returnData":"0x","depth":2,"refund":0,"opName":"PUSH1","error":""}
{"pc":9,"op":85,"gas":"0x6671","gasCost":"0x4e20","memory":"0x","memSize":0,"stack":["0x4","0x4"],"returnStack":[],"returnData":"0x","depth":2,"refund":0,"opName":"SSTORE","error":""}
{"pc":10,"op":97,"gas":"0x1851","gasCost":"0x3","memory":"0x","memSize":0,"stack":[],"returnStack":[],"returnData":"0x","depth":2,"refund":0,"opName":"PUSH2","error":""}
{"pc":13,"op":96,"gas":"0x184e","gasCost":"0x3","memory":"0x","memSize":0,"stack":["0x58ff"],"returnStack":[],"returnData":"0x","depth":2,"refund":0,"opName":"PUSH1","error":""}
{"pc":15,"op":82,"gas":"0x184b","gasCost":"0x6","memory":"0x0000000000000000000000000000000000000000000000000000000000000000","memSize":32,"stack":["0x58ff","0x0"],"returnStack":[],"returnData":"0x","depth":2,"refund":0,"opName":"MSTORE","error":""}
{"pc":16,"op":96,"gas":"0x1845","gasCost":"0x3","memory":"0x00000000000000000000000000000000000000000000000000000000000058ff","memSize":32,"stack":[],"returnStack":[],"returnData":"0x","depth":2,"refund":0,"opName":"PUSH1","error":""}
{"pc":18,"op":96,"gas":"0x1842","gasCost":"0x3","memory":"0x00000000000000000000000000000000000000000000000000000000000058ff","memSize":32,"stack":["0x2"],"returnStack":[],"returnData":"0x","depth":2,"refund":0,"opName":"PUSH1","error":""}
{"pc":20,"op":243,"gas":"0x183f","gasCost":"0x0","memory":"0x00000000000000000000000000000000000000000000000000000000000058ff","memSize":32,"stack":["0x2","0x1e"],"returnStack":[],"returnData":"0x","depth":2,"refund":0,"opName":"RETURN","error":""}
{"pc":34,"op":0,"gas":"0x198c","gasCost":"0x0","memory":"0x0000000000000000000000600360035560046004556158ff6000526002601ef3","memSize":32,"stack":["0x3f7691a1d75e77494aa15f3873d6d85e6c2e5e1e"],"returnStack":[],"returnData":"0x","depth":1,"refund":0,"opName":"STOP","error":""}
{"output":"","gasUsed":"0x11b0c","time":1972820}
{"pc":0,"op":88,"gas":"0x7148","gasCost":"0x2","memory":"0x","memSize":0,"stack":[],"returnStack":[],"returnData":"0x","depth":1,"refund":0,"opName":"PC","error":""}
{"pc":1,"op":255,"gas":"0x7146","gasCost":"0x1388","memory":"0x","memSize":0,"stack":["0x0"],"returnStack":[],"returnData":"0x","depth":1,"refund":24000,"opName":"SELFDESTRUCT","error":""}
{"output":"","gasUsed":"0x138a","time":1973803}
{"output":"","gasUsed":"0x0","time":1638}
==================
WARNING: DATA RACE
Write at 0x00c01ccfe29a by goroutine 306:
  testing.(*common).FailNow()
      /usr/local/go/src/testing/testing.go:697 +0x4c
  testing.(*common).Fatal()
      /usr/local/go/src/testing/testing.go:766 +0x89
  github.com/ethereum/go-ethereum/core.(*testChainIndexBackend).Process()
      /home/piersy/projects/go-ethereum/core/chain_indexer_test.go:227 +0x2ec
  github.com/ethereum/go-ethereum/core.(*ChainIndexer).processSection()
      /home/piersy/projects/go-ethereum/core/chain_indexer.go:408 +0x62a
  github.com/ethereum/go-ethereum/core.(*ChainIndexer).updateLoop()
      /home/piersy/projects/go-ethereum/core/chain_indexer.go:338 +0x4b3

Previous write at 0x00c01ccfe29a by goroutine 274:
  testing.(*common).FailNow()
      /usr/local/go/src/testing/testing.go:697 +0x4c
  testing.(*common).Fatalf()
      /usr/local/go/src/testing/testing.go:772 +0x9d
  github.com/ethereum/go-ethereum/core.(*testChainIndexBackend).assertBlocks()
      /home/piersy/projects/go-ethereum/core/chain_indexer_test.go:189 +0x50f
  github.com/ethereum/go-ethereum/core.testChainIndexer.func1()
      /home/piersy/projects/go-ethereum/core/chain_indexer_test.go:85 +0x349
  github.com/ethereum/go-ethereum/core.testChainIndexer()
      /home/piersy/projects/go-ethereum/core/chain_indexer_test.go:118 +0xaa9
  github.com/ethereum/go-ethereum/core.TestChainIndexerWithChildren()
      /home/piersy/projects/go-ethereum/core/chain_indexer_test.go:43 +0x49
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1039 +0x1eb

Goroutine 306 (running) created at:
  github.com/ethereum/go-ethereum/core.NewChainIndexer()
      /home/piersy/projects/go-ethereum/core/chain_indexer.go:119 +0x40e
  github.com/ethereum/go-ethereum/core.testChainIndexer()
      /home/piersy/projects/go-ethereum/core/chain_indexer_test.go:62 +0x55d
  github.com/ethereum/go-ethereum/core.TestChainIndexerWithChildren()
      /home/piersy/projects/go-ethereum/core/chain_indexer_test.go:43 +0x49
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1039 +0x1eb

Goroutine 274 (running) created at:
  testing.(*T).Run()
      /usr/local/go/src/testing/testing.go:1090 +0x700
  testing.runTests.func1()
      /usr/local/go/src/testing/testing.go:1334 +0xa6
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1039 +0x1eb
  testing.runTests()
      /usr/local/go/src/testing/testing.go:1332 +0x527
  testing.(*M).Run()
      /usr/local/go/src/testing/testing.go:1249 +0x43f
  main.main()
      _testmain.go:638 +0x223
==================
FAIL	github.com/ethereum/go-ethereum/core	410.497s
FAIL

[karalabe]

This is probably a simple data race in the test that we call t.Fatailf concurrently, which is not really allowed.

[s1na]

I'm not getting a warning from the race detector about this particular test case. However it does warn about a few txpool tests. I'm checking those out now.

[piersy]

Hey @s1na data race occurrences can be nondeterministic, so this data race may manifest itself on only 1 of 100 runs or only on specific hardware, but seeing it happen once means that there is a synchronisation problem with the code.