From 9dfa1126177952433f8339a87fb566c2959fc3d6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B8rn=20Erik=20Pedersen?= Date: Fri, 13 Dec 2024 09:23:09 +0100 Subject: [PATCH] Write all logging (INFO, WARN, ERROR) to stderr The old setup tried to log >= warning to stderr, the rest to stdout. However, that logic was flawed, so warnings ended up in stdout, which makes `hugo list all` etc. hard to reason about from scripts. This commit fixes this by making all logging (info, warn, error) log to stderr and let stdout be reserved for program output. Fixes #13074 --- commands/commandeer.go | 21 +++++---- commands/list.go | 2 +- common/loggers/handlerterminal.go | 4 +- common/loggers/logger.go | 44 ++++++++++--------- common/loggers/logger_test.go | 16 +++---- deps/deps.go | 8 ++-- hugolib/integrationtest_builder.go | 6 +-- hugolib/site.go | 11 +++-- modules/client.go | 4 +- testscripts/commands/deprecate.txt | 6 +-- testscripts/commands/hugo__configdir.txt | 3 +- testscripts/commands/hugo__path-warnings.txt | 2 +- .../commands/hugo_printpathwarnings.txt | 2 +- .../commands/hugo_printunusedtemplates.txt | 2 +- testscripts/commands/warnf_stderr.txt | 13 ++++++ 15 files changed, 85 insertions(+), 59 deletions(-) create mode 100644 testscripts/commands/warnf_stderr.txt diff --git a/commands/commandeer.go b/commands/commandeer.go index bb82ec654..3f9f02d23 100644 --- a/commands/commandeer.go +++ b/commands/commandeer.go @@ -103,7 +103,8 @@ type configKey struct { type rootCommand struct { Printf func(format string, v ...interface{}) Println func(a ...interface{}) - Out io.Writer + StdOut io.Writer + StdErr io.Writer logger loggers.Logger @@ -356,7 +357,7 @@ func (r *rootCommand) getOrCreateHugo(cfg config.Provider, ignoreModuleDoesNotEx } func (r *rootCommand) newDepsConfig(conf *commonConfig) deps.DepsCfg { - return deps.DepsCfg{Configs: conf.configs, Fs: conf.fs, LogOut: r.logger.Out(), LogLevel: r.logger.Level(), ChangesFromBuild: r.changesFromBuild} + return deps.DepsCfg{Configs: conf.configs, Fs: conf.fs, StdOut: r.logger.StdOut(), StdErr: r.logger.StdErr(), LogLevel: r.logger.Level(), ChangesFromBuild: r.changesFromBuild} } func (r *rootCommand) Name() string { @@ -421,21 +422,23 @@ func (r *rootCommand) Run(ctx context.Context, cd *simplecobra.Commandeer, args } func (r *rootCommand) PreRun(cd, runner *simplecobra.Commandeer) error { - r.Out = os.Stdout + r.StdOut = os.Stdout + r.StdErr = os.Stderr if r.quiet { - r.Out = io.Discard + r.StdOut = io.Discard + r.StdErr = io.Discard } // Used by mkcert (server). - log.SetOutput(r.Out) + log.SetOutput(r.StdOut) r.Printf = func(format string, v ...interface{}) { if !r.quiet { - fmt.Fprintf(r.Out, format, v...) + fmt.Fprintf(r.StdOut, format, v...) } } r.Println = func(a ...interface{}) { if !r.quiet { - fmt.Fprintln(r.Out, a...) + fmt.Fprintln(r.StdOut, a...) } } _, running := runner.Command.(*serverCommand) @@ -485,8 +488,8 @@ func (r *rootCommand) createLogger(running bool) (loggers.Logger, error) { optsLogger := loggers.Options{ DistinctLevel: logg.LevelWarn, Level: level, - Stdout: r.Out, - Stderr: r.Out, + StdOut: r.StdOut, + StdErr: r.StdErr, StoreErrors: running, } diff --git a/commands/list.go b/commands/list.go index f362e22f1..42f3408ba 100644 --- a/commands/list.go +++ b/commands/list.go @@ -57,7 +57,7 @@ func newListCommand() *listCommand { return err } - writer := csv.NewWriter(r.Out) + writer := csv.NewWriter(r.StdOut) defer writer.Flush() writer.Write([]string{ diff --git a/common/loggers/handlerterminal.go b/common/loggers/handlerterminal.go index c5f8fcce8..c6a86d3a2 100644 --- a/common/loggers/handlerterminal.go +++ b/common/loggers/handlerterminal.go @@ -40,8 +40,8 @@ func newNoAnsiEscapeHandler(outWriter, errWriter io.Writer, noLevelPrefix bool, type noAnsiEscapeHandler struct { mu sync.Mutex - outWriter io.Writer // Defaults to os.Stdout. - errWriter io.Writer // Defaults to os.Stderr. + outWriter io.Writer + errWriter io.Writer predicate func(*logg.Entry) bool noLevelPrefix bool } diff --git a/common/loggers/logger.go b/common/loggers/logger.go index 75c8102c7..77a21458a 100644 --- a/common/loggers/logger.go +++ b/common/loggers/logger.go @@ -38,8 +38,8 @@ var ( // Options defines options for the logger. type Options struct { Level logg.Level - Stdout io.Writer - Stderr io.Writer + StdOut io.Writer + StdErr io.Writer DistinctLevel logg.Level StoreErrors bool HandlerPost func(e *logg.Entry) error @@ -48,21 +48,22 @@ type Options struct { // New creates a new logger with the given options. func New(opts Options) Logger { - if opts.Stdout == nil { - opts.Stdout = os.Stdout + if opts.StdOut == nil { + opts.StdOut = os.Stdout } - if opts.Stderr == nil { - opts.Stderr = os.Stdout + if opts.StdErr == nil { + opts.StdErr = os.Stderr } + if opts.Level == 0 { opts.Level = logg.LevelWarn } var logHandler logg.Handler - if terminal.PrintANSIColors(os.Stdout) { - logHandler = newDefaultHandler(opts.Stdout, opts.Stderr) + if terminal.PrintANSIColors(os.Stderr) { + logHandler = newDefaultHandler(opts.StdErr, opts.StdErr) } else { - logHandler = newNoAnsiEscapeHandler(opts.Stdout, opts.Stderr, false, nil) + logHandler = newNoAnsiEscapeHandler(opts.StdErr, opts.StdErr, false, nil) } errorsw := &strings.Builder{} @@ -137,7 +138,8 @@ func New(opts Options) Logger { logCounters: logCounters, errors: errorsw, reset: reset, - out: opts.Stdout, + stdOut: opts.StdOut, + stdErr: opts.StdErr, level: opts.Level, logger: logger, tracel: l.WithLevel(logg.LevelTrace), @@ -153,8 +155,6 @@ func NewDefault() Logger { opts := Options{ DistinctLevel: logg.LevelWarn, Level: logg.LevelWarn, - Stdout: os.Stdout, - Stderr: os.Stdout, } return New(opts) } @@ -163,8 +163,6 @@ func NewTrace() Logger { opts := Options{ DistinctLevel: logg.LevelWarn, Level: logg.LevelTrace, - Stdout: os.Stdout, - Stderr: os.Stdout, } return New(opts) } @@ -189,7 +187,8 @@ type Logger interface { Level() logg.Level LoggCount(logg.Level) int Logger() logg.Logger - Out() io.Writer + StdOut() io.Writer + StdErr() io.Writer Printf(format string, v ...any) Println(v ...any) PrintTimerIfDelayed(start time.Time, name string) @@ -207,7 +206,8 @@ type logAdapter struct { logCounters *logLevelCounter errors *strings.Builder reset func() - out io.Writer + stdOut io.Writer + stdErr io.Writer level logg.Level logger logg.Logger tracel logg.LevelLogger @@ -259,8 +259,12 @@ func (l *logAdapter) Logger() logg.Logger { return l.logger } -func (l *logAdapter) Out() io.Writer { - return l.out +func (l *logAdapter) StdOut() io.Writer { + return l.stdOut +} + +func (l *logAdapter) StdErr() io.Writer { + return l.stdErr } // PrintTimerIfDelayed prints a time statement to the FEEDBACK logger @@ -279,11 +283,11 @@ func (l *logAdapter) Printf(format string, v ...any) { if !strings.HasSuffix(format, "\n") { format += "\n" } - fmt.Fprintf(l.out, format, v...) + fmt.Fprintf(l.stdOut, format, v...) } func (l *logAdapter) Println(v ...any) { - fmt.Fprintln(l.out, v...) + fmt.Fprintln(l.stdOut, v...) } func (l *logAdapter) Reset() { diff --git a/common/loggers/logger_test.go b/common/loggers/logger_test.go index dcf94b123..b03e6d903 100644 --- a/common/loggers/logger_test.go +++ b/common/loggers/logger_test.go @@ -31,8 +31,8 @@ func TestLogDistinct(t *testing.T) { opts := loggers.Options{ DistinctLevel: logg.LevelWarn, StoreErrors: true, - Stdout: io.Discard, - Stderr: io.Discard, + StdOut: io.Discard, + StdErr: io.Discard, } l := loggers.New(opts) @@ -54,8 +54,8 @@ func TestHookLast(t *testing.T) { HandlerPost: func(e *logg.Entry) error { panic(e.Message) }, - Stdout: io.Discard, - Stderr: io.Discard, + StdOut: io.Discard, + StdErr: io.Discard, } l := loggers.New(opts) @@ -70,8 +70,8 @@ func TestOptionStoreErrors(t *testing.T) { opts := loggers.Options{ StoreErrors: true, - Stderr: &sb, - Stdout: &sb, + StdErr: &sb, + StdOut: &sb, } l := loggers.New(opts) @@ -131,8 +131,8 @@ func TestReset(t *testing.T) { opts := loggers.Options{ StoreErrors: true, DistinctLevel: logg.LevelWarn, - Stdout: io.Discard, - Stderr: io.Discard, + StdOut: io.Discard, + StdErr: io.Discard, } l := loggers.New(opts) diff --git a/deps/deps.go b/deps/deps.go index ca0f5ee3b..8e9ec42d8 100644 --- a/deps/deps.go +++ b/deps/deps.go @@ -405,9 +405,11 @@ type DepsCfg struct { // The logging level to use. LogLevel logg.Level - // Where to write the logs. - // Currently we typically write everything to stdout. - LogOut io.Writer + // Logging output. + StdErr io.Writer + + // The console output. + StdOut io.Writer // The file systems to use Fs *hugofs.Fs diff --git a/hugolib/integrationtest_builder.go b/hugolib/integrationtest_builder.go index bc83d65b3..b593cd965 100644 --- a/hugolib/integrationtest_builder.go +++ b/hugolib/integrationtest_builder.go @@ -660,8 +660,8 @@ func (s *IntegrationTestBuilder) initBuilder() error { logger := loggers.New( loggers.Options{ - Stdout: w, - Stderr: w, + StdOut: w, + StdErr: w, Level: s.Cfg.LogLevel, DistinctLevel: logg.LevelWarn, }, @@ -685,7 +685,7 @@ func (s *IntegrationTestBuilder) initBuilder() error { s.Assert(err, qt.IsNil) - depsCfg := deps.DepsCfg{Configs: res, Fs: fs, LogLevel: logger.Level(), LogOut: logger.Out()} + depsCfg := deps.DepsCfg{Configs: res, Fs: fs, LogLevel: logger.Level(), StdErr: logger.StdErr()} sites, err := NewHugoSites(depsCfg) if err != nil { initErr = err diff --git a/hugolib/site.go b/hugolib/site.go index 7ec70eb6c..f73bd2517 100644 --- a/hugolib/site.go +++ b/hugolib/site.go @@ -145,8 +145,11 @@ func NewHugoSites(cfg deps.DepsCfg) (*HugoSites, error) { if cfg.Configs.Base.PanicOnWarning { logHookLast = loggers.PanicOnWarningHook } - if cfg.LogOut == nil { - cfg.LogOut = os.Stdout + if cfg.StdOut == nil { + cfg.StdOut = os.Stdout + } + if cfg.StdErr == nil { + cfg.StdErr = os.Stderr } if cfg.LogLevel == 0 { cfg.LogLevel = logg.LevelWarn @@ -156,8 +159,8 @@ func NewHugoSites(cfg deps.DepsCfg) (*HugoSites, error) { Level: cfg.LogLevel, DistinctLevel: logg.LevelWarn, // This will drop duplicate log warning and errors. HandlerPost: logHookLast, - Stdout: cfg.LogOut, - Stderr: cfg.LogOut, + StdOut: cfg.StdOut, + StdErr: cfg.StdErr, StoreErrors: conf.Watching(), SuppressStatements: conf.IgnoredLogs(), } diff --git a/modules/client.go b/modules/client.go index 404605c8c..d16af2d35 100644 --- a/modules/client.go +++ b/modules/client.go @@ -365,7 +365,7 @@ func (c *Client) Get(args ...string) error { } func (c *Client) get(args ...string) error { - if err := c.runGo(context.Background(), c.logger.Out(), append([]string{"get"}, args...)...); err != nil { + if err := c.runGo(context.Background(), c.logger.StdOut(), append([]string{"get"}, args...)...); err != nil { return fmt.Errorf("failed to get %q: %w", args, err) } return nil @@ -375,7 +375,7 @@ func (c *Client) get(args ...string) error { // If path is empty, Go will try to guess. // If this succeeds, this project will be marked as Go Module. func (c *Client) Init(path string) error { - err := c.runGo(context.Background(), c.logger.Out(), "mod", "init", path) + err := c.runGo(context.Background(), c.logger.StdOut(), "mod", "init", path) if err != nil { return fmt.Errorf("failed to init modules: %w", err) } diff --git a/testscripts/commands/deprecate.txt b/testscripts/commands/deprecate.txt index 3be4976d5..8791c3a78 100644 --- a/testscripts/commands/deprecate.txt +++ b/testscripts/commands/deprecate.txt @@ -1,13 +1,13 @@ # Test deprecation logging. hugo -e info --logLevel info -stdout 'INFO deprecated: item was deprecated in Hugo' +stderr 'INFO deprecated: item was deprecated in Hugo' hugo -e warn --logLevel warn -stdout 'WARN deprecated: item was deprecated in Hugo' +stderr 'WARN deprecated: item was deprecated in Hugo' ! hugo -e error --logLevel warn -stdout 'ERROR deprecated: item was deprecated in Hugo' +stderr 'ERROR deprecated: item was deprecated in Hugo' -- hugo.toml -- baseURL = "https://example.com/" diff --git a/testscripts/commands/hugo__configdir.txt b/testscripts/commands/hugo__configdir.txt index 4da62ade5..148523e9f 100644 --- a/testscripts/commands/hugo__configdir.txt +++ b/testscripts/commands/hugo__configdir.txt @@ -3,4 +3,5 @@ hugo ! stderr . -- config/_default/hugo.toml -- -baseURL = "https://example.com/" \ No newline at end of file +baseURL = "https://example.com/" +disableKinds = ["RSS", "page", "sitemap", "robotsTXT", "404", "taxonomy", "term", "home"] \ No newline at end of file diff --git a/testscripts/commands/hugo__path-warnings.txt b/testscripts/commands/hugo__path-warnings.txt index f7e3acd95..8eccb6567 100644 --- a/testscripts/commands/hugo__path-warnings.txt +++ b/testscripts/commands/hugo__path-warnings.txt @@ -1,6 +1,6 @@ hugo --printPathWarnings -stdout 'Duplicate' +stderr 'Duplicate' -- hugo.toml -- -- assets/css/styles.css -- diff --git a/testscripts/commands/hugo_printpathwarnings.txt b/testscripts/commands/hugo_printpathwarnings.txt index f4c76ebab..51eb46d91 100644 --- a/testscripts/commands/hugo_printpathwarnings.txt +++ b/testscripts/commands/hugo_printpathwarnings.txt @@ -1,6 +1,6 @@ hugo --printPathWarnings -stdout 'Duplicate target paths: .index.html \(2\)' +stderr 'Duplicate target paths: .index.html \(2\)' -- hugo.toml -- disableKinds = ["taxonomy", "term", "RSS", "sitemap", "robotsTXT", "404", "section"] diff --git a/testscripts/commands/hugo_printunusedtemplates.txt b/testscripts/commands/hugo_printunusedtemplates.txt index 312e4920d..eb9e068d7 100644 --- a/testscripts/commands/hugo_printunusedtemplates.txt +++ b/testscripts/commands/hugo_printunusedtemplates.txt @@ -1,6 +1,6 @@ hugo --printUnusedTemplates -stdout 'Template _default/list.html is unused' +stderr 'Template _default/list.html is unused' -- hugo.toml -- disableKinds = ["taxonomy", "term", "RSS", "sitemap", "robotsTXT", "404", "section", "page"] diff --git a/testscripts/commands/warnf_stderr.txt b/testscripts/commands/warnf_stderr.txt new file mode 100644 index 000000000..f899253c5 --- /dev/null +++ b/testscripts/commands/warnf_stderr.txt @@ -0,0 +1,13 @@ +# Issue #13074 + +hugo +stderr 'warning' +! stdout 'warning' + +-- hugo.toml -- +baseURL = "http://example.org/" +disableKinds = ["RSS", "page", "sitemap", "robotsTXT", "404", "taxonomy", "term"] +-- layouts/index.html -- +Home +{{ warnf "This is a warning" }} +