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

data race on BasicHost.AutoNAT when using fsrepo.Open with core.NewNode #7947

Closed
mvdan opened this issue Feb 25, 2021 · 5 comments · Fixed by libp2p/go-libp2p#1062
Closed

data race on BasicHost.AutoNAT when using fsrepo.Open with core.NewNode #7947

mvdan opened this issue Feb 25, 2021 · 5 comments · Fixed by libp2p/go-libp2p#1062
Labels
kind/bug A bug in existing code (including security flaws) need/triage Needs initial labeling and prioritization

Comments

@mvdan
Copy link
Contributor

mvdan commented Feb 25, 2021 •
edited
Loading

The example below is a minified test from a larger real one, so please bear that in mind if it makes little sense on its own.

First, the test:

package test

import (
	"context"
	"io/ioutil"
	"testing"

	config "github.com/ipfs/go-ipfs-config"
	ipfscore "github.com/ipfs/go-ipfs/core"
	"github.com/ipfs/go-ipfs/plugin/loader"
	"github.com/ipfs/go-ipfs/repo/fsrepo"
)

func TestRace(t *testing.T) {
	repoRoot := t.TempDir()

	loader, err := loader.NewPluginLoader("")
	if err != nil {
		t.Fatal(err)
	}
	err = loader.Initialize()
	if err != nil {
		t.Fatal(err)
	}
	err = loader.Inject()
	if err != nil {
		t.Fatal(err)
	}

	conf, err := config.Init(ioutil.Discard, 2048)
	if err != nil {
		t.Fatal(err)
	}

	if err := fsrepo.Init(repoRoot, conf); err != nil {
		t.Fatal(err)
	}
	r, err := fsrepo.Open(repoRoot)
	if err != nil {
		t.Fatal(err)
	}

	cfg := &ipfscore.BuildCfg{
		Repo:      r,
		Online:    true,
		Permanent: true,
	}

	_, err = ipfscore.NewNode(context.TODO(), cfg)
	if err != nil {
		t.Fatal(err)
	}
}

It simply initialises an empty repository in a temporary directory, and then starts a node with it. Note that the test ends shortly after, exiting the entire process.

Below is how I run it to reproduce the race:

$ go get golang.org/x/tools/cmd/stress
$ go version
go version go1.16 linux/amd64
$ go mod init test
$ go mod tidy
$ cat go.mod
module test

go 1.16

require (
	github.com/ipfs/go-ipfs v0.8.0
	github.com/ipfs/go-ipfs-config v0.12.0
)
$ go test -c -vet=off -race && stress -p 32 ./test.test -test.run TestRace

stress runs many processes in parallel, which helps run into the data race more quickly.

Below is one of the data races I found, after just 20 or so runs:

