diff --git a/examples/stderr_threshold_fix/main.go b/examples/stderr_threshold_fix/main.go new file mode 100644 index 00000000..74ad3725 --- /dev/null +++ b/examples/stderr_threshold_fix/main.go @@ -0,0 +1,37 @@ +// Example demonstrating the new stderr threshold behavior +package main + +import ( + "flag" + + "k8s.io/klog/v2" +) + +func main() { + klog.InitFlags(nil) + flag.Parse() + + klog.Info("This is an INFO message") + klog.Warning("This is a WARNING message") + klog.Error("This is an ERROR message") + + klog.Flush() +} + +// Run examples: +// +// 1. Legacy behavior (default) - all logs to stderr: +// go run main.go -logtostderr=true -stderrthreshold=ERROR +// Result: All three messages appear +// +// 2. New behavior - filter by severity: +// go run main.go -logtostderr=true -legacy_stderr_threshold_behavior=false -stderrthreshold=ERROR +// Result: Only ERROR message appears +// +// 3. New behavior - show WARNING and above: +// go run main.go -logtostderr=true -legacy_stderr_threshold_behavior=false -stderrthreshold=WARNING +// Result: WARNING and ERROR messages appear +// +// 4. Using alsologtostderrthreshold with file logging: +// go run main.go -logtostderr=false -alsologtostderr=true -alsologtostderrthreshold=ERROR -log_dir=/tmp/logs +// Result: All logs in files, only ERROR to stderr diff --git a/klog.go b/klog.go index 40b1b20b..319ffbe2 100644 --- a/klog.go +++ b/klog.go @@ -58,15 +58,30 @@ // // -logtostderr=true // Logs are written to standard error instead of to files. -// This shortcuts most of the usual output routing: -// -alsologtostderr, -stderrthreshold and -log_dir have no -// effect and output redirection at runtime with SetOutput is -// ignored. +// By default, all logs are written regardless of severity +// (legacy behavior). To filter logs by severity when +// -logtostderr=true, set -legacy_stderr_threshold_behavior=false +// and use -stderrthreshold. +// With -legacy_stderr_threshold_behavior=true, +// -stderrthreshold has no effect. +// +// The following flags always have no effect: +// -alsologtostderr, -alsologtostderrthreshold, and -log_dir. +// Output redirection at runtime with SetOutput is also ignored. // -alsologtostderr=false // Logs are written to standard error as well as to files. +// -alsologtostderrthreshold=INFO +// Log events at or above this severity are logged to standard +// error when -alsologtostderr=true (no effect when -logtostderr=true). +// Default is INFO to maintain backward compatibility. // -stderrthreshold=ERROR // Log events at or above this severity are logged to standard -// error as well as to files. +// error as well as to files. When -logtostderr=true, this flag +// has no effect unless -legacy_stderr_threshold_behavior=false. +// -legacy_stderr_threshold_behavior=true +// If true, -stderrthreshold is ignored when -logtostderr=true +// (legacy behavior). If false, -stderrthreshold is honored even +// when -logtostderr=true, allowing severity-based filtering. // -log_dir="" // Log files will be written to this directory instead of the // default temporary directory. @@ -156,7 +171,7 @@ func (s *severityValue) Set(value string) error { } threshold = severity.Severity(v) } - logging.stderrThreshold.set(threshold) + s.set(threshold) return nil } @@ -409,6 +424,15 @@ var commandLine flag.FlagSet // init sets up the defaults and creates command line flags. func init() { + // Initialize severity thresholds + logging.stderrThreshold = severityValue{ + Severity: severity.ErrorLog, // Default stderrThreshold is ERROR. + } + logging.alsologtostderrthreshold = severityValue{ + Severity: severity.InfoLog, // Default alsologtostderrthreshold is INFO (to maintain backward compatibility). + } + logging.setVState(0, nil, false) + commandLine.StringVar(&logging.logDir, "log_dir", "", "If non-empty, write log files in this directory (no effect when -logtostderr=true)") commandLine.StringVar(&logging.logFile, "log_file", "", "If non-empty, use this log file (no effect when -logtostderr=true)") commandLine.Uint64Var(&logging.logFileMaxSizeMB, "log_file_max_size", 1800, @@ -416,16 +440,14 @@ func init() { "If the value is 0, the maximum file size is unlimited.") commandLine.BoolVar(&logging.toStderr, "logtostderr", true, "log to standard error instead of files") commandLine.BoolVar(&logging.alsoToStderr, "alsologtostderr", false, "log to standard error as well as files (no effect when -logtostderr=true)") - logging.setVState(0, nil, false) + commandLine.BoolVar(&logging.legacyStderrThresholdBehavior, "legacy_stderr_threshold_behavior", true, "If true, stderrthreshold is ignored when logtostderr=true (legacy behavior). If false, stderrthreshold is honored even when logtostderr=true") commandLine.Var(&logging.verbosity, "v", "number for the log level verbosity") commandLine.BoolVar(&logging.addDirHeader, "add_dir_header", false, "If true, adds the file directory to the header of the log messages") commandLine.BoolVar(&logging.skipHeaders, "skip_headers", false, "If true, avoid header prefixes in the log messages") commandLine.BoolVar(&logging.oneOutput, "one_output", false, "If true, only write logs to their native severity level (vs also writing to each lower severity level; no effect when -logtostderr=true)") commandLine.BoolVar(&logging.skipLogHeaders, "skip_log_headers", false, "If true, avoid headers when opening log files (no effect when -logtostderr=true)") - logging.stderrThreshold = severityValue{ - Severity: severity.ErrorLog, // Default stderrThreshold is ERROR. - } - commandLine.Var(&logging.stderrThreshold, "stderrthreshold", "logs at or above this threshold go to stderr when writing to files and stderr (no effect when -logtostderr=true or -alsologtostderr=true)") + commandLine.Var(&logging.stderrThreshold, "stderrthreshold", "logs at or above this threshold go to stderr when writing to files and stderr (no effect when -logtostderr=true or -alsologtostderr=true unless -legacy_stderr_threshold_behavior=false)") + commandLine.Var(&logging.alsologtostderrthreshold, "alsologtostderrthreshold", "logs at or above this threshold go to stderr when -alsologtostderr=true (no effect when -logtostderr=true)") commandLine.Var(&logging.vmodule, "vmodule", "comma-separated list of pattern=N settings for file-filtered logging") commandLine.Var(&logging.traceLocation, "log_backtrace_at", "when logging hits line file:N, emit a stack trace") @@ -470,11 +492,13 @@ type settings struct { // Boolean flags. Not handled atomically because the flag.Value interface // does not let us avoid the =true, and that shorthand is necessary for // compatibility. TODO: does this matter enough to fix? Seems unlikely. - toStderr bool // The -logtostderr flag. - alsoToStderr bool // The -alsologtostderr flag. + toStderr bool // The -logtostderr flag. + alsoToStderr bool // The -alsologtostderr flag. + legacyStderrThresholdBehavior bool // The -legacy_stderr_threshold_behavior flag. // Level flag. Handled atomically. - stderrThreshold severityValue // The -stderrthreshold flag. + stderrThreshold severityValue // The -stderrthreshold flag. + alsologtostderrthreshold severityValue // The -alsologtostderrthreshold flag. // Access to all of the following fields must be protected via a mutex. @@ -890,9 +914,25 @@ func (l *loggingT) output(s severity.Severity, logger *logWriter, buf *buffer.Bu } } } else if l.toStderr { - os.Stderr.Write(data) + // When logging to stderr only, check if we should filter by severity. + // This is controlled by the legacy_stderr_threshold_behavior flag. + if l.legacyStderrThresholdBehavior { + // Legacy behavior: always write to stderr, ignore stderrthreshold + os.Stderr.Write(data) + } else { + // New behavior: honor stderrthreshold even when logtostderr=true + if s >= l.stderrThreshold.get() { + os.Stderr.Write(data) + } + } } else { - if alsoToStderr || l.alsoToStderr || s >= l.stderrThreshold.get() { + // Write to stderr if any of these conditions are met: + // - alsoToStderr is set (legacy behavior) + // - alsologtostderr is set and severity meets alsologtostderrthreshold + // - alsologtostderr is not set and severity meets stderrThreshold + if alsoToStderr || + (l.alsoToStderr && s >= l.alsologtostderrthreshold.get()) || + (!l.alsoToStderr && s >= l.stderrThreshold.get()) { os.Stderr.Write(data) } diff --git a/klog_test.go b/klog_test.go index 6195e468..3fd7bc15 100644 --- a/klog_test.go +++ b/klog_test.go @@ -944,6 +944,10 @@ func TestCommandLine(t *testing.T) { If true, adds the file directory to the header of the log messages -alsologtostderr log to standard error as well as files (no effect when -logtostderr=true) + -alsologtostderrthreshold value + logs at or above this threshold go to stderr when -alsologtostderr=true (no effect when -logtostderr=true) + -legacy_stderr_threshold_behavior + If true, stderrthreshold is ignored when logtostderr=true (legacy behavior). If false, stderrthreshold is honored even when logtostderr=true (default true) -log_backtrace_at value when logging hits line file:N, emit a stack trace -log_dir string @@ -961,7 +965,7 @@ func TestCommandLine(t *testing.T) { -skip_log_headers If true, avoid headers when opening log files (no effect when -logtostderr=true) -stderrthreshold value - logs at or above this threshold go to stderr when writing to files and stderr (no effect when -logtostderr=true or -alsologtostderr=true) (default 2) + logs at or above this threshold go to stderr when writing to files and stderr (no effect when -logtostderr=true or -alsologtostderr=true unless -legacy_stderr_threshold_behavior=false) (default 2) -v value number for the log level verbosity -vmodule value @@ -1949,19 +1953,21 @@ func checkLogrEntryCorrectCaller(t *testing.T, wantFile string, wantLine int, en // existedFlag contains all existed flag, without KlogPrefix var existedFlag = map[string]struct{}{ - "log_dir": {}, - "add_dir_header": {}, - "alsologtostderr": {}, - "log_backtrace_at": {}, - "log_file": {}, - "log_file_max_size": {}, - "logtostderr": {}, - "one_output": {}, - "skip_headers": {}, - "skip_log_headers": {}, - "stderrthreshold": {}, - "v": {}, - "vmodule": {}, + "log_dir": {}, + "add_dir_header": {}, + "alsologtostderr": {}, + "alsologtostderrthreshold": {}, + "legacy_stderr_threshold_behavior": {}, + "log_backtrace_at": {}, + "log_file": {}, + "log_file_max_size": {}, + "logtostderr": {}, + "one_output": {}, + "skip_headers": {}, + "skip_log_headers": {}, + "stderrthreshold": {}, + "v": {}, + "vmodule": {}, } // KlogPrefix define new flag prefix diff --git a/stderr_threshold_test.go b/stderr_threshold_test.go new file mode 100644 index 00000000..9405d7f0 --- /dev/null +++ b/stderr_threshold_test.go @@ -0,0 +1,351 @@ +// Go support for leveled logs, analogous to https://code.google.com/p/google-glog/ +// +// Copyright 2026 The Kubernetes Authors. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package klog + +import ( + "bytes" + "flag" + "fmt" + "io" + "os" + "strings" + "testing" + + "k8s.io/klog/v2/internal/buffer" + "k8s.io/klog/v2/internal/severity" +) + +// TestStderrThresholdWithLogToStderr tests the new behavior where stderrthreshold +// can be honored even when logtostderr=true, when legacy_stderr_threshold_behavior=false +func TestStderrThresholdWithLogToStderr(t *testing.T) { + defer CaptureState().Restore() + + tests := []struct { + name string + logtostderr bool + legacyBehavior bool + stderrthreshold string + logLevel severity.Severity + expectInStderr bool + description string + }{ + { + name: "legacy behavior - logtostderr=true, all logs to stderr", + logtostderr: true, + legacyBehavior: true, + stderrthreshold: "ERROR", + logLevel: severity.InfoLog, + expectInStderr: true, + description: "Legacy: INFO should appear in stderr even with stderrthreshold=ERROR", + }, + { + name: "legacy behavior - logtostderr=true, ERROR threshold ignored", + logtostderr: true, + legacyBehavior: true, + stderrthreshold: "ERROR", + logLevel: severity.ErrorLog, + expectInStderr: true, + description: "Legacy: ERROR should appear in stderr", + }, + { + name: "new behavior - logtostderr=true, stderrthreshold honored, INFO filtered", + logtostderr: true, + legacyBehavior: false, + stderrthreshold: "ERROR", + logLevel: severity.InfoLog, + expectInStderr: false, + description: "New: INFO should NOT appear in stderr with stderrthreshold=ERROR", + }, + { + name: "new behavior - logtostderr=true, stderrthreshold honored, WARNING filtered", + logtostderr: true, + legacyBehavior: false, + stderrthreshold: "ERROR", + logLevel: severity.WarningLog, + expectInStderr: false, + description: "New: WARNING should NOT appear in stderr with stderrthreshold=ERROR", + }, + { + name: "new behavior - logtostderr=true, stderrthreshold honored, ERROR passes", + logtostderr: true, + legacyBehavior: false, + stderrthreshold: "ERROR", + logLevel: severity.ErrorLog, + expectInStderr: true, + description: "New: ERROR should appear in stderr with stderrthreshold=ERROR", + }, + { + name: "new behavior - logtostderr=true, stderrthreshold=WARNING, INFO filtered", + logtostderr: true, + legacyBehavior: false, + stderrthreshold: "WARNING", + logLevel: severity.InfoLog, + expectInStderr: false, + description: "New: INFO should NOT appear in stderr with stderrthreshold=WARNING", + }, + { + name: "new behavior - logtostderr=true, stderrthreshold=WARNING, WARNING passes", + logtostderr: true, + legacyBehavior: false, + stderrthreshold: "WARNING", + logLevel: severity.WarningLog, + expectInStderr: true, + description: "New: WARNING should appear in stderr with stderrthreshold=WARNING", + }, + { + name: "new behavior - logtostderr=true, stderrthreshold=INFO, all pass", + logtostderr: true, + legacyBehavior: false, + stderrthreshold: "INFO", + logLevel: severity.InfoLog, + expectInStderr: true, + description: "New: INFO should appear in stderr with stderrthreshold=INFO", + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + // Reset state for each test + state := CaptureState() + defer state.Restore() + + // Capture stderr + oldStderr := os.Stderr + r, w, _ := os.Pipe() + os.Stderr = w + + // Configure flags + logging.mu.Lock() + logging.toStderr = tt.logtostderr + logging.legacyStderrThresholdBehavior = tt.legacyBehavior + logging.stderrThreshold.Set(tt.stderrthreshold) + logging.mu.Unlock() + + // Log message based on level + testMsg := fmt.Sprintf("test message %s", tt.name) + buf := buffer.GetBuffer() + buf.WriteString(testMsg) + buf.WriteString("\n") + + // Call output directly to test the logic + logging.output(tt.logLevel, nil, buf, 0, "test.go", 123, false) + + // Close writer and read stderr + w.Close() + var stderrBuf bytes.Buffer + io.Copy(&stderrBuf, r) + os.Stderr = oldStderr + + stderrContent := stderrBuf.String() + containsMsg := strings.Contains(stderrContent, testMsg) + + if tt.expectInStderr && !containsMsg { + t.Errorf("%s: expected message in stderr but not found.\nStderr: %q", tt.description, stderrContent) + } + if !tt.expectInStderr && containsMsg { + t.Errorf("%s: did not expect message in stderr but found it.\nStderr: %q", tt.description, stderrContent) + } + }) + } +} + +// TestAlsologtostderrthreshold tests the new alsologtostderrthreshold flag +func TestAlsologtostderrthreshold(t *testing.T) { + defer CaptureState().Restore() + + tests := []struct { + name string + alsologtostderr bool + alsologtostderrthreshold string + logLevel severity.Severity + expectInStderr bool + description string + }{ + { + name: "alsologtostderr=true, threshold=ERROR, INFO filtered", + alsologtostderr: true, + alsologtostderrthreshold: "ERROR", + logLevel: severity.InfoLog, + expectInStderr: false, + description: "INFO should NOT appear in stderr with alsologtostderrthreshold=ERROR", + }, + { + name: "alsologtostderr=true, threshold=ERROR, WARNING filtered", + alsologtostderr: true, + alsologtostderrthreshold: "ERROR", + logLevel: severity.WarningLog, + expectInStderr: false, + description: "WARNING should NOT appear in stderr with alsologtostderrthreshold=ERROR", + }, + { + name: "alsologtostderr=true, threshold=ERROR, ERROR passes", + alsologtostderr: true, + alsologtostderrthreshold: "ERROR", + logLevel: severity.ErrorLog, + expectInStderr: true, + description: "ERROR should appear in stderr with alsologtostderrthreshold=ERROR", + }, + { + name: "alsologtostderr=true, threshold=WARNING, INFO filtered", + alsologtostderr: true, + alsologtostderrthreshold: "WARNING", + logLevel: severity.InfoLog, + expectInStderr: false, + description: "INFO should NOT appear in stderr with alsologtostderrthreshold=WARNING", + }, + { + name: "alsologtostderr=true, threshold=WARNING, WARNING passes", + alsologtostderr: true, + alsologtostderrthreshold: "WARNING", + logLevel: severity.WarningLog, + expectInStderr: true, + description: "WARNING should appear in stderr with alsologtostderrthreshold=WARNING", + }, + { + name: "alsologtostderr=true, default threshold (INFO), all pass", + alsologtostderr: true, + alsologtostderrthreshold: "INFO", + logLevel: severity.InfoLog, + expectInStderr: true, + description: "INFO should appear in stderr with alsologtostderrthreshold=INFO (default)", + }, + { + name: "alsologtostderr=false, threshold=ERROR, no stderr", + alsologtostderr: false, + alsologtostderrthreshold: "ERROR", + logLevel: severity.ErrorLog, + expectInStderr: false, + description: "ERROR should NOT appear in stderr when alsologtostderr=false", + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + // Reset state for each test + state := CaptureState() + defer state.Restore() + + // Capture stderr + oldStderr := os.Stderr + r, w, _ := os.Pipe() + os.Stderr = w + + // Configure flags - disable logtostderr and enable file logging + logging.mu.Lock() + logging.toStderr = false + logging.alsoToStderr = tt.alsologtostderr + logging.alsologtostderrthreshold.Set(tt.alsologtostderrthreshold) + logging.stderrThreshold.Set("FATAL") // Set high to avoid interference + // Use buffer writers instead of files + logging.file = [severity.NumSeverity]io.Writer{ + new(flushBuffer), new(flushBuffer), new(flushBuffer), new(flushBuffer), + } + logging.mu.Unlock() + + // Log message based on level + testMsg := fmt.Sprintf("test message %s", tt.name) + buf := buffer.GetBuffer() + buf.WriteString(testMsg) + buf.WriteString("\n") + + // Call output directly to test the logic + logging.output(tt.logLevel, nil, buf, 0, "test.go", 123, false) + + // Close writer and read stderr + w.Close() + var stderrBuf bytes.Buffer + io.Copy(&stderrBuf, r) + os.Stderr = oldStderr + + stderrContent := stderrBuf.String() + containsMsg := strings.Contains(stderrContent, testMsg) + + if tt.expectInStderr && !containsMsg { + t.Errorf("%s: expected message in stderr but not found.\nStderr: %q", tt.description, stderrContent) + } + if !tt.expectInStderr && containsMsg { + t.Errorf("%s: did not expect message in stderr but found it.\nStderr: %q", tt.description, stderrContent) + } + }) + } +} + +// TestFlagParsing tests that the new flags can be parsed correctly +func TestNewFlagParsing(t *testing.T) { + defer CaptureState().Restore() + + // Create a new flag set for testing + fs := flag.NewFlagSet("test", flag.ContinueOnError) + InitFlags(fs) + + tests := []struct { + name string + args []string + expectError bool + }{ + { + name: "valid legacy_stderr_threshold_behavior=true", + args: []string{"-legacy_stderr_threshold_behavior=true"}, + }, + { + name: "valid legacy_stderr_threshold_behavior=false", + args: []string{"-legacy_stderr_threshold_behavior=false"}, + }, + { + name: "valid alsologtostderrthreshold=ERROR", + args: []string{"-alsologtostderrthreshold=ERROR"}, + }, + { + name: "valid alsologtostderrthreshold=WARNING", + args: []string{"-alsologtostderrthreshold=WARNING"}, + }, + { + name: "valid alsologtostderrthreshold=INFO", + args: []string{"-alsologtostderrthreshold=INFO"}, + }, + { + name: "invalid alsologtostderrthreshold", + args: []string{"-alsologtostderrthreshold=INVALID"}, + expectError: true, + }, + { + name: "combined flags", + args: []string{ + "-logtostderr=true", + "-legacy_stderr_threshold_behavior=false", + "-stderrthreshold=ERROR", + "-alsologtostderrthreshold=WARNING", + }, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + // Reset flags + fs = flag.NewFlagSet("test", flag.ContinueOnError) + InitFlags(fs) + + err := fs.Parse(tt.args) + if tt.expectError && err == nil { + t.Errorf("expected error but got none") + } + if !tt.expectError && err != nil { + t.Errorf("unexpected error: %v", err) + } + }) + } +}