Compare commits

...

3 Commits

Author SHA1 Message Date
james-prysm
62edbb7196 editing error handling 2026-01-23 16:09:31 -06:00
james-prysm
d407387193 removing duplicate logic in blockroot handler by using blocker lookup 2026-01-23 15:58:35 -06:00
Bastin
6a9bcbab3a logging: per package verbosity (#16272)
**What type of PR is this?**
Feature

**What does this PR do? Why is it needed?**
This PR adds a `--log.vmodule` flag to the beacon-chain and validator
apps, that allows setting a different verbosity for every* package.

*: not every package, but most packages. (all packages that define their
logger variable with a `package` field)

Combined with the `--verbosity` flag this allows users to control
exactly what they see.

This affects both the terminal and the log file (`--log-file`), but not
the ephemeral debug log file.

example usage: 
```
./beacon-chain --log.vmodule=beacon-chain/p2p=info,beacon-chain/sync=error,beacon-chain/sync/initial-sync=debug
```

There are improvements to be done later, like accepting just the package
name instead of the full path, etc.
2026-01-23 19:22:20 +00:00
22 changed files with 438 additions and 119 deletions

View File

@@ -8,7 +8,6 @@ import (
"io"
"net/http"
"strconv"
"strings"
"time"
"github.com/OffchainLabs/prysm/v7/api"
@@ -26,7 +25,6 @@ import (
"github.com/OffchainLabs/prysm/v7/consensus-types/blocks"
"github.com/OffchainLabs/prysm/v7/consensus-types/interfaces"
"github.com/OffchainLabs/prysm/v7/consensus-types/primitives"
"github.com/OffchainLabs/prysm/v7/encoding/bytesutil"
"github.com/OffchainLabs/prysm/v7/monitoring/tracing/trace"
"github.com/OffchainLabs/prysm/v7/network/httputil"
eth "github.com/OffchainLabs/prysm/v7/proto/prysm/v1alpha1"
@@ -1044,112 +1042,27 @@ func (s *Server) GetBlockRoot(w http.ResponseWriter, r *http.Request) {
ctx, span := trace.StartSpan(r.Context(), "beacon.GetBlockRoot")
defer span.End()
var err error
var root []byte
blockID := r.PathValue("block_id")
if blockID == "" {
httputil.HandleError(w, "block_id is required in URL params", http.StatusBadRequest)
return
}
switch blockID {
case "head":
root, err = s.ChainInfoFetcher.HeadRoot(ctx)
if err != nil {
httputil.HandleError(w, "Could not retrieve head root: "+err.Error(), http.StatusInternalServerError)
return
}
if root == nil {
httputil.HandleError(w, "No head root was found", http.StatusNotFound)
return
}
case "finalized":
finalized := s.ChainInfoFetcher.FinalizedCheckpt()
root = finalized.Root
case "genesis":
blk, err := s.BeaconDB.GenesisBlock(ctx)
if err != nil {
httputil.HandleError(w, "Could not retrieve genesis block: "+err.Error(), http.StatusInternalServerError)
return
}
if err := blocks.BeaconBlockIsNil(blk); err != nil {
httputil.HandleError(w, "Could not find genesis block: "+err.Error(), http.StatusNotFound)
return
}
blkRoot, err := blk.Block().HashTreeRoot()
if err != nil {
httputil.HandleError(w, "Could not hash genesis block: "+err.Error(), http.StatusInternalServerError)
return
}
root = blkRoot[:]
default:
isHex := strings.HasPrefix(blockID, "0x")
if isHex {
blockIDBytes, err := hexutil.Decode(blockID)
if err != nil {
httputil.HandleError(w, "Could not decode block ID into bytes: "+err.Error(), http.StatusBadRequest)
return
}
if len(blockIDBytes) != fieldparams.RootLength {
httputil.HandleError(w, fmt.Sprintf("Block ID has length %d instead of %d", len(blockIDBytes), fieldparams.RootLength), http.StatusBadRequest)
return
}
blockID32 := bytesutil.ToBytes32(blockIDBytes)
blk, err := s.BeaconDB.Block(ctx, blockID32)
if err != nil {
httputil.HandleError(w, fmt.Sprintf("Could not retrieve block for block root %#x: %v", blockID, err), http.StatusInternalServerError)
return
}
if err := blocks.BeaconBlockIsNil(blk); err != nil {
httputil.HandleError(w, "Could not find block: "+err.Error(), http.StatusNotFound)
return
}
root = blockIDBytes
} else {
slot, err := strconv.ParseUint(blockID, 10, 64)
if err != nil {
httputil.HandleError(w, "Could not parse block ID: "+err.Error(), http.StatusBadRequest)
return
}
hasRoots, roots, err := s.BeaconDB.BlockRootsBySlot(ctx, primitives.Slot(slot))
if err != nil {
httputil.HandleError(w, fmt.Sprintf("Could not retrieve blocks for slot %d: %v", slot, err), http.StatusInternalServerError)
return
}
if !hasRoots {
httputil.HandleError(w, "Could not find any blocks with given slot", http.StatusNotFound)
return
}
root = roots[0][:]
if len(roots) == 1 {
break
}
for _, blockRoot := range roots {
canonical, err := s.ChainInfoFetcher.IsCanonical(ctx, blockRoot)
if err != nil {
httputil.HandleError(w, "Could not determine if block root is canonical: "+err.Error(), http.StatusInternalServerError)
return
}
if canonical {
root = blockRoot[:]
break
}
}
}
root, err := s.Blocker.BlockRoot(ctx, []byte(blockID))
if !shared.WriteBlockRootFetchError(w, err) {
return
}
b32Root := bytesutil.ToBytes32(root)
isOptimistic, err := s.OptimisticModeFetcher.IsOptimisticForRoot(ctx, b32Root)
isOptimistic, err := s.OptimisticModeFetcher.IsOptimisticForRoot(ctx, root)
if err != nil {
httputil.HandleError(w, "Could not check if block is optimistic: "+err.Error(), http.StatusInternalServerError)
return
}
response := &structs.BlockRootResponse{
Data: &structs.BlockRoot{
Root: hexutil.Encode(root),
Root: hexutil.Encode(root[:]),
},
ExecutionOptimistic: isOptimistic,
Finalized: s.FinalizationFetcher.IsFinalized(ctx, b32Root),
Finalized: s.FinalizationFetcher.IsFinalized(ctx, root),
}
httputil.WriteJson(w, response)
}

View File

@@ -2509,6 +2509,10 @@ func TestServer_GetBlockRoot(t *testing.T) {
HeadFetcher: mockChainFetcher,
OptimisticModeFetcher: mockChainFetcher,
FinalizationFetcher: mockChainFetcher,
Blocker: &lookup.BeaconDbBlocker{
BeaconDB: beaconDB,
ChainInfoFetcher: mockChainFetcher,
},
}
root, err := genBlk.Block.HashTreeRoot()
@@ -2524,7 +2528,7 @@ func TestServer_GetBlockRoot(t *testing.T) {
{
name: "bad formatting",
blockID: map[string]string{"block_id": "3bad0"},
wantErr: "Could not parse block ID",
wantErr: "Invalid block ID",
wantCode: http.StatusBadRequest,
},
{
@@ -2572,7 +2576,7 @@ func TestServer_GetBlockRoot(t *testing.T) {
{
name: "non-existent root",
blockID: map[string]string{"block_id": hexutil.Encode(bytesutil.PadTo([]byte("hi there"), 32))},
wantErr: "Could not find block",
wantErr: "Block not found",
wantCode: http.StatusNotFound,
},
{
@@ -2585,7 +2589,7 @@ func TestServer_GetBlockRoot(t *testing.T) {
{
name: "no block",
blockID: map[string]string{"block_id": "105"},
wantErr: "Could not find any blocks with given slot",
wantErr: "Block not found",
wantCode: http.StatusNotFound,
},
}
@@ -2633,6 +2637,10 @@ func TestServer_GetBlockRoot(t *testing.T) {
HeadFetcher: mockChainFetcher,
OptimisticModeFetcher: mockChainFetcher,
FinalizationFetcher: mockChainFetcher,
Blocker: &lookup.BeaconDbBlocker{
BeaconDB: beaconDB,
ChainInfoFetcher: mockChainFetcher,
},
}
request := httptest.NewRequest(http.MethodGet, url, nil)
@@ -2668,6 +2676,10 @@ func TestServer_GetBlockRoot(t *testing.T) {
HeadFetcher: mockChainFetcher,
OptimisticModeFetcher: mockChainFetcher,
FinalizationFetcher: mockChainFetcher,
Blocker: &lookup.BeaconDbBlocker{
BeaconDB: beaconDB,
ChainInfoFetcher: mockChainFetcher,
},
}
t.Run("true", func(t *testing.T) {
request := httptest.NewRequest(http.MethodGet, url, nil)

View File

@@ -26,21 +26,30 @@ func WriteStateFetchError(w http.ResponseWriter, err error) {
httputil.HandleError(w, "Could not get state: "+err.Error(), http.StatusInternalServerError)
}
// WriteBlockFetchError writes an appropriate error based on the supplied argument.
// The argument error should be a result of fetching block.
func WriteBlockFetchError(w http.ResponseWriter, blk interfaces.ReadOnlySignedBeaconBlock, err error) bool {
// writeBlockIdError handles common block ID lookup errors.
// Returns true if an error was handled and written to the response, false if no error.
func writeBlockIdError(w http.ResponseWriter, err error, fallbackMsg string) bool {
if err == nil {
return false
}
var blockNotFoundErr *lookup.BlockNotFoundError
if errors.As(err, &blockNotFoundErr) {
httputil.HandleError(w, "Block not found: "+blockNotFoundErr.Error(), http.StatusNotFound)
return false
return true
}
var invalidBlockIdErr *lookup.BlockIdParseError
if errors.As(err, &invalidBlockIdErr) {
httputil.HandleError(w, "Invalid block ID: "+invalidBlockIdErr.Error(), http.StatusBadRequest)
return false
return true
}
if err != nil {
httputil.HandleError(w, "Could not get block from block ID: "+err.Error(), http.StatusInternalServerError)
httputil.HandleError(w, fallbackMsg+err.Error(), http.StatusInternalServerError)
return true
}
// WriteBlockFetchError writes an appropriate error based on the supplied argument.
// The argument error should be a result of fetching block.
func WriteBlockFetchError(w http.ResponseWriter, blk interfaces.ReadOnlySignedBeaconBlock, err error) bool {
if writeBlockIdError(w, err, "Could not get block from block ID: ") {
return false
}
if err = blocks.BeaconBlockIsNil(blk); err != nil {
@@ -49,3 +58,10 @@ func WriteBlockFetchError(w http.ResponseWriter, blk interfaces.ReadOnlySignedBe
}
return true
}
// WriteBlockRootFetchError writes an appropriate error based on the supplied argument.
// The argument error should be a result of fetching block root.
// Returns true if no error occurred, false otherwise.
func WriteBlockRootFetchError(w http.ResponseWriter, err error) bool {
return !writeBlockIdError(w, err, "Could not get block root from block ID: ")
}

View File

@@ -105,3 +105,59 @@ func TestWriteBlockFetchError(t *testing.T) {
})
}
}
// TestWriteBlockRootFetchError tests the WriteBlockRootFetchError function
// to ensure that the correct error message and code are written to the response
// and that the function returns the correct boolean value.
func TestWriteBlockRootFetchError(t *testing.T) {
cases := []struct {
name string
err error
expectedMessage string
expectedCode int
expectedReturn bool
}{
{
name: "Nil error should return true",
err: nil,
expectedReturn: true,
},
{
name: "BlockNotFoundError should return 404",
err: lookup.NewBlockNotFoundError("block not found at slot 123"),
expectedMessage: "Block not found",
expectedCode: http.StatusNotFound,
expectedReturn: false,
},
{
name: "BlockIdParseError should return 400",
err: &lookup.BlockIdParseError{},
expectedMessage: "Invalid block ID",
expectedCode: http.StatusBadRequest,
expectedReturn: false,
},
{
name: "Generic error should return 500",
err: errors.New("database connection failed"),
expectedMessage: "Could not get block root from block ID",
expectedCode: http.StatusInternalServerError,
expectedReturn: false,
},
}
for _, c := range cases {
t.Run(c.name, func(t *testing.T) {
writer := httptest.NewRecorder()
result := WriteBlockRootFetchError(writer, c.err)
assert.Equal(t, c.expectedReturn, result, "incorrect return value")
if !c.expectedReturn {
assert.Equal(t, c.expectedCode, writer.Code, "incorrect status code")
assert.StringContains(t, c.expectedMessage, writer.Body.String(), "incorrect error message")
e := &httputil.DefaultJsonError{}
assert.NoError(t, json.Unmarshal(writer.Body.Bytes(), e), "failed to unmarshal response")
}
})
}
}

View File

@@ -60,6 +60,7 @@ func (e BlockIdParseError) Error() string {
// Blocker is responsible for retrieving blocks.
type Blocker interface {
Block(ctx context.Context, id []byte) (interfaces.ReadOnlySignedBeaconBlock, error)
BlockRoot(ctx context.Context, id []byte) ([fieldparams.RootLength]byte, error)
BlobSidecars(ctx context.Context, id string, opts ...options.BlobsOption) ([]*blocks.VerifiedROBlob, *core.RpcError)
Blobs(ctx context.Context, id string, opts ...options.BlobsOption) ([][]byte, *core.RpcError)
DataColumns(ctx context.Context, id string, indices []int) ([]blocks.VerifiedRODataColumn, *core.RpcError)
@@ -225,6 +226,19 @@ func (p *BeaconDbBlocker) Block(ctx context.Context, id []byte) (interfaces.Read
return blk, nil
}
// BlockRoot returns the block root for a given identifier. The identifier can be one of:
// - "head" (canonical head in node's view)
// - "genesis"
// - "finalized"
// - "justified"
// - <slot>
// - <hex encoded block root with '0x' prefix>
// - <block root>
func (p *BeaconDbBlocker) BlockRoot(ctx context.Context, id []byte) ([fieldparams.RootLength]byte, error) {
root, _, err := p.resolveBlockID(ctx, string(id))
return root, err
}
// blobsContext holds common information needed for blob retrieval
type blobsContext struct {
root [fieldparams.RootLength]byte

View File

@@ -168,6 +168,111 @@ func TestGetBlock(t *testing.T) {
}
}
func TestBlockRoot(t *testing.T) {
beaconDB := testDB.SetupDB(t)
ctx := t.Context()
genBlk, blkContainers := testutil.FillDBWithBlocks(ctx, t, beaconDB)
canonicalRoots := make(map[[32]byte]bool)
for _, bContr := range blkContainers {
canonicalRoots[bytesutil.ToBytes32(bContr.BlockRoot)] = true
}
headBlock := blkContainers[len(blkContainers)-1]
wsb, err := blocks.NewSignedBeaconBlock(headBlock.Block.(*ethpb.BeaconBlockContainer_Phase0Block).Phase0Block)
require.NoError(t, err)
fetcher := &BeaconDbBlocker{
BeaconDB: beaconDB,
ChainInfoFetcher: &mockChain.ChainService{
DB: beaconDB,
Block: wsb,
Root: headBlock.BlockRoot,
FinalizedCheckPoint: &ethpb.Checkpoint{Root: blkContainers[64].BlockRoot},
CurrentJustifiedCheckPoint: &ethpb.Checkpoint{Root: blkContainers[32].BlockRoot},
CanonicalRoots: canonicalRoots,
},
}
genesisRoot, err := genBlk.Block.HashTreeRoot()
require.NoError(t, err)
tests := []struct {
name string
blockID []byte
want [32]byte
wantErr bool
}{
{
name: "slot",
blockID: []byte("30"),
want: bytesutil.ToBytes32(blkContainers[30].BlockRoot),
},
{
name: "bad formatting",
blockID: []byte("3bad0"),
wantErr: true,
},
{
name: "head",
blockID: []byte("head"),
want: bytesutil.ToBytes32(headBlock.BlockRoot),
},
{
name: "finalized",
blockID: []byte("finalized"),
want: bytesutil.ToBytes32(blkContainers[64].BlockRoot),
},
{
name: "justified",
blockID: []byte("justified"),
want: bytesutil.ToBytes32(blkContainers[32].BlockRoot),
},
{
name: "genesis",
blockID: []byte("genesis"),
want: genesisRoot,
},
{
name: "genesis root",
blockID: genesisRoot[:],
want: genesisRoot,
},
{
name: "root",
blockID: blkContainers[20].BlockRoot,
want: bytesutil.ToBytes32(blkContainers[20].BlockRoot),
},
{
name: "hex root",
blockID: []byte(hexutil.Encode(blkContainers[20].BlockRoot)),
want: bytesutil.ToBytes32(blkContainers[20].BlockRoot),
},
{
name: "non-existent root",
blockID: bytesutil.PadTo([]byte("hi there"), 32),
wantErr: true,
},
{
name: "no block at slot",
blockID: []byte("105"),
wantErr: true,
},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
result, err := fetcher.BlockRoot(ctx, tt.blockID)
if tt.wantErr {
assert.NotEqual(t, err, nil, "no error has been returned")
return
}
require.NoError(t, err)
assert.DeepEqual(t, tt.want, result)
})
}
}
func TestBlobsErrorHandling(t *testing.T) {
params.SetupTestConfigCleanup(t)
cfg := params.BeaconConfig().Copy()

View File

@@ -15,6 +15,7 @@ import (
// MockBlocker is a fake implementation of lookup.Blocker.
type MockBlocker struct {
BlockToReturn interfaces.ReadOnlySignedBeaconBlock
RootToReturn [32]byte
ErrorToReturn error
SlotBlockMap map[primitives.Slot]interfaces.ReadOnlySignedBeaconBlock
RootBlockMap map[[32]byte]interfaces.ReadOnlySignedBeaconBlock
@@ -39,6 +40,14 @@ func (m *MockBlocker) Block(_ context.Context, b []byte) (interfaces.ReadOnlySig
return m.SlotBlockMap[primitives.Slot(slotNumber)], nil
}
// BlockRoot --
func (m *MockBlocker) BlockRoot(_ context.Context, _ []byte) ([32]byte, error) {
if m.ErrorToReturn != nil {
return [32]byte{}, m.ErrorToReturn
}
return m.RootToReturn, nil
}
// BlobSidecars --
func (*MockBlocker) BlobSidecars(_ context.Context, _ string, _ ...options.BlobsOption) ([]*blocks.VerifiedROBlob, *core.RpcError) {
return nil, &core.RpcError{}

View File

@@ -0,0 +1,3 @@
### Added
- Flag `--log.vmodule` to set per-package verbosity levels for logging.

View File

@@ -0,0 +1,3 @@
### Ignored
- optmizing /eth/v1/beacon/blocks/{block_id}/root endpoint by reusing blocker lookup instead of duplicated logic.

View File

@@ -42,6 +42,7 @@ go_test(
"//testing/assert:go_default_library",
"//testing/require:go_default_library",
"@com_github_pkg_errors//:go_default_library",
"@com_github_sirupsen_logrus//:go_default_library",
"@com_github_urfave_cli_v2//:go_default_library",
"@org_uber_go_mock//gomock:go_default_library",
],

View File

@@ -8,6 +8,7 @@ import (
"os"
"path/filepath"
runtimeDebug "runtime/debug"
"strings"
"github.com/OffchainLabs/prysm/v7/beacon-chain/builder"
"github.com/OffchainLabs/prysm/v7/beacon-chain/node"
@@ -113,6 +114,7 @@ var appFlags = []cli.Flag{
cmd.PubsubQueueSize,
cmd.DataDirFlag,
cmd.VerbosityFlag,
cmd.LogVModuleFlag,
cmd.EnableTracingFlag,
cmd.TracingProcessNameFlag,
cmd.TracingEndpointFlag,
@@ -171,13 +173,22 @@ func before(ctx *cli.Context) error {
return errors.Wrap(err, "failed to load flags from config file")
}
// determine log verbosity
// determine default log verbosity
verbosity := ctx.String(cmd.VerbosityFlag.Name)
verbosityLevel, err := logrus.ParseLevel(verbosity)
if err != nil {
return errors.Wrap(err, "failed to parse log verbosity")
}
logs.SetLoggingLevel(verbosityLevel)
// determine per package verbosity. if not set, maxLevel will be 0.
vmoduleInput := strings.Join(ctx.StringSlice(cmd.LogVModuleFlag.Name), ",")
vmodule, maxLevel, err := cmd.ParseVModule(vmoduleInput)
if err != nil {
return errors.Wrap(err, "failed to parse log vmodule")
}
// set the global logging level to allow for the highest verbosity requested
logs.SetLoggingLevel(max(verbosityLevel, maxLevel))
format := ctx.String(cmd.LogFormat.Name)
switch format {
@@ -191,11 +202,13 @@ func before(ctx *cli.Context) error {
formatter.FullTimestamp = true
formatter.ForceFormatting = true
formatter.ForceColors = true
formatter.VModule = vmodule
formatter.BaseVerbosity = verbosityLevel
logrus.AddHook(&logs.WriterHook{
Formatter: formatter,
Writer: os.Stderr,
AllowedLevels: logrus.AllLevels[:verbosityLevel+1],
AllowedLevels: logrus.AllLevels[:max(verbosityLevel, maxLevel)+1],
})
case "fluentd":
f := joonix.NewFormatter()
@@ -219,7 +232,7 @@ func before(ctx *cli.Context) error {
logFileName := ctx.String(cmd.LogFileName.Name)
if logFileName != "" {
if err := logs.ConfigurePersistentLogging(logFileName, format, verbosityLevel); err != nil {
if err := logs.ConfigurePersistentLogging(logFileName, format, verbosityLevel, vmodule); err != nil {
log.WithError(err).Error("Failed to configuring logging to disk.")
}
}

View File

@@ -200,6 +200,7 @@ var appHelpFlagGroups = []flagGroup{
cmd.LogFileName,
cmd.VerbosityFlag,
flags.DisableEphemeralLogFile,
cmd.LogVModuleFlag,
},
},
{ // Feature flags.

View File

@@ -86,7 +86,7 @@ func main() {
logFileName := ctx.String(cmd.LogFileName.Name)
if logFileName != "" {
if err := logs.ConfigurePersistentLogging(logFileName, format, level); err != nil {
if err := logs.ConfigurePersistentLogging(logFileName, format, level, map[string]logrus.Level{}); err != nil {
log.WithError(err).Error("Failed to configuring logging to disk.")
}
}

View File

@@ -36,6 +36,11 @@ var (
Usage: "Logging verbosity. (trace, debug, info, warn, error, fatal, panic)",
Value: "info",
}
// LogVModuleFlag defines per-package log levels.
LogVModuleFlag = &cli.StringSliceFlag{
Name: "log.vmodule",
Usage: "Per-package log verbosity. packagePath=level entries separated by commas.",
}
// DataDirFlag defines a path on disk where Prysm databases are stored.
DataDirFlag = &cli.StringFlag{
Name: "datadir",

View File

@@ -6,6 +6,7 @@ import (
"testing"
"github.com/OffchainLabs/prysm/v7/testing/require"
"github.com/sirupsen/logrus"
"github.com/urfave/cli/v2"
)
@@ -237,3 +238,41 @@ func TestValidateNoArgs_SubcommandFlags(t *testing.T) {
err = app.Run([]string{"command", "bar", "subComm2", "--barfoo100", "garbage", "subComm4"})
require.ErrorContains(t, "unrecognized argument: garbage", err)
}
func TestParseVModule(t *testing.T) {
t.Run("valid", func(t *testing.T) {
input := "beacon-chain/p2p=error, beacon-chain/light-client=trace"
parsed, maxL, err := ParseVModule(input)
require.NoError(t, err)
require.Equal(t, logrus.ErrorLevel, parsed["beacon-chain/p2p"])
require.Equal(t, logrus.TraceLevel, parsed["beacon-chain/light-client"])
require.Equal(t, logrus.TraceLevel, maxL)
})
t.Run("empty", func(t *testing.T) {
parsed, maxL, err := ParseVModule(" ")
require.NoError(t, err)
require.IsNil(t, parsed)
require.Equal(t, logrus.PanicLevel, maxL)
})
t.Run("invalid", func(t *testing.T) {
tests := []string{
"beacon-chain/p2p",
"beacon-chain/p2p=",
"beacon-chain/p2p/=error",
"=info",
"beacon-chain/*=info",
"beacon-chain/p2p=meow",
"/beacon-chain/p2p=info",
"beacon-chain/../p2p=info",
"beacon-chain/p2p=info,",
"beacon-chain/p2p=info,beacon-chain/p2p=debug",
}
for _, input := range tests {
_, maxL, err := ParseVModule(input)
require.ErrorContains(t, "invalid", err)
require.Equal(t, logrus.PanicLevel, maxL)
}
})
}

View File

@@ -4,6 +4,7 @@ import (
"bufio"
"fmt"
"os"
"path"
"runtime"
"strings"
@@ -102,3 +103,63 @@ func ExpandSingleEndpointIfFile(ctx *cli.Context, flag *cli.StringFlag) error {
}
return nil
}
// ParseVModule parses a comma-separated list of package=level entries.
func ParseVModule(input string) (map[string]logrus.Level, logrus.Level, error) {
var l logrus.Level
trimmed := strings.TrimSpace(input)
if trimmed == "" {
return nil, l, nil
}
parts := strings.Split(trimmed, ",")
result := make(map[string]logrus.Level, len(parts))
for _, raw := range parts {
entry := strings.TrimSpace(raw)
if entry == "" {
return nil, l, fmt.Errorf("invalid vmodule entry: empty segment")
}
kv := strings.Split(entry, "=")
if len(kv) != 2 {
return nil, l, fmt.Errorf("invalid vmodule entry %q: expected path=level", entry)
}
pkg := strings.TrimSpace(kv[0])
levelText := strings.TrimSpace(kv[1])
if pkg == "" {
return nil, l, fmt.Errorf("invalid vmodule entry %q: empty package path", entry)
}
if levelText == "" {
return nil, l, fmt.Errorf("invalid vmodule entry %q: empty level", entry)
}
if strings.Contains(pkg, "*") {
return nil, l, fmt.Errorf("invalid vmodule package path %q: wildcards are not allowed", pkg)
}
if strings.ContainsAny(pkg, " \t\n") {
return nil, l, fmt.Errorf("invalid vmodule package path %q: whitespace is not allowed", pkg)
}
if strings.HasPrefix(pkg, "/") {
return nil, l, fmt.Errorf("invalid vmodule package path %q: leading slash is not allowed", pkg)
}
cleaned := path.Clean(pkg)
if cleaned != pkg || pkg == "." || pkg == ".." {
return nil, l, fmt.Errorf("invalid vmodule package path %q: must be an absolute package path. (trailing slash not allowed)", pkg)
}
if _, exists := result[pkg]; exists {
return nil, l, fmt.Errorf("invalid vmodule package path %q: duplicate entry", pkg)
}
level, err := logrus.ParseLevel(levelText)
if err != nil {
return nil, l, fmt.Errorf("invalid vmodule level %q: must be one of panic, fatal, error, warn, info, debug, trace", levelText)
}
result[pkg] = level
}
maxLevel := logrus.PanicLevel
for _, lvl := range result {
if lvl > maxLevel {
maxLevel = lvl
}
}
return result, maxLevel, nil
}

View File

@@ -9,6 +9,7 @@ import (
"os"
"path/filepath"
runtimeDebug "runtime/debug"
"strings"
"github.com/OffchainLabs/prysm/v7/cmd"
accountcommands "github.com/OffchainLabs/prysm/v7/cmd/validator/accounts"
@@ -95,6 +96,7 @@ var appFlags = []cli.Flag{
cmd.MinimalConfigFlag,
cmd.E2EConfigFlag,
cmd.VerbosityFlag,
cmd.LogVModuleFlag,
cmd.DataDirFlag,
cmd.ClearDB,
cmd.ForceClearDB,
@@ -150,13 +152,22 @@ func main() {
return err
}
// determine log verbosity
// determine default log verbosity
verbosity := ctx.String(cmd.VerbosityFlag.Name)
verbosityLevel, err := logrus.ParseLevel(verbosity)
if err != nil {
return errors.Wrap(err, "failed to parse log verbosity")
}
logs.SetLoggingLevel(verbosityLevel)
// determine per package verbosity. if not set, maxLevel will be 0.
vmoduleInput := strings.Join(ctx.StringSlice(cmd.LogVModuleFlag.Name), ",")
vmodule, maxLevel, err := cmd.ParseVModule(vmoduleInput)
if err != nil {
return errors.Wrap(err, "failed to parse log vmodule")
}
// set the global logging level to allow for the highest verbosity requested
logs.SetLoggingLevel(max(maxLevel, verbosityLevel))
logFileName := ctx.String(cmd.LogFileName.Name)
@@ -172,11 +183,13 @@ func main() {
formatter.FullTimestamp = true
formatter.ForceFormatting = true
formatter.ForceColors = true
formatter.VModule = vmodule
formatter.BaseVerbosity = verbosityLevel
logrus.AddHook(&logs.WriterHook{
Formatter: formatter,
Writer: os.Stderr,
AllowedLevels: logrus.AllLevels[:verbosityLevel+1],
AllowedLevels: logrus.AllLevels[:max(verbosityLevel, maxLevel)+1],
})
case "fluentd":
f := joonix.NewFormatter()
@@ -197,7 +210,7 @@ func main() {
}
if logFileName != "" {
if err := logs.ConfigurePersistentLogging(logFileName, format, verbosityLevel); err != nil {
if err := logs.ConfigurePersistentLogging(logFileName, format, verbosityLevel, vmodule); err != nil {
log.WithError(err).Error("Failed to configuring logging to disk.")
}
}

View File

@@ -76,6 +76,7 @@ var appHelpFlagGroups = []flagGroup{
cmd.AcceptTosFlag,
cmd.ApiTimeoutFlag,
flags.DisableEphemeralLogFile,
cmd.LogVModuleFlag,
},
},
{

View File

@@ -30,7 +30,7 @@ func addLogWriter(w io.Writer) {
}
// ConfigurePersistentLogging adds a log-to-file writer. File content is identical to stdout.
func ConfigurePersistentLogging(logFileName string, format string, lvl logrus.Level) error {
func ConfigurePersistentLogging(logFileName string, format string, lvl logrus.Level, vmodule map[string]logrus.Level) error {
logrus.WithField("logFileName", logFileName).Info("Logs will be made persistent")
if err := file.MkdirAll(filepath.Dir(logFileName)); err != nil {
return err
@@ -47,6 +47,13 @@ func ConfigurePersistentLogging(logFileName string, format string, lvl logrus.Le
return nil
}
maxVmoduleLevel := logrus.PanicLevel
for _, level := range vmodule {
if level > maxVmoduleLevel {
maxVmoduleLevel = level
}
}
// Create formatter and writer hook
formatter := new(prefixed.TextFormatter)
formatter.TimestampFormat = "2006-01-02 15:04:05.00"
@@ -54,11 +61,13 @@ func ConfigurePersistentLogging(logFileName string, format string, lvl logrus.Le
// If persistent log files are written - we disable the log messages coloring because
// the colors are ANSI codes and seen as gibberish in the log files.
formatter.DisableColors = true
formatter.BaseVerbosity = lvl
formatter.VModule = vmodule
logrus.AddHook(&WriterHook{
Formatter: formatter,
Writer: f,
AllowedLevels: logrus.AllLevels[:lvl+1],
AllowedLevels: logrus.AllLevels[:max(lvl, maxVmoduleLevel)+1],
})
logrus.Info("File logging initialized")

View File

@@ -28,20 +28,20 @@ func TestMaskCredentialsLogging(t *testing.T) {
}
}
func TestConfigurePersistantLogging(t *testing.T) {
func TestConfigurePersistentLogging(t *testing.T) {
testParentDir := t.TempDir()
// 1. Test creation of file in an existing parent directory
logFileName := "test.log"
existingDirectory := "test-1-existing-testing-dir"
err := ConfigurePersistentLogging(fmt.Sprintf("%s/%s/%s", testParentDir, existingDirectory, logFileName), "text", logrus.InfoLevel)
err := ConfigurePersistentLogging(fmt.Sprintf("%s/%s/%s", testParentDir, existingDirectory, logFileName), "text", logrus.InfoLevel, map[string]logrus.Level{})
require.NoError(t, err)
// 2. Test creation of file along with parent directory
nonExistingDirectory := "test-2-non-existing-testing-dir"
err = ConfigurePersistentLogging(fmt.Sprintf("%s/%s/%s", testParentDir, nonExistingDirectory, logFileName), "text", logrus.InfoLevel)
err = ConfigurePersistentLogging(fmt.Sprintf("%s/%s/%s", testParentDir, nonExistingDirectory, logFileName), "text", logrus.InfoLevel, map[string]logrus.Level{})
require.NoError(t, err)
// 3. Test creation of file in an existing parent directory with a non-existing sub-directory
@@ -52,7 +52,7 @@ func TestConfigurePersistantLogging(t *testing.T) {
return
}
err = ConfigurePersistentLogging(fmt.Sprintf("%s/%s/%s/%s", testParentDir, existingDirectory, nonExistingSubDirectory, logFileName), "text", logrus.InfoLevel)
err = ConfigurePersistentLogging(fmt.Sprintf("%s/%s/%s/%s", testParentDir, existingDirectory, nonExistingSubDirectory, logFileName), "text", logrus.InfoLevel, map[string]logrus.Level{})
require.NoError(t, err)
//4. Create log file in a directory without 700 permissions

View File

@@ -120,6 +120,13 @@ type TextFormatter struct {
// Timestamp format to use for display when a full timestamp is printed.
TimestampFormat string
// VModule overrides the allowed log level for exact package paths.
// When using VModule, you should also set BaseVerbosity to the default verbosity level provided by the user.
VModule map[string]logrus.Level
// BaseVerbosity is the default verbosity level for all packages.
BaseVerbosity logrus.Level
}
func getCompiledColor(main string, fallback string) func(string) string {
@@ -168,6 +175,11 @@ func (f *TextFormatter) SetColorScheme(colorScheme *ColorScheme) {
}
func (f *TextFormatter) Format(entry *logrus.Entry) ([]byte, error) {
// check for vmodule compatibility
if !f.shouldLog(entry) {
return []byte{}, nil
}
var b *bytes.Buffer
keys := make([]string, 0, len(entry.Data))
for k := range entry.Data {
@@ -236,6 +248,39 @@ func (f *TextFormatter) Format(entry *logrus.Entry) ([]byte, error) {
return b.Bytes(), nil
}
func (f *TextFormatter) shouldLog(entry *logrus.Entry) bool {
if len(f.VModule) == 0 {
return true
}
packagePath, ok := entry.Data["package"]
if !ok {
return entry.Level <= f.BaseVerbosity
}
packageName, ok := packagePath.(string)
if !ok {
return entry.Level <= f.BaseVerbosity
}
packageLevel := f.bestMatchLevel(packageName)
return entry.Level <= packageLevel
}
// bestMatchLevel returns the level of the most specific path that matches package name.
func (f *TextFormatter) bestMatchLevel(pkg string) logrus.Level {
bestLen := 0
bestLevel := f.BaseVerbosity
for k, v := range f.VModule {
if k == pkg || strings.HasPrefix(pkg, k+"/") {
if len(k) > bestLen {
bestLen = len(k)
bestLevel = v
}
}
}
return bestLevel
}
func (f *TextFormatter) printColored(b *bytes.Buffer, entry *logrus.Entry, keys []string, timestampFormat string, colorScheme *compiledColorScheme) (err error) {
var levelColor func(string) string
var levelText string

View File

@@ -71,7 +71,7 @@ func main() {
flag.Parse()
if *logFileName != "" {
if err := logs.ConfigurePersistentLogging(*logFileName, "text", logrus.DebugLevel); err != nil {
if err := logs.ConfigurePersistentLogging(*logFileName, "text", logrus.DebugLevel, map[string]logrus.Level{}); err != nil {
log.WithError(err).Error("Failed to configuring logging to disk.")
}
}