WARNING: DATA RACE
Write at 0x00c00025a818 by goroutine 19:
  github.com/libp2p/go-libp2p/config.(*Config).NewNode()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p@v0.13.0/config/config.go:338 +0x684
  github.com/libp2p/go-libp2p.NewWithoutDefaults()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p@v0.13.0/libp2p.go:71 +0x139
  github.com/libp2p/go-libp2p.New()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p@v0.13.0/libp2p.go:57 +0x253
  github.com/ipfs/go-ipfs/core/node/libp2p.constructPeerHost()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/core/node/libp2p/hostopt.go:24 +0x254
  github.com/ipfs/go-ipfs/core/node/libp2p.Host()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/core/node/libp2p/host.go:67 +0x5d8
  runtime.call256()
      /usr/lib/go/src/runtime/asm_amd64.s:554 +0x5b
  reflect.Value.Call()
      /usr/lib/go/src/reflect/value.go:337 +0xd8
  go.uber.org/dig.defaultInvoker()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/dig.go:284 +0x7a
  go.uber.org/dig.(*node).Call()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/dig.go:710 +0x2d3
  go.uber.org/dig.paramSingle.Build()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:245 +0x38e
  go.uber.org/dig.(*paramSingle).Build()
      <autogenerated>:1 +0xe7
  go.uber.org/dig.paramList.BuildList()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:201 +0xf7
  go.uber.org/dig.(*node).Call()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/dig.go:701 +0x156
  go.uber.org/dig.paramSingle.Build()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:245 +0x38e
  go.uber.org/dig.(*paramSingle).Build()
      <autogenerated>:1 +0xe7
  go.uber.org/dig.paramList.BuildList()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:201 +0xf7
  go.uber.org/dig.(*Container).Invoke()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/dig.go:432 +0x384
  go.uber.org/fx.(*App).executeInvokes()
      /home/mvdan/go/pkg/mod/go.uber.org/fx@v1.13.1/app.go:692 +0x5c4
  go.uber.org/fx.New()
      /home/mvdan/go/pkg/mod/go.uber.org/fx@v1.13.1/app.go:471 +0xb72
  github.com/ipfs/go-ipfs/core.NewNode()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/core/builder.go:41 +0x2ef
  test.TestRace()
      /home/mvdan/src/test/ipfs_test.go:49 +0x5e4
  github.com/syndtr/goleveldb/leveldb.(*DB).checkAndCleanFiles()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db_util.go:52 +0x301
  github.com/syndtr/goleveldb/leveldb.openDB()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:130 +0x9bb
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:458 +0x309
  fmt.Fscanf()
      /usr/lib/go/src/fmt/scan.go:143 +0xee
  fmt.Sscanf()
      /usr/lib/go/src/fmt/scan.go:114 +0x191
  github.com/syndtr/goleveldb/leveldb/storage.fsParseName()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:643 +0xa6
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:458 +0x309
  fmt.Fscanf()
      /usr/lib/go/src/fmt/scan.go:143 +0xee
  fmt.Sscanf()
      /usr/lib/go/src/fmt/scan.go:114 +0x284
  github.com/syndtr/goleveldb/leveldb/storage.fsParseName()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:657 +0x19e
  fmt.(*ss).doScanf()
      /usr/lib/go/src/fmt/scan.go:1230 +0x411
  fmt.Fscanf()
      /usr/lib/go/src/fmt/scan.go:143 +0xee
  fmt.Sscanf()
      /usr/lib/go/src/fmt/scan.go:114 +0x191
  github.com/syndtr/goleveldb/leveldb/storage.fsParseName()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:643 +0xa6
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:458 +0x309
  fmt.Fscanf()
      /usr/lib/go/src/fmt/scan.go:143 +0xee
  fmt.Sscanf()
      /usr/lib/go/src/fmt/scan.go:114 +0x191
  github.com/syndtr/goleveldb/leveldb/storage.fsParseName()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:643 +0xa6
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:458 +0x309
  github.com/syndtr/goleveldb/leveldb.(*DB).recoverJournal()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:476 +0xc8
  github.com/syndtr/goleveldb/leveldb.openDB()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:125 +0x997
  github.com/syndtr/goleveldb/leveldb.Open()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:197 +0x25a
  fmt.Fscanf()
      /usr/lib/go/src/fmt/scan.go:143 +0xee
  fmt.Sscanf()
      /usr/lib/go/src/fmt/scan.go:114 +0x191
  github.com/syndtr/goleveldb/leveldb/storage.fsParseName()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:643 +0xa6
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:458 +0x309
  github.com/syndtr/goleveldb/leveldb.(*session).recover.func1()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/session.go:113 +0xfc
  github.com/syndtr/goleveldb/leveldb.(*session).recover()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/session.go:121 +0x1a7f
  github.com/syndtr/goleveldb/leveldb.Open()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:183 +0x109
  github.com/syndtr/goleveldb/leveldb.OpenFile()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:219 +0xbb
  github.com/ipfs/go-ds-leveldb.NewDatastore()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ds-leveldb@v0.4.2/datastore.go:46 +0x40c
  github.com/ipfs/go-ipfs/plugin/plugins/levelds.(*datastoreConfig).Create()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/plugin/plugins/levelds/levelds.go:85 +0xfa
  github.com/ipfs/go-ipfs/repo/fsrepo.measureDatastoreConfig.Create()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/datastores.go:243 +0x5c
  github.com/ipfs/go-ipfs/repo/fsrepo.(*measureDatastoreConfig).Create()
      <autogenerated>:1 +0xac
  github.com/ipfs/go-ipfs/repo/fsrepo.(*mountDatastoreConfig).Create()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/datastores.go:154 +0x13e
  github.com/ipfs/go-ipfs/repo/fsrepo.(*FSRepo).openDatastore()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/fsrepo.go:440 +0x4aa
  github.com/ipfs/go-ipfs/repo/fsrepo.open()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/fsrepo.go:169 +0x476
  github.com/ipfs/go-ipfs/repo/fsrepo.Open.func1()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/fsrepo.go:113 +0x4e
  github.com/ipfs/go-ipfs/repo.(*OnlyOne).Open()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/onlyone.go:35 +0x207
  github.com/ipfs/go-ipfs/repo/fsrepo.Open()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/fsrepo.go:115 +0x9c
  test.TestCensus()
      /home/mvdan/src/test/ipfs_test.go:38 +0x43c
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1194 +0x202

