Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Race Condition Testing eth/ package #521

Open
AusIV opened this issue Jan 30, 2023 · 1 comment · May be fixed by #522
Open

Race Condition Testing eth/ package #521

AusIV opened this issue Jan 30, 2023 · 1 comment · May be fixed by #522
Assignees
@meowsbits
Labels
F2-bug 🐞 F4-tests 💻

Comments

@AusIV
Copy link
Contributor

AusIV commented Jan 30, 2023 •
edited
Loading

On v1.12.9, I've found that running

go test ./eth

Has intermittent failures such as:

--- FAIL: TestArtificialFinalityFeatureEnablingDisabling_NoDisable (23.20s)
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
	panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0xd8 pc=0xfbad5f]

goroutine 4393 [running]:
testing.tRunner.func1.2({0x11ba6a0, 0x223f3b0})
	/usr/local/go/src/testing/testing.go:1396 +0x24e
testing.tRunner.func1()
	/usr/local/go/src/testing/testing.go:1399 +0x39f
panic({0x11ba6a0, 0x223f3b0})
	/usr/local/go/src/runtime/panic.go:884 +0x212
github.com/ethereum/go-ethereum/eth/protocols/eth.(*Peer).Head(0x0)
	/home/circleci/project/eth/protocols/eth/peer.go:145 +0x5f
github.com/ethereum/go-ethereum/eth.peerToSyncOp(...)
	/home/circleci/project/eth/sync.go:261
github.com/ethereum/go-ethereum/eth.TestArtificialFinalityFeatureEnablingDisabling_NoDisable(0xc002450d00)
	/home/circleci/project/eth/sync_test.go:290 +0x6d4
testing.tRunner(0xc002450d00, 0x1bba898)
	/usr/local/go/src/testing/testing.go:1446 +0x10b
created by testing.(*T).Run
	/usr/local/go/src/testing/testing.go:1493 +0x35f
FAIL	github.com/ethereum/go-ethereum/eth	78.118s
FAIL

Running with multiple cores this only shows up occasionally, but running with

GOMAXPROCS=1 go test ./eth

It appears much more regularly.
@meowsbits meowsbits self-assigned this Jan 30, 2023
@meowsbits
Copy link
Contributor

Thanks for the report!

Just for reference, here's another failing racy test command

go test -race ./eth
[...]
INFO [01-30|12:26:51.846] Rebuilding state snapshot                                          
INFO [01-30|12:26:51.847] Resuming state snapshot generation       root=97688d..33485c accoun
ts=0 slots=0 storage=0.00B  dangling=0 elapsed=1.232ms                                       
INFO [01-30|12:26:51.847] Generated state snapshot                 accounts=1 slots=0 storage=41.00B dangling=0 elapsed=1.533ms                                                           
INFO [01-30|12:26:57.034] Imported new chain segment               blocks=1024 txs=0 mgas=0.0
00 elapsed=3.037s  mgasps=0.000 number=1024 hash=62c91f..999d67 dirty=56.98KiB               
==================                                                                           
WARNING: DATA RACE                                                                           Read at 0x00000222ce68 by goroutine 2389:                                                    
  github.com/ethereum/go-ethereum/eth.(*chainSyncer).nextSyncOp()                            
      /home/ia/go/src/github.com/ethereum/go-ethereum/eth/sync.go:218 +0x224                 
  github.com/ethereum/go-ethereum/eth.(*chainSyncer).loop()                                        /home/ia/go/src/github.com/ethereum/go-ethereum/eth/sync.go:160 +0x40f                 
  github.com/ethereum/go-ethereum/eth.(*handler).Start.func3()                               
      /home/ia/go/src/github.com/ethereum/go-ethereum/eth/handler.go:559 +0x39               
                                                                                             
