From d29699fa30356fbc04fd3655b9cf44bb41a11660 Mon Sep 17 00:00:00 2001 From: stg-annon <14135675+stg-annon@users.noreply.github.com> Date: Thu, 16 Sep 2021 19:09:44 -0400 Subject: [PATCH] Support scraper logging to specific log levels (#1648) * init scrapper log levels * Refactor plugin logging Co-authored-by: WithoutPants <53250216+WithoutPants@users.noreply.github.com> --- pkg/logger/plugin.go | 191 ++++++++++++++++++ pkg/plugin/common/log/log.go | 119 +++-------- pkg/plugin/log.go | 76 +------ pkg/scraper/script.go | 18 +- .../components/Changelog/versions/v0100.md | 1 + 5 files changed, 244 insertions(+), 161 deletions(-) create mode 100644 pkg/logger/plugin.go diff --git a/pkg/logger/plugin.go b/pkg/logger/plugin.go new file mode 100644 index 000000000..9882ebf72 --- /dev/null +++ b/pkg/logger/plugin.go @@ -0,0 +1,191 @@ +package logger + +import ( + "bufio" + "fmt" + "io" + "os" + "strconv" + "strings" +) + +type PluginLogLevel struct { + char byte + Name string +} + +// Valid Level values. +var ( + TraceLevel = PluginLogLevel{ + char: 't', + Name: "trace", + } + DebugLevel = PluginLogLevel{ + char: 'd', + Name: "debug", + } + InfoLevel = PluginLogLevel{ + char: 'i', + Name: "info", + } + WarningLevel = PluginLogLevel{ + char: 'w', + Name: "warning", + } + ErrorLevel = PluginLogLevel{ + char: 'e', + Name: "error", + } + ProgressLevel = PluginLogLevel{ + char: 'p', + Name: "progress", + } + NoneLevel = PluginLogLevel{ + Name: "none", + } +) + +var validLevels = []PluginLogLevel{ + TraceLevel, + DebugLevel, + InfoLevel, + WarningLevel, + ErrorLevel, + ProgressLevel, + NoneLevel, +} + +const startLevelChar byte = 1 +const endLevelChar byte = 2 + +func (l PluginLogLevel) prefix() string { + return string([]byte{ + startLevelChar, + byte(l.char), + endLevelChar, + }) +} + +func (l PluginLogLevel) Log(args ...interface{}) { + if l.char == 0 { + return + } + + argsToUse := []interface{}{ + l.prefix(), + } + argsToUse = append(argsToUse, args...) + fmt.Fprintln(os.Stderr, argsToUse...) +} + +func (l PluginLogLevel) Logf(format string, args ...interface{}) { + if l.char == 0 { + return + } + + formatToUse := string(l.prefix()) + format + "\n" + fmt.Fprintf(os.Stderr, formatToUse, args...) +} + +// PluginLogLevelFromName returns the Level that matches the provided name or nil if +// the name does not match a valid value. +func PluginLogLevelFromName(name string) *PluginLogLevel { + for _, l := range validLevels { + if l.Name == name { + return &l + } + } + + return nil +} + +// DetectLogLevel returns the Level and the logging string for a provided line +// of plugin output. It parses the string for logging control characters and +// determines the log level, if present. If not present, the plugin output +// is returned unchanged with a nil Level. +func DetectLogLevel(line string) (*PluginLogLevel, string) { + if len(line) < 4 || line[0] != startLevelChar || line[2] != endLevelChar { + return nil, line + } + + char := line[1] + var level *PluginLogLevel + for _, l := range validLevels { + if l.char == char { + level = &l + break + } + } + + if level == nil { + return nil, line + } + + line = strings.TrimSpace(line[3:]) + + return level, line +} + +type PluginLogger struct { + Prefix string + DefaultLogLevel *PluginLogLevel + ProgressChan chan float64 +} + +func (log *PluginLogger) HandleStderrLine(line string) { + level, ll := DetectLogLevel(line) + + // if no log level, just output to info + if level == nil { + if log.DefaultLogLevel != nil { + level = log.DefaultLogLevel + } else { + level = &InfoLevel + } + } + + switch *level { + case TraceLevel: + logger.Trace(log.Prefix, ll) + case DebugLevel: + logger.Debug(log.Prefix, ll) + case InfoLevel: + logger.Info(log.Prefix, ll) + case WarningLevel: + logger.Warn(log.Prefix, ll) + case ErrorLevel: + logger.Error(log.Prefix, ll) + case ProgressLevel: + p, err := strconv.ParseFloat(ll, 64) + if err != nil { + logger.Errorf("Error parsing progress value '%s': %s", ll, err.Error()) + } else { + // only pass progress through if channel present + if log.ProgressChan != nil { + // don't block on this + select { + case log.ProgressChan <- p: + default: + } + } + } + } +} + +func (log *PluginLogger) HandlePluginStdErr(pluginStdErr io.ReadCloser) { + // pipe plugin stderr to our logging + scanner := bufio.NewScanner(pluginStdErr) + for scanner.Scan() { + str := scanner.Text() + if str != "" { + log.HandleStderrLine(str) + } + } + + str := scanner.Text() + if str != "" { + log.HandleStderrLine(str) + } + + pluginStdErr.Close() +} diff --git a/pkg/plugin/common/log/log.go b/pkg/plugin/common/log/log.go index d4ebc0876..e64774a68 100644 --- a/pkg/plugin/common/log/log.go +++ b/pkg/plugin/common/log/log.go @@ -16,144 +16,94 @@ package log import ( - "fmt" "math" - "os" - "strings" + + "github.com/stashapp/stash/pkg/logger" ) // Level represents a logging level for plugin outputs. type Level struct { - char byte - Name string + *logger.PluginLogLevel } // Valid Level values. var ( TraceLevel = Level{ - char: 't', - Name: "trace", + &logger.TraceLevel, } DebugLevel = Level{ - char: 'd', - Name: "debug", + &logger.DebugLevel, } InfoLevel = Level{ - char: 'i', - Name: "info", + &logger.InfoLevel, } WarningLevel = Level{ - char: 'w', - Name: "warning", + &logger.WarningLevel, } ErrorLevel = Level{ - char: 'e', - Name: "error", + &logger.ErrorLevel, } ProgressLevel = Level{ - char: 'p', - Name: "progress", + &logger.ProgressLevel, } NoneLevel = Level{ - Name: "none", + &logger.NoneLevel, } ) -var validLevels = []Level{ - TraceLevel, - DebugLevel, - InfoLevel, - WarningLevel, - ErrorLevel, - ProgressLevel, - NoneLevel, -} - -const startLevelChar byte = 1 -const endLevelChar byte = 2 - -func (l Level) prefix() string { - return string([]byte{ - startLevelChar, - byte(l.char), - endLevelChar, - }) -} - -func (l Level) log(args ...interface{}) { - if l.char == 0 { - return - } - - argsToUse := []interface{}{ - l.prefix(), - } - argsToUse = append(argsToUse, args...) - fmt.Fprintln(os.Stderr, argsToUse...) -} - -func (l Level) logf(format string, args ...interface{}) { - if l.char == 0 { - return - } - - formatToUse := string(l.prefix()) + format + "\n" - fmt.Fprintf(os.Stderr, formatToUse, args...) -} - // Trace outputs a trace logging message to os.Stderr. Message is encoded with a // prefix that signifies to the server that it is a trace message. func Trace(args ...interface{}) { - TraceLevel.log(args...) + TraceLevel.Log(args...) } // Tracef is the equivalent of Printf outputting as a trace logging message. func Tracef(format string, args ...interface{}) { - TraceLevel.logf(format, args...) + TraceLevel.Logf(format, args...) } // Debug outputs a debug logging message to os.Stderr. Message is encoded with a // prefix that signifies to the server that it is a debug message. func Debug(args ...interface{}) { - DebugLevel.log(args...) + DebugLevel.Log(args...) } // Debugf is the equivalent of Printf outputting as a debug logging message. func Debugf(format string, args ...interface{}) { - DebugLevel.logf(format, args...) + DebugLevel.Logf(format, args...) } // Info outputs an info logging message to os.Stderr. Message is encoded with a // prefix that signifies to the server that it is an info message. func Info(args ...interface{}) { - InfoLevel.log(args...) + InfoLevel.Log(args...) } // Infof is the equivalent of Printf outputting as an info logging message. func Infof(format string, args ...interface{}) { - InfoLevel.logf(format, args...) + InfoLevel.Logf(format, args...) } // Warn outputs a warning logging message to os.Stderr. Message is encoded with a // prefix that signifies to the server that it is a warning message. func Warn(args ...interface{}) { - WarningLevel.log(args...) + WarningLevel.Log(args...) } // Warnf is the equivalent of Printf outputting as a warning logging message. func Warnf(format string, args ...interface{}) { - WarningLevel.logf(format, args...) + WarningLevel.Logf(format, args...) } // Error outputs an error logging message to os.Stderr. Message is encoded with a // prefix that signifies to the server that it is an error message. func Error(args ...interface{}) { - ErrorLevel.log(args...) + ErrorLevel.Log(args...) } // Errorf is the equivalent of Printf outputting as an error logging message. func Errorf(format string, args ...interface{}) { - ErrorLevel.logf(format, args...) + ErrorLevel.Logf(format, args...) } // Progress logs the current progress value. The progress value should be @@ -161,15 +111,16 @@ func Errorf(format string, args ...interface{}) { // complete. Values outside of this range will be clamp to be within it. func Progress(progress float64) { progress = math.Min(math.Max(0, progress), 1) - ProgressLevel.log(progress) + ProgressLevel.Log(progress) } // LevelFromName returns the Level that matches the provided name or nil if // the name does not match a valid value. func LevelFromName(name string) *Level { - for _, l := range validLevels { - if l.Name == name { - return &l + l := logger.PluginLogLevelFromName(name) + if l != nil { + return &Level{ + l, } } @@ -181,24 +132,14 @@ func LevelFromName(name string) *Level { // determines the log level, if present. If not present, the plugin output // is returned unchanged with a nil Level. func DetectLogLevel(line string) (*Level, string) { - if len(line) < 4 || line[0] != startLevelChar || line[2] != endLevelChar { - return nil, line - } - - char := line[1] - var level *Level - for _, l := range validLevels { - if l.char == char { - level = &l - break - } - } + var level *logger.PluginLogLevel + level, line = logger.DetectLogLevel(line) if level == nil { return nil, line } - line = strings.TrimSpace(line[3:]) - - return level, line + return &Level{ + level, + }, line } diff --git a/pkg/plugin/log.go b/pkg/plugin/log.go index 96727f688..3eadb9a5b 100644 --- a/pkg/plugin/log.go +++ b/pkg/plugin/log.go @@ -1,79 +1,25 @@ package plugin import ( - "bufio" "io" - "strconv" "github.com/stashapp/stash/pkg/logger" - "github.com/stashapp/stash/pkg/plugin/common/log" ) -func (t *pluginTask) handleStderrLine(line string, defaultLogLevel *log.Level) { - level, l := log.DetectLogLevel(line) - - const pluginPrefix = "[Plugin] " - // if no log level, just output to info - if level == nil { - if defaultLogLevel != nil { - level = defaultLogLevel - } else { - level = &log.InfoLevel - } - } - - switch *level { - case log.TraceLevel: - logger.Trace(pluginPrefix, l) - case log.DebugLevel: - logger.Debug(pluginPrefix, l) - case log.InfoLevel: - logger.Info(pluginPrefix, l) - case log.WarningLevel: - logger.Warn(pluginPrefix, l) - case log.ErrorLevel: - logger.Error(pluginPrefix, l) - case log.ProgressLevel: - progress, err := strconv.ParseFloat(l, 64) - if err != nil { - logger.Errorf("Error parsing progress value '%s': %s", l, err.Error()) - } else { - // only pass progress through if channel present - if t.progress != nil { - // don't block on this - select { - case t.progress <- progress: - default: - } - } - } - } -} - -func (t *pluginTask) handlePluginOutput(pluginOutputReader io.ReadCloser, defaultLogLevel *log.Level) { - // pipe plugin stderr to our logging - scanner := bufio.NewScanner(pluginOutputReader) - for scanner.Scan() { - str := scanner.Text() - if str != "" { - t.handleStderrLine(str, defaultLogLevel) - } - } - - str := scanner.Text() - if str != "" { - t.handleStderrLine(str, defaultLogLevel) - } - - pluginOutputReader.Close() -} - func (t *pluginTask) handlePluginStderr(pluginOutputReader io.ReadCloser) { - logLevel := log.LevelFromName(t.plugin.PluginErrLogLevel) + logLevel := logger.PluginLogLevelFromName(t.plugin.PluginErrLogLevel) if logLevel == nil { // default log level to error - logLevel = &log.ErrorLevel + logLevel = &logger.ErrorLevel } - t.handlePluginOutput(pluginOutputReader, logLevel) + const pluginPrefix = "[Plugin] " + + lgr := logger.PluginLogger{ + Prefix: pluginPrefix, + DefaultLogLevel: logLevel, + ProgressChan: t.progress, + } + + lgr.HandlePluginStdErr(pluginOutputReader) } diff --git a/pkg/scraper/script.go b/pkg/scraper/script.go index e3aa5f81a..e8fee8cfc 100644 --- a/pkg/scraper/script.go +++ b/pkg/scraper/script.go @@ -1,7 +1,6 @@ package scraper import ( - "bufio" "encoding/json" "errors" "io" @@ -66,12 +65,7 @@ func (s *scriptScraper) runScraperScript(inString string, out interface{}) error return errors.New("error running scraper script") } - scanner := bufio.NewScanner(stderr) - go func() { // log errors from stderr pipe - for scanner.Scan() { - logger.Errorf("scraper: %s", scanner.Text()) - } - }() + go handleScraperStderr(stderr) logger.Debugf("Scraper script <%s> started", strings.Join(cmd.Args, " ")) @@ -253,3 +247,13 @@ func findPythonExecutable() (string, error) { return "python3", nil } + +func handleScraperStderr(scraperOutputReader io.ReadCloser) { + const scraperPrefix = "[Scrape] " + + lgr := logger.PluginLogger{ + Prefix: scraperPrefix, + DefaultLogLevel: &logger.ErrorLevel, + } + lgr.HandlePluginStdErr(scraperOutputReader) +} diff --git a/ui/v2.5/src/components/Changelog/versions/v0100.md b/ui/v2.5/src/components/Changelog/versions/v0100.md index d49dd5d05..87d5c44ab 100644 --- a/ui/v2.5/src/components/Changelog/versions/v0100.md +++ b/ui/v2.5/src/components/Changelog/versions/v0100.md @@ -10,6 +10,7 @@ * Support filtering Movies by Performers. ([#1675](https://github.com/stashapp/stash/pull/1675)) ### 🎨 Improvements +* Support scraper script logging to specific log levels. ([#1648](https://github.com/stashapp/stash/pull/1648)) * Added sv-SE language option. ([#1691](https://github.com/stashapp/stash/pull/1691)) ### 🐛 Bug fixes