Compare commits

...

3 Commits

Author SHA1 Message Date
Bastin
850b7326eb per package visibility 2026-01-08 16:38:50 +01:00
Bastin
17245f4fac Ephemeral debug logfile (#16108)
**What type of PR is this?**
Feature

**What does this PR do? Why is it needed?**
This PR introduces an ephemeral log file that captures debug logs for 24
hours.

- it captures debug logs regardless of the user provided (or
non-provided) `--verbosity` flag.
- it allows a maximum of 250MB for each log file. 
- it keeps 1 backup logfile in case of size-based rotations. (as opposed
to time-based)
- this is enabled by default for beacon and validator nodes.
- the log files live in `datadir/logs/` directory under the names of
`beacon-chain.log` and `validator.log`. backups have a timestamp in
their name as well.
- the feature can be disabled using the `--disable-ephemeral-log-file`
flag.
2026-01-08 14:16:22 +00:00
Bastin
53b0a574ab Set logging verbosity per writer hook instead of globally (#16106)
**What type of PR is this?**
Feature

**What does this PR do? Why is it needed?**
This PR sets the logging verbosity level per writer hook (per output:
terminal, log file, etc) rather than setting a global logrus level which
limits customizing each output.

it set the terminal and log file output to be the same as the user
provided `--verbosity` flag. so nothing changes in reality.

it also introduces a `SetLoggingLevel()` to be used instead of
`logrus.SetLeveL()` in order for us to be able to set a different
baseline level later on if needed. (my next PR will use this).

I'm only making this change in the `beacon-chain` and `validator` apps,
skipping tools like `bootnode` and `client-stats`.
2026-01-08 12:19:16 +00:00
19 changed files with 287 additions and 25 deletions

View File

@@ -0,0 +1,5 @@
### Added
- Added an ephemeral debug logfile that for beacon and validator nodes that captures debug-level logs for 24 hours. It
also keeps 1 backup of in case of size-based rotation. The logfiles are stored in `datadir/logs/`. This feature is
enabled by default and can be disabled by setting the `--disable-ephemeral-log-file` flag.

View File

@@ -0,0 +1,3 @@
### Added
- Added `--log-only` and `--log-exclude` flags to the beacon chain client to allow users to filter log output.

View File

@@ -0,0 +1,4 @@
### Changed
- Moved verbosity settings to be configurable per hook, rather than just globally. This allows us to control the
verbosity of individual output independently.

View File

@@ -356,6 +356,12 @@ var (
Usage: "A comma-separated list of exponents (of 2) in decreasing order, defining the state diff hierarchy levels. The last exponent must be greater than or equal to 5.",
Value: cli.NewIntSlice(21, 18, 16, 13, 11, 9, 5),
}
// DisableEphemeralLogFile disables the 24 hour debug log file.
DisableEphemeralLogFile = &cli.BoolFlag{
Name: "disable-ephemeral-log-file",
Usage: "Disables the creation of a debug log file that keeps 24 hours of logs.",
Value: false,
}
// DisableGetBlobsV2 disables the engine_getBlobsV2 usage.
DisableGetBlobsV2 = &cli.BoolFlag{
Name: "disable-get-blobs-v2",

View File

@@ -113,6 +113,8 @@ var appFlags = []cli.Flag{
cmd.PubsubQueueSize,
cmd.DataDirFlag,
cmd.VerbosityFlag,
cmd.LogOnlyFlag,
cmd.LogExcludeFlag,
cmd.EnableTracingFlag,
cmd.TracingProcessNameFlag,
cmd.TracingEndpointFlag,
@@ -158,6 +160,7 @@ var appFlags = []cli.Flag{
dasFlags.BackfillOldestSlot,
dasFlags.BlobRetentionEpochFlag,
flags.BatchVerifierLimit,
flags.DisableEphemeralLogFile,
}
func init() {
@@ -170,8 +173,15 @@ func before(ctx *cli.Context) error {
return errors.Wrap(err, "failed to load flags from config file")
}
format := ctx.String(cmd.LogFormat.Name)
// determine 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)
format := ctx.String(cmd.LogFormat.Name)
switch format {
case "text":
// disabling logrus default output so we can control it via different hooks
@@ -183,10 +193,15 @@ func before(ctx *cli.Context) error {
formatter.FullTimestamp = true
formatter.ForceFormatting = true
formatter.ForceColors = true
logOnly, logExclude := cmd.ParseLogPackageFlags(ctx)
formatter.LogOnly = logOnly
formatter.LogExclude = logExclude
formatter.RespectLogFilters = true
logrus.AddHook(&logs.WriterHook{
Formatter: formatter,
Writer: os.Stderr,
Formatter: formatter,
Writer: os.Stderr,
AllowedLevels: logrus.AllLevels[:verbosityLevel+1],
})
case "fluentd":
f := joonix.NewFormatter()
@@ -210,11 +225,17 @@ func before(ctx *cli.Context) error {
logFileName := ctx.String(cmd.LogFileName.Name)
if logFileName != "" {
if err := logs.ConfigurePersistentLogging(logFileName, format); err != nil {
if err := logs.ConfigurePersistentLogging(logFileName, format, verbosityLevel); err != nil {
log.WithError(err).Error("Failed to configuring logging to disk.")
}
}
if !ctx.Bool(flags.DisableEphemeralLogFile.Name) {
if err := logs.ConfigureEphemeralLogFile(ctx.String(cmd.DataDirFlag.Name), ctx.App.Name); err != nil {
log.WithError(err).Error("Failed to configure debug log file")
}
}
if err := cmd.ExpandSingleEndpointIfFile(ctx, flags.ExecutionEngineEndpoint); err != nil {
return errors.Wrap(err, "failed to expand single endpoint")
}
@@ -291,7 +312,7 @@ func startNode(ctx *cli.Context, cancel context.CancelFunc) error {
if err != nil {
return err
}
logrus.SetLevel(level)
// Set libp2p logger to only panic logs for the info level.
golog.SetAllLoggers(golog.LevelPanic)

View File

@@ -200,6 +200,9 @@ var appHelpFlagGroups = []flagGroup{
cmd.LogFormat,
cmd.LogFileName,
cmd.VerbosityFlag,
flags.DisableEphemeralLogFile,
cmd.LogExcludeFlag,
cmd.LogOnlyFlag,
},
},
{ // Feature flags.

View File

@@ -62,6 +62,9 @@ func main() {
formatter := new(prefixed.TextFormatter)
formatter.TimestampFormat = "2006-01-02 15:04:05.00"
formatter.FullTimestamp = true
logOnly, logExclude := cmd.ParseLogPackageFlags(ctx)
formatter.LogOnly = logOnly
formatter.LogExclude = logExclude
// 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 = ctx.String(cmd.LogFileName.Name) != ""
@@ -86,7 +89,7 @@ func main() {
logFileName := ctx.String(cmd.LogFileName.Name)
if logFileName != "" {
if err := logs.ConfigurePersistentLogging(logFileName, format); err != nil {
if err := logs.ConfigurePersistentLogging(logFileName, format, level); err != nil {
log.WithError(err).Error("Failed to configuring logging to disk.")
}
}

View File

@@ -36,6 +36,16 @@ var (
Usage: "Logging verbosity. (trace, debug, info, warn, error, fatal, panic)",
Value: "info",
}
// LogOnlyFlag specifies the packages for which logging is enabled.
LogOnlyFlag = &cli.StringSliceFlag{
Name: "log-only",
Usage: "Enables logging only for the specified packages (comma-separated package paths). By default, all packages are logged.",
}
// LogExcludeFlag specifies the packages for which logging is disabled.
LogExcludeFlag = &cli.StringSliceFlag{
Name: "log-exclude",
Usage: "Disables logging for the specified packages (comma-separated package paths).",
}
// DataDirFlag defines a path on disk where Prysm databases are stored.
DataDirFlag = &cli.StringFlag{
Name: "datadir",
@@ -283,6 +293,25 @@ var (
}
)
// ParseLogPackageFlags returns flattened lists for log-only and log-exclude flags.
func ParseLogPackageFlags(ctx *cli.Context) (logOnly []string, logExclude []string) {
return parseCommaSeparatedEntries(ctx.StringSlice(LogOnlyFlag.Name)), parseCommaSeparatedEntries(ctx.StringSlice(LogExcludeFlag.Name))
}
func parseCommaSeparatedEntries(values []string) []string {
entries := make([]string, 0)
for _, value := range values {
for entry := range strings.SplitSeq(value, ",") {
entry = strings.TrimSpace(entry)
entry = strings.TrimSuffix(entry, "/")
if entry != "" {
entries = append(entries, entry)
}
}
}
return entries
}
// LoadFlagsFromConfig sets flags values from config file if ConfigFileFlag is set.
func LoadFlagsFromConfig(cliCtx *cli.Context, flags []cli.Flag) error {
if cliCtx.IsSet(ConfigFileFlag.Name) {

View File

@@ -41,6 +41,21 @@ func TestLoadFlagsFromConfig(t *testing.T) {
require.NoError(t, os.Remove("flags_test.yaml"))
}
func TestParseLogPackageFlags(t *testing.T) {
set := flag.NewFlagSet("test", 0)
require.NoError(t, LogOnlyFlag.Apply(set))
require.NoError(t, LogExcludeFlag.Apply(set))
require.NoError(t, set.Set(LogOnlyFlag.Name, "pkg/a/,pkg/b"))
require.NoError(t, set.Set(LogOnlyFlag.Name, "pkg/c"))
require.NoError(t, set.Set(LogExcludeFlag.Name, " pkg/d ,pkg/e/ "))
ctx := cli.NewContext(&cli.App{}, set, nil)
logOnly, logExclude := ParseLogPackageFlags(ctx)
require.DeepEqual(t, []string{"pkg/a", "pkg/b", "pkg/c"}, logOnly)
require.DeepEqual(t, []string{"pkg/d", "pkg/e"}, logExclude)
}
func TestValidateNoArgs(t *testing.T) {
app := &cli.App{
Before: ValidateNoArgs,

View File

@@ -410,6 +410,12 @@ var (
Usage: "Maximum number of health checks to perform before exiting if not healthy. Set to 0 or a negative number for indefinite checks.",
Value: DefaultMaxHealthChecks,
}
// DisableEphemeralLogFile disables the 24 hour debug log file.
DisableEphemeralLogFile = &cli.BoolFlag{
Name: "disable-ephemeral-log-file",
Usage: "Disables the creation of a debug log file that keeps 24 hours of logs.",
Value: false,
}
)
// DefaultValidatorDir returns OS-specific default validator directory.

View File

@@ -115,6 +115,7 @@ var appFlags = []cli.Flag{
debug.BlockProfileRateFlag,
debug.MutexProfileFractionFlag,
cmd.AcceptTosFlag,
flags.DisableEphemeralLogFile,
}
func init() {
@@ -147,6 +148,14 @@ func main() {
return err
}
// determine 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)
logFileName := ctx.String(cmd.LogFileName.Name)
format := ctx.String(cmd.LogFormat.Name)
@@ -161,10 +170,14 @@ func main() {
formatter.FullTimestamp = true
formatter.ForceFormatting = true
formatter.ForceColors = true
logOnly, logExclude := cmd.ParseLogPackageFlags(ctx)
formatter.LogOnly = logOnly
formatter.LogExclude = logExclude
logrus.AddHook(&logs.WriterHook{
Formatter: formatter,
Writer: os.Stderr,
Formatter: formatter,
Writer: os.Stderr,
AllowedLevels: logrus.AllLevels[:verbosityLevel+1],
})
case "fluentd":
f := joonix.NewFormatter()
@@ -185,11 +198,17 @@ func main() {
}
if logFileName != "" {
if err := logs.ConfigurePersistentLogging(logFileName, format); err != nil {
if err := logs.ConfigurePersistentLogging(logFileName, format, verbosityLevel); err != nil {
log.WithError(err).Error("Failed to configuring logging to disk.")
}
}
if !ctx.Bool(flags.DisableEphemeralLogFile.Name) {
if err := logs.ConfigureEphemeralLogFile(ctx.String(cmd.DataDirFlag.Name), ctx.App.Name); err != nil {
log.WithError(err).Error("Failed to configure debug log file")
}
}
// Fix data dir for Windows users.
outdatedDataDir := filepath.Join(file.HomeDir(), "AppData", "Roaming", "Eth2Validators")
currentDataDir := flags.DefaultValidatorDir()

View File

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

2
go.mod
View File

@@ -96,6 +96,7 @@ require (
google.golang.org/grpc v1.71.0
google.golang.org/protobuf v1.36.5
gopkg.in/d4l3k/messagediff.v1 v1.2.1
gopkg.in/natefinch/lumberjack.v2 v2.2.1
gopkg.in/yaml.v2 v2.4.0
gopkg.in/yaml.v3 v3.0.1
honnef.co/go/tools v0.6.0
@@ -273,7 +274,6 @@ require (
golang.org/x/tools/go/expect v0.1.1-deprecated // indirect
gopkg.in/cenkalti/backoff.v1 v1.1.0 // indirect
gopkg.in/inf.v0 v0.9.1 // indirect
gopkg.in/natefinch/lumberjack.v2 v2.2.1 // indirect
lukechampine.com/blake3 v1.3.0 // indirect
rsc.io/tmplfunc v0.0.3 // indirect
sigs.k8s.io/json v0.0.0-20221116044647-bc3834ca7abd // indirect

View File

@@ -17,7 +17,9 @@ go_library(
"//io/file:go_default_library",
"//runtime/logging/logrus-prefixed-formatter:go_default_library",
"@com_github_hashicorp_golang_lru//:go_default_library",
"@com_github_pkg_errors//:go_default_library",
"@com_github_sirupsen_logrus//:go_default_library",
"@in_gopkg_natefinch_lumberjack_v2//:go_default_library",
],
)
@@ -28,5 +30,8 @@ go_test(
"stream_test.go",
],
embed = [":go_default_library"],
deps = ["//testing/require:go_default_library"],
deps = [
"//testing/require:go_default_library",
"@com_github_sirupsen_logrus//:go_default_library",
],
)

View File

@@ -12,16 +12,25 @@ import (
"github.com/OffchainLabs/prysm/v7/config/params"
"github.com/OffchainLabs/prysm/v7/io/file"
prefixed "github.com/OffchainLabs/prysm/v7/runtime/logging/logrus-prefixed-formatter"
"github.com/pkg/errors"
"github.com/sirupsen/logrus"
"gopkg.in/natefinch/lumberjack.v2"
)
var ephemeralLogFileVerbosity = logrus.DebugLevel
// SetLoggingLevel sets the base logging level for logrus.
func SetLoggingLevel(lvl logrus.Level) {
logrus.SetLevel(max(lvl, ephemeralLogFileVerbosity))
}
func addLogWriter(w io.Writer) {
mw := io.MultiWriter(logrus.StandardLogger().Out, w)
logrus.SetOutput(mw)
}
// ConfigurePersistentLogging adds a log-to-file writer. File content is identical to stdout.
func ConfigurePersistentLogging(logFileName string, format string) error {
func ConfigurePersistentLogging(logFileName string, format string, lvl 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,14 +56,48 @@ func ConfigurePersistentLogging(logFileName string, format string) error {
formatter.DisableColors = true
logrus.AddHook(&WriterHook{
Formatter: formatter,
Writer: f,
Formatter: formatter,
Writer: f,
AllowedLevels: logrus.AllLevels[:lvl+1],
})
logrus.Info("File logging initialized")
return nil
}
// ConfigureEphemeralLogFile adds a log file that keeps 24 hours of logs with >debug verbosity.
func ConfigureEphemeralLogFile(datadirPath string, app string) error {
logFilePath := filepath.Join(datadirPath, "logs", app+".log")
if err := file.MkdirAll(filepath.Dir(logFilePath)); err != nil {
return errors.Wrap(err, "failed to create directory")
}
// Create formatter and writer hook
formatter := new(prefixed.TextFormatter)
formatter.TimestampFormat = "2006-01-02 15:04:05.00"
formatter.FullTimestamp = true
// 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
// configure the lumberjack log writer to rotate logs every ~24 hours
debugWriter := &lumberjack.Logger{
Filename: logFilePath,
MaxSize: 250, // MB, to avoid unbounded growth
MaxBackups: 1, // one backup in case of size-based rotations
MaxAge: 1, // days; files older than this are removed
}
logrus.AddHook(&WriterHook{
Formatter: formatter,
Writer: debugWriter,
AllowedLevels: logrus.AllLevels[:ephemeralLogFileVerbosity+1],
})
logrus.Info("Ephemeral log file initialized")
return nil
}
// MaskCredentialsLogging masks the url credentials before logging for security purpose
// [scheme:][//[userinfo@]host][/]path[?query][#fragment] --> [scheme:][//[***]host][/***][#***]
// if the format is not matched nothing is done, string is returned as is.

View File

@@ -6,6 +6,7 @@ import (
"testing"
"github.com/OffchainLabs/prysm/v7/testing/require"
"github.com/sirupsen/logrus"
)
var urltests = []struct {
@@ -34,13 +35,13 @@ func TestConfigurePersistantLogging(t *testing.T) {
logFileName := "test.log"
existingDirectory := "test-1-existing-testing-dir"
err := ConfigurePersistentLogging(fmt.Sprintf("%s/%s/%s", testParentDir, existingDirectory, logFileName), "text")
err := ConfigurePersistentLogging(fmt.Sprintf("%s/%s/%s", testParentDir, existingDirectory, logFileName), "text", logrus.InfoLevel)
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")
err = ConfigurePersistentLogging(fmt.Sprintf("%s/%s/%s", testParentDir, nonExistingDirectory, logFileName), "text", logrus.InfoLevel)
require.NoError(t, err)
// 3. Test creation of file in an existing parent directory with a non-existing sub-directory
@@ -51,7 +52,7 @@ func TestConfigurePersistantLogging(t *testing.T) {
return
}
err = ConfigurePersistentLogging(fmt.Sprintf("%s/%s/%s/%s", testParentDir, existingDirectory, nonExistingSubDirectory, logFileName), "text")
err = ConfigurePersistentLogging(fmt.Sprintf("%s/%s/%s/%s", testParentDir, existingDirectory, nonExistingSubDirectory, logFileName), "text", logrus.InfoLevel)
require.NoError(t, err)
//4. Create log file in a directory without 700 permissions
@@ -61,3 +62,38 @@ func TestConfigurePersistantLogging(t *testing.T) {
return
}
}
func TestConfigureEphemeralLogFile(t *testing.T) {
testParentDir := t.TempDir()
// 1. Test creation of file in an existing parent directory
existingDirectory := "test-1-existing-testing-dir"
err := ConfigureEphemeralLogFile(fmt.Sprintf("%s/%s", testParentDir, existingDirectory), "beacon-chain")
require.NoError(t, err)
// 2. Test creation of file along with parent directory
nonExistingDirectory := "test-2-non-existing-testing-dir"
err = ConfigureEphemeralLogFile(fmt.Sprintf("%s/%s", testParentDir, nonExistingDirectory), "beacon-chain")
require.NoError(t, err)
// 3. Test creation of file in an existing parent directory with a non-existing sub-directory
existingDirectory = "test-3-existing-testing-dir"
nonExistingSubDirectory := "test-3-non-existing-sub-dir"
err = os.Mkdir(fmt.Sprintf("%s/%s", testParentDir, existingDirectory), 0700)
if err != nil {
return
}
err = ConfigureEphemeralLogFile(fmt.Sprintf("%s/%s/%s", testParentDir, existingDirectory, nonExistingSubDirectory), "beacon-chain")
require.NoError(t, err)
//4. Create log file in a directory without 700 permissions
existingDirectory = "test-4-existing-testing-dir"
err = os.Mkdir(fmt.Sprintf("%s/%s", testParentDir, existingDirectory), 0750)
if err != nil {
return
}
err = ConfigureEphemeralLogFile(fmt.Sprintf("%s/%s/%s", testParentDir, existingDirectory, nonExistingSubDirectory), "beacon-chain")
require.NoError(t, err)
}

View File

@@ -104,6 +104,9 @@ type TextFormatter struct {
// Wrap empty fields in quotes if true.
QuoteEmptyFields bool
// Whether to respect the per-Package log filters.
RespectLogFilters bool
sync.Once
// Pad msg field with spaces on the right for display.
@@ -120,6 +123,10 @@ type TextFormatter struct {
// Timestamp format to use for display when a full timestamp is printed.
TimestampFormat string
// Per-Package log filters parsed from CLI flags.
LogOnly []string
LogExclude []string
}
func getCompiledColor(main string, fallback string) func(string) string {
@@ -168,6 +175,13 @@ func (f *TextFormatter) SetColorScheme(colorScheme *ColorScheme) {
}
func (f *TextFormatter) Format(entry *logrus.Entry) ([]byte, error) {
// check if entry should be dropped based on package filters
if f.RespectLogFilters {
if shouldDrop := f.shouldDropEntry(entry); shouldDrop {
return nil, nil
}
}
var b *bytes.Buffer
keys := make([]string, 0, len(entry.Data))
for k := range entry.Data {
@@ -403,6 +417,62 @@ func (f *TextFormatter) appendValue(b *bytes.Buffer, value any) (err error) {
return
}
func (f *TextFormatter) shouldDropEntry(entry *logrus.Entry) bool {
if len(f.LogOnly) == 0 && len(f.LogExclude) == 0 {
return false
}
// try to get package field
packageField, ok := entry.Data["package"]
if !ok {
return false
}
packageName, ok := packageField.(string)
if !ok {
return false
}
// get best matches. longer match means a more specific match
lengthOfBestIncludeMatch := bestMatchLen(packageName, f.LogOnly)
lengthOfBestExcludeMatch := bestMatchLen(packageName, f.LogExclude)
if len(f.LogOnly) > 0 && lengthOfBestIncludeMatch == 0 {
return true
}
if lengthOfBestExcludeMatch > 0 {
// if we're only excluding, then drop the entry
if len(f.LogOnly) == 0 {
return true
}
// if both include and exclude have matches, compare lengths. prefers include.
if lengthOfBestIncludeMatch >= lengthOfBestExcludeMatch {
return false
}
return true
}
return false
}
// bestMatchLen returns the length (specificity) of the most specific path that matches package name.
// 0 means "no match".
func bestMatchLen(pkg string, paths []string) int {
best := 0
for _, r := range paths {
if r == "" {
continue
}
if r == pkg || strings.HasPrefix(pkg, r+"/") {
if len(r) > best {
best = len(r)
}
}
}
return best
}
// This is to not silently overwrite `time`, `msg` and `level` fields when
// dumping it. If this code wasn't there doing:
//

View File

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

View File

@@ -75,13 +75,6 @@ func NewValidatorClient(cliCtx *cli.Context) (*ValidatorClient, error) {
return nil, err
}
verbosity := cliCtx.String(cmd.VerbosityFlag.Name)
level, err := logrus.ParseLevel(verbosity)
if err != nil {
return nil, err
}
logrus.SetLevel(level)
// Warn if user's platform is not supported
prereqs.WarnIfPlatformNotSupported(cliCtx.Context)