Skip to content

Improve logging of startup and errors in bootstrapping #2933

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

Merged
merged 1 commit into from
Apr 10, 2024
Merged

Improve logging of startup and errors in bootstrapping #2933

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
48 changes: 33 additions & 15 deletions snow/engine/snowman/bootstrap/bootstrapper.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -154,7 +154,16 @@ func (b *Bootstrapper) Clear(context.Context) error {
}

func (b *Bootstrapper) Start(ctx context.Context, startReqID uint32) error {
b.Ctx.Log.Info("starting bootstrapper")
lastAccepted, err := b.getLastAccepted(ctx)
if err != nil {
return err
}

lastAcceptedHeight := lastAccepted.Height()
b.Ctx.Log.Info("starting bootstrapper",
zap.Stringer("lastAcceptedID", lastAccepted.ID()),
zap.Uint64("lastAcceptedHeight", lastAcceptedHeight),
)

b.Ctx.State.Set(snow.EngineState{
Type: p2p.EngineType_ENGINE_TYPE_SNOWMAN,
Expand All @@ -165,10 +174,6 @@ func (b *Bootstrapper) Start(ctx context.Context, startReqID uint32) error {
}

// Set the starting height
lastAcceptedHeight, err := b.getLastAcceptedHeight(ctx)
if err != nil {
return err
}
b.startingHeight = lastAcceptedHeight
b.requestID = startReqID

Expand Down Expand Up @@ -563,7 +568,7 @@ func (b *Bootstrapper) process(
blk snowman.Block,
ancestors map[ids.ID]snowman.Block,
) error {
lastAcceptedHeight, err := b.getLastAcceptedHeight(ctx)
lastAccepted, err := b.getLastAccepted(ctx)
if err != nil {
return err
}
Expand All @@ -575,7 +580,7 @@ func (b *Bootstrapper) process(
batch,
b.tree,
b.missingBlockIDs,
lastAcceptedHeight,
lastAccepted.Height(),
blk,
ancestors,
)
Expand Down Expand Up @@ -636,7 +641,7 @@ func (b *Bootstrapper) tryStartExecuting(ctx context.Context) error {
return nil
}

lastAcceptedHeight, err := b.getLastAcceptedHeight(ctx)
lastAccepted, err := b.getLastAccepted(ctx)
if err != nil {
return err
}
Expand All @@ -658,10 +663,23 @@ func (b *Bootstrapper) tryStartExecuting(ctx context.Context) error {
numAccepted: b.numAccepted,
},
b.tree,
lastAcceptedHeight,
lastAccepted.Height(),
)
if err != nil || b.Halted() {
return err
if err != nil {
// If a fatal error has occurred, include the last accepted block
// information.
lastAccepted, lastAcceptedErr := b.getLastAccepted(ctx)
if lastAcceptedErr != nil {
return fmt.Errorf("%w after %w", lastAcceptedErr, err)
}
return fmt.Errorf("%w with last accepted %s (height=%d)",
err,
lastAccepted.ID(),
lastAccepted.Height(),
)
}
if b.Halted() {
return nil
}

previouslyExecuted := b.executedStateTransitions
Expand Down Expand Up @@ -696,16 +714,16 @@ func (b *Bootstrapper) tryStartExecuting(ctx context.Context) error {
return b.onFinished(ctx, b.requestID)
}

func (b *Bootstrapper) getLastAcceptedHeight(ctx context.Context) (uint64, error) {
func (b *Bootstrapper) getLastAccepted(ctx context.Context) (snowman.Block, error) {
lastAcceptedID, err := b.VM.LastAccepted(ctx)
if err != nil {
return 0, fmt.Errorf("couldn't get last accepted ID: %w", err)
return nil, fmt.Errorf("couldn't get last accepted ID: %w", err)
}
lastAccepted, err := b.VM.GetBlock(ctx, lastAcceptedID)
if err != nil {
return 0, fmt.Errorf("couldn't get last accepted block: %w", err)
return nil, fmt.Errorf("couldn't get last accepted block %s: %w", lastAcceptedID, err)
}
return lastAccepted.Height(), nil
return lastAccepted, nil
}

func (b *Bootstrapper) Timeout(ctx context.Context) error {
Expand Down
6 changes: 4 additions & 2 deletions snow/engine/snowman/bootstrap/storage.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -220,16 +220,18 @@ func execute(
}

if err := blk.Verify(ctx); err != nil {
return fmt.Errorf("failed to verify block %s (%d) in bootstrapping: %w",
return fmt.Errorf("failed to verify block %s (height=%d, parentID=%s) in bootstrapping: %w",
blk.ID(),
height,
blk.Parent(),
err,
)
}
if err := blk.Accept(ctx); err != nil {
return fmt.Errorf("failed to accept block %s (%d) in bootstrapping: %w",
return fmt.Errorf("failed to accept block %s (height=%d, parentID=%s) in bootstrapping: %w",
blk.ID(),
height,
blk.Parent(),
err,
)
}
Expand Down
8 changes: 5 additions & 3 deletions snow/engine/snowman/transitive.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -471,7 +471,8 @@ func (t *Transitive) Start(ctx context.Context, startReqID uint32) error {
}

// initialize consensus to the last accepted blockID
if err := t.Consensus.Initialize(t.Ctx, t.Params, lastAcceptedID, lastAccepted.Height(), lastAccepted.Timestamp()); err != nil {
lastAcceptedHeight := lastAccepted.Height()
if err := t.Consensus.Initialize(t.Ctx, t.Params, lastAcceptedID, lastAcceptedHeight, lastAccepted.Timestamp()); err != nil {
return err
}

Expand Down Expand Up @@ -501,8 +502,9 @@ func (t *Transitive) Start(ctx context.Context, startReqID uint32) error {
return err
}

t.Ctx.Log.Info("consensus starting",
zap.Stringer("lastAcceptedBlock", lastAcceptedID),
t.Ctx.Log.Info("starting consensus",
zap.Stringer("lastAcceptedID", lastAcceptedID),
zap.Uint64("lastAcceptedHeight", lastAcceptedHeight),
)
t.metrics.bootstrapFinished.Set(1)

Expand Down