Previous read at 0x00c00025a818 by goroutine 89:
  github.com/libp2p/go-libp2p/p2p/host/basic.(*BasicHost).AllAddrs()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p@v0.13.0/p2p/host/basic/basic_host.go:831 +0x254
  github.com/libp2p/go-libp2p/p2p/host/basic.(*BasicHost).Addrs()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p@v0.13.0/p2p/host/basic/basic_host.go:788 +0x3c
  github.com/libp2p/go-libp2p-kad-dht.PrivateRoutingTableFilter()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p-kad-dht@v0.11.1/dht_filters.go:143 +0x8e
  github.com/libp2p/go-libp2p-kad-dht.(*IpfsDHT).validRTPeer()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p-kad-dht@v0.11.1/subscriber_notifee.go:154 +0x266
  github.com/libp2p/go-libp2p-kad-dht.handlePeerChangeEvent()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p-kad-dht@v0.11.1/subscriber_notifee.go:106 +0x5c
  github.com/libp2p/go-libp2p-kad-dht.(*subscriberNotifee).subscribe()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p-kad-dht@v0.11.1/subscriber_notifee.go:87 +0x6ee
  github.com/libp2p/go-libp2p-kad-dht.(*subscriberNotifee).subscribe-fm()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p-kad-dht@v0.11.1/subscriber_notifee.go:62 +0x5e
  github.com/jbenet/goprocess.(*process).Go.func1()
      /home/mvdan/go/pkg/mod/github.com/jbenet/goprocess@v0.1.4/impl-mutex.go:134 +0x49

Goroutine 19 (running) created at:
  testing.(*T).Run()
      /usr/lib/go/src/testing/testing.go:1239 +0x5d7
  testing.runTests.func1()
      /usr/lib/go/src/testing/testing.go:1512 +0xa6
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1194 +0x202
  testing.runTests()
      /usr/lib/go/src/testing/testing.go:1510 +0x612
  testing.(*M).Run()
      /usr/lib/go/src/testing/testing.go:1418 +0x3b3
  main.main()
      _testmain.go:43 +0x236

