Skip to content
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.

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

core: improve logging #1187

Merged
merged 1 commit into from
Sep 28, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
34 changes: 16 additions & 18 deletions core/bcast/bcast.go
Original file line number Diff line number Diff line change
Expand Up @@ -76,7 +76,7 @@ func (b Broadcaster) Broadcast(ctx context.Context, duty core.Duty, pubkey core.
err = nil
}
if err == nil {
log.Info(ctx, "Attestation successfully submitted to beacon node",
log.Info(ctx, "Successfully submitted attestation to beacon node",
z.Any("delay", b.delayFunc(duty.Slot)),
)
}
Expand All @@ -90,7 +90,7 @@ func (b Broadcaster) Broadcast(ctx context.Context, duty core.Duty, pubkey core.

err = b.eth2Cl.SubmitBeaconBlock(ctx, &block.VersionedSignedBeaconBlock)
if err == nil {
log.Info(ctx, "Block proposal successfully submitted to beacon node",
log.Info(ctx, "Successfully submitted block proposal to beacon node",
z.Any("delay", b.delayFunc(duty.Slot)),
)
}
Expand All @@ -105,7 +105,7 @@ func (b Broadcaster) Broadcast(ctx context.Context, duty core.Duty, pubkey core.

err = b.eth2Cl.SubmitBlindedBeaconBlock(ctx, &block.VersionedSignedBlindedBeaconBlock)
if err == nil {
log.Info(ctx, "Blinded block proposal successfully submitted to beacon node",
log.Info(ctx, "Successfully submitted blinded block proposal to beacon node",
z.Any("delay", b.delayFunc(duty.Slot)),
)
}
Expand All @@ -120,7 +120,7 @@ func (b Broadcaster) Broadcast(ctx context.Context, duty core.Duty, pubkey core.

err = b.eth2Cl.SubmitValidatorRegistrations(ctx, []*eth2api.VersionedSignedValidatorRegistration{&registration.VersionedSignedValidatorRegistration})
if err == nil {
log.Info(ctx, "Validator registration successfully submitted to beacon node",
log.Info(ctx, "Successfully submitted validator registration to beacon node",
z.Any("delay", b.delayFunc(duty.Slot)),
)
}
Expand All @@ -135,7 +135,7 @@ func (b Broadcaster) Broadcast(ctx context.Context, duty core.Duty, pubkey core.

err = b.eth2Cl.SubmitVoluntaryExit(ctx, &exit.SignedVoluntaryExit)
if err == nil {
log.Info(ctx, "Voluntary exit successfully submitted to beacon node",
log.Info(ctx, "Successfully submitted voluntary exit to beacon node",
z.Any("delay", b.delayFunc(duty.Slot)),
)
}
Expand All @@ -155,27 +155,25 @@ func (b Broadcaster) Broadcast(ctx context.Context, duty core.Duty, pubkey core.
return nil
}

log.Debug(ctx, "V2 submit beacon committee subscriptions failed")
// Ignore error as beacon node probably doesn't support v2 SubmitBeaconCommitteeSubscriptions
// endpoint (yet). Just try again with v1.

// Beacon node doesn't support v2 SubmitBeaconCommitteeSubscriptions endpoint (yet). Try with v1.
res, err := eth2exp.CalculateCommitteeSubscriptionResponse(ctx, b.eth2Cl, &sub.BeaconCommitteeSubscription)
if err != nil {
return err
}

subs := []*eth2v1.BeaconCommitteeSubscription{
{
ValidatorIndex: res.ValidatorIndex,
Slot: res.Slot,
CommitteeIndex: res.CommitteeIndex,
CommitteesAtSlot: res.CommitteesAtSlot,
IsAggregator: res.IsAggregator,
},
}
subs := []*eth2v1.BeaconCommitteeSubscription{{
ValidatorIndex: res.ValidatorIndex,
Slot: res.Slot,
CommitteeIndex: res.CommitteeIndex,
CommitteesAtSlot: res.CommitteesAtSlot,
IsAggregator: res.IsAggregator,
}}

err = b.eth2Cl.SubmitBeaconCommitteeSubscriptions(ctx, subs)
if err == nil {
log.Info(ctx, "Beacon committee subscription successfully submitted to beacon node",
log.Info(ctx, "Successfully submitted beacon committee subscription to beacon node",
z.Any("delay", b.delayFunc(duty.Slot)))
}

Expand All @@ -188,7 +186,7 @@ func (b Broadcaster) Broadcast(ctx context.Context, duty core.Duty, pubkey core.

err = b.eth2Cl.SubmitAggregateAttestations(ctx, []*eth2p0.SignedAggregateAndProof{&aggAndProof.SignedAggregateAndProof})
if err == nil {
log.Info(ctx, "Attestation aggregation successfully submitted to beacon node",
log.Info(ctx, "Successfully submitted attestation aggregation to beacon node",
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

maybe "Successfully submitted aggregated attestation to beacon node"

Copy link
Contributor Author

@corverroos corverroos Sep 28, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

potato potato 😉

z.Any("delay", b.delayFunc(duty.Slot)))
}

Expand Down
2 changes: 1 addition & 1 deletion core/consensus/component.go
Original file line number Diff line number Diff line change
Expand Up @@ -167,7 +167,7 @@ func (c *Component) Propose(ctx context.Context, duty core.Duty, data core.Unsig
return nil
}

log.Debug(ctx, "Starting qbft consensus instance", z.Any("duty", duty))
log.Debug(ctx, "QBFT consensus instance starting", z.Any("duty", duty))

// Hash the proposed data, since qbft ony supports simple comparable values.
value, err := core.UnsignedDataSetToProto(data)
Expand Down
2 changes: 1 addition & 1 deletion core/fetcher/fetcher.go
Original file line number Diff line number Diff line change
Expand Up @@ -169,7 +169,7 @@ func (f *Fetcher) fetchAggregatorData(ctx context.Context, slot int64, defSet co

// This validator isn't an aggregator for this slot.
if !res.IsAggregator {
log.Debug(ctx, "Not selected for attester aggregation duty", z.Any("pubkey", pubkey))
log.Debug(ctx, "Attester not selected for aggregation duty", z.Any("pubkey", pubkey))
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

maybe "Validator not selected for aggregation duty"

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The validator is an attester at this point.

continue
}
log.Info(ctx, "Resolved attester aggregation duty", z.Any("pubkey", pubkey))
Expand Down
8 changes: 4 additions & 4 deletions core/parsigdb/memory.go
Original file line number Diff line number Diff line change
Expand Up @@ -91,14 +91,14 @@ func (db *MemDB) StoreExternal(ctx context.Context, duty core.Duty, signedSet co
if err != nil {
return err
} else if !ok {
log.Debug(ctx, "Not storing duplicate partial signed data",
z.Any("pubkey", pubkey), z.Int("share_idx", sig.ShareIdx))
log.Debug(ctx, "Partial signed data ignored since duplicate")
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

maybe "Duplicate partial signed data ignored"

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm using identical prefixes


continue
}

log.Debug(ctx, "Stored partial signed data",
z.Any("pubkey", pubkey), z.Int("count", len(sigs)), z.Int("share_idx", sig.ShareIdx))
log.Debug(ctx, "Partial signed data stored",
z.Int("count", len(sigs)),
z.Any("pubkey", pubkey))

// Call the threshSubs (which includes SigAgg component) if sufficient signatures have been received.
if len(sigs) != db.threshold {
Expand Down
14 changes: 10 additions & 4 deletions core/scheduler/scheduler.go
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@ package scheduler
import (
"context"
"math"
"sort"
"sync"
"testing"
"time"
Expand Down Expand Up @@ -280,6 +281,11 @@ func (s *Scheduler) resolveAttDuties(ctx context.Context, slot core.Slot, vals v
remaining[index] = true
}

// Sort so logging below in ascending slot order.
sort.Slice(attDuties, func(i, j int) bool {
return attDuties[i].Slot < attDuties[j].Slot
})

for _, attDuty := range attDuties {
delete(remaining, attDuty.ValidatorIndex)

Expand All @@ -301,11 +307,11 @@ func (s *Scheduler) resolveAttDuties(ctx context.Context, slot core.Slot, vals v
}

log.Info(ctx, "Resolved attester duty",
z.U64("epoch", uint64(slot.Epoch())),
z.U64("vidx", uint64(attDuty.ValidatorIndex)),
z.U64("slot", uint64(attDuty.Slot)),
z.U64("commidx", uint64(attDuty.CommitteeIndex)),
z.Any("pubkey", pubkey))
z.U64("vidx", uint64(attDuty.ValidatorIndex)),
z.Any("pubkey", pubkey),
z.U64("epoch", uint64(slot.Epoch())),
)

// Schedule aggregation duty as well.
aggDuty := core.NewAggregatorDuty(int64(attDuty.Slot))
Expand Down
2 changes: 1 addition & 1 deletion core/sigagg/sigagg.go
Original file line number Diff line number Diff line change
Expand Up @@ -85,7 +85,7 @@ func (a *Aggregator) Aggregate(ctx context.Context, duty core.Duty, pubkey core.
return err
}

log.Debug(ctx, "Aggregated threshold partial signatures")
log.Debug(ctx, "Threshold aggregated partial signatures")

// Call subscriptions.
for _, sub := range a.subs {
Expand Down
5 changes: 1 addition & 4 deletions core/validatorapi/validatorapi.go
Original file line number Diff line number Diff line change
Expand Up @@ -263,8 +263,6 @@ func (c Component) SubmitAttestations(ctx context.Context, attestations []*eth2p
duty := core.NewAttesterDuty(slot)
ctx := log.WithCtx(ctx, z.Any("duty", duty))

log.Debug(ctx, "Attestation(s) submitted by validator client")

for _, sub := range c.subs {
// No need to clone since sub auto clones.
err := sub(ctx, duty, set)
Expand Down Expand Up @@ -362,6 +360,7 @@ func (c Component) SubmitBeaconBlock(ctx context.Context, block *spec.VersionedS
}

log.Debug(ctx, "Beacon block submitted by validator client")

signedData, err := core.NewPartialVersionedSignedBeaconBlock(block, c.shareIdx)
if err != nil {
return err
Expand Down Expand Up @@ -516,8 +515,6 @@ func (c Component) submitRegistration(ctx context.Context, registration *eth2api
return err
}

log.Debug(ctx, "Builder registration submitted by validator client")

signedData, err := core.NewPartialVersionedSignedValidatorRegistration(registration, c.shareIdx)
if err != nil {
return err
Expand Down