chore: better logging for command output

src/environment.go

@@ -107,11 +107,18 @@ func (c *commandCache) get(command string) (string, bool) {
 	return command, ok
 }
 
+type logType string
+
+const (
+	Error logType = "error"
+	Debug logType = "debug"
+)
+
 type tracer interface {
 	init(home string)
 	close()
 	trace(start time.Time, function string, args ...string)
-	error(message string)
+	log(lt logType, function, message string)
 }
 
 type fileTracer struct {
@@ -150,11 +157,11 @@ func (t *fileTracer) trace(start time.Time, function string, args ...string) {
 	log.Println(trace)
 }
 
-func (t *fileTracer) error(message string) {
+func (t *fileTracer) log(lt logType, function, message string) {
 	if !t.debug {
 		return
 	}
-	trace := fmt.Sprintf("error: %s", message)
+	trace := fmt.Sprintf("%s: %s\n%s", lt, function, message)
 	log.Println(trace)
 }
 
@@ -182,7 +189,9 @@ func (env *environment) init(args *args) {
 
 func (env *environment) getenv(key string) string {
 	defer env.tracer.trace(time.Now(), "getenv", key)
-	return os.Getenv(key)
+	val := os.Getenv(key)
+	env.tracer.log(Debug, "getenv", val)
+	return val
 }
 
 func (env *environment) getcwd() string {
@@ -201,7 +210,7 @@ func (env *environment) getcwd() string {
 	}
 	dir, err := os.Getwd()
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "getcwd", err.Error())
 		return ""
 	}
 	env.cwd = correctPath(dir)
@@ -214,7 +223,7 @@ func (env *environment) hasFiles(pattern string) bool {
 	pattern = cwd + env.getPathSeperator() + pattern
 	matches, err := filepath.Glob(pattern)
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "hasFiles", err.Error())
 		return false
 	}
 	return len(matches) > 0
@@ -225,7 +234,7 @@ func (env *environment) hasFilesInDir(dir, pattern string) bool {
 	pattern = dir + env.getPathSeperator() + pattern
 	matches, err := filepath.Glob(pattern)
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "hasFilesInDir", err.Error())
 		return false
 	}
 	return len(matches) > 0
@@ -241,7 +250,7 @@ func (env *environment) getFileContent(file string) string {
 	defer env.tracer.trace(time.Now(), "getFileContent", file)
 	content, err := ioutil.ReadFile(file)
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "getFileContent", err.Error())
 		return ""
 	}
 	return string(content)
@@ -251,7 +260,7 @@ func (env *environment) getFoldersList(path string) []string {
 	defer env.tracer.trace(time.Now(), "getFoldersList", path)
 	content, err := os.ReadDir(path)
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "getFoldersList", err.Error())
 		return nil
 	}
 	var folderNames []string
@@ -281,7 +290,7 @@ func (env *environment) getHostName() (string, error) {
 	defer env.tracer.trace(time.Now(), "getHostName")
 	hostName, err := os.Hostname()
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "getHostName", err.Error())
 		return "", err
 	}
 	return cleanHostName(hostName), nil
@@ -327,7 +336,7 @@ func (env *environment) runCommand(command string, args ...string) (string, erro
 	err := cmd.Start()
 	if err != nil {
 		errorStr := fmt.Sprintf("cmd.Start() failed with '%s'", err)
-		env.tracer.error(errorStr)
+		env.tracer.log(Error, "runCommand", errorStr)
 		return "", errors.New(errorStr)
 	}
 	// cmd.Wait() should be called only after we finish reading
@@ -343,7 +352,7 @@ func (env *environment) runCommand(command string, args ...string) (string, erro
 	wg.Wait()
 	err = cmd.Wait()
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "runCommand", err.Error())
 		if exitErr, ok := err.(*exec.ExitError); ok {
 			return "", &commandError{
 				err:      exitErr.Error(),
@@ -353,14 +362,16 @@ func (env *environment) runCommand(command string, args ...string) (string, erro
 	}
 	if stdoutErr != nil || stderrErr != nil {
 		errString := "failed to capture stdout or stderr"
-		env.tracer.error(errString)
+		env.tracer.log(Error, "runCommand", errString)
 		return "", errors.New(errString)
 	}
 	stderrStr := normalizeOutput(stderr)
 	if len(stderrStr) > 0 {
 		return stderrStr, nil
 	}
-	return normalizeOutput(stdout), nil
+	output := normalizeOutput(stdout)
+	env.tracer.log(Debug, "runCommand", output)
+	return output, nil
 }
 
 func (env *environment) runShellCommand(shell, command string) string {
@@ -379,7 +390,7 @@ func (env *environment) hasCommand(command string) bool {
 		env.cmdCache.set(command, path)
 		return true
 	}
-	env.tracer.error(err.Error())
+	env.tracer.log(Error, "hasCommand", err.Error())
 	return false
 }
 
@@ -406,7 +417,7 @@ func (env *environment) getBatteryInfo() ([]*battery.Battery, error) {
 	batteries, err := battery.GetAll()
 	// actual error, return it
 	if err != nil && len(batteries) == 0 {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "getBatteryInfo", err.Error())
 		return nil, err
 	}
 	// there are no batteries found
@@ -427,7 +438,7 @@ func (env *environment) getBatteryInfo() ([]*battery.Battery, error) {
 	}
 	// another error occurred (possibly unmapped use-case), return it
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "getBatteryInfo", err.Error())
 		return nil, err
 	}
 	// everything is fine
