Compare commits

...

2 Commits

Author SHA1 Message Date
Bastin
b67c33dec1 fixes 2026-01-22 16:08:51 +01:00
Bastin
18d900c4dd logging: per package verbosity 2026-01-22 15:41:16 +01:00
14 changed files with 204 additions and 16 deletions

View File

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

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

@@ -113,6 +113,7 @@ var appFlags = []cli.Flag{
cmd.PubsubQueueSize,
cmd.DataDirFlag,
cmd.VerbosityFlag,
cmd.LogVModuleFlag,
cmd.EnableTracingFlag,
cmd.TracingProcessNameFlag,
cmd.TracingEndpointFlag,
@@ -171,13 +172,21 @@ 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.
vmodule, maxLevel, err := cmd.ParseVModule(ctx.String(cmd.LogVModuleFlag.Name))
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 +200,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 +230,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

@@ -201,6 +201,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,12 @@ var (
Usage: "Logging verbosity. (trace, debug, info, warn, error, fatal, panic)",
Value: "info",
}
// LogVModuleFlag defines per-package log levels.
LogVModuleFlag = &cli.StringFlag{
Name: "log.vmodule",
Usage: "Per-package log verbosity. packagePath=level entries separated by commas.",
Value: "",
}
// 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

@@ -95,6 +95,7 @@ var appFlags = []cli.Flag{
cmd.MinimalConfigFlag,
cmd.E2EConfigFlag,
cmd.VerbosityFlag,
cmd.LogVModuleFlag,
cmd.DataDirFlag,
cmd.ClearDB,
cmd.ForceClearDB,
@@ -150,13 +151,21 @@ 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.
vmodule, maxLevel, err := cmd.ParseVModule(ctx.String(cmd.LogVModuleFlag.Name))
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 +181,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 +208,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.")
}
}