Previous write at 0x00000222ce68 by goroutine 321:                                           
  github.com/ethereum/go-ethereum/eth.TestArtificialFinalityFeatureEnablingDisabling()       
      /home/ia/go/src/github.com/ethereum/go-ethereum/eth/sync_test.go:180 +0x1f3              testing.tRunner()                                                                          
      /home/ia/go1.19.2.linux-amd64/src/testing/testing.go:1446 +0x216                       
  testing.(*T).Run.func1()                                                                   
      /home/ia/go1.19.2.linux-amd64/src/testing/testing.go:1493 +0x47                        
                                                                                             Goroutine 2389 (running) created at:                                                         
  github.com/ethereum/go-ethereum/eth.(*handler).Start()                                     
      /home/ia/go/src/github.com/ethereum/go-ethereum/eth/handler.go:559 +0x3f7              
  github.com/ethereum/go-ethereum/eth.newTestHandlerWithBlocksWithOpts()                     
      /home/ia/go/src/github.com/ethereum/go-ethereum/eth/sync_test.go:83 +0x82f               github.com/ethereum/go-ethereum/eth.TestArtificialFinalityFeatureEnablingDisabling()       
      /home/ia/go/src/github.com/ethereum/go-ethereum/eth/sync_test.go:166 +0x5e             
  testing.tRunner()                                                                          
      /home/ia/go1.19.2.linux-amd64/src/testing/testing.go:1446 +0x216                         testing.(*T).Run.func1()                                                                   
      /home/ia/go1.19.2.linux-amd64/src/testing/testing.go:1493 +0x47                        
                                                                                             
Goroutine 321 (running) created at:                                                          
  testing.(*T).Run()                                                                         
      /home/ia/go1.19.2.linux-amd64/src/testing/testing.go:1493 +0x75d                       
  testing.runTests.func1()                                                                   
      /home/ia/go1.19.2.linux-amd64/src/testing/testing.go:1846 +0x99                        
  testing.tRunner()
      /home/ia/go1.19.2.linux-amd64/src/testing/testing.go:1446 +0x216
  testing.runTests()
      /home/ia/go1.19.2.linux-amd64/src/testing/testing.go:1844 +0x7ec
  testing.(*M).Run()
      /home/ia/go1.19.2.linux-amd64/src/testing/testing.go:1726 +0xa84
  main.main()
      _testmain.go:101 +0x2e9
==================

meowsbits added a commit that referenced this issue Jan 30, 2023
@meowsbits
eth: fix race condition in tests
891b12b 
The race was discoverable with
go test -race ./eth
or under 'slow' machine conditions, eg. GOMAXPROCS=1
and/or a 'slower' machine.

The race was around the minArtificialFinalityPeers
value, which was both
- assigned in (during) the tests, and
- checked in the nextSyncOp function

and the order of those uses was nondeterministic.

This patch resolves the issue by moving
the adhoc and temporary re-assignment of that
package-wide value to the start of the tests,
before any go routines for peer handling
or sync protocol are fired off.

Note that the real-clock timeouts in these
tests can still cause spurious test failures
under 'slow' conditions (see their 250ms sleeps).

Fixes #521

Date: 2023-01-30 13:39:38-08:00
Signed-off-by: meows <b5c6@protonmail.com>
@meowsbits meowsbits linked a pull request Jan 30, 2023 that will close this issue
Open
meowsbits added a commit that referenced this issue Feb 7, 2023
@meowsbits
eth: fix race condition in tests
51da9a4 
The race was discoverable with
go test -race ./eth
or under 'slow' machine conditions, eg. GOMAXPROCS=1
and/or a 'slower' machine.

The race was around the minArtificialFinalityPeers
value, which was both
- assigned in (during) the tests, and
- checked in the nextSyncOp function

and the order of those uses was nondeterministic.

This patch resolves the issue by moving
the adhoc and temporary re-assignment of that
package-wide value to the start of the tests,
before any go routines for peer handling
or sync protocol are fired off.

Note that the real-clock timeouts in these
tests can still cause spurious test failures
under 'slow' conditions (see their 250ms sleeps).

Fixes #521

Date: 2023-01-30 13:39:38-08:00
Signed-off-by: meows <b5c6@protonmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@meowsbits meowsbits

Labels
F2-bug 🐞 F4-tests 💻
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

eth: fix race condition in eth/sync tests etclabscore/core-geth
2 participants
@AusIV @meowsbits