mirror of
https://github.com/OffchainLabs/prysm.git
synced 2026-01-09 13:28:01 -05:00
#### This PR sets the foundation for the new logging features. --- The goal of this big PR is the following: 1. Adding a log.go file to every package: [_commit_](54f6396d4c) - Writing a bash script that adds the log.go file to every package that imports logrus, except the excluded packages, configured at the top of the bash script. - the log.go file creates a log variable and sets a field called `package` to the full path of that package. - I have tried to fix every error/problem that came from mass generation of this file. (duplicate declarations, different prefix names, etc...) - some packages had the log.go file from before, and had some helper functions in there as well. I've moved all of them to a `log_helpers.go` file within each package. 2. Create a CI rule which verifies that: [_commit_](b799c3a0ef) - every package which imports logrus, also has a log.go file, except the excluded packages. - the `package` field of each log.go variable, has the correct path. (to detect when we move a package or change it's name) - I pushed a commit with a manually changed log.go file to trigger the ci check failure and it worked. 3. Alter the logging system to read the prefix from this `package` field for every log while outputing: [_commit_](b0c7f1146c) - some packages have/want/need a different log prefix than their package name (like `kv`). This can be solved by keeping a map of package paths to prefix names somewhere. --- **Some notes:** - Please review everything carefully. - I created the `prefixReplacement` map and populated the data that I deemed necessary. Please check it and complain if something doesn't make sense or is missing. I attached at the bottom, the list of all the packages that used to use a different name than their package name as their prefix. - I have chosen to mark some packages to be excluded from this whole process. They will either not log anything, or log without a prefix, or log using their previously defined prefix. See the list of exclusions in the bottom. - I fixed all the tests that failed because of this change. These were failing because they were expecting the old prefix to be in the generated logs. I have changed those to expect the new `package` field instead. This might not be a great solution. Ideally we might want to remove this from the tests so they only test for relevant fields in the logs. but this is a problem for another day. - Please run the node with this config, and mention if you see something weird in the logs. (use different verbosities) - The CI workflow uses a script that basically runs the `hack/gen-logs.sh` and checks that the git diff is zero. that script is `hack/check-logs.sh`. This means that if one runs this script locally, it will not actually _check_ anything, rather than just regenerate the log.go files and fix any mistake. This might be confusing. Please suggest solutions if you think it's a problem. --- **A list of packages that used a different prefix than their package names for their logs:** - beacon-chain/cache/depositsnapshot/ package depositsnapshot, prefix "cache" - beacon-chain/core/transition/log.go — package transition, prefix "state" - beacon-chain/db/kv/log.go — package kv, prefix "db" - beacon-chain/db/slasherkv/log.go — package slasherkv, prefix "slasherdb" - beacon-chain/db/pruner/pruner.go — package pruner, prefix "db-pruner" - beacon-chain/light-client/log.go — package light_client, prefix "light-client" - beacon-chain/operations/attestations/log.go — package attestations, prefix "pool/attestations" - beacon-chain/operations/slashings/log.go — package slashings, prefix "pool/slashings" - beacon-chain/rpc/core/log.go — package core, prefix "rpc/core" - beacon-chain/rpc/eth/beacon/log.go — package beacon, prefix "rpc/beaconv1" - beacon-chain/rpc/eth/validator/log.go — package validator, prefix "beacon-api" - beacon-chain/rpc/prysm/v1alpha1/beacon/log.go — package beacon, prefix "rpc" - beacon-chain/rpc/prysm/v1alpha1/validator/log.go — package validator, prefix "rpc/validator" - beacon-chain/state/stategen/log.go — package stategen, prefix "state-gen" - beacon-chain/sync/checkpoint/log.go — package checkpoint, prefix "checkpoint-sync" - beacon-chain/sync/initial-sync/log.go — package initialsync, prefix "initial-sync" - cmd/prysmctl/p2p/log.go — package p2p, prefix "prysmctl-p2p" - config/features/log.go -- package features, prefix "flags" - io/file/log.go — package file, prefix "fileutil" - proto/prysm/v1alpha1/log.go — package eth, prefix "protobuf" - validator/client/beacon-api/log.go — package beacon_api, prefix "beacon-api" - validator/db/kv/log.go — package kv, prefix "db" - validator/db/filesystem/db.go — package filesystem, prefix "db" - validator/keymanager/derived/log.go — package derived, prefix "derived-keymanager" - validator/keymanager/local/log.go — package local, prefix "local-keymanager" - validator/keymanager/remote-web3signer/log.go — package remote_web3signer, prefix "remote-keymanager" - validator/keymanager/remote-web3signer/internal/log.go — package internal, prefix "remote-web3signer- internal" - beacon-chain/forkchoice/doubly... prefix is "forkchoice-doublylinkedtree" **List of excluded directories (their subdirectories are also excluded):** ``` EXCLUDED_PATH_PREFIXES=( "testing" "validator/client/testutil" "beacon-chain/p2p/testing" "beacon-chain/rpc/eth/config" "beacon-chain/rpc/prysm/v1alpha1/debug" "tools" "runtime" "monitoring" "io" "cmd" ".well-known" "changelog" "hack" "specrefs" "third_party" "bazel-out" "bazel-bin" "bazel-prysm" "bazel-testlogs" "build" ".github" ".jj" ".idea" ".vscode" ) ```
287 lines
9.1 KiB
Go
287 lines
9.1 KiB
Go
package monitor
|
|
|
|
import (
|
|
"fmt"
|
|
"testing"
|
|
|
|
"github.com/OffchainLabs/prysm/v7/beacon-chain/core/altair"
|
|
"github.com/OffchainLabs/prysm/v7/config/params"
|
|
"github.com/OffchainLabs/prysm/v7/consensus-types/blocks"
|
|
"github.com/OffchainLabs/prysm/v7/consensus-types/primitives"
|
|
"github.com/OffchainLabs/prysm/v7/encoding/bytesutil"
|
|
ethpb "github.com/OffchainLabs/prysm/v7/proto/prysm/v1alpha1"
|
|
"github.com/OffchainLabs/prysm/v7/testing/require"
|
|
"github.com/OffchainLabs/prysm/v7/testing/util"
|
|
logTest "github.com/sirupsen/logrus/hooks/test"
|
|
)
|
|
|
|
func TestProcessSlashings(t *testing.T) {
|
|
tests := []struct {
|
|
name string
|
|
block *ethpb.BeaconBlock
|
|
wantedErr string
|
|
}{
|
|
{
|
|
name: "Proposer slashing a tracked index",
|
|
block: ðpb.BeaconBlock{
|
|
Body: ðpb.BeaconBlockBody{
|
|
ProposerSlashings: []*ethpb.ProposerSlashing{
|
|
{
|
|
Header_1: ðpb.SignedBeaconBlockHeader{
|
|
Header: ðpb.BeaconBlockHeader{
|
|
ProposerIndex: 2,
|
|
Slot: params.BeaconConfig().SlotsPerEpoch + 1,
|
|
},
|
|
},
|
|
Header_2: ðpb.SignedBeaconBlockHeader{
|
|
Header: ðpb.BeaconBlockHeader{
|
|
ProposerIndex: 2,
|
|
Slot: 0,
|
|
},
|
|
},
|
|
},
|
|
},
|
|
},
|
|
},
|
|
wantedErr: "\"Proposer slashing was included\" bodyRoot1= bodyRoot2= package=beacon-chain/monitor proposerIndex=2",
|
|
},
|
|
{
|
|
name: "Proposer slashing an untracked index",
|
|
block: ðpb.BeaconBlock{
|
|
Body: ðpb.BeaconBlockBody{
|
|
ProposerSlashings: []*ethpb.ProposerSlashing{
|
|
{
|
|
Header_1: ðpb.SignedBeaconBlockHeader{
|
|
Header: ðpb.BeaconBlockHeader{
|
|
ProposerIndex: 3,
|
|
Slot: params.BeaconConfig().SlotsPerEpoch + 4,
|
|
},
|
|
},
|
|
Header_2: ðpb.SignedBeaconBlockHeader{
|
|
Header: ðpb.BeaconBlockHeader{
|
|
ProposerIndex: 3,
|
|
Slot: 0,
|
|
},
|
|
},
|
|
},
|
|
},
|
|
},
|
|
},
|
|
wantedErr: "",
|
|
},
|
|
{
|
|
name: "Attester slashing a tracked index",
|
|
block: ðpb.BeaconBlock{
|
|
Body: ðpb.BeaconBlockBody{
|
|
AttesterSlashings: []*ethpb.AttesterSlashing{
|
|
{
|
|
Attestation_1: util.HydrateIndexedAttestation(ðpb.IndexedAttestation{
|
|
Data: ðpb.AttestationData{
|
|
Source: ðpb.Checkpoint{Epoch: 1},
|
|
},
|
|
AttestingIndices: []uint64{1, 3, 4},
|
|
}),
|
|
Attestation_2: util.HydrateIndexedAttestation(ðpb.IndexedAttestation{
|
|
AttestingIndices: []uint64{1, 5, 6},
|
|
}),
|
|
},
|
|
},
|
|
},
|
|
},
|
|
wantedErr: "\"Attester slashing was included\" attestationSlot1=0 attestationSlot2=0 attesterIndex=1 " +
|
|
"beaconBlockRoot1=0x000000000000 beaconBlockRoot2=0x000000000000 blockInclusionSlot=0 package=beacon-chain/monitor sourceEpoch1=1 sourceEpoch2=0 targetEpoch1=0 targetEpoch2=0",
|
|
},
|
|
{
|
|
name: "Attester slashing untracked index",
|
|
block: ðpb.BeaconBlock{
|
|
Body: ðpb.BeaconBlockBody{
|
|
AttesterSlashings: []*ethpb.AttesterSlashing{
|
|
{
|
|
Attestation_1: util.HydrateIndexedAttestation(ðpb.IndexedAttestation{
|
|
Data: ðpb.AttestationData{
|
|
Source: ðpb.Checkpoint{Epoch: 1},
|
|
},
|
|
AttestingIndices: []uint64{1, 3, 4},
|
|
}),
|
|
Attestation_2: util.HydrateIndexedAttestation(ðpb.IndexedAttestation{
|
|
AttestingIndices: []uint64{3, 5, 6},
|
|
}),
|
|
},
|
|
},
|
|
},
|
|
},
|
|
wantedErr: "",
|
|
}}
|
|
|
|
for _, tt := range tests {
|
|
t.Run(tt.name, func(t *testing.T) {
|
|
hook := logTest.NewGlobal()
|
|
s := &Service{
|
|
TrackedValidators: map[primitives.ValidatorIndex]bool{
|
|
1: true,
|
|
2: true,
|
|
},
|
|
}
|
|
wb, err := blocks.NewBeaconBlock(tt.block)
|
|
require.NoError(t, err)
|
|
s.processSlashings(wb)
|
|
if tt.wantedErr != "" {
|
|
require.LogsContain(t, hook, tt.wantedErr)
|
|
} else {
|
|
require.LogsDoNotContain(t, hook, "slashing")
|
|
}
|
|
})
|
|
}
|
|
}
|
|
|
|
func TestProcessProposedBlock(t *testing.T) {
|
|
tests := []struct {
|
|
name string
|
|
block *ethpb.BeaconBlock
|
|
wantedErr string
|
|
}{
|
|
{
|
|
name: "Block proposed by tracked validator",
|
|
block: ðpb.BeaconBlock{
|
|
Slot: 6,
|
|
ProposerIndex: 12,
|
|
ParentRoot: bytesutil.PadTo([]byte("hello-world"), 32),
|
|
StateRoot: bytesutil.PadTo([]byte("state-world"), 32),
|
|
Body: ðpb.BeaconBlockBody{},
|
|
},
|
|
wantedErr: "\"Proposed beacon block was included\" balanceChange=100000000 blockRoot=0x68656c6c6f2d newBalance=32000000000 package=beacon-chain/monitor parentRoot=0x68656c6c6f2d proposerIndex=12 slot=6 version=0",
|
|
},
|
|
{
|
|
name: "Block proposed by untracked validator",
|
|
block: ðpb.BeaconBlock{
|
|
Slot: 6,
|
|
ProposerIndex: 13,
|
|
ParentRoot: bytesutil.PadTo([]byte("hello-world"), 32),
|
|
StateRoot: bytesutil.PadTo([]byte("state-world"), 32),
|
|
Body: ðpb.BeaconBlockBody{},
|
|
},
|
|
},
|
|
}
|
|
|
|
for _, tt := range tests {
|
|
t.Run(tt.name, func(t *testing.T) {
|
|
hook := logTest.NewGlobal()
|
|
s := setupService(t)
|
|
beaconState, _ := util.DeterministicGenesisState(t, 256)
|
|
var root [32]byte
|
|
copy(root[:], "hello-world")
|
|
wb, err := blocks.NewBeaconBlock(tt.block)
|
|
require.NoError(t, err)
|
|
s.processProposedBlock(beaconState, root, wb)
|
|
if tt.wantedErr != "" {
|
|
require.LogsContain(t, hook, tt.wantedErr)
|
|
} else {
|
|
require.LogsDoNotContain(t, hook, "included")
|
|
}
|
|
})
|
|
}
|
|
|
|
}
|
|
|
|
func TestProcessBlock_AllEventsTrackedVals(t *testing.T) {
|
|
hook := logTest.NewGlobal()
|
|
ctx := t.Context()
|
|
|
|
genesis, keys := util.DeterministicGenesisStateAltair(t, 64)
|
|
c, err := altair.NextSyncCommittee(ctx, genesis)
|
|
require.NoError(t, err)
|
|
require.NoError(t, genesis.SetCurrentSyncCommittee(c))
|
|
|
|
genConfig := util.DefaultBlockGenConfig()
|
|
genConfig.NumProposerSlashings = 1
|
|
genConfig.FullSyncAggregate = true
|
|
b, err := util.GenerateFullBlockAltair(genesis, keys, genConfig, 1)
|
|
require.NoError(t, err)
|
|
s := setupService(t)
|
|
|
|
pubKeys := make([][]byte, 3)
|
|
pubKeys[0] = genesis.Validators()[0].PublicKey
|
|
pubKeys[1] = genesis.Validators()[1].PublicKey
|
|
pubKeys[2] = genesis.Validators()[2].PublicKey
|
|
|
|
currentSyncCommittee := util.ConvertToCommittee([][]byte{
|
|
pubKeys[0], pubKeys[1], pubKeys[2], pubKeys[1], pubKeys[1],
|
|
})
|
|
require.NoError(t, genesis.SetCurrentSyncCommittee(currentSyncCommittee))
|
|
|
|
idx := b.Block.Body.ProposerSlashings[0].Header_1.Header.ProposerIndex
|
|
s.RLock()
|
|
if !s.trackedIndex(idx) {
|
|
s.TrackedValidators[idx] = true
|
|
s.latestPerformance[idx] = ValidatorLatestPerformance{
|
|
balance: 31900000000,
|
|
}
|
|
s.aggregatedPerformance[idx] = ValidatorAggregatedPerformance{}
|
|
}
|
|
s.RUnlock()
|
|
s.updateSyncCommitteeTrackedVals(genesis)
|
|
|
|
root, err := b.GetBlock().HashTreeRoot()
|
|
require.NoError(t, err)
|
|
require.NoError(t, s.config.StateGen.SaveState(ctx, root, genesis))
|
|
wanted1 := fmt.Sprintf("\"Proposed beacon block was included\" balanceChange=100000000 blockRoot=%#x newBalance=32000000000 package=beacon-chain/monitor parentRoot=0xf732eaeb7fae proposerIndex=15 slot=1 version=1", bytesutil.Trunc(root[:]))
|
|
wanted2 := fmt.Sprintf("\"Proposer slashing was included\" bodyRoot1=0x000100000000 bodyRoot2=0x000200000000 package=beacon-chain/monitor proposerIndex=%d slashingSlot=0 slot=1", idx)
|
|
wanted3 := "\"Sync committee contribution included\" balanceChange=0 contribCount=3 expectedContribCount=3 newBalance=32000000000 package=beacon-chain/monitor validatorIndex=1"
|
|
wanted4 := "\"Sync committee contribution included\" balanceChange=0 contribCount=1 expectedContribCount=1 newBalance=32000000000 package=beacon-chain/monitor validatorIndex=2"
|
|
wrapped, err := blocks.NewSignedBeaconBlock(b)
|
|
require.NoError(t, err)
|
|
s.processBlock(ctx, wrapped)
|
|
require.LogsContain(t, hook, wanted1)
|
|
require.LogsContain(t, hook, wanted2)
|
|
require.LogsContain(t, hook, wanted3)
|
|
require.LogsContain(t, hook, wanted4)
|
|
}
|
|
|
|
func TestLogAggregatedPerformance(t *testing.T) {
|
|
hook := logTest.NewGlobal()
|
|
latestPerformance := map[primitives.ValidatorIndex]ValidatorLatestPerformance{
|
|
1: {
|
|
balance: 32000000000,
|
|
},
|
|
2: {
|
|
balance: 32000000000,
|
|
},
|
|
12: {
|
|
balance: 31900000000,
|
|
},
|
|
15: {
|
|
balance: 31900000000,
|
|
},
|
|
}
|
|
aggregatedPerformance := map[primitives.ValidatorIndex]ValidatorAggregatedPerformance{
|
|
1: {
|
|
startEpoch: 0,
|
|
startBalance: 31700000000,
|
|
totalAttestedCount: 12,
|
|
totalRequestedCount: 15,
|
|
totalDistance: 14,
|
|
totalCorrectHead: 8,
|
|
totalCorrectSource: 11,
|
|
totalCorrectTarget: 12,
|
|
totalProposedCount: 1,
|
|
totalSyncCommitteeContributions: 0,
|
|
totalSyncCommitteeAggregations: 0,
|
|
},
|
|
2: {},
|
|
12: {},
|
|
15: {},
|
|
}
|
|
s := &Service{
|
|
latestPerformance: latestPerformance,
|
|
aggregatedPerformance: aggregatedPerformance,
|
|
}
|
|
|
|
s.logAggregatedPerformance()
|
|
wanted := "\"Aggregated performance since launch\" attestationInclusion=\"80.00%\"" +
|
|
" averageInclusionDistance=1.2 balanceChangePct=\"0.95%\" correctlyVotedHeadPct=\"66.67%\" " +
|
|
"correctlyVotedSourcePct=\"91.67%\" correctlyVotedTargetPct=\"100.00%\" package=beacon-chain/monitor startBalance=31700000000 " +
|
|
"startEpoch=0 totalAggregations=0 totalProposedBlocks=1 totalRequested=15 totalSyncContributions=0 " +
|
|
"validatorIndex=1"
|
|
require.LogsContain(t, hook, wanted)
|
|
}
|