@@ -443,7 +454,7 @@ func (env *environment) getShellName() string {
 	p, _ := process.NewProcess(int32(pid))
 	name, err := p.Name()
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "getShellName", err.Error())
 		return unknown
 	}
 	if name == "cmd.exe" {
@@ -451,7 +462,7 @@ func (env *environment) getShellName() string {
 		name, err = p.Name()
 	}
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "getShellName", err.Error())
 		return unknown
 	}
 	// Cache the shell value to speed things up.
@@ -469,13 +480,13 @@ func (env *environment) doGet(url string, timeout int) ([]byte, error) {
 	}
 	response, err := client.Do(request)
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "doGet", err.Error())
 		return nil, err
 	}
 	defer response.Body.Close()
 	body, err := ioutil.ReadAll(response.Body)
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "doGet", err.Error())
 		return nil, err
 	}
 	return body, nil
@@ -501,7 +512,7 @@ func (env *environment) hasParentFilePath(path string) (*fileInfo, error) {
 			currentFolder = dir
 			continue
 		}
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "hasParentFilePath", err.Error())
 		return nil, errors.New("no match at root level")
 	}
 }

src/environment_test.go

@@ -18,16 +18,16 @@ func (_m *MockedTracer) close() {
 	_m.Called()
 }
 
-// error provides a mock function with given fields: message
-func (_m *MockedTracer) error(message string) {
-	_m.Called(message)
-}
-
 // init provides a mock function with given fields: home
 func (_m *MockedTracer) init(home string) {
 	_m.Called(home)
 }
 
+// log provides a mock function with given fields: lt, function, message
+func (_m *MockedTracer) log(lt logType, function, message string) {
+	_m.Called(lt, function, message)
+}
+
 // trace provides a mock function with given fields: start, function, args
 func (_m *MockedTracer) trace(start time.Time, function string, args ...string) {
 	_va := make([]interface{}, len(args))

src/environment_unix.go

@@ -37,7 +37,7 @@ func (env *environment) getTerminalWidth() (int, error) {
 	defer env.tracer.trace(time.Now(), "getTerminalWidth")
 	width, err := terminal.Width()
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "runCommand", err.Error())
 	}
 	return int(width), err
 }

src/environment_windows.go

@@ -27,7 +27,7 @@ func (env *environment) isRunningAsRoot() bool {
 		0, 0, 0, 0, 0, 0,
 		&sid)
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "isRunningAsRoot", err.Error())
 		return false
 	}
 	defer func() {
@@ -41,7 +41,7 @@ func (env *environment) isRunningAsRoot() bool {
 
 	member, err := token.IsMember(sid)
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "isRunningAsRoot", err.Error())
 		return false
 	}
 
@@ -75,12 +75,12 @@ func (env *environment) getTerminalWidth() (int, error) {
 	defer env.tracer.trace(time.Now(), "getTerminalWidth")
 	handle, err := syscall.Open("CONOUT$", syscall.O_RDWR, 0)
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "getTerminalWidth", err.Error())
 		return 0, err
 	}
 	info, err := winterm.GetConsoleScreenBufferInfo(uintptr(handle))
 	if err != nil {
-		env.tracer.error(err.Error())
+		env.tracer.log(Error, "getTerminalWidth", err.Error())
 		return 0, err
 	}
 	// return int(float64(info.Size.X) * 0.57), nil