Move InitLogging to log utils so that it could be used in other modules like software update manager.

Author: Abhijith Dadaga Arkakeerthy

Makefile

@@ -1,10 +1,10 @@
-# Copyright (c) 2023 Veritas Technologies LLC. All rights reserved. IP63-2828-7171-04-15-9
+# Copyright (c) 2024 Veritas Technologies LLC. All rights reserved. IP63-2828-7171-04-15-9
 
 # A Self-Documenting Makefile: http://marmelab.com/blog/2016/02/29/auto-documented-makefile.html
 .DEFAULT_GOAL := help
 .PHONY: help
 help:	## Display this help message.
-	@grep -E '^[a-zA-Z0-9_-]+:.*?## .*$$' $(MAKEFILE_LIST) | sort | awk 'BEGIN {FS = ":.*?## "}; {printf "\033[36m%-20s\033[0m %s\n", $$1, $$2}'
+	@grep -Eh '^[a-zA-Z0-9_-]+:.*?## .*$$' $(MAKEFILE_LIST) | sort | awk 'BEGIN {FS = ":.*?## "}; {printf "\033[36m%-20s\033[0m %s\n", $$1, $$2}'
 
 TOP=$(CURDIR)
 include $(TOP)/Makefile.conf
@@ -29,8 +29,7 @@ clean: 	## Clean Plugin Manager go build & test artifacts
 	cd $(GOSRC); \
 	go clean -i -mod=vendor ./...;
 	@echo "Cleaning Go test artifacts... ";
-	-@rm $(GOSRC)/{,.}*{dot,html,log,svg,xml};
-	-@rm $(GOSRC)/cmd/pm/{,.}*{dot,log,svg};
+	-@find $(GOSRC) -name "*.dot" -o -name "*.html" -o -name "*.log" -o -name "*.svg" -o -name "*.xml" | xargs -i rm -f {}
 	-@rm -rf $(GOSRC)/plugins/
 	-@rm -rf $(GOCOVERDIR);
 
@@ -113,4 +112,13 @@ go-race: 	## Run Go tests with race detector enabled
 	export PM_CONF_FILE=$(GOSRC)/sample/pm.config.yaml; \
 	go test -mod=vendor -v -race ./...;
 
+.PHONY: update-go-tools
+update-go-tools: ## Update Go thirdparty tools to current go version  
+	export GOBIN=$(GOTOOLSBIN); \
+	go install github.com/axw/gocov/gocov@latest; \
+	go install github.com/AlekSi/gocov-xml@latest; \
+	go install github.com/matm/gocov-html/cmd/gocov-html@latest; \
+	go install github.com/jstemmer/go-junit-report/v2@latest; \
+	go install golang.org/x/lint/golint@latest
+
 .NOTPARALLEL:

cmd/pm/pm.go