Goroutine 89 (running) created at:
  github.com/jbenet/goprocess.(*process).Go()
      /home/mvdan/go/pkg/mod/github.com/jbenet/goprocess@v0.1.4/impl-mutex.go:133 +0x435
  github.com/libp2p/go-libp2p-kad-dht.New()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p-kad-dht@v0.11.1/dht.go:217 +0x879
  github.com/libp2p/go-libp2p-kad-dht/dual.New()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p-kad-dht@v0.11.1/dual/dual.go:134 +0x6ca
  github.com/ipfs/go-ipfs/core/node/libp2p.constructDHTRouting.func1()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/core/node/libp2p/routingopt.go:38 +0x304
  github.com/ipfs/go-ipfs/core/node/libp2p.Host.func1()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/core/node/libp2p/host.go:57 +0x13e
  github.com/libp2p/go-libp2p/config.(*Config).NewNode()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p@v0.13.0/config/config.go:236 +0x181d
  github.com/libp2p/go-libp2p.NewWithoutDefaults()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p@v0.13.0/libp2p.go:71 +0x139
  github.com/libp2p/go-libp2p.New()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p@v0.13.0/libp2p.go:57 +0x253
  github.com/ipfs/go-ipfs/core/node/libp2p.constructPeerHost()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/core/node/libp2p/hostopt.go:24 +0x254
  github.com/ipfs/go-ipfs/core/node/libp2p.Host()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/core/node/libp2p/host.go:67 +0x5d8
  runtime.call256()
      /usr/lib/go/src/runtime/asm_amd64.s:554 +0x5b
  reflect.Value.Call()
      /usr/lib/go/src/reflect/value.go:337 +0xd8
  go.uber.org/dig.defaultInvoker()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/dig.go:284 +0x7a
  go.uber.org/dig.(*node).Call()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/dig.go:710 +0x2d3
  go.uber.org/dig.paramSingle.Build()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:245 +0x38e
  go.uber.org/dig.(*paramSingle).Build()
      <autogenerated>:1 +0xe7
  go.uber.org/dig.paramList.BuildList()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:201 +0xf7
  go.uber.org/dig.(*node).Call()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/dig.go:701 +0x156
  go.uber.org/dig.paramSingle.Build()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:245 +0x38e
  go.uber.org/dig.(*paramSingle).Build()
      <autogenerated>:1 +0xe7
  go.uber.org/dig.paramList.BuildList()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:201 +0xf7
  go.uber.org/dig.(*Container).Invoke()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/dig.go:432 +0x384
  go.uber.org/fx.(*App).executeInvokes()
      /home/mvdan/go/pkg/mod/go.uber.org/fx@v1.13.1/app.go:692 +0x5c4
  go.uber.org/fx.New()
      /home/mvdan/go/pkg/mod/go.uber.org/fx@v1.13.1/app.go:471 +0xb72
  github.com/ipfs/go-ipfs/core.NewNode()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/core/builder.go:41 +0x2ef
  test.TestCensus()
      /home/mvdan/src/test/ipfs_test.go:49 +0x5e4
  github.com/syndtr/goleveldb/leveldb.(*DB).checkAndCleanFiles()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db_util.go:52 +0x301
  github.com/syndtr/goleveldb/leveldb.openDB()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:130 +0x9bb
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:458 +0x309
  fmt.Fscanf()
      /usr/lib/go/src/fmt/scan.go:143 +0xee
  fmt.Sscanf()
      /usr/lib/go/src/fmt/scan.go:114 +0x191
  github.com/syndtr/goleveldb/leveldb/storage.fsParseName()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:643 +0xa6
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:458 +0x309
  fmt.Fscanf()
      /usr/lib/go/src/fmt/scan.go:143 +0xee
  fmt.Sscanf()
      /usr/lib/go/src/fmt/scan.go:114 +0x284
  github.com/syndtr/goleveldb/leveldb/storage.fsParseName()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:657 +0x19e
  fmt.(*ss).doScanf()
      /usr/lib/go/src/fmt/scan.go:1230 +0x411
  fmt.Fscanf()
      /usr/lib/go/src/fmt/scan.go:143 +0xee
  fmt.Sscanf()
      /usr/lib/go/src/fmt/scan.go:114 +0x191
  github.com/syndtr/goleveldb/leveldb/storage.fsParseName()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:643 +0xa6
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:458 +0x309
  fmt.Fscanf()
      /usr/lib/go/src/fmt/scan.go:143 +0xee
  fmt.Sscanf()
      /usr/lib/go/src/fmt/scan.go:114 +0x191
  github.com/syndtr/goleveldb/leveldb/storage.fsParseName()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:643 +0xa6
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:458 +0x309
  github.com/syndtr/goleveldb/leveldb.(*DB).recoverJournal()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:476 +0xc8
  github.com/syndtr/goleveldb/leveldb.openDB()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:125 +0x997
  github.com/syndtr/goleveldb/leveldb.Open()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:197 +0x25a
  fmt.Fscanf()
      /usr/lib/go/src/fmt/scan.go:143 +0xee
  fmt.Sscanf()
      /usr/lib/go/src/fmt/scan.go:114 +0x191
  github.com/syndtr/goleveldb/leveldb/storage.fsParseName()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:643 +0xa6
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:458 +0x309
  github.com/syndtr/goleveldb/leveldb.(*session).recover.func1()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/session.go:113 +0xfc
  github.com/syndtr/goleveldb/leveldb.(*session).recover()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/session.go:121 +0x1a7f
  github.com/syndtr/goleveldb/leveldb.Open()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:183 +0x109
  github.com/syndtr/goleveldb/leveldb.OpenFile()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:219 +0xbb
  github.com/ipfs/go-ds-leveldb.NewDatastore()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ds-leveldb@v0.4.2/datastore.go:46 +0x40c
  github.com/ipfs/go-ipfs/plugin/plugins/levelds.(*datastoreConfig).Create()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/plugin/plugins/levelds/levelds.go:85 +0xfa
  github.com/ipfs/go-ipfs/repo/fsrepo.measureDatastoreConfig.Create()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/datastores.go:243 +0x5c
  github.com/ipfs/go-ipfs/repo/fsrepo.(*measureDatastoreConfig).Create()
      <autogenerated>:1 +0xac
  github.com/ipfs/go-ipfs/repo/fsrepo.(*mountDatastoreConfig).Create()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/datastores.go:154 +0x13e
  github.com/ipfs/go-ipfs/repo/fsrepo.(*FSRepo).openDatastore()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/fsrepo.go:440 +0x4aa
  github.com/ipfs/go-ipfs/repo/fsrepo.open()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/fsrepo.go:169 +0x476
  github.com/ipfs/go-ipfs/repo/fsrepo.Open.func1()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/fsrepo.go:113 +0x4e
  github.com/ipfs/go-ipfs/repo.(*OnlyOne).Open()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/onlyone.go:35 +0x207
  github.com/ipfs/go-ipfs/repo/fsrepo.Open()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/fsrepo.go:115 +0x9c
  test.TestCensus()
      /home/mvdan/src/test/ipfs_test.go:38 +0x43c
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1194 +0x202

