Merge pull request #7973 from onflow/peter/fix-flaky-access-tests

[Access] Fix noisy and flaky unittests

Author: peterargue

engine/access/access_test.go

@@ -3,7 +3,6 @@ package access_test
 import (
 	"context"
 	"encoding/json"
-	"os"
 	"testing"
 
 	"github.com/cockroachdb/pebble/v2"
@@ -93,7 +92,7 @@ func TestAccess(t *testing.T) {
 
 func (suite *Suite) SetupTest() {
 	suite.lockManager = storage.NewTestingLockManager()
-	suite.log = zerolog.New(os.Stderr)
+	suite.log = unittest.Logger()
 	suite.net = new(mocknetwork.EngineRegistry)
 	suite.state = new(protocol.State)
 	suite.finalSnapshot = new(protocol.Snapshot)
@@ -774,6 +773,10 @@ func (suite *Suite) TestGetSealedTransaction() {
 		ctx := irrecoverable.NewMockSignalerContext(suite.T(), background)
 		ingestEng.Start(ctx)
 		<-ingestEng.Ready()
+		defer func() {
+			cancel()
+			<-ingestEng.Done()
+		}()
 
 		// 2. Ingest engine was notified by the follower engine about a new block.
 		// Follower engine --> Ingest engine

engine/access/handle_irrecoverable_state_test.go

@@ -4,7 +4,6 @@ import (
 	"context"
 	"fmt"
 	"io"
-	"os"
 	"testing"
 	"time"
 
@@ -45,10 +44,12 @@ import (
 // IrrecoverableStateTestSuite tests that Access node indicate an inconsistent or corrupted node state
 type IrrecoverableStateTestSuite struct {
 	suite.Suite
+	log    zerolog.Logger
+	cancel context.CancelFunc
+
 	state      *protocol.State
 	snapshot   *protocol.Snapshot
 	epochQuery *protocol.EpochQuery
-	log        zerolog.Logger
 	net        *mocknetwork.EngineRegistry
 	request    *module.Requester
 	collClient *accessmock.AccessAPIClient
@@ -72,7 +73,7 @@ type IrrecoverableStateTestSuite struct {
 }
 
 func (suite *IrrecoverableStateTestSuite) SetupTest() {
-	suite.log = zerolog.New(os.Stdout)
+	suite.log = unittest.Logger()
 	suite.net = mocknetwork.NewEngineRegistry(suite.T())
 	suite.state = protocol.NewState(suite.T())
 	suite.snapshot = protocol.NewSnapshot(suite.T())
@@ -186,13 +187,17 @@ func (suite *IrrecoverableStateTestSuite) SetupTest() {
 	assert.NoError(suite.T(), err)
 
 	err = fmt.Errorf("inconsistent node's state")
+
+	ctx, cancel := context.WithCancel(context.Background())
+	suite.cancel = cancel
+
 	signCtxErr := irrecoverable.NewExceptionf("failed to lookup sealed header: %w", err)
-	ctx := irrecoverable.NewMockSignalerContextExpectError(suite.T(), context.Background(), signCtxErr)
+	signalCtx := irrecoverable.NewMockSignalerContextExpectError(suite.T(), ctx, signCtxErr)
 
-	suite.rpcEng.Start(ctx)
+	suite.rpcEng.Start(signalCtx)
 
-	suite.secureGrpcServer.Start(ctx)
-	suite.unsecureGrpcServer.Start(ctx)
+	suite.secureGrpcServer.Start(signalCtx)
+	suite.unsecureGrpcServer.Start(signalCtx)
 
 	// wait for the servers to startup
 	unittest.AssertClosesBefore(suite.T(), suite.secureGrpcServer.Ready(), 2*time.Second)
@@ -202,6 +207,13 @@ func (suite *IrrecoverableStateTestSuite) SetupTest() {
 	unittest.AssertClosesBefore(suite.T(), suite.rpcEng.Ready(), 2*time.Second)
 }
 
+func (suite *IrrecoverableStateTestSuite) TearDownTest() {
+	suite.cancel()
+	unittest.AssertClosesBefore(suite.T(), suite.secureGrpcServer.Done(), 2*time.Second)
+	unittest.AssertClosesBefore(suite.T(), suite.unsecureGrpcServer.Done(), 2*time.Second)
+	unittest.AssertClosesBefore(suite.T(), suite.rpcEng.Done(), 2*time.Second)
+}
+
 func TestIrrecoverableState(t *testing.T) {
 	suite.Run(t, new(IrrecoverableStateTestSuite))
 }

engine/access/ingestion/engine_test.go

@@ -92,7 +92,7 @@ func (s *Suite) TearDownTest() {
 }
 
 func (s *Suite) SetupTest() {
-	s.log = zerolog.New(os.Stderr)
+	s.log = unittest.Logger()
 	s.ctx, s.cancel = context.WithCancel(context.Background())
 	db, dbDir := unittest.TempPebbleDB(s.T())
 	s.db = pebbleimpl.ToDB(db)

engine/access/ingestion/tx_error_messages/tx_error_messages_core_test.go

@@ -3,7 +3,6 @@ package tx_error_messages
 import (
 	"context"
 	"fmt"
-	"os"
 	"testing"
 
 	execproto "github.com/onflow/flow/protobuf/go/flow/execution"
@@ -72,7 +71,7 @@ type mockCloser struct{}
 func (mc *mockCloser) Close() error { return nil }
 
 func (s *TxErrorMessagesCoreSuite) SetupTest() {
-	s.log = zerolog.New(os.Stderr)
+	s.log = unittest.Logger()
 	s.ctx, s.cancel = context.WithCancel(context.Background())
 	// mock out protocol state
 	s.proto.state = protocol.NewFollowerState(s.T())

engine/access/ingestion/tx_error_messages/tx_error_messages_engine_test.go

@@ -82,7 +82,7 @@ func (s *TxErrorMessagesEngineSuite) TearDownTest() {
 }
 
 func (s *TxErrorMessagesEngineSuite) SetupTest() {
-	s.log = zerolog.New(os.Stderr)
+	s.log = unittest.Logger()
 	s.ctx, s.cancel = context.WithCancel(context.Background())
 	pdb, dbDir := unittest.TempPebbleDB(s.T())
 	s.db = pebbleimpl.ToDB(pdb)

engine/access/integration_unsecure_grpc_server_test.go

@@ -3,7 +3,6 @@ package access
 import (
 	"context"
 	"io"
-	"os"
 	"testing"
 	"time"
 
@@ -96,7 +95,7 @@ type SameGRPCPortTestSuite struct {
 }
 
 func (suite *SameGRPCPortTestSuite) SetupTest() {
-	suite.log = zerolog.New(os.Stdout)
+	suite.log = unittest.Logger()
 	suite.net = new(network.EngineRegistry)
 	suite.state = new(protocol.State)
 	suite.snapshot = new(protocol.Snapshot)
@@ -317,6 +316,14 @@ func (suite *SameGRPCPortTestSuite) SetupTest() {
 	unittest.AssertClosesBefore(suite.T(), suite.stateStreamEng.Ready(), 2*time.Second)
 }
 
+func (suite *SameGRPCPortTestSuite) TearDownTest() {
+	suite.cancel()
+	unittest.AssertClosesBefore(suite.T(), suite.secureGrpcServer.Done(), 2*time.Second)
+	unittest.AssertClosesBefore(suite.T(), suite.unsecureGrpcServer.Done(), 2*time.Second)
+	unittest.AssertClosesBefore(suite.T(), suite.rpcEng.Done(), 2*time.Second)
+	unittest.AssertClosesBefore(suite.T(), suite.stateStreamEng.Done(), 2*time.Second)
+}
+
 // TestEnginesOnTheSameGrpcPort verifies if both AccessAPI and ExecutionDataAPI client successfully connect and continue
 // to work when configured on the same port
 func (suite *SameGRPCPortTestSuite) TestEnginesOnTheSameGrpcPort() {

engine/access/rest_api_test.go

@@ -5,7 +5,6 @@ import (
 	"fmt"
 	"math/rand"
 	"net/http"
-	"os"
 	"strings"
 	"testing"
 	"time"
@@ -80,7 +79,7 @@ type RestAPITestSuite struct {
 }
 
 func (suite *RestAPITestSuite) SetupTest() {
-	suite.log = zerolog.New(os.Stdout)
+	suite.log = unittest.Logger()
 	suite.net = new(network.EngineRegistry)
 	suite.state = new(protocol.State)
 	suite.sealedSnaphost = new(protocol.Snapshot)

engine/access/rpc/backend/scripts/executor/compare.go

@@ -31,7 +31,7 @@ func NewComparingScriptExecutor(
 	execNodeExecutor ScriptExecutor,
 ) *ComparingScriptExecutor {
 	return &ComparingScriptExecutor{
-		log:                   zerolog.New(log).With().Str("script_executor", "comparing").Logger(),
+		log:                   log.With().Str("script_executor", "comparing").Logger(),
 		metrics:               metrics,
 		scriptCache:           scriptCache,
 		localExecutor:         localExecutor,

engine/access/rpc/backend/scripts/executor/execution_node.go

@@ -40,7 +40,7 @@ func NewENScriptExecutor(
 	scriptCache *LoggedScriptCache,
 ) *ENScriptExecutor {
 	return &ENScriptExecutor{
-		log:              zerolog.New(log).With().Str("script_executor", "execution_node").Logger(),
+		log:              log.With().Str("script_executor", "execution_node").Logger(),
 		metrics:          metrics,
 		nodeProvider:     nodeProvider,
 		nodeCommunicator: nodeCommunicator,

engine/access/rpc/backend/scripts/executor/local.go

@@ -32,7 +32,7 @@ func NewLocalScriptExecutor(
 	scriptCache *LoggedScriptCache,
 ) *LocalScriptExecutor {
 	return &LocalScriptExecutor{
-		log:            zerolog.New(log).With().Str("script_executor", "local").Logger(),
+		log:            log.With().Str("script_executor", "local").Logger(),
 		metrics:        metrics,
 		scriptCache:    scriptCache,
 		scriptExecutor: executor,