@@ -5,7 +5,6 @@
 package main
 
 import (
-	"fmt"
 	"os"
 	"path/filepath"
 
@@ -18,7 +17,7 @@ import (
 var (
 	buildDate string
 	// Version of the Plugin Manager (PM) command.
-	version = "4.2"
+	version = "4.4"
 	// progname is name of my binary/program/executable.
 	progname = filepath.Base(os.Args[0])
 )
@@ -28,29 +27,7 @@ func init() {
 	config.EnvConfFile = "PM_CONF_FILE"
 	// DefaultConfigPath is default path for config file used when EnvConfFile is not set.
 	config.DefaultConfigPath = "/opt/veritas/appliance/asum/pm.config.yaml"
-	// DefaultLogPath is default path for log file.
-	config.DefaultLogPath = "./pm.log"
-	// Use syslog until the config file is read.
-	// If syslog initialization fails, file logging will be used.
-	useFileLog := true
-	if logger.IsSysLogConfigPresent() {
-		err := logger.InitSysLogger("pm-main", logger.DefaultLogLevel)
-		if err != nil {
-			fmt.Printf("Failed to initialize SysLog for logging [%#v]. Proceeding with FileLog...\n", err)
-			useFileLog = false
-		}
-	}
-	if useFileLog {
-		// NOTE: while running tests, the path of binary would be in `/tmp/<go-build*>`,
-		// so, using relative logging path w.r.t. binary wouldn't be accessible on Jenkins.
-		// So, use absolute path which also has write permissions (like current source directory).
-		err := logger.InitFileLogger(config.DefaultLogPath, logger.DefaultLogLevel)
-		if err != nil {
-			fmt.Printf("Failed to initialize file logger [%#v].\n", err)
-			os.Exit(1)
-		}
-	}
-
+	logger.InitLogging()
 }
 
 func main() {

config/config.go

@@ -31,8 +31,6 @@ var (
 	EnvConfFile string
 	// DefaultConfigPath is default path for config file used when EnvConfFile is not set.
 	DefaultConfigPath string
-	// DefaultLogPath is default path for log file.
-	DefaultLogPath string
 )
 
 // GetLogDir provides location for storing logs.

graph_test.go

@@ -6,8 +6,6 @@ import (
 	"reflect"
 	"sort"
 	"testing"
-
-	logger "github.com/VeritasOS/plugin-manager/utils/log"
 )
 
 func Test_getStatusColor(t *testing.T) {
@@ -199,8 +197,7 @@ func Test_initGraph(t *testing.T) {
 			wantErr: false,
 		},
 	}
-	// Set log file name to "test", so that cleaning becomes easier.
-	logger.InitFileLogger("test.log", "INFO")
+
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
 			if err := initGraph(tt.args.pluginType, tt.args.pluginsInfo); (err != nil) != tt.wantErr {

plugin.go

@@ -5,6 +5,7 @@
 package pm
 
 import (
+	"bufio"
 	"encoding/json"
 	"errors"
 	"flag"
@@ -29,7 +30,7 @@ import (
 
 var (
 	// Version of the Plugin Manager (PM).
-	version = "4.8"
+	version = "4.9"
 )
 
 // Status of plugin execution used for displaying to user on console.
@@ -48,15 +49,16 @@ type Plugin struct {
 	RequiredBy  []string
 	Requires    []string
 	Status      string
-	StdOutErr   string
+	StdOutErr   []string
 }
 
 // Plugins is a list of plugins' info.
 type Plugins []Plugin
 
 // RunStatus is the pm run status.
 type RunStatus struct {
-	Type string
+	Type    string
+	Library string
 	// TODO: Add Percentage to get no. of pending vs. completed run of plugins.
 	Plugins   Plugins `yaml:",omitempty"`
 	Status    string
@@ -158,10 +160,13 @@ func getPluginsInfoFromJSONStrOrFile(strOrFile string) (RunStatus, error) {
 			jsonFormat = false
 		}
 	}
+	// INFO: Use RunStatus to unmarshal to keep input consistent with current
+	//  output json, so that rerun failed could be done using result json.
+	var pluginsData RunStatus
 	if jsonFormat {
-		err = json.Unmarshal([]byte(rawData), &pluginsInfo)
+		err = json.Unmarshal([]byte(rawData), &pluginsData)
 	} else {
-		err = yaml.Unmarshal([]byte(rawData), &pluginsInfo)
+		err = yaml.Unmarshal([]byte(rawData), &pluginsData)
 	}
 	if err != nil {
 		logger.Error.Printf("Failed to call Unmarshal(%s, %v); err=%#v",
@@ -170,7 +175,7 @@ func getPluginsInfoFromJSONStrOrFile(strOrFile string) (RunStatus, error) {
 			logger.ConsoleError.PrintNReturnError(
 				"Plugins is not in expected format. Error: %s", err.Error())
 	}
-	return pluginsInfo, nil
+	return pluginsData, nil
 }
 
 func getPluginsInfoFromLibrary(pluginType, library string) (Plugins, error) {
@@ -411,7 +416,6 @@ func executePluginCmd(statusCh chan<- map[string]*Plugin, pInfo Plugin, failedDe
 	updateGraph(getPluginType(p), p, dStatusStart, "")
 	logger.ConsoleInfo.Printf("%s: %s", pInfo.Description, dStatusStart)
 	pluginLogFile := ""
-	// Create chLog, by default it will use syslog, if user specified logFile, then use previous defined log generator
 	var chLog *log.Logger
 	if !logger.IsFileLogger() {
 		var logTag string
@@ -496,21 +500,45 @@ func executePluginCmd(statusCh chan<- map[string]*Plugin, pInfo Plugin, failedDe
 	cmdParams := cmdParam[1:]
 	cmd := exec.Command(cmdStr, cmdParams...)
 	cmd.Env = envList
-	stdOutErr, err := cmd.CombinedOutput()
+	iostdout, err := cmd.StdoutPipe()
+	if err != nil {
+		pInfo.Status = dStatusFail
+		logger.Error.Printf("Failed to execute plugin %s. Error: %s\n", pInfo.Name, err.Error())
+		pInfo.StdOutErr = []string{err.Error()}
+		logger.ConsoleInfo.Printf("%s: %s\n", pInfo.Description, pInfo.Status)
+		statusCh <- map[string]*Plugin{p: &pInfo}
+		return
+	}
+	cmd.Stderr = cmd.Stdout
+
+	chLog.Println("Executing command:", pInfo.ExecStart)
+	err = cmd.Start()
+	var stdOutErr []string
+	if err == nil {
+		scanner := bufio.NewScanner(iostdout)
+		scanner.Split(bufio.ScanLines)
+		for scanner.Scan() {
+			iobytes := scanner.Text()
+			chLog.Println(string(iobytes))
+			stdOutErr = append(stdOutErr, iobytes)
+		}
+		err = cmd.Wait()
+		// chLog.Printf("command exited with code: %+v", err)
+	}
 
 	func() {
 		chLog.Printf("INFO: Plugin(%s): Executing command: %s", p, pInfo.ExecStart)
 		if err != nil {
 			chLog.Printf("ERROR: Plugin(%s): Failed to execute command, err=%s", p, err.Error())
 			updateGraph(getPluginType(p), p, dStatusFail, pluginLogFile)
 		} else {
-			chLog.Printf("INFO: Plugin(%s): Stdout & Stderr: %s", p, string(stdOutErr))
+			chLog.Printf("INFO: Plugin(%s): Stdout & Stderr: %v", p, stdOutErr)
 			updateGraph(getPluginType(p), p, dStatusOk, pluginLogFile)
 		}
 	}()
 
-	logger.Debug.Println("Stdout & Stderr:", string(stdOutErr))
-	pStatus := Plugin{StdOutErr: string(stdOutErr)}
+	logger.Debug.Println("Stdout & Stderr:", stdOutErr)
+	pStatus := Plugin{StdOutErr: stdOutErr}
 	if err != nil {
 		pStatus.Status = dStatusFail
 		logger.Error.Printf("Failed to execute plugin %s. err=%s\n", p, err.Error())
@@ -760,9 +788,20 @@ func RunFromJSONStrOrFile(result *RunStatus, jsonStrOrFile string, runOptions Ru
 		result.StdOutErr = err.Error()
 		return err
 	}
-	result.Plugins = pluginsInfo.Plugins
 	result.Type = pluginsInfo.Type
-
+	result.Library = pluginsInfo.Library
+	result.Plugins = pluginsInfo.Plugins
+	// INFO: Override values of json/file with explicitly passed cmdline parameter. Else, set runOptions type from json/file.
+	if runOptions.Type != "" {
+		result.Type = runOptions.Type
+	} else {
+		runOptions.Type = pluginsInfo.Type
+	}
+	if runOptions.Library != "" {
+		result.Library = runOptions.Library
+	} else {
+		runOptions.Library = pluginsInfo.Library
+	}
 	return run(result, runOptions)
 }
 
@@ -903,7 +942,7 @@ func ScanCommandOptions(options map[string]interface{}) error {
 		//  but only extensions (i.e., they get created as hidden files).
 		config.SetPMLogFile(tLogFile)
 		myLogFile += config.GetPMLogFile()
-		if myLogFile != config.DefaultLogPath {
+		if myLogFile != logger.DefaultLogPath {
 			myLogFile := filepath.Clean(myLogFile)
 			logger.Info.Println("Logging to specified log file:", myLogFile)
 			errList := logger.DeInitLogger()

plugin_test.go

@@ -527,7 +527,7 @@ func Test_executePlugins(t *testing.T) {
 			pluginInfo: Plugins{},
 			want: want{
 				returnStatus: true,
-				// psStatus:     Plugins{},
+				psStatus:     Plugins{},
 			},
 		},
 		{
@@ -602,16 +602,16 @@ func Test_executePlugins(t *testing.T) {
 		{
 			name: "Plugin with dependency",
 			pluginInfo: Plugins{
+				{
+					Name:        "A/a.test",
+					Description: "Applying \"A\" settings",
+					ExecStart:   `/bin/echo Running A...`,
+				},
 				{
 					Name:        "D/d.test",
 					Description: "Applying \"D\" settings",
 					Requires:    []string{"A/a.test"},
-					ExecStart:   `/bin/echo "Running D..."`,
-				},
-				{
-					Name:        "A/a.test",
-					Description: "Applying \"A\" settings",
-					ExecStart:   `/bin/echo "Running A..."`,
+					ExecStart:   `/bin/echo Running D...`,
 				},
 			},
 			want: want{
@@ -624,6 +624,7 @@ func Test_executePlugins(t *testing.T) {
 						RequiredBy:  []string{"D/d.test"},
 						Requires:    []string{},
 						Status:      "Succeeded",
+						StdOutErr:   []string{"Running A..."},
 					},
 					{
 						Description: "Applying \"D\" settings",
@@ -632,6 +633,7 @@ func Test_executePlugins(t *testing.T) {
 						RequiredBy:  []string{},
 						Requires:    []string{"A/a.test"},
 						Status:      "Succeeded",
+						StdOutErr:   []string{"Running D..."},
 					},
 				},
 			},
@@ -763,17 +765,16 @@ func Test_executePlugins(t *testing.T) {
 				returnStatus: false,
 				psStatus: Plugins{
 					{
-						Description: "Applying \"A\" settings",
 						Name:        "A/a.test",
+						Description: "Applying \"A\" settings",
 						ExecStart:   "exit 1",
-						RequiredBy:  []string{"D/d.test"},
 						Status:      "Failed",
 					},
 					{
+						Name:        "D/d.test",
 						Description: "Applying \"D\" settings",
-						Requires:    []string{"A/a.test"},
 						ExecStart:   "/bin/echo \"Running D...!\"",
-						Name:        "D/d.test",
+						Requires:    []string{"A/a.test"},
 						RequiredBy:  []string{},
 						Status:      "Skipped",
 					},
@@ -788,41 +789,28 @@ func Test_executePlugins(t *testing.T) {
 		for _, tt.sequential = range []bool{false, true} {
 			t.Run(tt.name+fmt.Sprintf("(sequential=%v)", tt.sequential),
 				func(t *testing.T) {
-					// result := tt.pluginInfo
 					res := executePlugins(&tt.pluginInfo, tt.sequential, map[string]string{})
 					// t.Logf("res: %+v, expected: %v", res, tt.want.returnStatus)
 					if res != tt.want.returnStatus {
 						t.Errorf("Return value: got %+v, want %+v",
 							res, tt.want.returnStatus)
 						return
 					}
-					// if len(result) != 0 {
-					t.Logf("result of all plugins: %+v", tt.pluginInfo)
+					// t.Logf("result of all plugins: %+v", tt.pluginInfo)
 					for i := range tt.pluginInfo {
-						// TODO: Currently even though the expected and
-						// 	obtained values are same, it's still failing.
-						// 	Explore more on why that's the case for below
-						// 	commented ones.
-						// if reflect.DeepEqual(result[i].Plugin,
-						// 	tt.want.psStatus[i].Plugin) == false {
-						// 	t.Errorf("Plugins Plugin: got %+v, want %+v",
-						// 		result[i].Plugin,
-						// 		tt.want.psStatus[i].Plugin)
-						// }
 						if reflect.DeepEqual(tt.pluginInfo[i].Status,
 							tt.want.psStatus[i].Status) == false {
 							t.Errorf("Plugins %s Status: got %+v, want %+v",
 								tt.pluginInfo[i].Name,
 								tt.pluginInfo[i].Status, tt.want.psStatus[i].Status)
 						}
-						// if tt.want.psStatus[i].StdOutErr != "" &&
-						// 	reflect.DeepEqual(result[i].StdOutErr,
-						// 		tt.want.psStatus[i].StdOutErr) == false {
-						// 	t.Errorf("Plugins StdOutErr: got %+v, want %+v",
-						// 		result[i].StdOutErr,
-						// 		tt.want.psStatus[i].StdOutErr)
-						// }
-						// }
+						if len(tt.want.psStatus[i].StdOutErr) != 0 &&
+							reflect.DeepEqual(tt.pluginInfo[i].StdOutErr,
+								tt.want.psStatus[i].StdOutErr) == false {
+							t.Errorf("Plugins StdOutErr: got %+v, want %+v",
+								tt.pluginInfo[i].StdOutErr,
+								tt.want.psStatus[i].StdOutErr)
+						}
 					}
 				},
 			)