Data race when using testutil/network

[prettymuchbryce]

Summary of Bug

When running tests which use testutil/network (such as the cli tests generated via ignite), data races occur. I believe this is because the listener in server/api/server.go is being written and read concurrently in separate goroutines without any locking.

This happens because while there is a global lock which attempts to wrap the testutil/network creation, the startInProcess function invokes apiSrv.Start in a separate goroutine. The main routine then simply waits 5 seconds and assumes the API server has been properly created during this time. I believe the Go race detector will consider this is a data race since it's possible one routine could call Close() concurrently while the initial goroutine is still in the process of calling Start(), both of which access the underlying listener.

WARNING: DATA RACE
Read at 0x00c000187170 by goroutine 18:
  github.com/cosmos/cosmos-sdk/server/api.(*Server).Close()
      /home/runner/go/pkg/mod/github.com/cosmos/[email protected]/server/api/server.go:123 +0x269
  github.com/cosmos/cosmos-sdk/testutil/network.(*Network).Cleanup()


Previous write at 0x00c000187170 by goroutine 13:
  github.com/cosmos/cosmos-sdk/server/api.(*Server).Start()
      /home/runner/go/pkg/mod/github.com/cosmos/[email protected]/server/api/server.go:109 +0x2e4
  github.com/cosmos/cosmos-sdk/testutil/network.startInProcess.func1()
      /home/runner/go/pkg/mod/github.com/cosmos/[email protected]/testutil/network/util.go:86 +0x104

Goroutine 18 (running) created at:
  testing.(*T).Run()
      /opt/hostedtoolcache/go/1.17.8/x64/src/testing/testing.go:1306 +0x726
  testing.runTests.func1()

  Goroutine 13 (running) created at:
  github.com/cosmos/cosmos-sdk/testutil/network.startInProcess()
      /home/runner/go/pkg/mod/github.com/cosmos/[email protected]/testutil/network/util.go:85 +0xe0d
  github.com/syndtr/goleveldb/leveldb/storage.(*fileStorage).List()
      /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/storage/file_storage.go:458 +0x3ea
  fmt.Fscanf()

One way to properly resolve this would be to wrap access to the listener in a mutex in server/api/server.go:

func (s *Server) Start(cfg config.Config) error {
+	m.Lock()
	if cfg.Telemetry.Enabled {
		m, err := telemetry.New(cfg.Telemetry)
		if err != nil {
+                       m.Unlock()
			return err
		}

		s.metrics = m
		s.registerMetrics()
	}

	tmCfg := tmrpcserver.DefaultConfig()
	tmCfg.MaxOpenConnections = int(cfg.API.MaxOpenConnections)
	tmCfg.ReadTimeout = time.Duration(cfg.API.RPCReadTimeout) * time.Second
	tmCfg.WriteTimeout = time.Duration(cfg.API.RPCWriteTimeout) * time.Second
	tmCfg.MaxBodyBytes = int64(cfg.API.RPCMaxBodyBytes)

	listener, err := tmrpcserver.Listen(cfg.API.Address, tmCfg)
	if err != nil {
+              m.Unlock()
		return err
	}

	s.registerGRPCGatewayRoutes()

	s.listener = listener
	var h http.Handler = s.Router

	if cfg.API.EnableUnsafeCORS {
		allowAllCORS := handlers.CORS(handlers.AllowedHeaders([]string{"Content-Type"}))
+	         m.Unlock()
		return tmrpcserver.Serve(s.listener, allowAllCORS(h), s.logger, tmCfg)
	}

	s.logger.Info("starting API server...")
+	m.Unlock()
	return tmrpcserver.Serve(s.listener, s.Router, s.logger, tmCfg)
}

// Close closes the API server.
func (s *Server) Close() error {
+	m.Lock()
+	defer m.Unlock()
	return s.listener.Close()
}

Version

v0.45.3

Steps to Reproduce

1. Create a project with ignite
2. Generate a new module with cli tests. i.e.

ignite scaffold module mymodule --require-registration
ignite scaffold message MyMessage mymodule --module mymodule

3. Run tests with race detector. i.e. go test ./... -mod=readonly -timeout 12m -race -coverprofile=coverage.out -covermode=atomic -tags='ledger test_ledger_mock'

---

For Admin Use

• Not duplicate issue
• Appropriate labels applied
• Appropriate contributors tagged
• Contributor assigned/self-assigned

[alexanderbez]

Thanks @prettymuchbryce for creating such a detailed issue! Yeah, as you've pointed out it's technically possible to call Close prior to Start returning from the goroutine it was executed in.

While in practice, this would never happen as you'd wait for Start to return (as we do), the go compiler doesn't know this. So we should fix it for the sake of passing race detecting tests.

Since you've already posted the diff, which looks reasonable, would you open to creating a PR?

[prettymuchbryce]

Since you've already posted the diff, which looks reasonable, would you open to creating a PR?

Sure. I can take a crack at it shortly.