Merge pull request #5367 from onflow/leo/add-logs-for-en-startup

Log progress of loading wal segment file
onflow · Feb 13, 2024 · d22727b · d22727b
2 parents 26ac4b4 + 9a016d8
commit d22727b
Show file tree

Hide file tree

Showing 10 changed files with 22 additions and 12 deletions.
diff --git a/cmd/scaffold.go b/cmd/scaffold.go
@@ -1299,6 +1299,7 @@ func (fnb *FlowNodeBuilder) initFvmOptions() {
 
 // handleModules initializes the given module.
 func (fnb *FlowNodeBuilder) handleModule(v namedModuleFunc) error {
+	fnb.Logger.Info().Str("module", v.name).Msg("module initialization started")
 	err := v.fn(fnb.NodeConfig)
 	if err != nil {
 		return fmt.Errorf("module %s initialization failed: %w", v.name, err)
@@ -1398,6 +1399,7 @@ func (fnb *FlowNodeBuilder) handleComponent(v namedComponentFunc, dependencies <
 
 		logger := fnb.Logger.With().Str("component", v.name).Logger()
 
+		logger.Info().Msg("component initialization started")
 		// First, build the component using the factory method.
 		readyAware, err := v.fn(fnb.NodeConfig)
 		if err != nil {
@@ -1469,6 +1471,7 @@ func (fnb *FlowNodeBuilder) handleRestartableComponent(v namedComponentFunc, par
 
 		// This may be called multiple times if the component is restarted
 		componentFactory := func() (component.Component, error) {
+			log.Info().Msg("component initialization started")
 			c, err := v.fn(fnb.NodeConfig)
 			if err != nil {
 				return nil, err

diff --git a/go.mod b/go.mod
@@ -107,7 +107,7 @@ require (
 	github.com/mitchellh/mapstructure v1.5.0
 	github.com/onflow/flow-ft/lib/go/contracts v0.7.1-0.20230711213910-baad011d2b13
 	github.com/onflow/flow-nft/lib/go/contracts v1.1.0
-	github.com/onflow/wal v0.0.0-20230529184820-bc9f8244608d
+	github.com/onflow/wal v0.0.0-20240208022732-d756cd497d3b
 	github.com/slok/go-http-metrics v0.10.0
 	github.com/sony/gobreaker v0.5.0
 	google.golang.org/genproto/googleapis/api v0.0.0-20231016165738-49dd2c1f3d0b

diff --git a/go.sum b/go.sum
@@ -1370,8 +1370,8 @@ github.com/onflow/go-bitswap v0.0.0-20230703214630-6d3db958c73d h1:QcOAeEyF3iAUH
 github.com/onflow/go-bitswap v0.0.0-20230703214630-6d3db958c73d/go.mod h1:GCPpiyRoHncdqPj++zPr9ZOYBX4hpJ0pYZRYqSE8VKk=
 github.com/onflow/sdks v0.5.0 h1:2HCRibwqDaQ1c9oUApnkZtEAhWiNY2GTpRD5+ftdkN8=
 github.com/onflow/sdks v0.5.0/go.mod h1:F0dj0EyHC55kknLkeD10js4mo14yTdMotnWMslPirrU=
-github.com/onflow/wal v0.0.0-20230529184820-bc9f8244608d h1:gAEqYPn3DS83rHIKEpsajnppVD1+zwuYPFyeDVFaQvg=
-github.com/onflow/wal v0.0.0-20230529184820-bc9f8244608d/go.mod h1:iMC8gkLqu4nkbkAla5HkSBb+FGyQOZiWz3DYm2wSXCk=
+github.com/onflow/wal v0.0.0-20240208022732-d756cd497d3b h1:6O/BEmA99PDT5QVjoJgrYlGsWnpxGJTAMmsC+V9gyds=
+github.com/onflow/wal v0.0.0-20240208022732-d756cd497d3b/go.mod h1:iMC8gkLqu4nkbkAla5HkSBb+FGyQOZiWz3DYm2wSXCk=
 github.com/onsi/ginkgo v1.6.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE=
 github.com/onsi/ginkgo v1.7.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE=
 github.com/onsi/ginkgo v1.8.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE=

diff --git a/insecure/go.mod b/insecure/go.mod
@@ -214,7 +214,7 @@ require (
 	github.com/onflow/flow/protobuf/go/flow v0.3.7 // indirect
 	github.com/onflow/go-bitswap v0.0.0-20230703214630-6d3db958c73d // indirect
 	github.com/onflow/sdks v0.5.0 // indirect
-	github.com/onflow/wal v0.0.0-20230529184820-bc9f8244608d // indirect
+	github.com/onflow/wal v0.0.0-20240208022732-d756cd497d3b // indirect
 	github.com/onsi/ginkgo/v2 v2.9.7 // indirect
 	github.com/opencontainers/runtime-spec v1.0.2 // indirect
 	github.com/opentracing/opentracing-go v1.2.0 // indirect

diff --git a/insecure/go.sum b/insecure/go.sum
@@ -1344,8 +1344,8 @@ github.com/onflow/go-bitswap v0.0.0-20230703214630-6d3db958c73d h1:QcOAeEyF3iAUH
 github.com/onflow/go-bitswap v0.0.0-20230703214630-6d3db958c73d/go.mod h1:GCPpiyRoHncdqPj++zPr9ZOYBX4hpJ0pYZRYqSE8VKk=
 github.com/onflow/sdks v0.5.0 h1:2HCRibwqDaQ1c9oUApnkZtEAhWiNY2GTpRD5+ftdkN8=
 github.com/onflow/sdks v0.5.0/go.mod h1:F0dj0EyHC55kknLkeD10js4mo14yTdMotnWMslPirrU=
-github.com/onflow/wal v0.0.0-20230529184820-bc9f8244608d h1:gAEqYPn3DS83rHIKEpsajnppVD1+zwuYPFyeDVFaQvg=
-github.com/onflow/wal v0.0.0-20230529184820-bc9f8244608d/go.mod h1:iMC8gkLqu4nkbkAla5HkSBb+FGyQOZiWz3DYm2wSXCk=
+github.com/onflow/wal v0.0.0-20240208022732-d756cd497d3b h1:6O/BEmA99PDT5QVjoJgrYlGsWnpxGJTAMmsC+V9gyds=
+github.com/onflow/wal v0.0.0-20240208022732-d756cd497d3b/go.mod h1:iMC8gkLqu4nkbkAla5HkSBb+FGyQOZiWz3DYm2wSXCk=
 github.com/onsi/ginkgo v1.6.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE=
 github.com/onsi/ginkgo v1.7.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE=
 github.com/onsi/ginkgo v1.8.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE=

diff --git a/integration/go.mod b/integration/go.mod
@@ -257,7 +257,7 @@ require (
 	github.com/onflow/go-bitswap v0.0.0-20230703214630-6d3db958c73d // indirect
 	github.com/onflow/nft-storefront/lib/go/contracts v0.0.0-20221222181731-14b90207cead // indirect
 	github.com/onflow/sdks v0.5.0 // indirect
-	github.com/onflow/wal v0.0.0-20230529184820-bc9f8244608d // indirect
+	github.com/onflow/wal v0.0.0-20240208022732-d756cd497d3b // indirect
 	github.com/onsi/ginkgo/v2 v2.9.7 // indirect
 	github.com/opencontainers/go-digest v1.0.0 // indirect
 	github.com/opencontainers/image-spec v1.0.2 // indirect

diff --git a/integration/go.sum b/integration/go.sum
@@ -1440,8 +1440,8 @@ github.com/onflow/nft-storefront/lib/go/contracts v0.0.0-20221222181731-14b90207
 github.com/onflow/nft-storefront/lib/go/contracts v0.0.0-20221222181731-14b90207cead/go.mod h1:E3ScfQb5XcWJCIAdtIeEnr5i5l2y60GT0BTXeIHseWg=
 github.com/onflow/sdks v0.5.0 h1:2HCRibwqDaQ1c9oUApnkZtEAhWiNY2GTpRD5+ftdkN8=
 github.com/onflow/sdks v0.5.0/go.mod h1:F0dj0EyHC55kknLkeD10js4mo14yTdMotnWMslPirrU=
-github.com/onflow/wal v0.0.0-20230529184820-bc9f8244608d h1:gAEqYPn3DS83rHIKEpsajnppVD1+zwuYPFyeDVFaQvg=
-github.com/onflow/wal v0.0.0-20230529184820-bc9f8244608d/go.mod h1:iMC8gkLqu4nkbkAla5HkSBb+FGyQOZiWz3DYm2wSXCk=
+github.com/onflow/wal v0.0.0-20240208022732-d756cd497d3b h1:6O/BEmA99PDT5QVjoJgrYlGsWnpxGJTAMmsC+V9gyds=
+github.com/onflow/wal v0.0.0-20240208022732-d756cd497d3b/go.mod h1:iMC8gkLqu4nkbkAla5HkSBb+FGyQOZiWz3DYm2wSXCk=
 github.com/onsi/ginkgo v1.6.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE=
 github.com/onsi/ginkgo v1.7.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE=
 github.com/onsi/ginkgo v1.8.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE=

diff --git a/ledger/complete/compactor_test.go b/ledger/complete/compactor_test.go
@@ -816,7 +816,7 @@ func replaySegments(
 	updateFn func(update *ledger.TrieUpdate) error,
 	deleteFn func(rootHash ledger.RootHash) error,
 ) error {
-	sr, err := prometheusWAL.NewSegmentsRangeReader(prometheusWAL.SegmentRange{
+	sr, err := prometheusWAL.NewSegmentsRangeReader(unittest.Logger(), prometheusWAL.SegmentRange{
 		Dir:   dir,
 		First: 0,
 		Last:  to,

diff --git a/ledger/complete/wal/wal.go b/ledger/complete/wal/wal.go
@@ -262,7 +262,7 @@ func (w *DiskWAL) replay(
 		Int("loaded_checkpoint", loadedCheckpoint).
 		Msgf("replaying segments from %d to %d", startSegment, to)
 
-	sr, err := prometheusWAL.NewSegmentsRangeReader(prometheusWAL.SegmentRange{
+	sr, err := prometheusWAL.NewSegmentsRangeReader(w.log, prometheusWAL.SegmentRange{
 		Dir:   w.wal.Dir(),
 		First: startSegment,
 		Last:  to,

diff --git a/module/executiondatasync/tracker/storage.go b/module/executiondatasync/tracker/storage.go
@@ -189,6 +189,7 @@ func WithPruneCallback(callback PruneCallback) StorageOption {
 }
 
 func OpenStorage(dbPath string, startHeight uint64, logger zerolog.Logger, opts ...StorageOption) (*storage, error) {
+	lg := logger.With().Str("module", "tracker_storage").Logger()
 	db, err := badger.Open(badger.LSMOnlyOptions(dbPath))
 	if err != nil {
 		return nil, fmt.Errorf("could not open tracker db: %w", err)
@@ -197,17 +198,21 @@ func OpenStorage(dbPath string, startHeight uint64, logger zerolog.Logger, opts
 	storage := &storage{
 		db:            db,
 		pruneCallback: func(c cid.Cid) error { return nil },
-		logger:        logger.With().Str("module", "tracker_storage").Logger(),
+		logger:        lg,
 	}
 
 	for _, opt := range opts {
 		opt(storage)
 	}
 
+	lg.Info().Msgf("initialize storage with start height: %d", startHeight)
+
 	if err := storage.init(startHeight); err != nil {
 		return nil, fmt.Errorf("failed to initialize storage: %w", err)
 	}
 
+	lg.Info().Msgf("storage initialized")
+
 	return storage, nil
 }
 
@@ -224,10 +229,12 @@ func (s *storage) init(startHeight uint64) error {
 			)
 		}
 
+		s.logger.Info().Msgf("prune from height %v up to height %d", fulfilledHeight, prunedHeight)
 		// replay pruning in case it was interrupted during previous shutdown
 		if err := s.PruneUpToHeight(prunedHeight); err != nil {
 			return fmt.Errorf("failed to replay pruning: %w", err)
 		}
+		s.logger.Info().Msgf("finished pruning")
 	} else if errors.Is(fulfilledHeightErr, badger.ErrKeyNotFound) && errors.Is(prunedHeightErr, badger.ErrKeyNotFound) {
 		// db is empty, we need to bootstrap it
 		if err := s.bootstrap(startHeight); err != nil {