As far as I can tell, the test code is not racy in itself, and makes valid uses of the APIs.
@mvdan mvdan added kind/bug A bug in existing code (including security flaws) need/triage Needs initial labeling and prioritization labels Feb 25, 2021
@mvdan mvdan mentioned this issue Feb 25, 2021
Closed
@Stebalien
Copy link
Member

The bug was introduced here: libp2p/go-libp2p#983

We're reading the "AutoNAT" variable from AllAddrs, and calling AllAddrs from a goroutine.

@Stebalien
Copy link
Member

Specifically, AutoNAT itself calls AllAddrs from within a background goroutine.

@mvdan
Copy link
Contributor Author

mvdan commented Feb 26, 2021

Good find. I did think about opening an issue in go-libp2p directly, but one can argue that it's also a bug in go-ipfs until its dependency on go-libp2p is bumped after that fix.

Should I open a sibling issue on go-libp2p?

@mvdan
Copy link
Contributor Author

mvdan commented Feb 26, 2021 •
edited
Loading

There's actually another data race I can reproduce with the exact same test code, if I comment out the code that causes the first race. It concerns go-bitswap's internal/decision/blockstoreManager. I haven't investigated further just yet; the goroutine call stack dump is fairly complex, unfortunately.

WARNING: DATA RACE
Read at 0x00c001713dc0 by goroutine 390:
  github.com/ipfs/go-bitswap/internal/decision.(*blockstoreManager).addJob()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-bitswap@v0.3.3/internal/decision/blockstoremanager.go:58 +0x84
  github.com/ipfs/go-bitswap/internal/decision.(*blockstoreManager).jobPerKey()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-bitswap@v0.3.3/internal/decision/blockstoremanager.go:115 +0x1f4
  github.com/ipfs/go-bitswap/internal/decision.(*blockstoreManager).getBlockSizes()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-bitswap@v0.3.3/internal/decision/blockstoremanager.go:72 +0x1bc
  github.com/ipfs/go-bitswap/internal/decision.(*Engine).MessageReceived()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-bitswap@v0.3.3/internal/decision/engine.go:453 +0x36d
  github.com/ipfs/go-bitswap.(*Bitswap).ReceiveMessage()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-bitswap@v0.3.3/bitswap.go:444 +0x169
  github.com/ipfs/go-bitswap/network.(*impl).handleNewStream()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-bitswap@v0.3.3/network/ipfs_impl.go:402 +0x585
  github.com/ipfs/go-bitswap/network.(*impl).handleNewStream-fm()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-bitswap@v0.3.3/network/ipfs_impl.go:378 +0x5e
  github.com/libp2p/go-libp2p/p2p/host/basic.(*BasicHost).SetStreamHandler.func1()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p@v0.13.0/p2p/host/basic/basic_host.go:566 +0xb9

