Log more when resolving Python

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
 	}()

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,19 +25,32 @@ 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) {
-	_, err := exec.LookPath("python3")
+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)
+		}
+	}
+
+	python3, err := exec.LookPath("python3")
 
 	if err != nil {
-		_, err = exec.LookPath("python")
+		python, err := exec.LookPath("python")
 		if err != nil {
-			return nil, err
+			return nil, fmt.Errorf("python executable not in PATH: %s", err)
 		}
-		ret := Python("python")
+		ret := Python(python)
 		return &ret, nil
 	}
 
-	ret := Python("python3")
+	ret := Python(python3)
 	return &ret, nil
 }
 

pkg/scraper/script.go

@@ -38,21 +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 != "" {
-			p = python.New(pythonPath)
-		} else {
-			p, _ = python.Resolve()
-		}
+		p, err := python.Resolve(pythonPath)
 
-		if p != nil {
-			cmd = p.Command(ctx, command[1:])
+		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:]...)
 	}
 
@@ -88,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.
@@ -116,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)