From 6e3bd225f3f1d67fbedfaeeb91d236bbffa48ff9 Mon Sep 17 00:00:00 2001 From: protolambda Date: Sat, 8 Feb 2025 00:00:18 +0100 Subject: [PATCH] op-supervisor: improve logging --- op-supervisor/supervisor/backend/db/anchor.go | 20 ++++++++++--------- op-supervisor/supervisor/backend/db/db.go | 2 ++ .../supervisor/backend/syncnode/controller.go | 6 +++++- .../backend/syncnode/controller_test.go | 4 ++++ .../supervisor/backend/syncnode/iface.go | 3 +++ .../supervisor/backend/syncnode/node.go | 2 +- 6 files changed, 26 insertions(+), 11 deletions(-) diff --git a/op-supervisor/supervisor/backend/db/anchor.go b/op-supervisor/supervisor/backend/db/anchor.go index d3a4faf69aaf..44f314a04c26 100644 --- a/op-supervisor/supervisor/backend/db/anchor.go +++ b/op-supervisor/supervisor/backend/db/anchor.go @@ -10,32 +10,34 @@ import ( // maybeInitSafeDB initializes the chain database if it is not already initialized // it checks if the Local Safe database is empty, and loads it with the Anchor Point if so func (db *ChainsDB) maybeInitSafeDB(id eth.ChainID, anchor types.DerivedBlockRefPair) { + logger := db.logger.New("chain", id, "derived", anchor.Derived, "source", anchor.Source) _, err := db.LocalSafe(id) if errors.Is(err, types.ErrFuture) { - db.logger.Info("initializing chain database", "chain", id, "anchor", anchor) + logger.Info("initializing chain database") if err := db.UpdateCrossSafe(id, anchor.Source, anchor.Derived); err != nil { - db.logger.Warn("failed to initialize cross safe", "chain", id, "error", err) + logger.Warn("failed to initialize cross safe", "err", err) } db.UpdateLocalSafe(id, anchor.Source, anchor.Derived) } else if err != nil { - db.logger.Warn("failed to check if chain database is initialized", "chain", id, "error", err) + logger.Warn("failed to check if chain database is initialized", "err", err) } else { - db.logger.Debug("chain database already initialized", "chain", id) + logger.Debug("chain database already initialized") } } func (db *ChainsDB) maybeInitEventsDB(id eth.ChainID, anchor types.DerivedBlockRefPair) { + logger := db.logger.New("chain", id, "derived", anchor.Derived, "source", anchor.Source) _, _, _, err := db.OpenBlock(id, 0) if errors.Is(err, types.ErrFuture) { - db.logger.Debug("initializing events database", "chain", id) + logger.Debug("initializing events database") err := db.SealBlock(id, anchor.Derived) if err != nil { - db.logger.Warn("failed to seal initial block", "chain", id, "error", err) + logger.Warn("failed to seal initial block", "err", err) } - db.logger.Debug("initialized events database", "chain", id) + logger.Info("Initialized events database") } else if err != nil { - db.logger.Warn("failed to check if logDB is initialized", "chain", id, "error", err) + logger.Warn("Failed to check if logDB is initialized", "err", err) } else { - db.logger.Debug("events database already initialized", "chain", id) + logger.Debug("Events database already initialized") } } diff --git a/op-supervisor/supervisor/backend/db/db.go b/op-supervisor/supervisor/backend/db/db.go index 2e844e0fcc03..b98600062028 100644 --- a/op-supervisor/supervisor/backend/db/db.go +++ b/op-supervisor/supervisor/backend/db/db.go @@ -144,6 +144,8 @@ func (db *ChainsDB) AttachEmitter(em event.Emitter) { func (db *ChainsDB) OnEvent(ev event.Event) bool { switch x := ev.(type) { case superevents.AnchorEvent: + db.logger.Info("Received chain anchor information", + "chain", x.ChainID, "derived", x.Anchor.Derived, "source", x.Anchor.Source) db.maybeInitEventsDB(x.ChainID, x.Anchor) db.maybeInitSafeDB(x.ChainID, x.Anchor) case superevents.LocalDerivedEvent: diff --git a/op-supervisor/supervisor/backend/syncnode/controller.go b/op-supervisor/supervisor/backend/syncnode/controller.go index 2b2e3474ab02..a1f1cfc7d71c 100644 --- a/op-supervisor/supervisor/backend/syncnode/controller.go +++ b/op-supervisor/supervisor/backend/syncnode/controller.go @@ -75,10 +75,14 @@ func (snc *SyncNodesController) AttachNodeController(chainID eth.ChainID, ctrl S return &locks.RWMap[*ManagedNode, struct{}]{} }) controllersForChain, _ := snc.controllers.Get(chainID) - node := NewManagedNode(snc.logger, chainID, ctrl, snc.backend, noSubscribe) nodeID := snc.id.Add(1) name := fmt.Sprintf("syncnode-%s-%d", chainID, nodeID) + logger := snc.logger.New("syncnode", name, "endpoint", ctrl.String()) + + logger.Info("Attaching node", "chain", chainID, "passive", noSubscribe) + + node := NewManagedNode(logger, chainID, ctrl, snc.backend, noSubscribe) snc.eventSys.Register(name, node, event.DefaultRegisterOpts()) controllersForChain.Set(node, struct{}{}) diff --git a/op-supervisor/supervisor/backend/syncnode/controller_test.go b/op-supervisor/supervisor/backend/syncnode/controller_test.go index 337df7c444d2..203cc6bfbe12 100644 --- a/op-supervisor/supervisor/backend/syncnode/controller_test.go +++ b/op-supervisor/supervisor/backend/syncnode/controller_test.go @@ -87,6 +87,10 @@ func (m *mockSyncControl) UpdateFinalized(ctx context.Context, id eth.BlockID) e return nil } +func (m *mockSyncControl) String() string { + return "mock" +} + var _ SyncControl = (*mockSyncControl)(nil) type mockBackend struct { diff --git a/op-supervisor/supervisor/backend/syncnode/iface.go b/op-supervisor/supervisor/backend/syncnode/iface.go index 10d77e007718..a37455bacf0e 100644 --- a/op-supervisor/supervisor/backend/syncnode/iface.go +++ b/op-supervisor/supervisor/backend/syncnode/iface.go @@ -2,6 +2,7 @@ package syncnode import ( "context" + "fmt" "github.com/ethereum/go-ethereum" "github.com/ethereum/go-ethereum/common" @@ -45,6 +46,8 @@ type SyncControl interface { Reset(ctx context.Context, unsafe, safe, finalized eth.BlockID) error ProvideL1(ctx context.Context, nextL1 eth.BlockRef) error AnchorPoint(ctx context.Context) (types.DerivedBlockRefPair, error) + + fmt.Stringer } type SyncNode interface { diff --git a/op-supervisor/supervisor/backend/syncnode/node.go b/op-supervisor/supervisor/backend/syncnode/node.go index 00944cada15a..18de88aff468 100644 --- a/op-supervisor/supervisor/backend/syncnode/node.go +++ b/op-supervisor/supervisor/backend/syncnode/node.go @@ -268,7 +268,7 @@ func (m *ManagedNode) onFinalizedL2(seal types.BlockSeal) { id := seal.ID() err := m.Node.UpdateFinalized(ctx, id) if err != nil { - m.log.Warn("Node failed finality updating", "err", err) + m.log.Warn("Node failed finality updating", "update", seal, "err", err) return } }