Previous write at 0x00c001713dc0 by goroutine 19:
  github.com/ipfs/go-bitswap/internal/decision.(*blockstoreManager).start()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-bitswap@v0.3.3/internal/decision/blockstoremanager.go:33 +0x44
  github.com/ipfs/go-bitswap/internal/decision.(*Engine).StartWorkers()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-bitswap@v0.3.3/internal/decision/engine.go:235 +0x6a
  github.com/ipfs/go-bitswap.New()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-bitswap@v0.3.3/bitswap.go:219 +0x18b4
  github.com/ipfs/go-ipfs/core/node.OnlineExchange.func1()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/core/node/core.go:94 +0x1e4
  runtime.call128()
      /usr/lib/go/src/runtime/asm_amd64.s:553 +0x58
  reflect.Value.Call()
      /usr/lib/go/src/reflect/value.go:337 +0xd8
  go.uber.org/dig.defaultInvoker()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/dig.go:284 +0x7a
  go.uber.org/dig.(*node).Call()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/dig.go:710 +0x2d3
  go.uber.org/dig.paramSingle.Build()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:245 +0x38e
  go.uber.org/dig.(*paramSingle).Build()
      <autogenerated>:1 +0xe7
  go.uber.org/dig.paramList.BuildList()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:201 +0xf7
  go.uber.org/dig.(*node).Call()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/dig.go:701 +0x156
  go.uber.org/dig.paramSingle.Build()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:245 +0x38e
  go.uber.org/dig.(*paramSingle).Build()
      <autogenerated>:1 +0xe7
  go.uber.org/dig.paramList.BuildList()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:201 +0xf7
  go.uber.org/dig.(*node).Call()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/dig.go:701 +0x156
  go.uber.org/dig.paramSingle.Build()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:245 +0x38e
  go.uber.org/dig.(*paramSingle).Build()
      <autogenerated>:1 +0xe7
  go.uber.org/dig.paramList.BuildList()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:201 +0xf7
  go.uber.org/dig.(*node).Call()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/dig.go:701 +0x156
  go.uber.org/dig.paramSingle.Build()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:245 +0x38e
  go.uber.org/dig.(*paramSingle).Build()
      <autogenerated>:1 +0xe7
  go.uber.org/dig.paramObjectField.Build()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:384 +0x193
  go.uber.org/dig.paramObject.Build()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:311 +0x130
  go.uber.org/dig.(*paramObject).Build()
      <autogenerated>:1 +0xe7
  go.uber.org/dig.paramList.BuildList()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/param.go:201 +0xf7
  go.uber.org/dig.(*Container).Invoke()
      /home/mvdan/go/pkg/mod/go.uber.org/dig@v1.10.0/dig.go:432 +0x384
  go.uber.org/fx.(*App).executeInvokes()
      /home/mvdan/go/pkg/mod/go.uber.org/fx@v1.13.1/app.go:692 +0x5c4
  go.uber.org/fx.New()
      /home/mvdan/go/pkg/mod/go.uber.org/fx@v1.13.1/app.go:471 +0xb72
  github.com/ipfs/go-ipfs/core.NewNode()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/core/builder.go:41 +0x2ef
  test.TestRace()
      /home/mvdan/src/test/ipfs_test.go:49 +0x5e4
  github.com/syndtr/goleveldb/leveldb.(*DB).checkAndCleanFiles()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db_util.go:52 +0x301
  github.com/syndtr/goleveldb/leveldb.openDB()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:130 +0x9bb
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:458 +0x309
  fmt.Fscanf()
      /usr/lib/go/src/fmt/scan.go:143 +0xee
  fmt.Sscanf()
      /usr/lib/go/src/fmt/scan.go:114 +0x191
  github.com/syndtr/goleveldb/leveldb/storage.fsParseName()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:643 +0xa6
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:458 +0x309
  fmt.Fscanf()
      /usr/lib/go/src/fmt/scan.go:143 +0xee
  fmt.Sscanf()
      /usr/lib/go/src/fmt/scan.go:114 +0x284
  github.com/syndtr/goleveldb/leveldb/storage.fsParseName()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:657 +0x19e
  fmt.(*ss).doScanf()
      /usr/lib/go/src/fmt/scan.go:1230 +0x411
  fmt.Fscanf()
      /usr/lib/go/src/fmt/scan.go:143 +0xee
  fmt.Sscanf()
      /usr/lib/go/src/fmt/scan.go:114 +0x191
  github.com/syndtr/goleveldb/leveldb/storage.fsParseName()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:643 +0xa6
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:458 +0x309
  fmt.Fscanf()
      /usr/lib/go/src/fmt/scan.go:143 +0xee
  fmt.Sscanf()
      /usr/lib/go/src/fmt/scan.go:114 +0x191
  github.com/syndtr/goleveldb/leveldb/storage.fsParseName()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:643 +0xa6
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:458 +0x309
  github.com/syndtr/goleveldb/leveldb.(*DB).recoverJournal()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:476 +0xc8
  github.com/syndtr/goleveldb/leveldb.openDB()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:125 +0x997
  github.com/syndtr/goleveldb/leveldb.Open()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:197 +0x25a
  fmt.Fscanf()
      /usr/lib/go/src/fmt/scan.go:143 +0xee
  fmt.Sscanf()
      /usr/lib/go/src/fmt/scan.go:114 +0x191
  github.com/syndtr/goleveldb/leveldb/storage.fsParseName()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:643 +0xa6
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/storage/file_storage.go:458 +0x309
  github.com/syndtr/goleveldb/leveldb.(*session).recover.func1()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/session.go:113 +0xfc
  github.com/syndtr/goleveldb/leveldb.(*session).recover()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/session.go:121 +0x1a7f
  github.com/syndtr/goleveldb/leveldb.Open()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:183 +0x109
  github.com/syndtr/goleveldb/leveldb.OpenFile()
      /home/mvdan/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:219 +0xbb
  github.com/ipfs/go-ds-leveldb.NewDatastore()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ds-leveldb@v0.4.2/datastore.go:46 +0x40c
  github.com/ipfs/go-ipfs/plugin/plugins/levelds.(*datastoreConfig).Create()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/plugin/plugins/levelds/levelds.go:85 +0xfa
  github.com/ipfs/go-ipfs/repo/fsrepo.measureDatastoreConfig.Create()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/datastores.go:243 +0x5c
  github.com/ipfs/go-ipfs/repo/fsrepo.(*measureDatastoreConfig).Create()
      <autogenerated>:1 +0xac
  github.com/ipfs/go-ipfs/repo/fsrepo.(*mountDatastoreConfig).Create()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/datastores.go:154 +0x13e
  github.com/ipfs/go-ipfs/repo/fsrepo.(*FSRepo).openDatastore()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/fsrepo.go:440 +0x4aa
  github.com/ipfs/go-ipfs/repo/fsrepo.open()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/fsrepo.go:169 +0x476
  github.com/ipfs/go-ipfs/repo/fsrepo.Open.func1()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/fsrepo.go:113 +0x4e
  github.com/ipfs/go-ipfs/repo.(*OnlyOne).Open()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/onlyone.go:35 +0x207
  github.com/ipfs/go-ipfs/repo/fsrepo.Open()
      /home/mvdan/go/pkg/mod/github.com/ipfs/go-ipfs@v0.8.0/repo/fsrepo/fsrepo.go:115 +0x9c
  test.TestRace()
      /home/mvdan/src/test/ipfs_test.go:38 +0x43c
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1194 +0x202

