From 5fa080ea4bba3e66215ae2050d9a1a5cf0eb8453 Mon Sep 17 00:00:00 2001 From: Maista6969 Date: Mon, 9 Oct 2023 03:51:12 +0200 Subject: [PATCH 1/4] Log more when resolving Python Users often have problems configuring their Python installations --- pkg/python/exec.go | 20 +++++++++----------- pkg/scraper/script.go | 20 +++++++++++++++++--- 2 files changed, 26 insertions(+), 14 deletions(-) diff --git a/pkg/python/exec.go b/pkg/python/exec.go index bd5679533bc..e73771a4335 100644 --- a/pkg/python/exec.go +++ b/pkg/python/exec.go @@ -23,19 +23,17 @@ func New(path string) *Python { // It first checks for python3, then python. // Returns nil and an exec.ErrNotFound error if not found. func Resolve() (*Python, error) { - _, err := exec.LookPath("python3") - - if err != nil { - _, err = exec.LookPath("python") - if err != nil { - return nil, err - } - ret := Python("python") - return &ret, nil + python3, err := exec.LookPath("python3") + if err == nil { + return New(python3), nil } - ret := Python("python3") - return &ret, nil + python, err := exec.LookPath("python") + if err == nil { + return New(python), nil + } + + return nil, err } // IsPythonCommand returns true if arg is "python" or "python3" diff --git a/pkg/scraper/script.go b/pkg/scraper/script.go index 5d6e25acfeb..86e39a9c5f8 100644 --- a/pkg/scraper/script.go +++ b/pkg/scraper/script.go @@ -11,6 +11,7 @@ import ( "strings" stashExec "github.com/stashapp/stash/pkg/exec" + "github.com/stashapp/stash/pkg/fsutil" "github.com/stashapp/stash/pkg/logger" "github.com/stashapp/stash/pkg/models" "github.com/stashapp/stash/pkg/python" @@ -40,16 +41,29 @@ func (s *scriptScraper) runScraperScript(ctx context.Context, inString string, o pythonPath := s.globalConfig.GetPythonPath() var p *python.Python if pythonPath != "" { - p = python.New(pythonPath) + // Users commonly set the path to a folder instead of the executable + isFile, err := fsutil.FileExists(pythonPath) + if err != nil { + logger.Warnf("Unable to validate python path: %s", err) + } else if !isFile { + logger.Warnf("Python path is not a file: %s", pythonPath) + } else { + logger.Debugf("Using configured python path: %s", *p) + p = python.New(pythonPath) + } } else { p, _ = python.Resolve() + if p == nil { + logger.Warnf("Unable to resolve python from environment") + } } if p != nil { cmd = p.Command(ctx, command[1:]) + } else { + // if could not find python, just use the command args as-is + logger.Warnf("Could not find python executable, using command args as-is: %s", strings.Join(command, " ")) } - - // if could not find python, just use the command args as-is } if cmd == nil { From 797923912a89b48ce7738e25079991cf840e413e Mon Sep 17 00:00:00 2001 From: Maista6969 Date: Tue, 10 Oct 2023 05:09:59 +0200 Subject: [PATCH 2/4] Convert if-else ladder to switch statement --- pkg/scraper/script.go | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/pkg/scraper/script.go b/pkg/scraper/script.go index 86e39a9c5f8..2b3f30f9348 100644 --- a/pkg/scraper/script.go +++ b/pkg/scraper/script.go @@ -43,13 +43,14 @@ func (s *scriptScraper) runScraperScript(ctx context.Context, inString string, o if pythonPath != "" { // Users commonly set the path to a folder instead of the executable isFile, err := fsutil.FileExists(pythonPath) - if err != nil { - logger.Warnf("Unable to validate python path: %s", err) - } else if !isFile { - logger.Warnf("Python path is not a file: %s", pythonPath) - } else { - logger.Debugf("Using configured python path: %s", *p) + switch { + case err == nil && isFile: + logger.Debugf("Using configured python path: %s", pythonPath) p = python.New(pythonPath) + case err == nil && !isFile: + logger.Warnf("Python path is not a file: %s", pythonPath) + case err != nil: + logger.Warnf("Unable to validate python path: %s", err) } } else { p, _ = python.Resolve() From 109202ee0c2f2c4ad0b781935dfd9586524f561f Mon Sep 17 00:00:00 2001 From: Maista6969 Date: Fri, 13 Oct 2023 05:06:39 +0200 Subject: [PATCH 3/4] Consolidate Python resolution Adds additional logging to plugin tasks to align with the logging that scrapers output. --- pkg/plugin/raw.go | 18 +++++++++--------- pkg/python/exec.go | 34 ++++++++++++++++++++++++++-------- pkg/scraper/script.go | 33 +++++++-------------------------- 3 files changed, 42 insertions(+), 43 deletions(-) diff --git a/pkg/plugin/raw.go b/pkg/plugin/raw.go index 55516072ce5..37d16e7a4c1 100644 --- a/pkg/plugin/raw.go +++ b/pkg/plugin/raw.go @@ -7,6 +7,7 @@ import ( "fmt" "io" "os/exec" + "strings" "sync" stashExec "github.com/stashapp/stash/pkg/exec" @@ -45,21 +46,17 @@ func (t *rawPluginTask) Start() error { var cmd *exec.Cmd if python.IsPythonCommand(command[0]) { pythonPath := t.serverConfig.GetPythonPath() - var p *python.Python - if pythonPath != "" { - p = python.New(pythonPath) - } else { - p, _ = python.Resolve() - } + p, err := python.Resolve(pythonPath) - if p != nil { + if err != nil { + logger.Warnf("%s", err) + } else { cmd = p.Command(context.TODO(), command[1:]) } - - // if could not find python, just use the command args as-is } if cmd == nil { + // if could not find python, just use the command args as-is cmd = stashExec.Command(command[0], command[1:]...) } @@ -99,6 +96,8 @@ func (t *rawPluginTask) Start() error { go t.handlePluginStderr(t.plugin.Name, stderr) t.cmd = cmd + logger.Infof("Plugin %s started: %s", t.plugin.Name, strings.Join(cmd.Args, " ")) + // send the stdout to the plugin output go func() { defer t.waitGroup.Done() @@ -113,6 +112,7 @@ func (t *rawPluginTask) Start() error { errStr := err.Error() output.Error = &errStr } + logger.Infof("Plugin %s finished", t.plugin.Name) t.result = &output }() diff --git a/pkg/python/exec.go b/pkg/python/exec.go index e73771a4335..14f6f192795 100644 --- a/pkg/python/exec.go +++ b/pkg/python/exec.go @@ -2,9 +2,12 @@ package python import ( "context" + "fmt" "os/exec" stashExec "github.com/stashapp/stash/pkg/exec" + "github.com/stashapp/stash/pkg/fsutil" + "github.com/stashapp/stash/pkg/logger" ) type Python string @@ -22,18 +25,33 @@ func New(path string) *Python { // Resolve tries to find the python executable in the system. // It first checks for python3, then python. // Returns nil and an exec.ErrNotFound error if not found. -func Resolve() (*Python, error) { - python3, err := exec.LookPath("python3") - if err == nil { - return New(python3), nil +func Resolve(configuredPythonPath string) (*Python, error) { + if configuredPythonPath != "" { + isFile, err := fsutil.FileExists(configuredPythonPath) + switch { + case err == nil && isFile: + logger.Tracef("using configured python path: %s", configuredPythonPath) + return New(configuredPythonPath), nil + case err == nil && !isFile: + logger.Warnf("configured python path is not a file: %s", configuredPythonPath) + case err != nil: + logger.Warnf("unable to use configured python path: %s", err) + } } - python, err := exec.LookPath("python") - if err == nil { - return New(python), nil + python3, err := exec.LookPath("python3") + + if err != nil { + python, err := exec.LookPath("python") + if err != nil { + return nil, fmt.Errorf("python executable not in PATH: %s", err) + } + ret := Python(python) + return &ret, nil } - return nil, err + ret := Python(python3) + return &ret, nil } // IsPythonCommand returns true if arg is "python" or "python3" diff --git a/pkg/scraper/script.go b/pkg/scraper/script.go index 2b3f30f9348..aa410d7ff37 100644 --- a/pkg/scraper/script.go +++ b/pkg/scraper/script.go @@ -11,7 +11,6 @@ import ( "strings" stashExec "github.com/stashapp/stash/pkg/exec" - "github.com/stashapp/stash/pkg/fsutil" "github.com/stashapp/stash/pkg/logger" "github.com/stashapp/stash/pkg/models" "github.com/stashapp/stash/pkg/python" @@ -39,35 +38,17 @@ func (s *scriptScraper) runScraperScript(ctx context.Context, inString string, o var cmd *exec.Cmd if python.IsPythonCommand(command[0]) { pythonPath := s.globalConfig.GetPythonPath() - var p *python.Python - if pythonPath != "" { - // Users commonly set the path to a folder instead of the executable - isFile, err := fsutil.FileExists(pythonPath) - switch { - case err == nil && isFile: - logger.Debugf("Using configured python path: %s", pythonPath) - p = python.New(pythonPath) - case err == nil && !isFile: - logger.Warnf("Python path is not a file: %s", pythonPath) - case err != nil: - logger.Warnf("Unable to validate python path: %s", err) - } - } else { - p, _ = python.Resolve() - if p == nil { - logger.Warnf("Unable to resolve python from environment") - } - } + p, err := python.Resolve(pythonPath) - if p != nil { - cmd = p.Command(ctx, command[1:]) + if err != nil { + logger.Warnf("%s", err) } else { - // if could not find python, just use the command args as-is - logger.Warnf("Could not find python executable, using command args as-is: %s", strings.Join(command, " ")) + cmd = p.Command(context.TODO(), command[1:]) } } if cmd == nil { + // if could not find python, just use the command args as-is cmd = stashExec.Command(command[0], command[1:]...) } @@ -103,7 +84,7 @@ func (s *scriptScraper) runScraperScript(ctx context.Context, inString string, o go handleScraperStderr(s.config.Name, stderr) - logger.Debugf("Scraper script <%s> started", strings.Join(cmd.Args, " ")) + logger.Infof("Scraper script <%s> started", strings.Join(cmd.Args, " ")) // TODO - add a timeout here // Make a copy of stdout here. This allows us to decode it twice. @@ -131,7 +112,7 @@ func (s *scriptScraper) runScraperScript(ctx context.Context, inString string, o } err = cmd.Wait() - logger.Debugf("Scraper script finished") + logger.Infof("Scraper script finished") if err != nil { return fmt.Errorf("%w: %v", ErrScraperScript, err) From b1e9e365ef7cac321182f504a46975851a077f90 Mon Sep 17 00:00:00 2001 From: Maista6969 Date: Thu, 19 Oct 2023 22:11:47 +0200 Subject: [PATCH 4/4] Log plugin/scraper scopes at debug level --- pkg/plugin/raw.go | 4 ++-- pkg/scraper/script.go | 4 ++-- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/pkg/plugin/raw.go b/pkg/plugin/raw.go index 37d16e7a4c1..5c2fcea4efa 100644 --- a/pkg/plugin/raw.go +++ b/pkg/plugin/raw.go @@ -96,7 +96,7 @@ func (t *rawPluginTask) Start() error { go t.handlePluginStderr(t.plugin.Name, stderr) t.cmd = cmd - logger.Infof("Plugin %s started: %s", t.plugin.Name, strings.Join(cmd.Args, " ")) + logger.Debugf("Plugin %s started: %s", t.plugin.Name, strings.Join(cmd.Args, " ")) // send the stdout to the plugin output go func() { @@ -112,7 +112,7 @@ func (t *rawPluginTask) Start() error { errStr := err.Error() output.Error = &errStr } - logger.Infof("Plugin %s finished", t.plugin.Name) + logger.Debugf("Plugin %s finished", t.plugin.Name) t.result = &output }() diff --git a/pkg/scraper/script.go b/pkg/scraper/script.go index aa410d7ff37..70bebfe4d34 100644 --- a/pkg/scraper/script.go +++ b/pkg/scraper/script.go @@ -84,7 +84,7 @@ func (s *scriptScraper) runScraperScript(ctx context.Context, inString string, o go handleScraperStderr(s.config.Name, stderr) - logger.Infof("Scraper script <%s> started", strings.Join(cmd.Args, " ")) + logger.Debugf("Scraper script <%s> started", strings.Join(cmd.Args, " ")) // TODO - add a timeout here // Make a copy of stdout here. This allows us to decode it twice. @@ -112,7 +112,7 @@ func (s *scriptScraper) runScraperScript(ctx context.Context, inString string, o } err = cmd.Wait() - logger.Infof("Scraper script finished") + logger.Debugf("Scraper script finished") if err != nil { return fmt.Errorf("%w: %v", ErrScraperScript, err)