Goroutine 390 (running) created at:
  github.com/libp2p/go-libp2p/p2p/host/basic.(*BasicHost).newStreamHandler()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p@v0.13.0/p2p/host/basic/basic_host.go:416 +0x7a9
  github.com/libp2p/go-libp2p/p2p/host/basic.(*BasicHost).newStreamHandler-fm()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p@v0.13.0/p2p/host/basic/basic_host.go:373 +0x5e
  github.com/libp2p/go-libp2p-swarm.(*Conn).start.func1.1()
      /home/mvdan/go/pkg/mod/github.com/libp2p/go-libp2p-swarm@v0.4.0/swarm_conn.go:125 +0x11a

Goroutine 19 (running) created at:
  testing.(*T).Run()
      /usr/lib/go/src/testing/testing.go:1239 +0x5d7
  testing.runTests.func1()
      /usr/lib/go/src/testing/testing.go:1512 +0xa6
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1194 +0x202
  testing.runTests()
      /usr/lib/go/src/testing/testing.go:1510 +0x612
  testing.(*M).Run()
      /usr/lib/go/src/testing/testing.go:1418 +0x3b3
  main.main()
      _testmain.go:43 +0x236

@Stebalien Stebalien mentioned this issue Feb 26, 2021
Closed
@willscott willscott mentioned this issue Feb 27, 2021
Merged
@mvdan
Copy link
Contributor Author

mvdan commented Mar 9, 2021

I re-ran the test with the race detector a thousand times in parallel, and found no more races :) Thank you @Stebalien @willscott!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
kind/bug A bug in existing code (including security flaws) need/triage Needs initial labeling and prioritization
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

fix autonat race libp2p/go-libp2p
2 participants
@Stebalien @mvdan