diff --git a/.github/workflows/go.yml b/.github/workflows/go.yml index 7f4cef8..49ec4fe 100644 --- a/.github/workflows/go.yml +++ b/.github/workflows/go.yml @@ -19,7 +19,11 @@ jobs: go-version: 1.19 - name: Static analysis of code for errors - run: make analyze + env: + PM_LOG_DIR: ${{ github.workspace }}/test-logs + run: | + mkdir -p ${{ github.workspace }}/test-logs + make analyze # - name: Build # run: go build -v ./... @@ -30,10 +34,12 @@ jobs: - name: Test - go test env: PM_CONF_FILE: ${{ github.workspace }}/sample/pm.config.yaml + PM_LOG_DIR: ${{ github.workspace }}/test-logs INTEGRATION_TEST: START INTEG_TEST_BIN: ${{ github.workspace }} run: | mkdir -p ${{ github.workspace }}/cover + mkdir -p ${{ github.workspace }}/test-logs go test -mod=vendor -v ./... # - name: Test - make test diff --git a/Makefile b/Makefile index add296f..1247b23 100644 --- a/Makefile +++ b/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 @@ -14,7 +14,7 @@ GOSRC=$(TOP) # Set GOBIN to where binaries get picked up while creating RPM/ISO. GOBIN?=$(TOP)/bin -GOCOVER=$(GOSRC)/cover +GOCOVERDIR=$(GOSRC)/cover GOTOOLSBIN=$(TOP)/tools/go/ .SILENT: @@ -29,10 +29,9 @@ 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 $(GOCOVER); + -@rm -rf $(GOCOVERDIR); .PHONY: build build: ## Build source code @@ -75,24 +74,25 @@ govet: ## Run go vet .PHONY: test test: ## Run all tests echo "Running Plugin Manager Go Unit Tests..."; - mkdir -p $(GOCOVER); + mkdir -p $(GOCOVERDIR); + export GOCOVERDIR=$(GOCOVERDIR); \ export INTEG_TEST_BIN=$(GOSRC); \ export PM_CONF_FILE=$(GOSRC)/sample/pm.config.yaml; \ export INTEGRATION_TEST=START; \ cd $(GOSRC); \ test_failed=0; \ d=pm; \ - go test -mod=vendor -v --cover -covermode=count -coverprofile=$(GOCOVER)/$${d}.out ./... | \ + go test -mod=vendor -v --cover -covermode=count -coverprofile=$(GOCOVERDIR)/$${d}.out ./... | \ $(GOTOOLSBIN)/go-junit-report > TEST-$${d}.xml; \ ret=$${PIPESTATUS[0]}; \ if [ $${ret} -ne 0 ]; then \ echo "Go unit test failed for $${d}."; \ test_failed=1; \ fi ; \ - awk -f $(TOP)/tools/gocoverage-collate.awk $(GOCOVER)/* > $(GOCOVER)/cover.out; \ - go tool cover -html=$(GOCOVER)/cover.out -o go-coverage-$${d}.html; \ - $(GOTOOLSBIN)/gocov convert $(GOCOVER)/cover.out | $(GOTOOLSBIN)/gocov-xml > go-coverage-$${d}.xml; \ - rm -rf $(GOCOVER)/*; \ + awk -f $(TOP)/tools/gocoverage-collate.awk $(GOCOVERDIR)/* > $(GOCOVERDIR)/cover.out; \ + go tool cover -html=$(GOCOVERDIR)/cover.out -o go-coverage-$${d}.html; \ + $(GOTOOLSBIN)/gocov convert $(GOCOVERDIR)/cover.out | $(GOTOOLSBIN)/gocov-xml > go-coverage-$${d}.xml; \ + rm -rf $(GOCOVERDIR)/*; \ export INTEGRATION_TEST=DONE; \ if [ $${test_failed} -ne 0 ]; then \ echo "Go unit tests failed."; \ @@ -104,11 +104,21 @@ go-race: ## Run Go tests with race detector enabled echo "Checking Go code for race conditions..."; # NOTE: COVER directory should be present, along with INTEGRATION_TEST # value being set to "START" for integ_test.go to succeed. - mkdir -p $(GOCOVER); + mkdir -p $(GOCOVERDIR); + export GOCOVERDIR=$(GOCOVERDIR); \ export INTEGRATION_TEST=START; \ export INTEG_TEST_BIN=$(GOSRC); \ cd $(GOSRC); \ 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: diff --git a/README.md b/README.md index 93da094..c748482 100644 --- a/README.md +++ b/README.md @@ -16,7 +16,10 @@ systemd. - [Example: Plugin Manager (PM) `list`](#example-plugin-manager-pm-list) - [Configuring Plugin Manager](#configuring-plugin-manager) - [Running Plugins](#running-plugins) - - [Example: Plugin Manager (PM) `run`](#example-plugin-manager-pm-run) + - [Example: Plugin Manager (PM) `run -plugins`](#example-plugin-manager-pm-run--plugins) + - [Specify `-plugins` details as a json string](#specify--plugins-details-as-a-json-string) + - [Specify `-plugins` details via json file](#specify--plugins-details-via-json-file) + - [Example: Plugin Manager (PM) `run -type`](#example-plugin-manager-pm-run--type) - [Example: Plugin Manager (PM) with `sequential` flag](#example-plugin-manager-pm-with-sequential-flag) - [Example: Overriding Plugin Manager (PM) configuration - `library`, `log-dir` and `log-file`](#example-overriding-plugin-manager-pm-configuration---library-log-dir-and-log-file) - [Example: Writing plugins result to a `output-file` in `output-format` {json, yaml} format](#example-writing-plugins-result-to-a-output-file-in-output-format-json-yaml-format) @@ -87,6 +90,7 @@ The PM list command syntax / usage is as shown below: ```bash pm list -type [-library=] + [-log-tag=] [-log-dir=] [-log-file=] ``` @@ -96,6 +100,9 @@ where - **`type`**: Indicates the plugin type. - **`library`**: Indicates the location of plugins library. **Overrides** value present in PM configuration. +- **`log-tag`**: Indicates the log tag written by rsyslog. + Note: rsyslog is used as default logger for both main and plugin logs. + It will be overwritten if `log-file` option set. - **`log-dir`**: Indicates the log directory path. **Overrides** value present in PM configuration. - **`log-file`**: Indicates the name of the log file. @@ -113,7 +120,7 @@ The list of plugins are mapped in .//preupgrade.2020-01-13T15:56:46.725348-08:00 Plugin Manager can be configured to look for plugins at a specific location, and to write logs to a specific file by specifying those details in the -Plugin Manager configuration file `/etc/asum/pm.config.yml`. +Plugin Manager configuration file `/opt/veritas/appliance/asum/pm.config.yml`. Instead of updating the default config file, one can choose to provide his/her own custom config file. @@ -138,7 +145,7 @@ PluginManager: # The timestamp and '.log' extension would be appended to this name. # I.e., The format of the log file generated would be: "..log" # Example: The below value results in following log file: pm.2020-01-13T16:11:58.6006565-08:00.log - log file: "pm" + log file: "pm.log" ... ``` @@ -156,9 +163,11 @@ exit value of plugins, the PM exits with 1. The PM run command syntax / usage is as shown below: ```bash -pm run -type +pm run [-plugins ] + [-type ] [-library=] [-sequential[={true|1|false|0}]] + [-log-tag=] [-log-dir=] [-log-file=] [-output={json|yaml}] @@ -167,13 +176,16 @@ pm run -type where +- **`plugins`**: A json string or a json file containing plugins and its dependencies. - **`type`**: Indicates the plugin type. - **`library`**: Indicates the location of plugins library. **Overrides** value present in PM configuration. + **NOTE** The specified value gets set as an environment variable `PM_LIBRARY` for the plugins being run. The plugin file can access any scripts in the same folder via `PM_LIBRARY` variable. - **`-sequential`**: Indicates PM to execute only one plugin at a time regardless of how many plugins' dependencies are met. **Default: Disabled**. To enable, specify `-sequential=true` or just `-sequential` while running PM. +- **`log-tag`**: Indicates the log tag written by rsyslog. The `log-tag` option will supercede `log-dir` and `log-file` options. - **`log-dir`**: Indicates the log directory path. **Overrides** value present in PM configuration. - **`log-file`**: Indicates the name of the log file. @@ -185,7 +197,86 @@ where If `output` format is specified, and `output-file` is not specified, then result will be displayed on console. -### Example: Plugin Manager (PM) `run` +### Example: Plugin Manager (PM) `run -plugins` + +```json +$ jq -n "$plugins" | tee sample/plugins-prereboot.json +{ + "Plugins": [ + { + "Name": "A/a.prereboot", + "Description": "Applying \"A\" settings", + "ExecStart": "/usr/bin/ls -l -t", + "Requires": [ + "C/c.prereboot", + "D/d.prereboot" + ] + }, + { + "Name": "B/b.prereboot", + "Description": "Applying \"B\" settings...", + "ExecStart": "/bin/echo \"Running B...\"", + "RequiredBy": [ + "D/d.prereboot" + ] + }, + { + "Name": "C/c.prereboot", + "Description": "Applying \"C\" settings...", + "ExecStart": "/bin/echo \"Running C...\"", + "RequiredBy": [ + "A/a.prereboot" + ] + }, + { + "Name": "D/d.prereboot", + "Description": "Applying \"D\" settings...", + "ExecStart": "/bin/echo 'Running D...!'", + "RequiredBy": [ + "A/a.prereboot" + ], + "Requires": [ + "B/b.prereboot" + ] + } + ] +} +$ +``` + +#### Specify `-plugins` details as a json string + +```bash +$ $GOBIN/pm run -plugins "$plugins" +Applying "B" settings...: Starting +Applying "C" settings...: Starting +Applying "B" settings...: Succeeded +Applying "D" settings...: Starting +Applying "C" settings...: Succeeded +Applying "D" settings...: Succeeded +Applying "A" settings: Starting +Applying "A" settings: Succeeded +Running plugins: Succeeded +bash-5.1$ +``` + +#### Specify `-plugins` details via json file + +```bash +$ $GOBIN/pm run -plugins "./sample/plugins-prereboot.json" -library sample/library/ +Applying "C" settings...: Starting +Applying "B" settings...: Starting +Applying "C" settings...: Succeeded +Applying "B" settings...: Succeeded +Applying "D" settings...: Starting +Applying "D" settings...: Succeeded +Applying "A" settings: Starting +Applying "A" settings: Succeeded +Running plugins: Succeeded +$ +``` + +### Example: Plugin Manager (PM) `run -type` ```bash $ $GOBIN/pm run -type=prereboot @@ -253,7 +344,7 @@ $ ```bash $ $GOBIN/pm run -type preupgrade -output-format=json -output-file=a.json -library ./sample/library/ -Log: /log/asum/pm.2021-01-29T17:46:57.6904918-08:00.log +Log: /var/log/asum/pm.2021-01-29T17:46:57.6904918-08:00.log Checking for "D" settings...: Starting Checking for "D" settings...: Succeeded @@ -271,7 +362,7 @@ $ cat a.json "Plugins": [ { "Description": "Checking for \"D\" settings...", - "FileName": "D/d.preupgrade", + "Name": "D/d.preupgrade", "ExecStart": "$PM_LIBRARY/D/preupgrade.sh", "RequiredBy": [ "A/a.preupgrade" @@ -282,7 +373,7 @@ $ cat a.json }, { "Description": "Checking for \"A\" settings", - "FileName": "A/a.preupgrade", + "Name": "A/a.preupgrade", "ExecStart": "/bin/echo \"Checking A...\"", "RequiredBy": null, "Requires": [ @@ -299,7 +390,7 @@ $ cat a.json ```bash $ $GOBIN/pm run -type preupgrade -output-format=yaml -output-file=a.yaml -library ./sample/library/ -Log: /log/asum/pm.2021-01-29T17:53:15.8128937-08:00.log +Log: /var/log/asum/pm.2021-01-29T17:53:15.8128937-08:00.log Checking for "D" settings...: Starting Checking for "D" settings...: Failed @@ -308,19 +399,49 @@ $ ``` ```yaml -$ cat a.yaml -type: preupgrade +# cat a.yaml +name: preupgrade +description: "" +requiredby: [] +requires: [] +execstart: "" plugins: -- description: Checking for "D" settings... - filename: D/d.preupgrade - execstart: $PM_LIBRARY/D/preupgrade.sh - requiredby: - - A/a.preupgrade - requires: [] - status: Failed - stdouterr: "Running preupgrade.sh (path: sample/library//D/preupgrade.sh) with - status(1)...\nDisplaying Plugin Manager (PM) Config file path: \nFail(1)\n" + - name: A/a.preupgrade + description: Checking for "A" settings + requiredby: [] + requires: + - D/d.preupgrade + execstart: /bin/echo "Checking A..." + plugins: [] + library: "" + runtime: + starttime: 2024-10-28T18:21:17.289968946-05:00 + endtime: 2024-10-28T18:21:17.337773824-05:00 + duration: 47.804888ms + status: Skipped + stdouterr: [] + - name: D/d.preupgrade + description: Checking for "D" settings... + requiredby: [] + requires: [] + execstart: $PM_LIBRARY/D/preupgrade.sh + plugins: [] + library: "" + runtime: + starttime: 2024-10-28T18:21:17.220368224-05:00 + endtime: 2024-10-28T18:21:17.289945583-05:00 + duration: 69.577293ms + status: Failed + stdouterr: + - 'Running preupgrade.sh (path: sample/library//D/preupgrade.sh) with status(1)...' + - 'Displaying Plugin Manager (PM) Config file path: ' + - Fail(1) +library: "" +runtime: + starttime: 2024-10-28T18:21:17.185365352-05:00 + endtime: 2024-10-28T18:21:17.337805574-05:00 + duration: 152.440222ms status: Failed -stdouterr: 'Running preupgrade plugins: Failed' -$ +stdouterr: + - 'Running preupgrade plugins: Failed' ``` diff --git a/bin/pm.py b/bin/pm.py new file mode 100755 index 0000000..1572cde --- /dev/null +++ b/bin/pm.py @@ -0,0 +1,129 @@ +# Copyright (c) 2024 Veritas Technologies LLC. All rights reserved. IP63-2828-7171-04-15-9 + +# A python library for invoking Plugin Manager (PM) to run plugins in parallel while specifying dependencies between plugins. + +import json +import logging +import os +import sys +import subprocess +import tempfile +import traceback +from pathlib import Path + + +DEFAULT_PM_PATH = "/opt/veritas/appliance/asum/bin/pm" + +logger = logging.getLogger() + + +def get_pm_path(): + """ + get_pm_path returns Plugin Manager binary path based on: + + 1. Returns PM path in current directory if present. + This enables upgrade RPMs that bundle latest PM to use it. + 2. Returns default PM path if present in default path. + 3. Return "" when it cannot be found in current dir or default dir. + """ + pm_path = os.path.dirname(os.path.abspath(__file__)) + "/pm" + if os.path.exists(pm_path): + return pm_path + if os.path.exists(DEFAULT_PM_PATH): + return DEFAULT_PM_PATH + return "" + + +def run(plugins=None, + type=None, + library=os.path.dirname(os.path.abspath(__file__)), + display_stdout=True, + log_file=None, + output_format="json", + output_file=None + ): + """ + Run commands in parallel depending on the order specified. + Returns 0 on success, and 1 on failure + + "plugins" A map of plugins containing their description, command and any dependencies information. + Format: {"plugin-name": {"Description": "Description of plugin", "ExecStart": "command to run", + "Requires": "List of space separated plugins to be run before current one", "RequiredBy": "List of plugins that want current plugin to be run before them."}} + "display_stdout" Display Plugin Manager output. + Set to 'False' when you do not want output to be displayed on console and just want results to be returned. + """ + logger.debug( + f"Entering run(plugins={plugins}, type={type}, library={library}, display_stdout={display_stdout}, log_file={log_file}, output_format={output_format}, output_file={output_file})...") + + pm_path = get_pm_path() + logger.debug(f"PM binary path: {pm_path}") + if pm_path == "": + err_msg = f"Failed to find plugin manager 'pm' binary. Install VRTSvxos-asum*.rpm and then try again." + logger.error(err_msg) + return 1, "" + + cmd = [pm_path, "run"] + if plugins != None: + cmd = cmd + ["-plugins", str(plugins)] + if type != None: + cmd = cmd + ["-type", type] + if library != None: + cmd = cmd + ["-library", library] + log_dir = None + if log_file != None: + log_dir = os.path.dirname(log_file) + cmd = cmd + ["-log-dir", log_dir, + "-log-file", os.path.basename(log_file)] + if output_format == None: + output_format = "json" + if output_file == None: + prefix = "" + if type != None: + prefix = type+"-" + tmp_dir = "/tmp" + if log_dir != None: + tmp_dir = log_dir + # INFO: tmp dir needs to exist for mkstemp to work, so create if it + # doesn't exist. + if not os.path.exists(tmp_dir): + os.makedirs(tmp_dir, exist_ok=True) + _, output_file = tempfile.mkstemp( + dir=tmp_dir, prefix=prefix, suffix="."+output_format) + logger.debug("File name: %s", output_file) + cmd = cmd + ["-output-format", output_format, + "-output-file", output_file] + logger.debug("COMMAND: %s", ' '.join(cmd)) + + popen_options = {} + if display_stdout == False: + output_file_no_ext = Path(output_file).with_suffix("").as_posix() + output_file = output_file_no_ext+"."+output_format + popen_options["stdout"] = open( + output_file_no_ext+"_pm_stdout.log", mode="w+") + popen_options["stderr"] = open( + output_file_no_ext+"_pm_stderr.log", mode="w+") + logger.debug(f"subprocess.Popen() options: {popen_options}") + process = subprocess.Popen(cmd, **popen_options) + process.wait() # Wait for the subprocess to finish + logger.debug(f"CMD output: {process}") + if process.returncode != 0: + logger.debug( + f"COMMAND: {' '.join(cmd)} exited with status: {process.returncode}") + # INFO: Do not return here because of non-zero exit!!! + # Plugin Manager (PM) would return non-zero in case if any of the + # plugins fail. But, we still want to send those failures back to + # caller, so continue down below... + + pluginsStatus = "" + # For now, supporting only 'json'. "Maybe" support 'yaml' in future when required! + if output_format == "json": + try: + with open(output_file, 'r') as json_fp: + pluginsStatus = json.load(json_fp) + except Exception as e: + logger.error( + f"Failed to load data from json file {output_file}.") + logger.debug(f"Error: {str(e)}") + logger.debug(traceback.format_exc()) + + return process.returncode, pluginsStatus diff --git a/cmd/pm/integ_test.go b/cmd/pm/integ_test.go index 2e2ae98..7537dd2 100644 --- a/cmd/pm/integ_test.go +++ b/cmd/pm/integ_test.go @@ -1,11 +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 package main import ( "fmt" "io/ioutil" - "log" "os" "os/exec" "path/filepath" @@ -15,6 +14,8 @@ import ( "testing" "github.com/VeritasOS/plugin-manager/config" + "github.com/VeritasOS/plugin-manager/types/status" + logger "github.com/VeritasOS/plugin-manager/utils/log" yaml "gopkg.in/yaml.v3" ) @@ -27,40 +28,30 @@ type Config struct { Library string `yaml:"library"` LogDir string `yaml:"log dir"` LogFile string `yaml:"log file"` - // PluginDir is deprecated. Use Library instead. - PluginDir string `yaml:"plugin dir"` } } -// Status of plugin execution used for displaying to user on console. -const ( - dStatusFail = "Failed" - dStatusOk = "Succeeded" - dStatusSkip = "Skipped" - dStatusStart = "Starting" -) - func saveConfig(newConfig Config, configFile string) error { - log.Println("Entering saveConfig") - defer log.Println("Exiting saveConfig") + logger.Info.Println("Entering saveConfig") + defer logger.Info.Println("Exiting saveConfig") - log.Printf("config file: %s\n", configFile) + logger.Info.Printf("config file: %s", configFile) out, err := yaml.Marshal(newConfig) if err != nil { - log.Printf("Failed to marshal plugin config: %+v\n", newConfig) + logger.Error.Printf("Failed to marshal plugin config: %+v, err=%v", newConfig, err) return err } ioutil.WriteFile(configFile, out, os.FileMode(0644)) if err != nil { - log.Printf("Failed to write %s file\n", configFile) + logger.Error.Printf("Failed to write %s file, err=%v", configFile, err) return err } return nil } func setIntegrationEnvironment(topPath string) string { - log.Println("Entering setIntegrationEnvironment") - defer log.Println("Exiting setIntegrationEnvironment") + logger.Info.Println("Entering setIntegrationEnvironment") + defer logger.Info.Println("Exiting setIntegrationEnvironment") configFile := filepath.FromSlash(topPath + "/pm.config-integ.yaml") @@ -75,26 +66,6 @@ func setIntegrationEnvironment(topPath string) string { return configFile } -// setDeprecatedIntegrationEnvironment() sets the values that are now deprecated and tests to make sure that -// there are no regressions until they are removed. -// TODO: Delete this once PluginDir support is removed. -func setDeprecatedIntegrationEnvironment(topPath string) string { - log.Println("Entering setIntegrationEnvironment") - defer log.Println("Exiting setIntegrationEnvironment") - - configFile := filepath.FromSlash(topPath + "/pm.config-integ.yaml") - - var newConfig Config - newConfig.PluginManager.LogDir = filepath.FromSlash(topPath) - newConfig.PluginManager.LogFile = "pm-integ" - newConfig.PluginManager.PluginDir = filepath.FromSlash(topPath + "/sample/library") - - saveConfig(newConfig, configFile) - os.Setenv(config.EnvConfFile, configFile) - - return configFile -} - // REFERENCE: https://www.cyphar.com/blog/post/20170412-golang-integration-coverage func TestIntegration(t *testing.T) { var ( @@ -141,17 +112,13 @@ func TestIntegration(t *testing.T) { defer os.Remove(configFile) defer os.Setenv(config.EnvConfFile, oriConfigFile) - integTest(t, pmBinary, tDir, "") - - // setIntegrationEnvironment() for deprecated scenario - setDeprecatedIntegrationEnvironment(tDir) - integTest(t, pmBinary, tDir, " deprecated") + integTest(t, pmBinary, tDir) os.Setenv("INTEGRATION_TEST", "DONE") os.Remove(pmBinary) } -func integTest(t *testing.T, pmBinary, tDir, deprecated string) { +func integTest(t *testing.T, pmBinary, tDir string) { type args struct { pluginType string sequential bool @@ -170,13 +137,11 @@ func integTest(t *testing.T, pmBinary, tDir, deprecated string) { pluginType: "preupgrade", }, want: []string{ - "", - "Checking for \"D\" settings...: " + dStatusStart, - "Checking for \"D\" settings...: " + dStatusOk, - "", - "Checking for \"A\" settings: " + dStatusStart, - "Checking for \"A\" settings: " + dStatusOk, - "Running preupgrade plugins: " + dStatusOk, + "Checking for \"D\" settings...: " + status.Start, + "Checking for \"D\" settings...: " + status.Ok, + "Checking for \"A\" settings: " + status.Start, + "Checking for \"A\" settings: " + status.Ok, + "Running preupgrade plugins: " + status.Ok, }, wantErr: false, }, @@ -187,13 +152,11 @@ func integTest(t *testing.T, pmBinary, tDir, deprecated string) { testPluginExitStatus: 1, }, want: []string{ - "", - "Checking for \"D\" settings...: " + dStatusStart, - "Checking for \"D\" settings...: " + dStatusFail, - "", - "Checking for \"A\" settings: " + dStatusStart, - "Checking for \"A\" settings: " + dStatusSkip, - "Running preupgrade plugins: " + dStatusFail, + "Checking for \"D\" settings...: " + status.Start, + "Checking for \"D\" settings...: " + status.Fail, + "Checking for \"A\" settings: " + status.Start, + "Checking for \"A\" settings: " + status.Skip, + "Running preupgrade plugins: " + status.Fail, "", }, wantErr: true, @@ -202,7 +165,7 @@ func integTest(t *testing.T, pmBinary, tDir, deprecated string) { for _, tc := range tests { for _, tc.args.sequential = range []bool{false, true} { - t.Run(tc.name+fmt.Sprintf("(sequential=%v)", tc.args.sequential)+fmt.Sprintf("%v", deprecated), func(t *testing.T) { + t.Run(tc.name+fmt.Sprintf("(sequential=%v)", tc.args.sequential), func(t *testing.T) { cmdStr := pmBinary tmpfile, err := ioutil.TempFile(tDir+"/cover/", "cover.out") if err != nil { @@ -215,6 +178,7 @@ func integTest(t *testing.T, pmBinary, tDir, deprecated string) { cmdParams = append(cmdParams, "run") cmdParams = append(cmdParams, "-type") cmdParams = append(cmdParams, tc.args.pluginType) + // cmdParams = append(cmdParams, "-log-file=integ_test.log") } // TODO: Update test cases & output to handle sequential execution. cmdParams = append(cmdParams, "-sequential="+strconv.FormatBool(tc.args.sequential)) @@ -250,9 +214,16 @@ func integTest(t *testing.T, pmBinary, tDir, deprecated string) { cmdStr, cmdParams, err, tc.wantErr) } if !reflect.DeepEqual(got, tc.want) { - t.Errorf("got %v, want %v", got, tc.want) + if len(got) != len(tc.want) { + t.Errorf("\ngot(%d): %v, \nwant(%d) %v", len(got), got, len(tc.want), tc.want) + } else { + for i := range got { + if strings.Compare(got[i], tc.want[i]) != 0 { + t.Errorf("Comparing line %d not the same: \ngot : %s, \nwant: %s", i, got[i], tc.want[i]) + } + } + } } - }) } } diff --git a/cmd/pm/pm.go b/cmd/pm/pm.go index c976a4c..105f970 100644 --- a/cmd/pm/pm.go +++ b/cmd/pm/pm.go @@ -1,23 +1,23 @@ -// Copyright (c) 2021 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 // Package main provides a commandline tool interface for interacting with // Plugin Manager (PM). package main import ( - "log" "os" "path/filepath" + logger "github.com/VeritasOS/plugin-manager/utils/log" + pm "github.com/VeritasOS/plugin-manager" "github.com/VeritasOS/plugin-manager/config" - logutil "github.com/VeritasOS/plugin-manager/utils/log" ) 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]) ) @@ -26,42 +26,22 @@ func init() { // EnvConfFile is environment variable containing PluginManager config file path. config.EnvConfFile = "PM_CONF_FILE" // DefaultConfigPath is default path for config file used when EnvConfFile is not set. - config.DefaultConfigPath = "/etc/pm.config.yaml" - // DefaultLogPath is default path for log file. - config.DefaultLogPath = "./" - - // INFO: Use DefaultLogPath when it's available (until the config file is read). - // If not, use basename of file. - // NOTE: while running tests, the path of binary would be in `/tmp/`, - // 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). - myLogFile := config.DefaultLogPath - if _, err := os.Stat(filepath.Dir(myLogFile)); os.IsNotExist(err) { - myLogFile = progname - } - logutil.SetLogging(myLogFile) + config.DefaultConfigPath = "/opt/veritas/appliance/asum/pm.config.yaml" + logger.InitLogging() } func main() { - log.Println("Entering main::main with", os.Args[:]) - defer log.Println("Exiting main::main") + logger.Debug.Println("Entering main::main with", os.Args[:]) + defer logger.Debug.Println("Exiting main::main") cmd := os.Args[1] if cmd == "version" { - logutil.PrintNLog("%s version %s %s\n", - progname, version, buildDate) + logger.ConsoleInfo.Printf("%s version %s %s", progname, version, buildDate) os.Exit(0) } if err := config.Load(); err != nil { - logutil.PrintNLogWarning("Failed to load config file. Using default values " + - "and proceeding with the operation") - } - if config.GetPMLogDir() != "" && config.GetPMLogFile() != "" { - myLogFile := config.GetPMLogDir() + config.GetPMLogFile() - if myLogFile != config.DefaultLogPath { - logutil.SetLogging(myLogFile) - } + logger.ConsoleWarning.Printf("Failed to load config file. Using default values and proceeding with the operation") } pm.RegisterCommandOptions(progname) diff --git a/config/config.go b/config/config.go index 53aa40c..80fd202 100644 --- a/config/config.go +++ b/config/config.go @@ -1,16 +1,15 @@ -// 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 package config import ( "io/ioutil" - "log" "os" "path/filepath" + "strings" + logger "github.com/VeritasOS/plugin-manager/utils/log" "gopkg.in/yaml.v3" - - logutil "github.com/VeritasOS/plugin-manager/utils/log" ) // Config is Plugin Manager's configuration information. @@ -18,11 +17,10 @@ type Config struct { // PluginManager configuration information. PluginManager struct { // Library is the path where plugin directories containing plugin files are present. - Library string `yaml:"library"` - LogDir string `yaml:"log dir"` - LogFile string `yaml:"log file"` - // PluginDir is deprecated. Use Library instead. - PluginDir string `yaml:"plugin dir"` + Library string `yaml:"library"` + LogDir string `yaml:"log dir"` + LogFile string `yaml:"log file"` + LogLevel string `yaml:"log level"` } } @@ -33,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. @@ -52,20 +48,17 @@ func GetLogFile() string { return myConfig.PluginManager.LogFile } +// GetLogLevel provides name of loglevel. +func GetLogLevel() string { + return myConfig.PluginManager.LogLevel +} + // GetPluginsLibrary gets location of plugins library. func GetPluginsLibrary() string { return filepath.FromSlash(filepath.Clean(myConfig.PluginManager.Library) + string(os.PathSeparator)) } -// GetPluginsDir gets location of plugins directory. -// -// NOTE: This is deprecated, Use GetPluginsLibrary() instead. -func GetPluginsDir() string { - return filepath.FromSlash(filepath.Clean(myConfig.PluginManager.PluginDir) + - string(os.PathSeparator)) -} - // GetPMLogDir provides location for storing Plugin Manager logs. // // NOTE: The plugin logs would be stored "plugins" directory under the @@ -87,53 +80,51 @@ func GetPluginsLogDir() string { // Load config information func Load() error { - log.Println("Entering config.Load()") - defer log.Println("Exiting config.Load()") + logger.Debug.Println("Entering config.Load()") + defer logger.Debug.Println("Exiting config.Load()") myConfigFile := os.Getenv(EnvConfFile) if myConfigFile == "" { - log.Printf("%s env is not set. Using default config file.\n", - EnvConfFile) + logger.Info.Printf("%s env is not set. Using default config file.", EnvConfFile) myConfigFile = DefaultConfigPath } myConfigFile = filepath.FromSlash(myConfigFile) - log.Printf("config file: %s\n", myConfigFile) + logger.Debug.Printf("config file: %s", myConfigFile) var err error myConfig, err = readConfigFile(myConfigFile) - - // INFO: Library replaces PluginDir. - // Keeping PluginDir for backward compatibility for couple of releases. - // (Currently Px is 1.x, and we can keep say until Px 3.x). - // If older versions of PM is out there, then PluginDir value will be read from config file, - // and assigned to Library variable. - log.Printf("Plugin Manager Config: %+v", myConfig) - if myConfig.PluginManager.Library == "" && - myConfig.PluginManager.PluginDir != "" { - myConfig.PluginManager.Library = myConfig.PluginManager.PluginDir + // Set default values when it's not specified in config file. + if myConfig.PluginManager.LogDir == "" { + myConfig.PluginManager.LogDir = logger.DefaultLogDir } - + if myConfig.PluginManager.LogFile == "" { + myConfig.PluginManager.LogFile = logger.DefaultLogFile + } + if myConfig.PluginManager.LogLevel == "" { + myConfig.PluginManager.LogLevel = logger.DefaultLogLevel + } + logger.Debug.Printf("Plugin Manager Config: %+v", myConfig) return err } func readConfigFile(confFilePath string) (Config, error) { - log.Printf("Entering readConfigFile(%s)", confFilePath) - defer log.Println("Exiting readConfigFile") + logger.Debug.Printf("Entering readConfigFile(%s)", confFilePath) + defer logger.Debug.Println("Exiting readConfigFile") var conf Config bFileContents, err := ioutil.ReadFile(confFilePath) if err != nil { - return conf, logutil.PrintNLogWarning("Failed to read \"" + + return conf, logger.ConsoleError.PrintNReturnError("Failed to read \"" + confFilePath + "\" file.") } err = yaml.Unmarshal(bFileContents, &conf) if err != nil { - log.Printf("yaml.Unmarshal(%s, %s); Error: %s", + logger.Error.Printf("Failed to call yaml.Unmarshal(%s, %s); err=%s", bFileContents, &conf, err.Error()) - return conf, logutil.PrintNLogError("Failed to parse %s config file.", confFilePath) + return conf, logger.ConsoleError.PrintNReturnError("Failed to parse %s config file.", confFilePath) } - log.Printf("Config: %+v\n", conf) + logger.Debug.Printf("Config: %+v", conf) return conf, nil } @@ -160,22 +151,23 @@ func SetLogFile(logFile string) { myConfig.PluginManager.LogFile = logFile } +// SetLogLevel sets the log level. +func SetLogLevel(logLevel string) { + myConfig.PluginManager.LogLevel = logLevel +} + // SetPluginsLibrary sets the plugins library location. func SetPluginsLibrary(library string) { myConfig.PluginManager.Library = filepath.FromSlash( filepath.Clean(library) + string(os.PathSeparator)) } -// SetPluginsDir sets location of plugins directory. -// -// NOTE: This is deprecated, Use SetPluginsLibrary() instead. -func SetPluginsDir(library string) { - myConfig.PluginManager.PluginDir = filepath.FromSlash(filepath.Clean(library) + - string(os.PathSeparator)) -} - // SetPMLogFile sets the file for storing Plugin Manager logs. func SetPMLogFile(logfile string) { + // add .log suffix if it doesn't exist. + if !strings.HasSuffix(logfile, ".log") { + logfile += ".log" + } myConfig.PluginManager.LogFile = logfile } diff --git a/config/config_test.go b/config/config_test.go index 58258e2..a894291 100644 --- a/config/config_test.go +++ b/config/config_test.go @@ -1,13 +1,37 @@ -// Copyright (c) 2021 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 package config import ( + "fmt" "os" "reflect" "testing" + + logger "github.com/VeritasOS/plugin-manager/utils/log" ) +func initTestLogging() { + myLogFile := "pm.log" + if GetPMLogFile() != "" { + myLogFile = GetPMLogFile() + } + if GetPMLogDir() != "" { + myLogFile = GetPMLogDir() + myLogFile + } + errList := logger.DeInitLogger() + if len(errList) > 0 { + fmt.Printf("Failed to deinitialize logger, err=[%v]", errList) + os.Exit(-1) + } + err := logger.InitFileLogger(myLogFile, "INFO") + if err != nil { + fmt.Printf("Failed to initialize logger, err=[%v]", err) + os.Exit(-1) + } +} + func init() { + initTestLogging() // EnvConfFile is environment variable containing config file path. // NOTE: "PM_CONF_FILE" value would be set in Makefile. EnvConfFile = "PM_CONF_FILE" @@ -28,10 +52,9 @@ func Test_Load(t *testing.T) { EnvConfFile string } type PluginManager struct { - Library string `yaml:"library"` - LogDir string `yaml:"log dir"` - LogFile string `yaml:"log file"` - PluginDir string `yaml:"plugin dir"` + Library string `yaml:"library"` + LogDir string `yaml:"log dir"` + LogFile string `yaml:"log file"` } tests := []struct { name string @@ -44,10 +67,16 @@ func Test_Load(t *testing.T) { EnvConfFile: "../sample/pm.config.yaml", }, want: Config{ - PluginManager{ - Library: "../sample/library", - LogDir: "./", - LogFile: "pm", + PluginManager: struct { + Library string "yaml:\"library\"" + LogDir string "yaml:\"log dir\"" + LogFile string "yaml:\"log file\"" + LogLevel string "yaml:\"log level\"" + }{ + Library: "../sample/library", + LogDir: "./", + LogFile: "pm", + LogLevel: "DEBUG", }, }, }, @@ -56,9 +85,21 @@ func Test_Load(t *testing.T) { args: args{ EnvConfFile: "non-existing/pm.config.yaml", }, - want: Config{}, + want: Config{ + PluginManager: struct { + Library string "yaml:\"library\"" + LogDir string "yaml:\"log dir\"" + LogFile string "yaml:\"log file\"" + LogLevel string "yaml:\"log level\"" + }{ + LogDir: logger.DefaultLogDir, + LogFile: logger.DefaultLogFile, + LogLevel: logger.DefaultLogLevel, + }, + }, }, } + for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { if err := os.Setenv(EnvConfFile, tt.args.EnvConfFile); nil != err { @@ -102,10 +143,16 @@ func Test_readConfigFile(t *testing.T) { confFilePath: "../sample/pm.config.yaml", }, want: Config{ - PluginManager{ - Library: "../sample/library", - LogDir: "./", - LogFile: "pm", + PluginManager: struct { + Library string "yaml:\"library\"" + LogDir string "yaml:\"log dir\"" + LogFile string "yaml:\"log file\"" + LogLevel string "yaml:\"log level\"" + }{ + Library: "../sample/library", + LogDir: "./", + LogFile: "pm", + LogLevel: "DEBUG", }, }, wantErr: false, @@ -116,7 +163,12 @@ func Test_readConfigFile(t *testing.T) { confFilePath: "non-existing-dir/pm.config.yaml", }, want: Config{ - PluginManager{}, + PluginManager: struct { + Library string "yaml:\"library\"" + LogDir string "yaml:\"log dir\"" + LogFile string "yaml:\"log file\"" + LogLevel string "yaml:\"log level\"" + }{}, }, wantErr: true, }, @@ -126,7 +178,12 @@ func Test_readConfigFile(t *testing.T) { confFilePath: "../../sample/library/D/preupgrade.sh", }, want: Config{ - PluginManager{}, + PluginManager: struct { + Library string "yaml:\"library\"" + LogDir string "yaml:\"log dir\"" + LogFile string "yaml:\"log file\"" + LogLevel string "yaml:\"log level\"" + }{}, }, wantErr: true, }, diff --git a/etc/rsyslog.d/10-vxos-asum.conf b/etc/rsyslog.d/10-vxos-asum.conf new file mode 100644 index 0000000..38a02ac --- /dev/null +++ b/etc/rsyslog.d/10-vxos-asum.conf @@ -0,0 +1,4 @@ +$umask 0022 +:programname, isequal, "vxos-asum@ansible" /var/log/asum/ansible.log +:programname, startswith, "vxos-asum@asum-" /var/log/asum/asum.log +:programname, startswith, "vxos-asum@pm-" /var/log/asum/pm.log diff --git a/graph.go b/graph/graph.go similarity index 62% rename from graph.go rename to graph/graph.go index 6712478..ca4e1dc 100644 --- a/graph.go +++ b/graph/graph.go @@ -1,19 +1,20 @@ -// 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 -// Package pm graph is used for generating the graph image. -package pm +// Package graph is used for generating the graph image. +package graph import ( - "log" "os" "path/filepath" - "sort" "strconv" "strings" "sync" "time" "github.com/VeritasOS/plugin-manager/config" + "github.com/VeritasOS/plugin-manager/types" + "github.com/VeritasOS/plugin-manager/types/status" + logger "github.com/VeritasOS/plugin-manager/utils/log" osutils "github.com/VeritasOS/plugin-manager/utils/os" ) @@ -32,73 +33,74 @@ type graph struct { var g graph var dotCmdPresent = true -func initGraphConfig(imgNamePrefix string) { +// Plugin is of type types.Plugin +type Plugin = types.Plugin + +// Plugins is of type types.Plugins +type Plugins = types.Plugins + +// InitGraphConfig initliazes output file names. +func InitGraphConfig(imgNamePrefix string) { // Initialization should be done only once. if g.fileNoExt == "" { + // Remove imgNamePrefix if it's end with ".log" + imgNamePrefix = strings.TrimSuffix(imgNamePrefix, ".log") g.fileNoExt = imgNamePrefix + "." + time.Now().Format(time.RFC3339Nano) } } -func getImagePath() string { +// GetImagePath gets the path of the image file. +func GetImagePath() string { return config.GetPMLogDir() + g.fileNoExt + ".svg" } -func getDotFilePath() string { +// GetDotFilePath gets the path of the dot file. +func GetDotFilePath() string { return config.GetPMLogDir() + g.fileNoExt + ".dot" } -// initGraph initliazes the graph data structure and invokes generateGraph. -func initGraph(pluginType string, pluginsInfo map[string]*PluginAttributes) error { - initGraphConfig(config.GetPMLogFile()) +// InitGraph initliazes the graph data structure and invokes generateGraph. +func InitGraph(pluginType string, pluginsInfo Plugins) error { + InitGraphConfig(config.GetPMLogFile()) // DOT guide: https://graphviz.gitlab.io/_pages/pdf/dotguide.pdf - // INFO: Sort the plugins so that list of dependencies generated - // (used by documentation) doesn't change. - // NOTE: If not sorted, then even without addition of any new plugin, - // the dependency file generated will keep changing and appears in - // git staged list. - orderedPluginsList := []string{} - for p := range pluginsInfo { - orderedPluginsList = append(orderedPluginsList, p) - } - sort.Strings(orderedPluginsList) - for _, p := range orderedPluginsList { - pFileString := "\"" + p + "\"" + for pIdx, p := range pluginsInfo { + pFileString := "\"" + p.Name + "\"" absLogPath, _ := filepath.Abs(config.GetPMLogDir()) absLibraryPath, _ := filepath.Abs(config.GetPluginsLibrary()) relPath, _ := filepath.Rel(absLogPath, absLibraryPath) - pURL := "\"" + filepath.FromSlash(relPath+string(os.PathSeparator)+p) + "\"" + pURL := "\"" + filepath.FromSlash(relPath+string(os.PathSeparator)+p.Name) + "\"" rows := []string{} rowsInterface, ok := g.subgraph.Load(pluginType) if ok { rows = rowsInterface.([]string) } rows = append(rows, pFileString+" [label=\""+ - strings.Replace(pluginsInfo[p].Description, "\"", `\"`, -1)+ + strings.Replace(pluginsInfo[pIdx].Description, "\"", `\"`, -1)+ "\",style=filled,fillcolor=lightgrey,URL="+pURL+"]") - rows = append(rows, "\""+p+"\"") - rbyLen := len(pluginsInfo[p].RequiredBy) + rows = append(rows, "\""+p.Name+"\"") + rbyLen := len(pluginsInfo[pIdx].RequiredBy) if rbyLen != 0 { - graphRow := "\"" + p + "\" -> " - for rby := range pluginsInfo[p].RequiredBy { - graphRow += "\"" + pluginsInfo[p].RequiredBy[rby] + "\"" + graphRow := "\"" + p.Name + "\" -> " + for rby := range pluginsInfo[pIdx].RequiredBy { + graphRow += "\"" + pluginsInfo[pIdx].RequiredBy[rby] + "\"" if rby != rbyLen-1 { graphRow += ", " } } rows = append(rows, graphRow) } - rsLen := len(pluginsInfo[p].Requires) + rsLen := len(pluginsInfo[pIdx].Requires) if rsLen != 0 { graphRow := "" - for rs := range pluginsInfo[p].Requires { - graphRow += "\"" + pluginsInfo[p].Requires[rs] + "\"" + for rs := range pluginsInfo[pIdx].Requires { + graphRow += "\"" + pluginsInfo[pIdx].Requires[rs] + "\"" if rs != rsLen-1 { graphRow += ", " } } - graphRow += " -> \"" + p + "\"" + graphRow += " -> \"" + p.Name + "\"" rows = append(rows, graphRow) } g.subgraph.Store(pluginType, rows) @@ -110,14 +112,13 @@ func initGraph(pluginType string, pluginsInfo map[string]*PluginAttributes) erro // generateGraph generates an input `.dot` file based on the fileNoExt name, // and then generates an `.svg` image output file as fileNoExt.svg. func generateGraph() error { - dotFile := getDotFilePath() - svgFile := getImagePath() + dotFile := GetDotFilePath() + svgFile := GetImagePath() fhDigraph, openerr := osutils.OsOpenFile(dotFile, os.O_RDWR|os.O_CREATE|os.O_TRUNC, 0666) if openerr != nil { abspath, _ := filepath.Abs(dotFile) - log.Printf("OsOpenFile(%s) Abs path: %v, Error: %s", - dotFile, abspath, openerr.Error()) + logger.Error.Printf("OsOpenFile(%s) Abs path: %v, err=%s", dotFile, abspath, openerr.Error()) return openerr } defer fhDigraph.Close() @@ -135,7 +136,7 @@ func generateGraph() error { _, writeerr := fhDigraph.WriteString(graphContent) if writeerr != nil { - log.Printf("fhDigraph.WriteString(%s) Err: %s", graphContent, writeerr.Error()) + logger.Error.Printf("fhDigraph.WriteString(%s), err=%s", graphContent, writeerr.Error()) return writeerr } @@ -154,30 +155,31 @@ func generateGraph() error { dotCmdPresent = false return nil } - log.Printf("osutils.ExecCommand(%v, %v) Error: %s", cmd, cmdParams, err.Error()) + logger.Error.Printf("osutils.ExecCommand(%v, %v), err=%s", cmd, cmdParams, err.Error()) } if len(stdOutErr) != 0 { - log.Println("Stdout & Stderr:", string(stdOutErr)) + logger.Debug.Println("Stdout & Stderr:", string(stdOutErr)) } return err } // getStatusColor returns the color for a given result status. -func getStatusColor(status string) string { +func getStatusColor(myStatus string) string { // Node color - ncolor := "blue" // dStatusStart by default - if status == dStatusFail { + ncolor := "blue" // status.Start by default + if myStatus == status.Fail { ncolor = "red" - } else if status == dStatusOk { + } else if myStatus == status.Ok { ncolor = "green" - } else if status == dStatusSkip { + } else if myStatus == status.Skip { ncolor = "yellow" } return ncolor } -func updateGraph(subgraphName, plugin, status, url string) error { +// UpdateGraph updates the plugin node with the status and url. +func UpdateGraph(subgraphName, plugin, status, url string) error { ncolor := getStatusColor(status) gContents := []string{} gContentsInterface, ok := g.subgraph.Load(subgraphName) diff --git a/graph_test.go b/graph/graph_test.go similarity index 82% rename from graph_test.go rename to graph/graph_test.go index 2ab18a8..03596ce 100644 --- a/graph_test.go +++ b/graph/graph_test.go @@ -1,5 +1,5 @@ -// Copyright (c) 2021 Veritas Technologies LLC. All rights reserved. IP63-2828-7171-04-15-9 -package pm +// Copyright (c) 2024 Veritas Technologies LLC. All rights reserved. IP63-2828-7171-04-15-9 +package graph import ( "os" @@ -7,7 +7,7 @@ import ( "sort" "testing" - "github.com/VeritasOS/plugin-manager/config" + "github.com/VeritasOS/plugin-manager/types/status" ) func Test_getStatusColor(t *testing.T) { @@ -26,22 +26,22 @@ func Test_getStatusColor(t *testing.T) { }{ { name: "Start", - args: args{status: dStatusStart}, + args: args{status: status.Start}, want: "blue", }, { name: "Ok/Pass", - args: args{status: dStatusOk}, + args: args{status: status.Ok}, want: "green", }, { name: "Fail", - args: args{status: dStatusFail}, + args: args{status: status.Fail}, want: "red", }, { name: "Skip", - args: args{status: dStatusSkip}, + args: args{status: status.Skip}, want: "yellow", }, } @@ -54,7 +54,7 @@ func Test_getStatusColor(t *testing.T) { } } -func Test_updateGraph(t *testing.T) { +func Test_UpdateGraph(t *testing.T) { if os.Getenv("INTEGRATION_TEST") == "RUNNING" { t.Skip("Not applicable while running integration tests.") return @@ -79,7 +79,7 @@ func Test_updateGraph(t *testing.T) { name: "Append a row", args: args{ plugin: "A/a.test", - status: dStatusOk, + status: status.Ok, url: "url/A/a.test", }, wantErr: false, @@ -90,10 +90,10 @@ func Test_updateGraph(t *testing.T) { } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - if err := updateGraph(getPluginType(tt.args.plugin), tt.args.plugin, tt.args.status, tt.args.url); (err != nil) != tt.wantErr { + if err := UpdateGraph("test", tt.args.plugin, tt.args.status, tt.args.url); (err != nil) != tt.wantErr { t.Errorf("updateGraph() error = %v, wantErr %v", err, tt.wantErr) } - rowsInterface, _ := g.subgraph.Load(getPluginType(tt.args.plugin)) + rowsInterface, _ := g.subgraph.Load("test") rows := rowsInterface.([]string) if !reflect.DeepEqual(rows, tt.wants.rows) { t.Errorf("updateGraph() g.rows = %v, wants.rows %v", rows, tt.wants.rows) @@ -102,7 +102,7 @@ func Test_updateGraph(t *testing.T) { } } -func Test_initGraph(t *testing.T) { +func Test_InitGraph(t *testing.T) { type args struct { pluginType string pluginsInfo Plugins @@ -127,7 +127,8 @@ func Test_initGraph(t *testing.T) { args: args{ pluginType: "test1", pluginsInfo: Plugins{ - "A/a.test1": { + { + Name: "A/a.test1", Description: "A's description", Requires: []string{}, ExecStart: "/bin/echo 'Running A...!'", @@ -145,12 +146,16 @@ func Test_initGraph(t *testing.T) { args: args{ pluginType: "test2", pluginsInfo: Plugins{ - "A/a.test2": { + { + + Name: "A/a.test2", Description: "A's description", Requires: []string{}, ExecStart: "/bin/echo 'Running A...!'", }, - "B/b.test2": { + { + + Name: "B/b.test2", Description: "B's description", Requires: []string{}, ExecStart: "/bin/echo 'Running B...!'", @@ -170,12 +175,14 @@ func Test_initGraph(t *testing.T) { args: args{ pluginType: "test3", pluginsInfo: Plugins{ - "A/a.test3": { + { + Name: "A/a.test3", Description: "A's description", Requires: []string{}, ExecStart: "/bin/echo 'Running A...!'", }, - "B/b.test3": { + { + Name: "B/b.test3", Description: "B's description", Requires: []string{"A/a.test3"}, ExecStart: "/bin/echo 'Running B...!'", @@ -188,17 +195,14 @@ func Test_initGraph(t *testing.T) { `"B/b.test3" [label="B's description",style=filled,fillcolor=lightgrey,URL="./B/b.test3"]`, `"B/b.test3"`, `"A/a.test3" -> "B/b.test3"`, - `"A/a.test3" -> "B/b.test3"`, }, wantErr: false, }, } - // Set log file name to "test", so that cleaning becomes easier. - config.SetPMLogFile("test") + for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - nPInfo := normalizePluginsInfo(tt.args.pluginsInfo) - if err := initGraph(tt.args.pluginType, nPInfo); (err != nil) != tt.wantErr { + if err := InitGraph(tt.args.pluginType, tt.args.pluginsInfo); (err != nil) != tt.wantErr { t.Errorf("initGraph() error = %v, wantErr %v", err, tt.wantErr) } rowsI, _ := g.subgraph.Load(tt.args.pluginType) diff --git a/plugin.go b/plugin.go index 8aeeee1..27df116 100644 --- a/plugin.go +++ b/plugin.go @@ -1,111 +1,80 @@ -// 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 // Package pm defines Plugin Manager (PM) functions like executing // all plugins of a particular plugin type. package pm import ( + "bufio" + "encoding/json" "errors" "flag" "fmt" "io/ioutil" "log" + "log/syslog" "os" "os/exec" "path" "path/filepath" "regexp" - "sort" "strings" "time" "github.com/VeritasOS/plugin-manager/config" - logutil "github.com/VeritasOS/plugin-manager/utils/log" + "github.com/VeritasOS/plugin-manager/graph" + "github.com/VeritasOS/plugin-manager/types" + "github.com/VeritasOS/plugin-manager/types/status" + logger "github.com/VeritasOS/plugin-manager/utils/log" osutils "github.com/VeritasOS/plugin-manager/utils/os" "github.com/VeritasOS/plugin-manager/utils/output" + "gopkg.in/yaml.v3" ) var ( // Version of the Plugin Manager (PM). - version = "4.6" + version = "5.0" ) -// Status of plugin execution used for displaying to user on console. -const ( - dStatusFail = "Failed" - dStatusOk = "Succeeded" - dStatusSkip = "Skipped" - dStatusStart = "Starting" -) - -// PluginAttributes that are supported in a plugin file. -type PluginAttributes struct { - Description string - FileName string - ExecStart string - RequiredBy []string - Requires []string -} - -// Plugins is basically a map of file and its contents. -type Plugins map[string]*PluginAttributes - -// PluginStatus is the plugin run's info: status, stdouterr. -type PluginStatus struct { - PluginAttributes `yaml:",inline"` - Status string - StdOutErr string -} - -// RunStatus is the pm run status. -type RunStatus struct { - Type string - // TODO: Add Percentage to get no. of pending vs. completed run of plugins. - Plugins PluginsStatus `yaml:",omitempty"` - Status string - StdOutErr string -} +// Plugin is of type types.Plugin +type Plugin = types.Plugin -// PluginsStatus is a list of plugins' run info. -type PluginsStatus []PluginStatus +// Plugins is of type types.Plugins +type Plugins = types.Plugins // getPluginFiles retrieves the plugin files under each component matching // the specified pluginType. -func getPluginFiles(pluginType string) ([]string, error) { - log.Println("Entering getPluginFiles") - defer log.Println("Exiting getPluginFiles") +func getPluginFiles(pluginType, library string) ([]string, error) { + logger.Debug.Println("Entering getPluginFiles") + defer logger.Debug.Println("Exiting getPluginFiles") var pluginFiles []string - - library := config.GetPluginsLibrary() if _, err := os.Stat(library); os.IsNotExist(err) { - return pluginFiles, logutil.PrintNLogError("Library '%s' doesn't exist. "+ + return pluginFiles, logger.ConsoleError.PrintNReturnError("Library '%s' doesn't exist. "+ "A valid plugins library path must be specified.", library) } var files []string dirs, err := ioutil.ReadDir(library) if err != nil { - log.Printf("ioutil.ReadDir(%s); Error: %s", library, err.Error()) - return pluginFiles, logutil.PrintNLogError("Failed to get contents of %s plugins library.", library) + logger.Error.Printf("Failed to call ioutil.ReadDir(%s), err=%s", library, err.Error()) + return pluginFiles, logger.ConsoleError.PrintNReturnError("Failed to get contents of %s plugins library.", library) } for _, dir := range dirs { compPluginDir := filepath.FromSlash(library + "/" + dir.Name()) fi, err := os.Stat(compPluginDir) if err != nil { - log.Printf("Unable to stat on %s directory. Error: %s\n", - dir, err.Error()) + logger.Error.Printf("Unable to stat on %s directory, err=%s", dir, err.Error()) continue } if !fi.IsDir() { - log.Printf("%s is not a directory.\n", compPluginDir) + logger.Error.Printf("%s is not a directory.", compPluginDir) continue } tfiles, err := ioutil.ReadDir(compPluginDir) if err != nil { - log.Printf("Unable to read contents of %s directory. Error: %s\n", - compPluginDir, err.Error()) + logger.Error.Printf("Unable to read contents of %s directory, err=%s", compPluginDir, err.Error()) } for _, tf := range tfiles { files = append(files, filepath.FromSlash(dir.Name()+"/"+tf.Name())) @@ -115,7 +84,7 @@ func getPluginFiles(pluginType string) ([]string, error) { for _, file := range files { matched, err := regexp.MatchString("[.]"+pluginType+"$", file) if err != nil { - log.Printf("regexp.MatchString(%s, %s); Error: %s", "[.]"+pluginType, file, err.Error()) + logger.Error.Printf("Failed to call regexp.MatchString(%s, %s), err=%s", "[.]"+pluginType, file, err.Error()) continue } if matched == true { @@ -130,121 +99,183 @@ func getPluginType(file string) string { return strings.Replace(path.Ext(file), ".", ``, -1) } -func getPluginsInfo(pluginType string) (Plugins, error) { - var pluginsInfo = make(Plugins) - pluginFiles, err := getPluginFiles(pluginType) +func getPluginsInfoFromJSONStrOrFile(strOrFile string) (Plugin, error) { + var err error + var pluginsInfo Plugin + rawData := strOrFile + jsonFormat := true + + // If Plugins information is in file... + fi, err := os.Stat(strOrFile) + if err != nil { + logger.Debug.Printf("Specified input is not a file. Err: %s", + err.Error()) + } else { + if fi.IsDir() { + return pluginsInfo, + logger.ConsoleError.PrintNReturnError( + "Specified path %s is directory. Plugins info should be specified either as a json string or in a json file.", + strOrFile) + } + + pluginsFile := strOrFile + fh, err := os.Open(pluginsFile) + if err != nil { + logger.ConsoleError.PrintNReturnError("%s", err) + return pluginsInfo, err + } + defer fh.Close() + + rawData, err = readFile(filepath.FromSlash(pluginsFile)) + if err != nil { + return pluginsInfo, + logger.ConsoleError.PrintNReturnError(err.Error()) + } + + logger.Debug.Printf("Plugins file %v has ext %v", pluginsFile, path.Ext(pluginsFile)) + if path.Ext(pluginsFile) == ".yaml" || path.Ext(pluginsFile) == ".yml" { + jsonFormat = false + } + } + // INFO: Use Plugin to unmarshal to keep input consistent with current + // output json, so that rerun failed could be done using result json. + var pluginsData Plugin + if jsonFormat { + err = json.Unmarshal([]byte(rawData), &pluginsData) + } else { + err = yaml.Unmarshal([]byte(rawData), &pluginsData) + } + if err != nil { + logger.Error.Printf("Failed to call Unmarshal(%s, %v); err=%#v", + rawData, &pluginsInfo, err) + return pluginsInfo, + logger.ConsoleError.PrintNReturnError( + "Plugins is not in expected format. Error: %s", err.Error()) + } + return pluginsData, nil +} + +func getPluginsInfoFromLibrary(pluginType, library string) (Plugins, error) { + var pluginsInfo Plugins + pluginFiles, err := getPluginFiles(pluginType, library) if err != nil { return pluginsInfo, err } for file := range pluginFiles { fContents, rerr := readFile(filepath.FromSlash( - config.GetPluginsLibrary() + pluginFiles[file])) + library + pluginFiles[file])) if rerr != nil { - return pluginsInfo, logutil.PrintNLogError(rerr.Error()) + return pluginsInfo, logger.ConsoleError.PrintNReturnError(rerr.Error()) } - // log.Printf("Plugin file %s contents: \n%s\n", pluginFiles[file], fContents) + logger.Debug.Printf("Plugin file %s contents: \n%s\n", + pluginFiles[file], fContents) pInfo, perr := parseUnitFile(fContents) if perr != nil { return pluginsInfo, perr } - log.Printf("Plugin %s info: %+v\n", pluginFiles[file], pInfo) - pluginsInfo[pluginFiles[file]] = &pInfo + logger.Info.Printf("Plugin %s info: %+v", pluginFiles[file], pInfo) + pInfo.Name = pluginFiles[file] + pluginsInfo = append(pluginsInfo, &pInfo) } return pluginsInfo, nil } func normalizePluginsInfo(pluginsInfo Plugins) Plugins { - log.Println("Entering normalizePluginsInfo") - defer log.Println("Exiting normalizePluginsInfo") - - nPInfo := Plugins{} - for pFile, pFContents := range pluginsInfo { - nPInfo[pFile] = &PluginAttributes{ - Description: pFContents.Description, - ExecStart: pFContents.ExecStart, - FileName: pFile, - } - nPInfo[pFile].RequiredBy = append(nPInfo[pFile].Requires, pFContents.RequiredBy...) - nPInfo[pFile].Requires = append(nPInfo[pFile].Requires, pFContents.Requires...) - log.Printf("%s plugin dependencies: %v", pFile, nPInfo[pFile]) - } - for p := range nPInfo { - log.Printf("nPInfo key(%s): %v", p, nPInfo[p]) - for _, rs := range nPInfo[p].Requires { + logger.Debug.Printf("Entering normalizePluginsInfo(%+v)...", pluginsInfo) + defer logger.Debug.Println("Exiting normalizePluginsInfo") + + nPInfo := make(Plugins, len(pluginsInfo)) + pluginIndexes := make(map[string]int, len(pluginsInfo)) + for pIdx, pInfo := range pluginsInfo { + pluginIndexes[pInfo.Name] = pIdx + nPInfo[pIdx] = &Plugin{ + Name: pInfo.Name, + Description: pInfo.Description, + ExecStart: pInfo.ExecStart, + Plugins: pInfo.Plugins, + Library: pInfo.Library, + } + nPInfo[pIdx].RequiredBy = append(nPInfo[pIdx].Requires, pInfo.RequiredBy...) + nPInfo[pIdx].Requires = append(nPInfo[pIdx].Requires, pInfo.Requires...) + logger.Debug.Printf("%s plugin dependencies: %v", nPInfo[pIdx].Name, nPInfo[pIdx]) + } + for pIdx, pInfo := range nPInfo { + p := pInfo.Name + logger.Debug.Printf("nPInfo key(%v): %v", p, nPInfo[pIdx]) + for _, rs := range nPInfo[pIdx].Requires { // Check whether it's already marked as RequiredBy dependency in `Requires` plugin. - // log.Printf("Check whether `in` (%s) already marked as RequiredBy dependency in `Requires`(%s) plugin: %v", + // logger.Info.Printf("Check whether `in` (%s) already marked as RequiredBy dependency in `Requires`(%s) plugin: %v", // p, rs, nPInfo[rs]) present := false - // If dependencies are missing, then nPInfo[rs] value will not be defined. - if nPInfo[rs] != nil { - log.Printf("PluginInfo for %s is present: %v", rs, nPInfo[rs]) - for _, rby := range nPInfo[rs].RequiredBy { - log.Printf("p(%s) == rby(%s)? %v", p, rby, p == rby) + // If dependencies are missing, then pluginIndexes[rs] value will not be defined. + if rsIdx, ok := pluginIndexes[rs]; ok { + logger.Debug.Printf("PluginInfo for %s is present: %v", rs, nPInfo[rsIdx]) + for _, rby := range nPInfo[rsIdx].RequiredBy { + logger.Debug.Printf("p(%s) == rby(%s)? %v", p, rby, p == rby) if p == rby { present = true break } } if !present { - nPInfo[rs].RequiredBy = append(nPInfo[rs].RequiredBy, p) - log.Printf("Added %s as RequiredBy dependency of %s: %+v", p, rs, nPInfo[rs]) + nPInfo[rsIdx].RequiredBy = append(nPInfo[rsIdx].RequiredBy, p) + logger.Info.Printf("Added %s as RequiredBy dependency of %s: %+v", p, rs, nPInfo[rsIdx]) } } } // Check whether RequiredBy dependencies are also marked as Requires dependency on other plugin. - log.Printf("Check whether RequiredBy dependencies are also marked as Requires dependency on other plugin.") - for _, rby := range nPInfo[p].RequiredBy { - log.Printf("RequiredBy of %s: %s", p, rby) - log.Printf("nPInfo of %s: %+v", rby, nPInfo[rby]) + logger.Info.Println("Check whether RequiredBy dependencies are also marked as Requires dependency on other plugin.") + for _, rby := range nPInfo[pIdx].RequiredBy { + rbyIdx := pluginIndexes[rby] + logger.Debug.Printf("RequiredBy of %s: %s", p, rby) + logger.Debug.Printf("nPInfo of %s: %+v", rby, nPInfo[rbyIdx]) // INFO: If one plugin type is added as dependent on another by // any chance, then skip checking its contents as the other // plugin type files were not parsed. - if nPInfo[rby] == nil { + if _, ok := pluginIndexes[rby]; !ok { // NOTE: Add the missing plugin in Requires, So that the issue // gets caught during validation. - nPInfo[p].Requires = append(nPInfo[p].Requires, rby) + nPInfo[pIdx].Requires = append(nPInfo[pIdx].Requires, rby) continue } present := false - for _, rs := range nPInfo[rby].Requires { + for _, rs := range nPInfo[rbyIdx].Requires { if p == rs { present = true break } } if !present { - nPInfo[rby].Requires = append(nPInfo[rby].Requires, p) - log.Printf("Added %s as Requires dependency of %s: %+v", p, rby, nPInfo[rby]) + nPInfo[rbyIdx].Requires = append(nPInfo[rbyIdx].Requires, p) + logger.Debug.Printf("Added %s as Requires dependency of %s: %+v", p, rby, nPInfo[rbyIdx]) } } } - log.Printf("Plugins info after normalizing: \n%+v\n", nPInfo) + logger.Debug.Printf("Plugins info after normalizing: \n%+v\n", nPInfo) return nPInfo } // parseUnitFile parses the plugin file contents. -func parseUnitFile(fileContents string) (PluginAttributes, error) { - log.Println("Entering parseUnitFile") - defer log.Println("Exiting parseUnitFile") +func parseUnitFile(fileContents string) (Plugin, error) { + logger.Debug.Println("Entering parseUnitFile") + defer logger.Debug.Println("Exiting parseUnitFile") - pluginInfo := PluginAttributes{} + pluginInfo := Plugin{} if len(fileContents) == 0 { return pluginInfo, nil } lines := strings.Split(fileContents, "\n") for l := range lines { line := strings.TrimSpace(lines[l]) - // TODO: Log as debug message - // log.Println("line...", line) + logger.Debug.Println("line...", line) line = strings.TrimSpace(line) if len(line) == 0 { continue } if strings.HasPrefix(line, "#") { // No need to parse comments. - // TODO: Log as debug message - // log.Println("Skipping comment line...", line) + logger.Debug.Println("Skipping comment line...", line) continue } @@ -268,8 +299,7 @@ func parseUnitFile(fileContents string) (PluginAttributes, error) { pluginInfo.Requires = strings.Split(val, " ") break default: - // TODO: Log as debug message - // log.Printf("Non-standard line found: %s", line) + logger.Debug.Printf("Non-standard line found: %s", line) break } } @@ -278,33 +308,28 @@ func parseUnitFile(fileContents string) (PluginAttributes, error) { } func validateDependencies(nPInfo Plugins) ([]string, error) { - log.Println("Entering validateDependencies") - defer log.Println("Exiting validateDependencies") + logger.Debug.Println("Entering validateDependencies") + defer logger.Debug.Println("Exiting validateDependencies") var pluginOrder []string notPlacedPlugins := []string{} dependencyMet := map[string]bool{} - // for pFile, pFContents := range pluginsInfo {} - sortedPFiles := []string{} - for pFile := range nPInfo { - sortedPFiles = append(sortedPFiles, pFile) - } - // NOTE: Sorting plugin files mainly to have a deterministic order, - // though it's not required for solution to work. - // (Sorting takes care of unit tests as maps return keys/values in random order). - sort.Strings(sortedPFiles) - log.Printf("Plugin files in sorted order: %+v\n", sortedPFiles) - - for pFileIndex := range sortedPFiles { - pFile := sortedPFiles[pFileIndex] - pFContents := nPInfo[pFile] - log.Printf("\nFile: %s \n%+v \n\n", pFile, pFContents) - if len(pFContents.Requires) == 0 { - dependencyMet[pFile] = true - pluginOrder = append(pluginOrder, pFile) + + pluginIndexes := make(map[string]int) + for pIdx, pInfo := range nPInfo { + pluginIndexes[pInfo.Name] = pIdx + } + + for pNameIndex := range nPInfo { + pName := nPInfo[pNameIndex].Name + pContents := nPInfo[pNameIndex] + logger.Debug.Printf("\nPlugin: %s \n%+v \n\n", pName, pContents) + if len(pContents.Requires) == 0 { + dependencyMet[pName] = true + pluginOrder = append(pluginOrder, pName) } else { - dependencyMet[pFile] = false - notPlacedPlugins = append(notPlacedPlugins, pFile) + dependencyMet[pName] = false + notPlacedPlugins = append(notPlacedPlugins, pName) } } @@ -318,39 +343,40 @@ func validateDependencies(nPInfo Plugins) ([]string, error) { // plugin's dependency has been met (i.e., prevLen != curLen). If not, // then there is a circular dependency, or plugins are missing dependencies. for curLen != 0 { - pFile := notPlacedPlugins[0] + pName := notPlacedPlugins[0] notPlacedPlugins = notPlacedPlugins[1:] - pDependencies := nPInfo[pFile].Requires - log.Printf("Plugin %s dependencies: %+v\n", pFile, pDependencies) + pIdx := pluginIndexes[pName] + pDependencies := nPInfo[pIdx].Requires + logger.Info.Printf("Plugin %s dependencies: %+v", pName, pDependencies) - dependencyMet[pFile] = true + dependencyMet[pName] = true for w := range pDependencies { val := dependencyMet[pDependencies[w]] if false == val { // If dependency met is false, then process it later again after all dependencies are met. - dependencyMet[pFile] = false - log.Printf("Adding %s back to list %s to process as %s plugin dependency is not met.\n", - pFile, notPlacedPlugins, pDependencies[w]) - notPlacedPlugins = append(notPlacedPlugins, pFile) + dependencyMet[pName] = false + logger.Warning.Printf("Adding %s back to list %s to process as %s plugin dependency is not met.", + pName, notPlacedPlugins, pDependencies[w]) + notPlacedPlugins = append(notPlacedPlugins, pName) break } } // If dependency met is not set to false, then it means all // dependencies are met. So, add it to pluginOrder - if false != dependencyMet[pFile] { - log.Printf("Dependency met for %s: %v\n", pFile, dependencyMet[pFile]) - pluginOrder = append(pluginOrder, pFile) + if false != dependencyMet[pName] { + logger.Info.Printf("Dependency met for %s: %v.", pName, dependencyMet[pName]) + pluginOrder = append(pluginOrder, pName) } elementsLeft-- if elementsLeft == 0 { - log.Printf("PrevLen: %d; CurLen: %d\n", prevLen, curLen) + logger.Debug.Printf("PrevLen: %d; CurLen: %d.", prevLen, curLen) curLen = len(notPlacedPlugins) if prevLen == curLen { // INFO: Clear out the pluginOrder as we cannot run all the // plugins either due to missing dependencies or having // circular dependency. - return []string{}, logutil.PrintNLogError( + return []string{}, logger.ConsoleError.PrintNReturnError( "There is either a circular dependency between plugins, "+ "or some dependencies are missing in these plugins: %+v", notPlacedPlugins) @@ -363,28 +389,43 @@ func validateDependencies(nPInfo Plugins) ([]string, error) { return pluginOrder, nil } -func executePluginCmd(statusCh chan<- map[string]*PluginStatus, p string, pluginsInfo Plugins, failedDependency bool) { - pInfo := pluginsInfo[p] - log.Printf("\nChannel: Plugin %s info: \n%+v\n", p, pInfo) - updateGraph(getPluginType(p), p, dStatusStart, "") - logutil.PrintNLog("\n%s: %s\n", pInfo.Description, dStatusStart) - // Get relative path to plugins log file from PM log dir, so that linking - // in plugin graph works even when the logs are copied to another system. - pluginLogFile := strings.Replace(config.GetPluginsLogDir(), - config.GetPMLogDir(), "", -1) + - strings.Replace(p, string(os.PathSeparator), ":", -1) + - "." + time.Now().Format(time.RFC3339Nano) + ".log" - logFile := config.GetPMLogDir() + pluginLogFile - fh, openerr := os.OpenFile(logFile, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0666) - if openerr != nil { - log.Printf("os.OpenFile(%s) Error: %s", logFile, openerr.Error()) - // Ignore error and continue as plugin log file creation is not fatal. - } - defer fh.Close() - // chLog is a channel logger - chLog := log.New(fh, "", log.LstdFlags) - chLog.SetOutput(fh) - chLog.Println("Plugin file:", p) +func executePluginCmd(statusCh chan<- map[string]*Plugin, pInfo Plugin, failedDependency bool, env map[string]string) { + p := pInfo.Name + logger.Debug.Printf("Channel: Plugin %s info: \n%+v", p, pInfo) + graph.UpdateGraph(getPluginType(p), p, status.Start, "") + logger.ConsoleInfo.Printf("%s: %s", pInfo.Description, status.Start) + pluginLogFile := "" + var chLog *log.Logger + if !logger.IsFileLogger() { + var logTag string + // Set log tag for + logTag = logger.SyslogTagPrefix + "pm-" + logger.GetLogTag() + logger.Debug.Printf("logTag = %s", logTag) + syslogHandle, err := syslog.New(syslog.LOG_LOCAL0|syslog.LOG_INFO, logTag) + if err != nil { + logger.Error.Printf("Failed to call syslog.New, err=%s", err.Error()) + } + defer syslogHandle.Close() + chLog = log.New(syslogHandle, "", 0) + } else { + // Get relative path to plugins log file from PM log dir, so that linking + // in plugin graph works even when the logs are copied to another system. + pluginLogFile = strings.Replace(config.GetPluginsLogDir(), config.GetPMLogDir(), "", -1) + + strings.Replace(p, string(os.PathSeparator), ":", -1) + + "." + time.Now().Format(time.RFC3339Nano) + ".log" + logFile := config.GetPMLogDir() + pluginLogFile + fh, openerr := os.OpenFile(logFile, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0600) + if openerr != nil { + logger.Error.Printf("Failed to call os.OpenFile(%s), err=%s", logFile, openerr.Error()) + // Ignore error and continue as plugin log file creation is not fatal. + } + defer fh.Close() + // chLog is a channel logger + chLog = log.New(fh, "", log.LstdFlags) + chLog.SetOutput(fh) + } + + chLog.Println("INFO: Plugin file:", p) // If already marked as failed/skipped due to dependency fail, // then just return that status. @@ -392,90 +433,144 @@ func executePluginCmd(statusCh chan<- map[string]*PluginStatus, p string, plugin myStatusMsg := "" if failedDependency { myStatusMsg = "Skipping as its dependency failed." - myStatus = dStatusSkip + myStatus = status.Skip + } else if len(pInfo.Plugins) != 0 { + execStatus := executePlugins(&pInfo.Plugins, false, env) + if !execStatus { + myStatus = status.Fail + graph.UpdateGraph(getPluginType(p), p, myStatus, "") + err := fmt.Errorf("Running %s plugins: %s", p, myStatus) + statusCh <- map[string]*Plugin{p: {Status: myStatus, StdOutErr: []string{err.Error()}}} + return + } + myStatus = status.Ok } else if pInfo.ExecStart == "" { myStatusMsg = "Passing as ExecStart value is empty!" - myStatus = dStatusOk + myStatus = status.Ok } if myStatus != "" { - log.Println(myStatusMsg) - chLog.Println(myStatusMsg) - updateGraph(getPluginType(p), p, myStatus, "") - logutil.PrintNLog("%s: %s\n", pInfo.Description, myStatus) - statusCh <- map[string]*PluginStatus{p: {Status: myStatus}} + chLog.Println("INFO: ", myStatusMsg) + logger.Info.Printf("Plugin(%s): %s", p, myStatusMsg) + graph.UpdateGraph(getPluginType(p), p, myStatus, "") + logger.ConsoleInfo.Printf("%s: %s", pInfo.Description, myStatus) + statusCh <- map[string]*Plugin{p: {Status: myStatus}} return } - log.Printf("\nExecuting command: %s\n", pInfo.ExecStart) - cmdParam := strings.Split(pInfo.ExecStart, " ") - cmdStr := cmdParam[0] - cmdParams := os.ExpandEnv(strings.Join(cmdParam[1:], " ")) - cmdParamsExpanded := strings.Split(cmdParams, " ") + // INFO: First initialize with existing OS env, and then overwrite any + // existing keys with user specified values. I.e., Even if PM_LIBRARY + // env is set in shell, it'll be overwritten by Library parameter passed + // by user. + envList := osutils.OsEnviron() + envMap := osutils.EnvMap() + for envKey, envValue := range env { + envList = append(envList, envKey+"="+envValue) + envMap[envKey] = envValue + } - cmd := exec.Command(os.ExpandEnv(cmdStr), cmdParamsExpanded...) - stdOutErr, err := cmd.CombinedOutput() + getEnvVal := func(name string) string { + // logger.Debug.Printf("In getEnvVal(%v)...", name) + // logger.Debug.Printf("env: %+v", envMap) + if val, ok := envMap[name]; ok { + // logger.Debug.Printf("Key:%v = Value:%v", name, val) + return val + } + return "" + } + + logger.Info.Printf("Executing command, cmd=%s", pInfo.ExecStart) + // INFO: Expand environment values like "PM_LIBRARY" so that ... + // 1. Binaries or scripts placed in the same directory as that of plugins + // can be accessed as ${PM_LIBRARY}/ path. + // 2. Envs that are set by caller of calling plugin manager gets expanded. + cmdParam := strings.Split(os.Expand(pInfo.ExecStart, getEnvVal), " ") + cmdStr := cmdParam[0] + cmdParams := cmdParam[1:] + cmd := exec.Command(cmdStr, cmdParams...) + cmd.Env = envList + iostdout, err := cmd.StdoutPipe() + if err != nil { + pInfo.Status = status.Fail + 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.Println("Executing command:", pInfo.ExecStart) + chLog.Printf("INFO: Plugin(%s): Executing command: %s", p, pInfo.ExecStart) if err != nil { - chLog.Println("Error:", err.Error()) - updateGraph(getPluginType(p), p, dStatusFail, pluginLogFile) + chLog.Printf("ERROR: Plugin(%s): Failed to execute command, err=%s", p, err.Error()) + graph.UpdateGraph(getPluginType(p), p, status.Fail, pluginLogFile) } else { - chLog.Println("Stdout & Stderr:", string(stdOutErr)) - updateGraph(getPluginType(p), p, dStatusOk, pluginLogFile) + chLog.Printf("INFO: Plugin(%s): Stdout & Stderr: %v", p, stdOutErr) + graph.UpdateGraph(getPluginType(p), p, status.Ok, pluginLogFile) } }() - log.Println("Stdout & Stderr:", string(stdOutErr)) - pStatus := PluginStatus{StdOutErr: string(stdOutErr)} + logger.Debug.Println("Stdout & Stderr:", stdOutErr) + pStatus := Plugin{StdOutErr: stdOutErr} if err != nil { - pStatus.Status = dStatusFail - log.Printf("Failed to execute plugin %s. Error: %s\n", p, err.Error()) - logutil.PrintNLog("%s: %s\n", pInfo.Description, dStatusFail) - statusCh <- map[string]*PluginStatus{p: &pStatus} + pStatus.Status = status.Fail + logger.Error.Printf("Failed to execute plugin %s. err=%s\n", p, err.Error()) + logger.ConsoleError.Printf("%s: %s\n", pInfo.Description, status.Fail) + statusCh <- map[string]*Plugin{p: &pStatus} return } - pStatus.Status = dStatusOk - logutil.PrintNLog("%s: %s\n", pInfo.Description, dStatusOk) - statusCh <- map[string]*PluginStatus{p: &pStatus} + pStatus.Status = status.Ok + logger.ConsoleInfo.Printf("%s: %s\n", pInfo.Description, status.Ok) + statusCh <- map[string]*Plugin{p: &pStatus} } -func executePlugins(psStatus *PluginsStatus, nPInfo Plugins, sequential bool) bool { - log.Println("Entering executePlugins") - defer log.Println("Exiting executePlugins") +func executePlugins(psStatus *Plugins, sequential bool, env map[string]string) bool { + logger.Debug.Printf("Entering executePlugins(%+v, %v, %+v)...", + psStatus, sequential, env) + defer logger.Debug.Println("Exiting executePlugins") retStatus := true + nPInfo := normalizePluginsInfo(*psStatus) + _, err := validateDependencies(nPInfo) if err != nil { return false } - // INFO: Set the PM_LIBRARY env variable so that binaries/scripts placed - // in the same directory as that of plugins can be accessed using - // ${PM_LIBRARY}/ path. - os.Setenv("PM_LIBRARY", config.GetPluginsLibrary()) - - // INFO: PM_PLUGIN_DIR is deprecated. Use PM_LIBRARY instead. - // Keeping it for backward compatibility for couple of releases. - // (Currently Px is 1.x, and we can keep say until Px 3.x). - // If older versions of PM is out there, then PM_PLUGIN_DIR env value - // will be expected in plugins. - os.Setenv("PM_PLUGIN_DIR", config.GetPluginsLibrary()) - waitCount := map[string]int{} - for p := range nPInfo { - waitCount[p] = len(nPInfo[p].Requires) - log.Printf("%s plugin dependencies: %+v", p, nPInfo[p]) + for pIdx, pInfo := range nPInfo { + p := pInfo.Name + waitCount[p] = len(nPInfo[pIdx].Requires) + logger.Debug.Printf("%s plugin dependencies: %+v", p, nPInfo[pIdx]) } - executingCnt := 0 - exeCh := make(chan map[string]*PluginStatus) pluginIndexes := make(map[string]int) + for pIdx, pInfo := range *psStatus { + pluginIndexes[pInfo.Name] = pIdx + } + executingCnt := 0 + exeCh := make(chan map[string]*Plugin) failedDependency := make(map[string]bool) - for len(nPInfo) > 0 || executingCnt != 0 { - for p := range nPInfo { + for len(pluginIndexes) > 0 || executingCnt != 0 { + for _, pInfo := range nPInfo { + p := pInfo.Name // INFO: When all dependencies are met, plugin waitCount would be 0. // When sequential execution is enforced, even if a plugin is ready // to run, make sure that only one plugin is running at time, by @@ -483,15 +578,13 @@ func executePlugins(psStatus *PluginsStatus, nPInfo Plugins, sequential bool) bo // When sequential execution is not enforced, run plugins that are ready. if waitCount[p] == 0 && ((sequential == false) || (sequential == true && executingCnt == 0)) { - log.Printf("Plugin %s is ready for execution: %v.", p, nPInfo[p]) + logger.Info.Printf("Plugin %s is ready for execution: %v.", p, pInfo) waitCount[p]-- + pIdx := pluginIndexes[p] + ps := *psStatus + ps[pIdx].RunTime.StartTime = time.Now() - ps := PluginStatus{} - ps.PluginAttributes = *nPInfo[p] - *psStatus = append(*psStatus, ps) - pluginIndexes[p] = len(*psStatus) - 1 - - go executePluginCmd(exeCh, p, nPInfo, failedDependency[p]) + go executePluginCmd(exeCh, *pInfo, failedDependency[p], env) executingCnt++ } } @@ -499,18 +592,20 @@ func executePlugins(psStatus *PluginsStatus, nPInfo Plugins, sequential bool) bo exeStatus := <-exeCh executingCnt-- for plugin, pStatus := range exeStatus { - log.Printf("%s status: %v", plugin, pStatus.Status) + logger.Info.Printf("%s status: %v", plugin, pStatus.Status) pIdx := pluginIndexes[plugin] ps := *psStatus + ps[pIdx].RunTime.EndTime = time.Now() + ps[pIdx].RunTime.Duration = ps[pIdx].RunTime.EndTime.Sub(ps[pIdx].RunTime.StartTime) ps[pIdx].Status = pStatus.Status ps[pIdx].StdOutErr = pStatus.StdOutErr - if pStatus.Status == dStatusFail { + if pStatus.Status == status.Fail { retStatus = false } - for _, rby := range nPInfo[plugin].RequiredBy { - if pStatus.Status == dStatusFail || - pStatus.Status == dStatusSkip { + for _, rby := range nPInfo[pIdx].RequiredBy { + if pStatus.Status == status.Fail || + pStatus.Status == status.Skip { // TODO: When "Wants" and "WantedBy" options are supported similar to // "Requires" and "RequiredBy", the failedDependency flag should be // checked in conjunction with if its required dependency is failed, @@ -519,7 +614,7 @@ func executePlugins(psStatus *PluginsStatus, nPInfo Plugins, sequential bool) bo } waitCount[rby]-- } - delete(nPInfo, plugin) + delete(pluginIndexes, plugin) } } return retStatus @@ -536,6 +631,10 @@ var CmdOptions struct { // (If sequential is disabled, plugins whose dependencies are met would be executed in parallel). sequential *bool + // pluginsPtr specifies plugins Name and its Description, ExecStart and any dependencies (Requires, RequiredBy). + // For input format, check 'Plugins' struct. + pluginsPtr *string + // pluginTypePtr indicates type of the plugin to run. pluginTypePtr *string @@ -545,29 +644,57 @@ var CmdOptions struct { // pluginDirPtr indicates the location of the plugins. // NOTE: `pluginDir` is deprecated, use `library` instead. pluginDirPtr *string +} - // logDirPtr indicates the location for writing log file. - logDirPtr *string +// ListOptions are optional parameters related to list function. +type ListOptions struct { + Type string +} - // logFilePtr indicates the log file name to write to in the logDirPtr location. - logFilePtr *string +// RunOptions are optional parameters related to run function. +type RunOptions struct { + Library string + Type string + Sequential bool } -// List the plugin and its dependencies. -func List(pluginType string) error { - var pluginsInfo, err = getPluginsInfo(pluginType) +// ListFromLibrary lists the plugin and its dependencies from the plugins +// library path. +func ListFromLibrary(pluginType, library string) error { + pluginsInfo, err := getPluginsInfoFromLibrary(pluginType, library) + if err != nil { + return err + } + + listOptions := ListOptions{ + Type: pluginType, + } + return list(pluginsInfo, listOptions) +} + +// ListFromJSONStrOrFile lists the plugin and its dependencies from a json +// string or a json file. +func ListFromJSONStrOrFile(jsonStrOrFile string, listOptions ListOptions) error { + pluginsInfo, err := getPluginsInfoFromJSONStrOrFile(jsonStrOrFile) if err != nil { return err } - nPInfo := normalizePluginsInfo(pluginsInfo) - err = initGraph(pluginType, nPInfo) + return list(pluginsInfo.Plugins, listOptions) +} + +// List the plugin and its dependencies. +func list(pluginsInfo Plugins, listOptions ListOptions) error { + pluginType := listOptions.Type + + var err error + + err = graph.InitGraph(pluginType, pluginsInfo) if err != nil { return err } - logutil.PrintNLog("The list of plugins are mapped in %s\n", - getImagePath()) + logger.ConsoleInfo.Printf("The list of plugins are mapped in %s", graph.GetImagePath()) return nil } @@ -584,13 +711,18 @@ func readFile(filePath string) (string, error) { // RegisterCommandOptions registers the command options that are supported func RegisterCommandOptions(progname string) { - log.Println("Entering RegisterCommandOptions") - defer log.Println("Exiting RegisterCommandOptions") + logger.Debug.Println("Entering RegisterCommandOptions") + defer logger.Debug.Println("Exiting RegisterCommandOptions") CmdOptions.versionCmd = flag.NewFlagSet(progname+" version", flag.ContinueOnError) CmdOptions.versionPtr = CmdOptions.versionCmd.Bool("version", false, "print Plugin Manager (PM) version.") CmdOptions.RunCmd = flag.NewFlagSet(progname+" run", flag.PanicOnError) + CmdOptions.pluginsPtr = CmdOptions.RunCmd.String( + "plugins", + "", + "Plugins and its dependencies in json format as a string or in a file (Ex: './plugins.json').\nWhen specified, plugin files are not looked up in specified -library path.", + ) CmdOptions.pluginTypePtr = CmdOptions.RunCmd.String( "type", "", @@ -599,26 +731,29 @@ func RegisterCommandOptions(progname string) { CmdOptions.libraryPtr = CmdOptions.RunCmd.String( "library", "", - "Path of the plugins library.", + "Path of the plugins library.\nSets PM_LIBRARY env value.\n"+ + "When '-plugins' is specified, only PM_LIBRARY env value is set. "+ + "The plugin files are not read from library path.", ) CmdOptions.sequential = CmdOptions.RunCmd.Bool( "sequential", false, "Enforce running plugins in sequential.", ) - CmdOptions.logDirPtr = CmdOptions.RunCmd.String( - "log-dir", - "", - "Directory for the log file.", - ) - CmdOptions.logFilePtr = CmdOptions.RunCmd.String( - "log-file", - "", - "Name of the log file.", - ) + logger.RegisterCommandOptions(CmdOptions.RunCmd, map[string]string{ + "log-dir": config.GetLogDir(), + "log-file": config.GetLogFile(), + "log-level": config.GetLogLevel(), + }) output.RegisterCommandOptions(CmdOptions.RunCmd, map[string]string{}) CmdOptions.ListCmd = flag.NewFlagSet(progname+" list", flag.PanicOnError) + CmdOptions.ListCmd.StringVar( + CmdOptions.pluginsPtr, + "plugins", + "", + "Plugins and its dependencies in json format as a string or in a file (Ex: './plugins.json')", + ) CmdOptions.ListCmd.StringVar( CmdOptions.pluginTypePtr, "type", @@ -631,53 +766,93 @@ func RegisterCommandOptions(progname string) { "", "Path of the plugins library.", ) - CmdOptions.ListCmd.StringVar( - CmdOptions.logDirPtr, - "log-dir", - "", - "Directory for the log file.", - ) - CmdOptions.ListCmd.StringVar( - CmdOptions.logFilePtr, - "log-file", - "", - "Name of the log file.", - ) + logger.RegisterCommandOptions(CmdOptions.ListCmd, map[string]string{ + "log-dir": config.GetLogDir(), + "log-file": config.GetLogFile(), + "log-level": config.GetLogLevel(), + }) } -// Run the specified plugin type plugins. -func Run(result *RunStatus, pluginType string) error { - result.Type = pluginType - status := true +// RunFromJSONStrOrFile runs the plugins based on dependencies specified in a +// json string or a json/yaml file. +func RunFromJSONStrOrFile(result *Plugin, jsonStrOrFile string, runOptions RunOptions) error { + pluginsInfo, err := getPluginsInfoFromJSONStrOrFile(jsonStrOrFile) + if err != nil { + result.Status = status.Fail + result.StdOutErr = append(result.StdOutErr, err.Error()) + return err + } + result.Name = pluginsInfo.Name + 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.Name = runOptions.Type + } else { + runOptions.Type = pluginsInfo.Name + } + if runOptions.Library != "" { + result.Library = runOptions.Library + } else { + runOptions.Library = pluginsInfo.Library + } + return run(result, runOptions) +} + +// RunFromLibrary runs the specified plugin type plugins from the library. +func RunFromLibrary(result *Plugin, pluginType string, runOptions RunOptions) error { + result.Name = pluginType + + var pluginsInfo, err = getPluginsInfoFromLibrary(pluginType, runOptions.Library) + if err != nil { + result.Status = status.Fail + result.StdOutErr = append(result.StdOutErr, err.Error()) + return err + } + result.Plugins = pluginsInfo + + runOptions.Type = pluginType + return run(result, runOptions) +} + +// run the specified plugins. +func run(result *Plugin, runOptions RunOptions) error { + logger.Debug.Printf("Entering run(%+v, %+v)...", result, runOptions) + defer logger.Debug.Println("Exiting run") + pluginType := runOptions.Type + sequential := runOptions.Sequential + + result.RunTime.StartTime = time.Now() + defer func() { + result.RunTime.EndTime = time.Now() + result.RunTime.Duration = result.RunTime.EndTime.Sub(result.RunTime.StartTime) + }() if err := osutils.OsMkdirAll(config.GetPluginsLogDir(), 0755); nil != err { - err = logutil.PrintNLogError( + err = logger.ConsoleError.PrintNReturnError( "Failed to create the plugins logs directory: %s. "+ "Error: %s", config.GetPluginsLogDir(), err.Error()) - result.Status = dStatusFail - result.StdOutErr = err.Error() + result.Status = status.Fail + result.StdOutErr = append(result.StdOutErr, err.Error()) return err } - var pluginsInfo, err = getPluginsInfo(pluginType) - if err != nil { - result.Status = dStatusFail - result.StdOutErr = err.Error() - return err - } - nPInfo := normalizePluginsInfo(pluginsInfo) - initGraph(pluginType, nPInfo) + graph.InitGraph(pluginType, result.Plugins) - status = executePlugins(&result.Plugins, nPInfo, *CmdOptions.sequential) - if status != true { - result.Status = dStatusFail - err = fmt.Errorf("Running %s plugins: %s", pluginType, dStatusFail) - result.StdOutErr = err.Error() - logutil.PrintNLog("%s\n", err.Error()) + env := map[string]string{} + if runOptions.Library != "" { + env["PM_LIBRARY"] = runOptions.Library + } + execStatus := executePlugins(&result.Plugins, sequential, env) + if execStatus != true { + result.Status = status.Fail + err := fmt.Errorf("Running %s plugins: %s", pluginType, status.Fail) + result.StdOutErr = append(result.StdOutErr, err.Error()) + logger.ConsoleError.Printf("%s\n", err.Error()) return err } - result.Status = dStatusOk - logutil.PrintNLog("Running %s plugins: %s\n", pluginType, dStatusOk) + result.Status = status.Ok + logger.ConsoleInfo.Printf("Running %s plugins: %s\n", pluginType, status.Ok) return nil } @@ -689,8 +864,8 @@ func Run(result *RunStatus, pluginType string) error { // "progname": Name of the program along with any cmds (ex: asum pm) // "cmd-index": Index to the cmd (ex: run) func ScanCommandOptions(options map[string]interface{}) error { - log.Printf("Entering ScanCommandOptions(%+v)...", options) - defer log.Println("Exiting ScanCommandOptions") + logger.Debug.Printf("Entering ScanCommandOptions(%+v)...", options) + defer logger.Debug.Println("Exiting ScanCommandOptions") progname := filepath.Base(os.Args[0]) cmdIndex := 1 @@ -701,22 +876,22 @@ func ScanCommandOptions(options map[string]interface{}) error { cmdIndex = valI.(int) } cmd := os.Args[cmdIndex] - log.Println("progname:", progname, "cmd with arguments: ", os.Args[cmdIndex:]) + logger.Debug.Println("progname:", progname, "cmd with arguments: ", os.Args[cmdIndex:]) switch cmd { case "version": - logutil.PrintNLog("Plugin Manager (PM) version %s\n", version) + logger.ConsoleInfo.Printf("Plugin Manager (PM) version %s", version) case "list": err := CmdOptions.ListCmd.Parse(os.Args[cmdIndex+1:]) if err != nil { - log.Fatalln(cmd, "command arguments parse error:", err.Error()) + logger.Error.Printf("Command arguments parse error, cmd=%s, err=%s", cmd, err.Error()) } case "run": err := CmdOptions.RunCmd.Parse(os.Args[cmdIndex+1:]) if err != nil { - log.Fatalln(cmd, "command arguments parse error:", err.Error()) + logger.Error.Printf("Command arguments parse error, cmd=%s, err=%s", cmd, err.Error()) } case "help": @@ -739,41 +914,90 @@ func ScanCommandOptions(options map[string]interface{}) error { if *CmdOptions.libraryPtr != "" { config.SetPluginsLibrary(*CmdOptions.libraryPtr) } - logToNewFile := false - if *CmdOptions.logDirPtr != "" { - config.SetPMLogDir(*CmdOptions.logDirPtr) - logToNewFile = true + myLogFile := logger.DefaultLogDir + if logger.GetLogDir() != "" { + config.SetPMLogDir(logger.GetLogDir()) + myLogFile = config.GetPMLogDir() } // Info: Call set PM log-dir to clean extra slashes, and to append path // separator at the end. config.SetPMLogDir(config.GetPMLogDir()) - if *CmdOptions.logFilePtr != "" { - config.SetPMLogFile(*CmdOptions.logFilePtr) - logToNewFile = true - } - if logToNewFile { - myLogFile := config.GetPMLogDir() + config.GetPMLogFile() - log.Println("Logging to specified log file:", myLogFile) - logutil.SetLogging(myLogFile) + + // Reinit logging if required. + if logger.GetLogTag() != "" { + // Use Syslog whenever logTag is specified. + err := logger.InitSysLogger(logger.GetLogTag(), logger.GetLogLevel()) + if err != nil { + fmt.Printf("Failed to initialize SysLog [%v]. Exiting...\n", err) + os.Exit(-1) + } + } else { + tLogFile := logger.DefaultLogFile + if logger.GetLogFile() != "" { + tLogFile = logger.GetLogFile() + } + // NOTE: Even when no log file is specified, and we're using default log + // file name, we still need to call SetPMLogFile() as SVG image file name + // is based on this. Otherwise image and dot files will not have any names + // but only extensions (i.e., they get created as hidden files). + config.SetPMLogFile(tLogFile) + myLogFile += config.GetPMLogFile() + if myLogFile != logger.DefaultLogPath { + myLogFile := filepath.Clean(myLogFile) + logger.Info.Println("Logging to specified log file:", myLogFile) + errList := logger.DeInitLogger() + if len(errList) > 0 { + fmt.Printf("Failed to deinitialize logger, err=[%v]", errList) + os.Exit(-1) + } + err := logger.InitFileLogger(myLogFile, logger.GetLogLevel()) + if err != nil { + fmt.Printf("Failed to initialize logger, err=[%v]", err) + os.Exit(-1) + } + } } - if *CmdOptions.pluginTypePtr != "" { - pluginType := *CmdOptions.pluginTypePtr - var err error + var err error + pluginType := *CmdOptions.pluginTypePtr + if *CmdOptions.pluginsPtr != "" { + jsonStrOrFile := *CmdOptions.pluginsPtr switch cmd { case "list": - err = List(pluginType) + err = ListFromJSONStrOrFile(jsonStrOrFile, + ListOptions{Type: pluginType}) case "run": - pmstatus := RunStatus{} - err = Run(&pmstatus, pluginType) + pmstatus := Plugin{} + runOptions := RunOptions{ + Type: pluginType, + Sequential: *CmdOptions.sequential, + } + // NOTE: When '-plugins' info is passed as str or file, don't use + // Library from config. + // The config file is expected to have some library path, and that + // may not be applicable for this set of inputs. So, set/use + // "Library" value only if it's passed as cmdline argument. + if *CmdOptions.libraryPtr != "" { + runOptions.Library = config.GetPluginsLibrary() + } + err = RunFromJSONStrOrFile(&pmstatus, jsonStrOrFile, runOptions) output.Write(pmstatus) } - if err != nil { - return err + } else if pluginType != "" { + switch cmd { + case "list": + err = ListFromLibrary(pluginType, config.GetPluginsLibrary()) + + case "run": + pmstatus := Plugin{} + err = RunFromLibrary(&pmstatus, pluginType, + RunOptions{Library: config.GetPluginsLibrary(), + Sequential: *CmdOptions.sequential}) + output.Write(pmstatus) } } - return nil + return err } // Usage of Plugin Manager (pm) command. diff --git a/plugin_test.go b/plugin_test.go index e3087fa..8f0adb2 100644 --- a/plugin_test.go +++ b/plugin_test.go @@ -1,4 +1,4 @@ -// Copyright (c) 2021 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 package pm @@ -10,8 +10,35 @@ import ( "testing" "github.com/VeritasOS/plugin-manager/config" + "github.com/VeritasOS/plugin-manager/graph" + logger "github.com/VeritasOS/plugin-manager/utils/log" ) +func initTestLogging( /*t *testing.T*/ ) { + myLogFile := "pm.log" + if config.GetPMLogFile() != "" { + myLogFile = config.GetPMLogFile() + } + if config.GetPMLogDir() != "" { + myLogFile = config.GetPMLogDir() + myLogFile + } + // t.Logf("Logging to specified log file: %s", myLogFile) + errList := logger.DeInitLogger() + if len(errList) > 0 { + fmt.Printf("Failed to deinitialize logger, err=[%v]", errList) + os.Exit(-1) + } + err := logger.InitFileLogger(myLogFile, "DEBUG") + if err != nil { + fmt.Printf("Failed to initialize logger, err=[%v]", err) + os.Exit(-1) + } +} + +func init() { + initTestLogging() +} + func Test_getPluginFiles(t *testing.T) { if os.Getenv("INTEGRATION_TEST") == "RUNNING" { t.Skip("Not applicable while running integration tests.") @@ -89,73 +116,10 @@ func Test_getPluginFiles(t *testing.T) { // }, } + library := config.GetPluginsLibrary() for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - resFiles, resStatus := getPluginFiles(tt.pluginType) - if resStatus != tt.output.err { - t.Errorf("Status: got %+v, want %+v", resStatus, tt.output.err) - } - if reflect.DeepEqual(resFiles, tt.output.pluginFiles) == false { - t.Errorf("File list: got %+v, want %+v", resFiles, tt.output.pluginFiles) - } - }) - } -} - -// TODO: PluginDir is deprecated. Delete below test once it's removed. -func Test_getPluginFiles_PluginDir(t *testing.T) { - if os.Getenv("INTEGRATION_TEST") == "RUNNING" { - t.Skip("Not applicable while running integration tests.") - return - } - myConfigFile := os.Getenv(config.EnvConfFile) - if myConfigFile == "" { - // For case, where tests are run through IDE. - myConfigFile = filepath.FromSlash("./sample/pm.config.deprecated.yaml") - } - t.Logf("Config file: %+v\n", myConfigFile) - config.SetPluginsDir(filepath.FromSlash(filepath.Dir(myConfigFile) + "/library")) - // t.Logf("Config: %+v\n", myConfig) - tests := []struct { - name string - pluginType string - output struct { - pluginFiles []string - err error - } - }{ - { - name: "1 postreboot plugin file", - pluginType: "postreboot", - output: struct { - pluginFiles []string - err error - }{ - pluginFiles: []string{filepath.FromSlash("A/a.postreboot")}, - err: nil, - }, - }, - { - name: "4 prereboot plugin files", - pluginType: "prereboot", - output: struct { - pluginFiles []string - err error - }{ - pluginFiles: []string{ - filepath.FromSlash("A/a.prereboot"), - filepath.FromSlash("B/b.prereboot"), - filepath.FromSlash("C/c.prereboot"), - filepath.FromSlash("D/d.prereboot"), - }, - err: nil, - }, - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - resFiles, resStatus := getPluginFiles(tt.pluginType) + resFiles, resStatus := getPluginFiles(tt.pluginType, library) if resStatus != tt.output.err { t.Errorf("Status: got %+v, want %+v", resStatus, tt.output.err) } @@ -185,12 +149,14 @@ func Test_validateDependencies(t *testing.T) { name: "No dependencies", args: args{ pluginsInfo: Plugins{ - "A/a.test": { + { + Name: "A/a.test", Description: "Applying \"A\" settings", Requires: []string{}, ExecStart: "/bin/echo 'Running A...!'", }, - "B/b.test": { + { + Name: "B/b.test", Description: "Applying \"B\" settings", Requires: []string{}, ExecStart: "/bin/echo \"Running B...\"", @@ -207,12 +173,14 @@ func Test_validateDependencies(t *testing.T) { name: "Single dependency", args: args{ pluginsInfo: Plugins{ - "A/a.test": { + { + Name: "A/a.test", Description: "Applying \"A\" settings", Requires: []string{}, ExecStart: "/bin/echo 'Running A...!'", }, - "B/b.test": { + { + Name: "B/b.test", Description: "Applying \"B\" settings", Requires: []string{ "A/a.test", @@ -231,17 +199,20 @@ func Test_validateDependencies(t *testing.T) { name: "Multiple dependencies", args: args{ pluginsInfo: Plugins{ - "A/a.test": { + { + Name: "A/a.test", Description: "Applying \"A\" settings", Requires: []string{}, ExecStart: "/bin/echo 'Running A...!'", }, - "B/b.test": { + { + Name: "B/b.test", Description: "Applying \"B\" settings", Requires: []string{}, ExecStart: "/bin/echo \"Running B...\"", }, - "C/c.test": { + { + Name: "C/c.test", Description: "Applying \"C\" settings", Requires: []string{ "A/a.test", @@ -262,7 +233,8 @@ func Test_validateDependencies(t *testing.T) { name: "Multi-level dependencies", args: args{ pluginsInfo: Plugins{ - "A/a.test": { + { + Name: "A/a.test", Description: "Applying \"A\" settings", Requires: []string{ "D/d.test", @@ -270,17 +242,20 @@ func Test_validateDependencies(t *testing.T) { }, ExecStart: "/bin/echo 'Running A...!'", }, - "B/b.test": { + { + Name: "B/b.test", Description: "Applying \"B\" settings", Requires: []string{}, ExecStart: "/bin/echo \"Running B...\"", }, - "C/c.test": { + { + Name: "C/c.test", Description: "Applying \"C\" settings", Requires: []string{}, ExecStart: "/bin/echo \"Running C...\"", }, - "D/d.test": { + { + Name: "D/d.test", Description: "Applying \"D\" settings", Requires: []string{ "B/b.test", @@ -301,14 +276,16 @@ func Test_validateDependencies(t *testing.T) { name: "Direct circular dependency", args: args{ pluginsInfo: Plugins{ - "A/a.test": { + { + Name: "A/a.test", Description: "Applying \"A\" settings", Requires: []string{ "B/b.test", }, ExecStart: "/bin/echo 'Running A...!'", }, - "B/b.test": { + { + Name: "B/b.test", Description: "Applying \"B\" settings", Requires: []string{ "A/a.test", @@ -324,7 +301,8 @@ func Test_validateDependencies(t *testing.T) { name: "Requires & Required-by circular dependency", args: args{ pluginsInfo: Plugins{ - "A/a.circular": { + { + Name: "A/a.circular", Description: "Applying \"A\" settings", Requires: []string{ "B/b.circular", @@ -334,7 +312,8 @@ func Test_validateDependencies(t *testing.T) { }, ExecStart: "/bin/echo 'Running A...!'", }, - "B/b.circular": { + { + Name: "B/b.circular", Description: "Applying \"B\" settings", ExecStart: "/bin/echo \"Running B...\"", }, @@ -347,21 +326,24 @@ func Test_validateDependencies(t *testing.T) { name: "Indirect circular dependency", args: args{ pluginsInfo: Plugins{ - "A/a.test": { + { + Name: "A/a.test", Description: "Applying \"A\" settings", Requires: []string{ "B/b.test", }, ExecStart: "/bin/echo 'Running A...!'", }, - "B/b.test": { + { + Name: "B/b.test", Description: "Applying \"B\" settings", Requires: []string{ "C/c.test", }, ExecStart: "/bin/echo \"Running B...\"", }, - "C/c.test": { + { + Name: "C/c.test", Description: "Applying \"C\" settings", Requires: []string{ "A/a.test", @@ -377,7 +359,8 @@ func Test_validateDependencies(t *testing.T) { name: "Dependency not met", args: args{ pluginsInfo: Plugins{ - "A/a.test": { + { + Name: "A/a.test", Description: "Applying \"A\" settings", Requires: []string{ "B/b.test", @@ -393,14 +376,16 @@ func Test_validateDependencies(t *testing.T) { name: "Dependencies not met", args: args{ pluginsInfo: Plugins{ - "A/a.test": { + { + Name: "A/a.test", Description: "Applying \"A\" settings", Requires: []string{ "C/c.test", }, ExecStart: "/bin/echo 'Running A...!'", }, - "B/b.test": { + { + Name: "B/b.test", Description: "Applying \"B\" settings", Requires: []string{ "C/c.test", @@ -440,12 +425,12 @@ func Test_parseUnitFile(t *testing.T) { tests := []struct { name string fileContents string - pluginInfo PluginAttributes + pluginInfo Plugin }{ { name: "Plugin file with no contents", fileContents: "", - pluginInfo: PluginAttributes{}, + pluginInfo: Plugin{}, }, { name: "Plugin file with desc & exec", @@ -453,7 +438,7 @@ func Test_parseUnitFile(t *testing.T) { Description=Applying "A" settings ExecStart=/bin/echo "Running A...!" `, - pluginInfo: PluginAttributes{ + pluginInfo: Plugin{ Description: "Applying \"A\" settings", ExecStart: "/bin/echo \"Running A...!\"", }, @@ -464,7 +449,7 @@ Description=Applying "A" settings # Requires= ExecStart=/bin/echo "Running A...!" `, - pluginInfo: PluginAttributes{ + pluginInfo: Plugin{ Description: "Applying \"A\" settings", ExecStart: "/bin/echo \"Running A...!\"", }, @@ -476,7 +461,7 @@ Description=Applying "D" settings Requires=a.test ExecStart=/bin/echo "Running D...!" `, - pluginInfo: PluginAttributes{ + pluginInfo: Plugin{ Description: "Applying \"D\" settings", Requires: []string{"a.test"}, ExecStart: "/bin/echo \"Running D...!\"", @@ -489,7 +474,7 @@ Description=Applying "D" settings Requires=a.test b.test c.test ExecStart=/bin/echo "Running D...!" `, - pluginInfo: PluginAttributes{ + pluginInfo: Plugin{ Description: "Applying \"D\" settings", Requires: []string{ "a.test", @@ -505,7 +490,7 @@ ExecStart=/bin/echo "Running D...!" Description=Applying "A:B" settings ExecStart=/bin/echo "Running A & B...!" `, - pluginInfo: PluginAttributes{ + pluginInfo: Plugin{ Description: "Applying \"A:B\" settings", ExecStart: "/bin/echo \"Running A & B...!\"", }, @@ -529,7 +514,7 @@ func Test_executePlugins(t *testing.T) { } type want struct { returnStatus bool - psStatus PluginsStatus + psStatus Plugins } tests := []struct { @@ -543,27 +528,28 @@ func Test_executePlugins(t *testing.T) { pluginInfo: Plugins{}, want: want{ returnStatus: true, - // psStatus: PluginsStatus{}, + psStatus: Plugins{}, }, }, { name: "One plugin only with multiple arguments to ExecStart", - pluginInfo: Plugins{"A/a.test": { - Description: "Applying \"A\" settings", - ExecStart: "/usr/bin/top -b -n 1", - }}, + pluginInfo: Plugins{ + { + Name: "A/a.test", + Description: "Applying \"A\" settings", + ExecStart: "/usr/bin/top -b -n 1", + }, + }, want: want{ returnStatus: true, - psStatus: PluginsStatus{ - PluginStatus{ - PluginAttributes: PluginAttributes{ - Description: "Applying \"A\" settings", - FileName: "A/a.test", - ExecStart: "/usr/bin/top -b -n 1", - RequiredBy: []string{}, - Requires: []string{}, - }, - Status: "Succeeded", + psStatus: Plugins{ + { + Name: "A/a.test", + Description: "Applying \"A\" settings", + ExecStart: "/usr/bin/top -b -n 1", + RequiredBy: []string{}, + Requires: []string{}, + Status: "Succeeded", }, }, }, @@ -571,23 +557,22 @@ func Test_executePlugins(t *testing.T) { { name: "One plugin without ExecStart value", pluginInfo: Plugins{ - "A/a.test": { + { + Name: "A/a.test", Description: "Applying \"A\" settings", ExecStart: "", }, }, want: want{ returnStatus: true, - psStatus: PluginsStatus{ - PluginStatus{ - PluginAttributes: PluginAttributes{ - Description: "Applying \"A\" settings", - FileName: "A/a.test", - ExecStart: "", - RequiredBy: []string{}, - Requires: []string{}, - }, - Status: "Succeeded", + psStatus: Plugins{ + { + Description: "Applying \"A\" settings", + Name: "A/a.test", + ExecStart: "", + RequiredBy: []string{}, + Requires: []string{}, + Status: "Succeeded", }, }, }, @@ -595,23 +580,22 @@ func Test_executePlugins(t *testing.T) { { name: "Only one failing plugin", pluginInfo: Plugins{ - "A/a.test": { + { + Name: "A/a.test", Description: "Applying \"A\" settings", ExecStart: "exit 1", }, }, want: want{ returnStatus: false, - psStatus: PluginsStatus{ - PluginStatus{ - PluginAttributes: PluginAttributes{ - Description: "Applying \"A\" settings", - FileName: "A/a.test", - ExecStart: "exit 1", - RequiredBy: []string{}, - Requires: []string{}, - }, - Status: "Failed", + psStatus: Plugins{ + { + Description: "Applying \"A\" settings", + Name: "A/a.test", + ExecStart: "exit 1", + RequiredBy: []string{}, + Requires: []string{}, + Status: "Failed", }, }, }, @@ -619,40 +603,38 @@ func Test_executePlugins(t *testing.T) { { name: "Plugin with dependency", pluginInfo: Plugins{ - "D/d.test": { + { + 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..."`, - }, - "A/a.test": { - Description: "Applying \"A\" settings", - ExecStart: `/bin/echo "Running A..."`, + ExecStart: `/bin/echo Running D...`, }, }, want: want{ returnStatus: true, - psStatus: PluginsStatus{ - PluginStatus{ - PluginAttributes: PluginAttributes{ - Description: "Applying \"A\" settings", - FileName: "A/a.test", - ExecStart: `/bin/echo "Running A..."`, - RequiredBy: []string{"D/d.test"}, - Requires: []string{}, - }, - Status: "Succeeded", - StdOutErr: `Running A...`, - }, - PluginStatus{ - PluginAttributes: PluginAttributes{ - Description: "Applying \"D\" settings", - FileName: "D/d.test", - ExecStart: `/bin/echo "Running D..."`, - RequiredBy: []string{}, - Requires: []string{"A/a.test"}, - }, - Status: "Succeeded", - StdOutErr: `"Running D..."`, + psStatus: Plugins{ + { + Description: "Applying \"A\" settings", + Name: "A/a.test", + ExecStart: `/bin/echo "Running A..."`, + RequiredBy: []string{"D/d.test"}, + Requires: []string{}, + Status: "Succeeded", + StdOutErr: []string{"Running A..."}, + }, + { + Description: "Applying \"D\" settings", + Name: "D/d.test", + ExecStart: `/bin/echo "Running D..."`, + RequiredBy: []string{}, + Requires: []string{"A/a.test"}, + Status: "Succeeded", + StdOutErr: []string{"Running D..."}, }, }, }, @@ -660,28 +642,48 @@ func Test_executePlugins(t *testing.T) { { name: "Plugin with RequiredBy & Requires circular dependency", pluginInfo: Plugins{ - "D/d.test": { + { + Name: "D/d.test", Description: "Applying \"D\" settings", Requires: []string{"A/a.test"}, RequiredBy: []string{"A/a.test"}, ExecStart: "/bin/echo \"Running D...!\"", }, - "A/a.test": { + { + Name: "A/a.test", Description: "Applying \"A\" settings", ExecStart: "/bin/echo \"Running A...!\"", }, }, - want: want{returnStatus: false, psStatus: PluginsStatus{}}, + want: want{ + returnStatus: false, + psStatus: Plugins{ + { + Name: "D/d.test", + Description: "Applying \"D\" settings", + Requires: []string{"A/a.test"}, + RequiredBy: []string{"A/a.test"}, + ExecStart: "/bin/echo \"Running D...!\"", + }, + { + Name: "A/a.test", + Description: "Applying \"A\" settings", + ExecStart: "/bin/echo \"Running A...!\"", + }, + }, + }, }, { name: "Plugin with RequiredBy & Requires dependency", pluginInfo: Plugins{ - "D/d.test": { + { + Name: "D/d.test", Description: "Applying \"D\" settings", Requires: []string{"A/a.test"}, ExecStart: "/bin/echo \"Running D...!\"", }, - "A/a.test": { + { + Name: "A/a.test", Description: "Applying \"A\" settings", RequiredBy: []string{"D/d.test"}, ExecStart: "/bin/echo \"Running A...!\"", @@ -689,28 +691,22 @@ func Test_executePlugins(t *testing.T) { }, want: want{ returnStatus: true, - psStatus: PluginsStatus{ - PluginStatus{ - PluginAttributes: PluginAttributes{ - Description: "Applying \"A\" settings", - FileName: "A/a.test", - ExecStart: "/bin/echo \"Running A...!\"", - RequiredBy: []string{"D/d.test"}, - Requires: []string{}, - }, - Status: "Succeeded", - StdOutErr: "Running A...!\"\"", - }, - PluginStatus{ - PluginAttributes: PluginAttributes{ - Description: "Applying \"D\" settings", - FileName: "D/d.test", - ExecStart: "/bin/echo \"Running D...!\"", - RequiredBy: []string{}, - Requires: []string{"A/a.test"}, - }, - Status: "Succeeded", - StdOutErr: "\"Running D...!\"\"", + psStatus: Plugins{ + { + Description: "Applying \"A\" settings", + Name: "A/a.test", + ExecStart: "/bin/echo \"Running A...!\"", + RequiredBy: []string{"D/d.test"}, + Requires: []string{}, + Status: "Succeeded", + }, + { + Description: "Applying \"D\" settings", + Name: "D/d.test", + ExecStart: "/bin/echo \"Running D...!\"", + RequiredBy: []string{}, + Requires: []string{"A/a.test"}, + Status: "Succeeded", }, }, }, @@ -718,11 +714,13 @@ func Test_executePlugins(t *testing.T) { { name: "Plugin with RequiredBy dependency", pluginInfo: Plugins{ - "D/d.test": { + { + Name: "D/d.test", Description: "Applying \"D\" settings", ExecStart: "/bin/echo \"Running D...!\"", }, - "A/a.test": { + { + Name: "A/a.test", Description: "Applying \"A\" settings", RequiredBy: []string{"D/d.test"}, ExecStart: "/bin/echo \"Running A...!\"", @@ -730,27 +728,21 @@ func Test_executePlugins(t *testing.T) { }, want: want{ returnStatus: true, - psStatus: PluginsStatus{ - PluginStatus{ - PluginAttributes: PluginAttributes{ - Description: "Applying \"A\" settings", FileName: "A/a.test", - ExecStart: "/bin/echo \"Running A...!\"", - RequiredBy: []string{"D/d.test"}, - Requires: []string{}, - }, - Status: "Succeeded", - StdOutErr: "\"Running A...!\"", + psStatus: Plugins{ + { + Description: "Applying \"A\" settings", Name: "A/a.test", + ExecStart: "/bin/echo \"Running A...!\"", + RequiredBy: []string{"D/d.test"}, + Requires: []string{}, + Status: "Succeeded", }, { - PluginAttributes: PluginAttributes{ - Description: "Applying \"D\" settings", - FileName: "D/d.test", - ExecStart: "/bin/echo \"Running D...!\"", - RequiredBy: []string{}, - Requires: []string{"A/a.test"}, - }, - Status: "Succeeded", - StdOutErr: "\"Running D...!\"", + Description: "Applying \"D\" settings", + Name: "D/d.test", + ExecStart: "/bin/echo \"Running D...!\"", + RequiredBy: []string{}, + Requires: []string{"A/a.test"}, + Status: "Succeeded", }, }, }, @@ -758,88 +750,287 @@ func Test_executePlugins(t *testing.T) { { name: "Skip when dependency fails and mark overall status as Failed", pluginInfo: Plugins{ - "D/d.test": { + { + Name: "A/a.test", + Description: "Applying \"A\" settings", + ExecStart: "exit 1", + }, + { + Name: "D/d.test", Description: "Applying \"D\" settings", Requires: []string{"A/a.test"}, ExecStart: "/bin/echo \"Running D...!\"", }, - "A/a.test": { - Description: "Applying \"A\" settings", - ExecStart: "exit 1", - }, }, want: want{ returnStatus: false, - psStatus: PluginsStatus{ - PluginStatus{ - PluginAttributes: PluginAttributes{ - Description: "Applying \"A\" settings", - FileName: "A/a.test", - ExecStart: "exit 1", - RequiredBy: []string{"D/d.test"}, - }, - Status: "Failed", - }, - PluginStatus{ - PluginAttributes: PluginAttributes{ - Description: "Applying \"D\" settings", - Requires: []string{"A/a.test"}, - ExecStart: "/bin/echo \"Running D...!\"", - FileName: "D/d.test", - RequiredBy: []string{}, - }, - Status: "Skipped", + psStatus: Plugins{ + { + Name: "A/a.test", + Description: "Applying \"A\" settings", + ExecStart: "exit 1", + Status: "Failed", + }, + { + Name: "D/d.test", + Description: "Applying \"D\" settings", + ExecStart: "/bin/echo \"Running D...!\"", + Requires: []string{"A/a.test"}, + RequiredBy: []string{}, + Status: "Skipped", }, }, }, }, } - initGraphConfig(config.GetPMLogFile()) + graph.InitGraphConfig(config.GetPMLogFile()) for _, tt := range tests { // Test Sequential as well as sequential execution for _, tt.sequential = range []bool{false, true} { t.Run(tt.name+fmt.Sprintf("(sequential=%v)", tt.sequential), func(t *testing.T) { - npInfo := normalizePluginsInfo(tt.pluginInfo) - var result PluginsStatus - res := executePlugins(&result, npInfo, tt.sequential) + 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", result) - for i := range result { - // 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].PluginAttributes, - // tt.want.psStatus[i].PluginAttributes) == false { - // t.Errorf("Plugins PluginAttributes: got %+v, want %+v", - // result[i].PluginAttributes, - // tt.want.psStatus[i].PluginAttributes) - // } - if reflect.DeepEqual(result[i].Status, + // t.Logf("result of all plugins: %+v", tt.pluginInfo) + for i := range tt.pluginInfo { + if reflect.DeepEqual(tt.pluginInfo[i].Status, tt.want.psStatus[i].Status) == false { t.Errorf("Plugins %s Status: got %+v, want %+v", - result[i].FileName, - result[i].Status, tt.want.psStatus[i].Status) + tt.pluginInfo[i].Name, + tt.pluginInfo[i].Status, tt.want.psStatus[i].Status) + } + 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) } - // 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) - // } - // } } }, ) } } } + +func Test_getPluginsInfoFromJSONStrOrFile(t *testing.T) { + if os.Getenv("INTEGRATION_TEST") == "RUNNING" { + t.Skip("Not applicable while running integration tests.") + return + } + + type args struct { + jsonStrOrFile string + } + tests := []struct { + name string + args args + want Plugin + wantErr bool + }{ + { + name: "Plugins in JSON String", + args: args{jsonStrOrFile: ` + { + "Plugins": [ + { + "Name": "plugin1", + "Description": "plugin 1 description...", + "ExecStart": "echo command to run..." + }, + { + "Name": "plugin2", + "Description": "plugin 2 description...", + "ExecStart": "echo command to run..." + }, + { + "Name": "plugin3", + "Description": "Plugin 3 depends on 1 and 2", + "ExecStart": "echo Running plugin 3", + "Requires": [ + "plugin1", + "plugin2" + ] + } + ] + }`, + }, + want: Plugin{ + Plugins: Plugins{ + { + Name: "plugin1", + Description: "plugin 1 description...", + ExecStart: "echo command to run...", + }, + { + Name: "plugin2", + Description: "plugin 2 description...", + ExecStart: "echo command to run...", + }, + { + Name: "plugin3", + Description: "Plugin 3 depends on 1 and 2", + ExecStart: "echo Running plugin 3", + Requires: []string{"plugin1", "plugin2"}, + }, + }, + }, + wantErr: false, + }, + { + name: "Plugins in JSON file", + args: args{jsonStrOrFile: "./sample/plugins-prereboot.json"}, + want: Plugin{ + Plugins: Plugins{ + { + Name: "A/a.prereboot", + Description: "Applying \"A\" settings", + ExecStart: "/usr/bin/ls -l -t", + Requires: []string{ + "C/c.prereboot", + "D/d.prereboot", + }, + }, + { + Name: "B/b.prereboot", + Description: "Applying \"B\" settings...", + ExecStart: "/bin/echo \"Running B...\"", + }, + { + Name: "C/c.prereboot", + Description: "Applying \"C\" settings...", + ExecStart: "/bin/echo \"Running C...\"", + }, + { + Name: "D/d.prereboot", + Description: "Applying \"D\" settings...", + ExecStart: "/bin/echo 'Running D...!'", + Requires: []string{"B/b.prereboot"}, + }, + }, + }, + wantErr: false, + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + got, err := getPluginsInfoFromJSONStrOrFile(tt.args.jsonStrOrFile) + if (err != nil) != tt.wantErr { + t.Errorf("getPluginsInfoFromJSONStrOrFile() error = %v, wantErr %v", err, tt.wantErr) + return + } + if !reflect.DeepEqual(got, tt.want) { + t.Errorf("getPluginsInfoFromJSONStrOrFile() = %v, want %v", got, tt.want) + } + }) + } +} + +func Test_normalizePluginsInfo(t *testing.T) { + type args struct { + pluginsInfo Plugins + } + tests := []struct { + name string + args args + want Plugins + }{ + { + name: "A requires B", + args: args{ + pluginsInfo: Plugins{ + { + Name: "A", + Description: "Plugin A", + Requires: []string{"B"}, + }, + { + Name: "B", + Description: "Plugin B", + }, + }, + }, + want: Plugins{ + { + Name: "A", + Description: "Plugin A", + Requires: []string{"B"}, + }, + { + Name: "B", + Description: "Plugin B", + RequiredBy: []string{"A"}, + }, + }, + }, + { + name: "A requires B with A in later index", + args: args{ + pluginsInfo: Plugins{ + { + Name: "B", + Description: "Plugin B", + }, + { + Name: "A", + Description: "Plugin A", + Requires: []string{"B"}, + }, + }, + }, + want: Plugins{ + { + Name: "B", + Description: "Plugin B", + RequiredBy: []string{"A"}, + }, + { + Name: "A", + Description: "Plugin A", + Requires: []string{"B"}, + }, + }, + }, + { + name: "B requires A", + args: args{ + pluginsInfo: Plugins{ + { + Name: "A", + Description: "Plugin A", + }, + { + Name: "B", + Description: "Plugin B", + Requires: []string{"A"}, + }, + }, + }, + want: Plugins{ + { + Name: "A", + Description: "Plugin A", + RequiredBy: []string{"B"}, + }, + { + Name: "B", + Description: "Plugin B", + Requires: []string{"A"}, + }, + }, + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + if got := normalizePluginsInfo(tt.args.pluginsInfo); !reflect.DeepEqual(got, tt.want) { + t.Errorf("normalizePluginsInfo() = %+v, want %+v", got, tt.want) + } + }) + } +} diff --git a/sample/plugins-prereboot.json b/sample/plugins-prereboot.json new file mode 100644 index 0000000..e3ae30c --- /dev/null +++ b/sample/plugins-prereboot.json @@ -0,0 +1,31 @@ +{ + "Plugins": [ + { + "Name": "A/a.prereboot", + "Description": "Applying \"A\" settings", + "ExecStart": "/usr/bin/ls -l -t", + "Requires": [ + "C/c.prereboot", + "D/d.prereboot" + ] + }, + { + "Name": "B/b.prereboot", + "Description": "Applying \"B\" settings...", + "ExecStart": "/bin/echo \"Running B...\"" + }, + { + "Name": "C/c.prereboot", + "Description": "Applying \"C\" settings...", + "ExecStart": "/bin/echo \"Running C...\"" + }, + { + "Name": "D/d.prereboot", + "Description": "Applying \"D\" settings...", + "ExecStart": "/bin/echo 'Running D...!'", + "Requires": [ + "B/b.prereboot" + ] + } + ] +} \ No newline at end of file diff --git a/sample/plugins-preupgrade.yaml b/sample/plugins-preupgrade.yaml new file mode 100755 index 0000000..d8bda75 --- /dev/null +++ b/sample/plugins-preupgrade.yaml @@ -0,0 +1,10 @@ +name: preupgrade +plugins: + - name: A/a.preupgrade + description: Checking for "A" settings + execstart: /bin/echo "Checking A..." + requires: + - D/d.preupgrade + - name: D/d.preupgrade + description: Checking for "D" settings... + execstart: $PM_LIBRARY/D/preupgrade.sh diff --git a/sample/pm.config.deprecated.yaml b/sample/pm.config.deprecated.yaml deleted file mode 100644 index 3347f57..0000000 --- a/sample/pm.config.deprecated.yaml +++ /dev/null @@ -1,8 +0,0 @@ ---- -# Copyright (c) 2020 Veritas Technologies LLC. All rights reserved. IP63-2828-7171-04-15-9 -pluginmanager: - # `plugin dir` is the location where plugins library is expected to be present - plugin dir: "../sample/library" - log dir: "./" - log file: "pm" -... diff --git a/sample/pm.config.yaml b/sample/pm.config.yaml index 28565cb..0cc4f70 100644 --- a/sample/pm.config.yaml +++ b/sample/pm.config.yaml @@ -1,5 +1,5 @@ --- -# Copyright (c) 2020 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 pluginmanager: # `library` is the location where plugins directories containing plugins are expected to be present library: "../sample/library" @@ -9,4 +9,6 @@ pluginmanager: # I.e., The format of the log file generated would be: "..log" # Example: The below value results in following log file: pm.2020-01-13T16:11:58.6006565-08:00.log log file: "pm" + # 'log level' indicates the type (ERROR, WARNING, INFO, DEBUG) of log messages to be logged. Setting a particular log-level say "INFO", logs all messages of that type (i.e., "INFO") as well as the previous messages types (i.e., ERROR and WARNING). + log level: "DEBUG" ... diff --git a/sample/pm.py b/sample/pm.py new file mode 100644 index 0000000..80a75ca --- /dev/null +++ b/sample/pm.py @@ -0,0 +1,136 @@ +# Copyright (c) 2024 Veritas Technologies LLC. All rights reserved. IP63-2828-7171-04-15-9 + +# A python library for invoking Plugin Manager (PM) to run plugins in parallel while specifying dependencies between plugins. + +import logging +import os +import sys +from pathlib import Path + +DEFAULT_LOG_DIR = "/var/log/asum/" + +logger = logging.getLogger() + + +def help(exit_status=None): + """ Prints help on command line """ + cmd = Path(__file__).name + print(f""" +Plugin Manager allows one to run multiple commands in parallel while specifying any dependencies among them. + +Usage: + + {cmd} --plugins + [-type <"Type of plugin e.g. 'precheck'">] + [--json-output-file <"path/to/output/file.json">]) + +Where, + output-format The format of output to display the results. Supported output formats are 'json', 'yaml'. + output-file path to file to write the results. + library path to plugins' library contains plugin directories and + plugin files. + Default: Current directory of script. I.e., {os.path.dirname(os.path.abspath(__file__))}. + Library directory structure: + $PM_LIBRARY/$pluginDir/$pluginFile.$pluginType + plugins plugins and its dependencies.""") + + print(""" + Format: + { + "plugin-name": { + "Description": "Description of plugin", + "ExecStart": "command to run", + "Requires": "[space separated plugins to be run before current one]", + "RequiredBy": "[space separated plugins that want current plugin to be run before them.]" + } + } + type type of plugins e.g. "precheck". + +Example: + +$ plugins='{"plugin1": {"Description": "plugin 1 description...", "ExecStart": "echo command to run..."}, "plugin2": {"Description": "plugin 2 description...", "ExecStart": "echo command to run..."}, "plugin3": {"Description": "Plugin 3 depends on 1 and 2", "ExecStart": "echo Running plugin 3", "Requires": [ "plugin1" , "plugin2"]}}' + """) + + print(f'''$ {cmd} --plugins "$plugins" --log-dir /tmp --json-output-file /tmp/ab.json + ''') + + if exit_status != None: + exit(exit_status) + + +def init_logging(log_file_path): + log_dir = os.path.dirname(log_file_path) + if not os.path.exists(log_dir): + os.makedirs(log_dir) + logging.basicConfig(filename=log_file_path, + encoding='utf-8', level=logging.DEBUG) + print(f"Log file: {log_file_path}") + + +if __name__ == "__main__": + log_file = None + output_file = None + output_format = None + plugins = None + type = None + + import argparse + parser = argparse.ArgumentParser() + parser.add_argument("--plugins", + type=str, + help="Plugins' and its dependencies in json format as a string or in a file (Ex: './plugins.json')") + parser.add_argument("--library", + default=os.path.dirname(os.path.abspath(__file__)), + type=str, + help="Path to plugins library.") + parser.add_argument("--type", + help="Type of plugin.") + parser.add_argument("--display-stdout", + action=argparse.BooleanOptionalAction, + help="Display plugins details and status on console/stdout.") + parser.add_argument("--log-file", + default=DEFAULT_LOG_DIR + Path(__file__).stem + ".log", + type=str, + help="Path to the log file.") + parser.add_argument("--log-level", + choices=['ERROR', 'WARNING', 'INFO', 'DEBUG'], + default="INFO", + type=str, + help="Log level.") + parser.add_argument("--output-file", + help="Name of the file to write the results.") + parser.add_argument("--output-format", + choices=['json', 'yaml'], + default="json", + help="The format of output to display the results.") + args = parser.parse_args() + + init_logging(args.log_file) + + logger.debug("Args:") + logger.debug(args) + + sys.path.insert(0, os.path.join(os.path.dirname( + os.path.abspath(__file__)), "../../", "opt/veritas/appliance/bin")) + import pm + + status, plugins_result = pm.run( + display_stdout=args.display_stdout, + plugins=args.plugins, + type=args.type, + library=args.library, + log_file=args.log_file, + log_level=args.log_level, + output_file=args.output_file, + output_format=args.output_format) + logger.debug("Status:") + logger.debug(status) + if status != 0: + logger.error("Failed to run specified plugins.") + print("Failed to run specified plugins.") + exit(1) + logger.info("Successfully ran specified plugins.") + logger.info("Plugins Status") + logger.info(plugins_result) + # print("Plugins Status") + # print(plugins_result) diff --git a/types/runtime/runtime.go b/types/runtime/runtime.go new file mode 100644 index 0000000..5dfb774 --- /dev/null +++ b/types/runtime/runtime.go @@ -0,0 +1,12 @@ +// Copyright (c) 2024 Veritas Technologies LLC. All rights reserved. IP63-2828-7171-04-15-9 + +package runtime + +import "time" + +// RunTime to hold start time, end time and duration of a plugin and/or plugin manager execution. +type RunTime struct { + StartTime time.Time + EndTime time.Time + Duration time.Duration +} diff --git a/types/status/status.go b/types/status/status.go new file mode 100644 index 0000000..dabd34a --- /dev/null +++ b/types/status/status.go @@ -0,0 +1,15 @@ +// Copyright (c) 2024 Veritas Technologies LLC. All rights reserved. IP63-2828-7171-04-15-9 + +package status + +// Status of plugin execution used for displaying to user on console. +const ( + // Fail + Fail = "Failed" + // Ok means success state. + Ok = "Succeeded" + // Skip + Skip = "Skipped" + // Start indicate process started / is running. + Start = "Starting" +) diff --git a/types/types.go b/types/types.go new file mode 100644 index 0000000..1270608 --- /dev/null +++ b/types/types.go @@ -0,0 +1,24 @@ +// Copyright (c) 2024 Veritas Technologies LLC. All rights reserved. IP63-2828-7171-04-15-9 + +// Package types defines new plugin manager types. +package types + +import "github.com/VeritasOS/plugin-manager/types/runtime" + +// Plugin is plugin's info: name, description, cmd to run, status, stdouterr. +type Plugin struct { + Name string + Description string + RequiredBy []string + Requires []string + ExecStart string + Plugins Plugins + Library string + // TODO: Add Percentage to get no. of pending vs. completed run of plugins. + RunTime runtime.RunTime + Status string + StdOutErr []string +} + +// Plugins is a list of plugins' info. +type Plugins []*Plugin diff --git a/utils/log/log.go b/utils/log/log.go index f5c09dc..cc89b91 100644 --- a/utils/log/log.go +++ b/utils/log/log.go @@ -1,57 +1,567 @@ -// 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 -package log +package logger import ( + "errors" + "flag" "fmt" + "io" + "io/ioutil" "log" + "log/syslog" "os" "path/filepath" + "strings" + "sync" "time" ) -// PrintNLog prints to console as well as logs to file. -func PrintNLog(format string, a ...interface{}) { - log.Printf(format, a...) - fmt.Printf(format, a...) +// options contains command line or config file parameters/options/fields related to logging. +var options struct { + // logDir indicates the location for writing log file. + logDir string + + // logFile indicates the log file name to write to in the logDir location. + logFile string + + // logLevel indicates the type (ERROR, WARNING, INFO, DEBUG) of log messages to be logged. Setting a particular log-level say "INFO", logs all messages of that type (i.e., "INFO") as well as the previous messages types (i.e., ERROR and WARNING). + logLevel string + + // syslogTag indicates the log tag to write into syslog. + syslogTag string } -// PrintNLogError prints to console and log file along with returning the -// message in error format. -func PrintNLogError(format string, a ...interface{}) error { - err := fmt.Errorf(format, a...) - log.Printf("ERROR: %v", err.Error()) - fmt.Fprintf(os.Stderr, "ERROR: %v\n", err.Error()) - return err +// Type is used to track logger type +type Type int + +// Below logger types are supported. +const ( + FileLog = 1 << iota + SysLog +) + +var progname = filepath.Base(os.Args[0]) + +// DefaultLogDir used before reading conf file or cmdline params, and could be overridden by conf file or cmdline params. +var DefaultLogDir = "/var/log/asum/" + +// DefaultLogFile used before reading conf file or cmdline params, and could be overriden by conf file or cmdline params +var DefaultLogFile = progname + ".log" + +// DefaultLogPath used in case if path to log file is not specified in config or cmdline. +var DefaultLogPath = DefaultLogDir + DefaultLogFile + +// DefaultLogLevel used in case if it's not specified in config or cmdline. +var DefaultLogLevel = "INFO" + +const ( + syslogConfig = "/etc/rsyslog.d/10-vxos-asum.conf" + syslogFacility = syslog.LOG_LOCAL0 +) + +// SyslogTagPrefix defines tag name for syslog. +const SyslogTagPrefix = "vxos-asum@" + +// Config is used to track user defined configuration. +type Config struct { + loggerType Type + level string + module string + logfilePath string +} + +// FileLogConfig Setup FileLog Config +func FileLogConfig(level, file, module string) Config { + return Config{loggerType: FileLog, level: level, module: module, logfilePath: file} } -// PrintNLogWarning prints warning message to console and log file along with -// returning the message in error format. -func PrintNLogWarning(format string, a ...interface{}) error { - err := fmt.Errorf(format, a...) - log.Printf("WARNING: %v", err.Error()) - fmt.Fprintf(os.Stderr, "WARNING: %v\n", err.Error()) +// SyslogConfig Setup SysLog Config +func SyslogConfig(level, module string) Config { + return Config{loggerType: SysLog, level: level, module: module, logfilePath: ""} +} + +// ConsoleLogger will print message on screen and write to log file +// The message will always be printed regardless the log level +// The writing action depends on the log level +type ConsoleLogger struct { + prefix string + logger *log.Logger +} + +// Logger implements functions for all log levels +type Logger struct { + //Logger for log Debug messages. + debug *log.Logger + //Logger for log Info messages. + info *log.Logger + //Logger for log Warning messages. + warning *log.Logger + //Logger for log Error messages. + error *log.Logger +} + +// Debug returns the debug logger +func (logger *Logger) Debug() *log.Logger { + return logger.debug +} + +// Info returns the info logger +func (logger *Logger) Info() *log.Logger { + return logger.info +} + +// Warning returns the warning logger +func (logger *Logger) Warning() *log.Logger { + return logger.warning +} + +// Error returns te error logger +func (logger *Logger) Error() *log.Logger { + return logger.error +} + +// Get returns the object of logger type +func Get() *Logger { + return &Logger{debug: Debug, info: Info, warning: Warning, error: Error} +} + +// Printf prints message in console and writes to log file +func (consoleLog *ConsoleLogger) Printf(msg string, args ...interface{}) { + if !strings.HasSuffix(msg, "\n") { + msg += "\n" + } + fmt.Printf(msg, args...) + str := consoleLog.prefix + msg + consoleLog.logger.Printf(str, args...) +} + +// PrintNReturnError calls Printf and returns wrapped message as error +func (consoleLog *ConsoleLogger) PrintNReturnError(msg string, args ...interface{}) error { + err := fmt.Errorf(msg, args...) + consoleLog.Printf(msg, args...) return err } -// SetLogging sets the logfile for this program. -// To handle log rotation, the specified myLogFile would be suffixed with -// the current date before the log file extension. -// Ex: If myLogFile := "/log/asum/pm", then the logfile used for -// logging would be "/log/asum/pm.20181212235500.0000.log". -func SetLogging(myLogFile string) error { - ts := time.Now().Format(time.RFC3339Nano) +// LogHandle the log handle interface +type LogHandle interface { + Write(p []byte) (n int, err error) + Close() error +} + +// CloseLogHandle closes log handler +func CloseLogHandle(handle LogHandle) error { + if handle != nil { + err := handle.Close() + if err == nil { + handle = nil + } + return err + } + return nil +} + +// FileLogHandle the file log handler +type FileLogHandle struct { + logFile *os.File + hostname *string +} + +func (handle *FileLogHandle) Write(p []byte) (n int, err error) { + t := time.Now() + // required timestamp format is based on both rfc3339 and ISO 8601 + // YYYY-MM-DDThh:mm:ss.mmm+04:00 + prefix := t.Format(strings.Replace(time.RFC3339, "Z", ".000-", 1)) + if handle.hostname != nil { + prefix = prefix + " " + *handle.hostname + " " + } + + buf := []byte(prefix) + buf = append(buf, p...) + + n, err = handle.logFile.Write(buf) + if err != nil || n != len(buf) { + return n, err + } + // io.MultiWriter will verify write count, return original bytes without prefixes + return len(p), nil +} + +// Close close the FileLog handler. +func (handle *FileLogHandle) Close() error { + if handle.logFile != nil { + return handle.logFile.Close() + } + return nil +} + +var ( + //ConsoleDebug logger for console and log Debug messages. + ConsoleDebug ConsoleLogger + //ConsoleInfo logger for console and log Info messages. + ConsoleInfo ConsoleLogger + //ConsoleWarning logger for console and log Warning messages. + ConsoleWarning ConsoleLogger + //ConsoleError logger for console and log Error messages. + ConsoleError ConsoleLogger + //Debug logger for logging Debug messages. + Debug *log.Logger + //Info logger for logging Info messages. + Info *log.Logger + //Warning logger for logging Warning messages. + Warning *log.Logger + //Error logger for logging Error messages. + Error *log.Logger + fileLogHandle LogHandle + syslogDebugHandle LogHandle + syslogInfoHandle LogHandle + syslogWarnHandle LogHandle + syslogErrorHandle LogHandle + + fOpenFile = os.OpenFile + fCloseLogHandle = CloseLogHandle + fHostname = os.Hostname + fMkdirAll = os.MkdirAll + fNewSyslogger = func(priority syslog.Priority, tag string) (LogHandle, error) { + return syslog.New(priority, tag) + } + + // Lock to ensure thread safe behaviour when initializing and de-initializing the singleton logger object + singleLogger = sync.Mutex{} +) + +// IsFileLogger returns true if file log is initialized (and not syslog) +func IsFileLogger() bool { + if fileLogHandle != nil { + return true + } + return false +} + +// initLogger sets logger for all supported log levels +func initLogger( + traceHandle io.Writer, + infoHandle io.Writer, + warningHandle io.Writer, + errorHandle io.Writer) { + + Debug = log.New(traceHandle, + "DEBUG: ", + 0) + + Info = log.New(infoHandle, + "INFO: ", + 0) + + Warning = log.New(warningHandle, + "WARNING: ", + 0) + + Error = log.New(errorHandle, + "ERROR: ", + 0) + + ConsoleDebug = ConsoleLogger{"[DEBUG] ", Debug} + ConsoleInfo = ConsoleLogger{"[INFO] ", Info} + ConsoleWarning = ConsoleLogger{"[WARNING] ", Warning} + ConsoleError = ConsoleLogger{"[ERROR] ", Error} +} + +func initFileLogHandle(myLogFile string) error { + if fileLogHandle != nil { + return nil + } + + var err error myLogFile = filepath.Clean(myLogFile) - tLogFile := myLogFile + "." + ts + ".log" + myLogFileNoExt := myLogFile + if strings.HasSuffix(myLogFile, ".log") { + myLogFileNoExt = strings.TrimSuffix(myLogFile, filepath.Ext(myLogFile)) + } + ts := time.Now().Format(time.RFC3339Nano) + logFile := myLogFileNoExt + "." + ts + ".log" - fh, err := os.OpenFile(tLogFile, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0666) + _, err = os.Stat(logFile) + if os.IsNotExist(err) { + logFileDir := filepath.Dir(logFile) + err = fMkdirAll(logFileDir, 0755) + if err != nil { + return fmt.Errorf("os.MkdirAll(%s) failed", logFileDir) + } + } + + file, err := fOpenFile(logFile, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0600) + if err != nil { + return err + } + hostname, err := fHostname() if err != nil { - log.Printf("os.OpenFile(%s) Error: %s", tLogFile, err.Error()) - return PrintNLogError("Failed to open log file: %s", tLogFile) + hostname = "unknown" + } + fh := FileLogHandle{} + fh.logFile = file + fh.hostname = &hostname + fileLogHandle = &fh + + fmt.Println("Log:", logFile) + return nil +} + +func initSyslogHandle(syslogTag string) (err error) { + if syslogDebugHandle == nil { + syslogDebugHandle, err = fNewSyslogger(syslogFacility|syslog.LOG_DEBUG, syslogTag) + if err != nil { + syslogDebugHandle = nil + return errors.New("creating syslog debug handle failed") + } + } + + if syslogInfoHandle == nil { + syslogInfoHandle, err = fNewSyslogger(syslogFacility|syslog.LOG_INFO, syslogTag) + if err != nil { + syslogInfoHandle = nil + return errors.New("creating syslog info handle failed") + } + } + + if syslogWarnHandle == nil { + syslogWarnHandle, err = fNewSyslogger(syslogFacility|syslog.LOG_WARNING, syslogTag) + if err != nil { + syslogWarnHandle = nil + return errors.New("creating syslog warning handle failed") + } + } + if syslogErrorHandle == nil { + syslogErrorHandle, err = fNewSyslogger(syslogFacility|syslog.LOG_ERR, syslogTag) + if err != nil { + syslogErrorHandle = nil + return errors.New("creating syslog error handle failed") + } } - // defer fh.Close() - log.SetOutput(fh) - fmt.Println("Log:", tLogFile) - log.Println("CMD:", os.Args[:]) return nil } + +// InitLogging initializes logging to use syslog when its config exists, or to use file logging automatically. This setting might be overridden after reading config or cmdline parameters and by calling InitializeLogger(). +func InitLogging() { + // Use syslog until the config file is read. + // If syslog initialization fails, file logging will be used. + useFileLog := true + if IsSysLogConfigPresent() { + useFileLog = false + module := progname + "-" + os.Args[1] + err := InitSysLogger(module, DefaultLogLevel) + if err != nil { + fmt.Printf("Failed to initialize SysLog for logging [%#v]. Proceeding with FileLog...\n", err) + useFileLog = true + } + } + if useFileLog { + // NOTE: while running tests, the path of binary would be in `/tmp/`, + // 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). + + // Update default values with specified env values. + logDir := os.Getenv("PM_LOG_DIR") + if logDir != "" { + DefaultLogDir = filepath.Clean(logDir) + } + logFile := os.Getenv("PM_LOG_FILE") + if logFile != "" { + DefaultLogFile = filepath.Clean(logFile) + } + // INFO: Update DefaultLogPath in case if values are passed via env, + // so that comparison at a later path succeeds. + DefaultLogPath = filepath.Clean(DefaultLogDir + string(os.PathSeparator) + DefaultLogFile) + + logLevel := os.Getenv("PM_LOG_LEVEL") + if logLevel != "" { + DefaultLogLevel = logLevel + } + + err := InitFileLogger(DefaultLogPath, DefaultLogLevel) + if err != nil { + fmt.Printf("Failed to initialize file logger [%#v].\n", err) + os.Exit(1) + } + } +} + +// InitializeLogger initializes customized file logger or syslog logger with given log config +func InitializeLogger(config Config) error { + singleLogger.Lock() + defer singleLogger.Unlock() + var debugWriter, infoWriter, warnWriter, errWriter io.Writer + if config.loggerType == FileLog { + if err := initFileLogHandle(config.logfilePath); err != nil { + return err + } + debugWriter = fileLogHandle + infoWriter = fileLogHandle + warnWriter = fileLogHandle + errWriter = fileLogHandle + } else { + syslogTag := config.module + if strings.Index(syslogTag, SyslogTagPrefix) != 0 { + // all flex appliance syslog tag starts with same prefix, in case we could filter the logs + syslogTag = SyslogTagPrefix + syslogTag + } + if err := initSyslogHandle(syslogTag); err != nil { + return err + } + debugWriter = syslogDebugHandle + infoWriter = syslogInfoHandle + warnWriter = syslogWarnHandle + errWriter = syslogErrorHandle + } + + switch config.level { + case "DEBUG": + // Enabled logging levels: debug, info, warning, error + initLogger(debugWriter, infoWriter, warnWriter, errWriter) + case "INFO": + // Enabled logging levels: info, warning, error + initLogger(ioutil.Discard, infoWriter, warnWriter, errWriter) + case "WARNING": + // Enabled logging levels: warning, error + initLogger(ioutil.Discard, ioutil.Discard, warnWriter, errWriter) + default: + // Enabled logging levels: error only + initLogger(ioutil.Discard, ioutil.Discard, ioutil.Discard, errWriter) + } + Info.Println("CMD:", os.Args[:]) + return nil +} + +// InitFileLogger initializes logger with given log level. +func InitFileLogger(logFile, logLevel string) error { + return InitializeLogger(FileLogConfig(logLevel, logFile, "")) +} + +// IsSysLogConfigPresent indicates whether syslog config is present. +func IsSysLogConfigPresent() bool { + _, err := os.Stat(syslogConfig) + if err != nil { + return false + } + return true +} + +// InitSysLogger initializes logger with given log level. +func InitSysLogger(module, logLevel string) error { + // Make sure the config file exist + if !IsSysLogConfigPresent() { + return fmt.Errorf("syslog config file %v is not present", syslogConfig) + } + return InitializeLogger(SyslogConfig(logLevel, module)) +} + +// DeInitLogger closes the log file and syslog handler +func DeInitLogger() []error { + singleLogger.Lock() + defer singleLogger.Unlock() + var errList []error + closeErr := fCloseLogHandle(fileLogHandle) + if closeErr != nil { + errList = append(errList, closeErr) + } + fileLogHandle = nil + + closeErr = fCloseLogHandle(syslogDebugHandle) + if closeErr != nil { + errList = append(errList, closeErr) + } + syslogDebugHandle = nil + + closeErr = fCloseLogHandle(syslogInfoHandle) + if closeErr != nil { + errList = append(errList, closeErr) + } + syslogInfoHandle = nil + + closeErr = fCloseLogHandle(syslogWarnHandle) + if closeErr != nil { + errList = append(errList, closeErr) + } + syslogWarnHandle = nil + + closeErr = fCloseLogHandle(syslogErrorHandle) + if closeErr != nil { + errList = append(errList, closeErr) + } + syslogErrorHandle = nil + + return errList +} + +// RegisterCommandOptions registers the command options related to the log options. +func RegisterCommandOptions(f *flag.FlagSet, defaultParams map[string]string) { + defaultLogDir, ok := defaultParams["log-dir"] + if !ok { + defaultLogDir = DefaultLogDir + } + defaultLogFile, ok := defaultParams["log-file"] + if !ok { + defaultLogFile = DefaultLogFile + } + defaultLogLevel, ok := defaultParams["log-level"] + if !ok { + defaultLogLevel = DefaultLogLevel + } + f.StringVar( + &options.logDir, + "log-dir", + defaultLogDir, + "Directory for the log file.", + ) + f.StringVar( + &options.logFile, + "log-file", + defaultLogFile, + "Name of the log file.", + ) + f.StringVar( + &options.logLevel, + "log-level", + defaultLogLevel, + "Log level ('ERROR', 'WARNING', 'INFO', 'DEBUG').", + ) + f.StringVar( + &options.syslogTag, + "log-tag", + "", + "Syslog tag name.", + ) +} + +// GetLogDir provides location for storing logs. +func GetLogDir() string { + // Clean path only if it's not empty, as otherwise it'll convert empty value to current directory. + if options.logDir != "" { + return filepath.FromSlash(filepath.Clean(options.logDir) + + string(os.PathSeparator)) + } + return "" +} + +// GetLogFile provides name of logfile. +func GetLogFile() string { + return options.logFile +} + +// GetLogLevel provides log level. +func GetLogLevel() string { + switch options.logLevel { + case "ERROR": + case "WARNING": + case "INFO": + case "DEBUG": + default: + options.logLevel = DefaultLogLevel + } + return options.logLevel +} + +// GetLogTag provides syslog tag name. +func GetLogTag() string { + return options.syslogTag +} diff --git a/utils/os/os.go b/utils/os/os.go index 202251f..fc7e92f 100644 --- a/utils/os/os.go +++ b/utils/os/os.go @@ -1,12 +1,16 @@ -// 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 -// Package os contains pointers to os package functions so as to help -// in unit testing (mocking). +// Package os contains some utility functions as well as pointers to os package +// functions so as to help in unit testing (mocking). package os import ( "os" "os/exec" + "strings" + "sync" + + logger "github.com/VeritasOS/plugin-manager/utils/log" ) // ExecCommand a pointer to exec.Command @@ -22,4 +26,45 @@ var ( // OsMkdirAll is a pointer to os.MkdirAll OsMkdirAll = os.MkdirAll + + // OsEnviron is a pointer to os.Environ + OsEnviron = os.Environ + + // Map maintaining os environment variables. + envMap = map[string]string{} + isEnvMapInit sync.Once ) + +// EnvMap returns OS environment variable values in a map. +// Any ENV variables set after this program is started (or func is called first time) would not be part of the map. +func EnvMap() map[string]string { + logger.Debug.Printf("In EnvMap()") + defer logger.Debug.Printf("Exiting EnvMap()") + // If already initialized once, return that map. + isEnvMapInit.Do(initEnvMap) + // Make copy as maps are passed/returned as reference. + // INFO: maps.Copy requires 1.21 golang version on builder. + // maps.Copy(em, envMap) + em := make(map[string]string, len(envMap)) + for k, v := range envMap { + em[k] = v + } + return em +} + +func initEnvMap() { + logger.Debug.Printf("In initEnvMap()") + defer logger.Debug.Printf("Exiting initEnvMap()") + + for _, keyval := range OsEnviron() { + // INFO: strings.Cut requires 1.18 golang version on builder. + // key, val, found := strings.Cut(keyval, "=") + fields := strings.SplitN(keyval, "=", 2) + if len(fields) == 2 { + key := fields[0] + val := fields[1] + // logger.Debug.Printf("%v (key) = %v (value)", key, val) + envMap[key] = val + } + } +} diff --git a/utils/output/output.go b/utils/output/output.go index 634d8a0..1aa5c01 100644 --- a/utils/output/output.go +++ b/utils/output/output.go @@ -1,4 +1,4 @@ -// 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 package output @@ -7,9 +7,10 @@ import ( "flag" "fmt" "io/ioutil" - "log" "path/filepath" + logger "github.com/VeritasOS/plugin-manager/utils/log" + "gopkg.in/yaml.v3" ) @@ -53,35 +54,31 @@ func RegisterCommandOptions(f *flag.FlagSet, defaultParams map[string]string) { &cmdOptions.Format, "output-format", defaultOutputFormat, - "The format of output to display the results. "+ + "The format of output to display the results.\n"+ "Supported output formats are 'json', 'yaml'.", ) } -// Write writes the given data in the format {json|yaml} that was set in options. -// -// into a specified file. If file is not specified, then it will print -// on STDOUT. +// Write the given data in the format {json|yaml} that was set in options into +// a specified file. If file is not specified, then it will print on STDOUT. func Write(data interface{}) error { - log.Println("Entering Write") - defer log.Println("Exiting Write") + logger.Debug.Println("Entering Write") + defer logger.Debug.Println("Exiting Write") if cmdOptions.Format == "" { // log.Printf("Skipping the Write() as output format is not set.") return nil } - log.Printf("Writing output in %s to file name: %s", + logger.Info.Printf("Writing output in %s to file name: %s", cmdOptions.Format, cmdOptions.File) return writeToFile(data, cmdOptions.Format, cmdOptions.File) } -// writeToFile writes the given data in the specified format {json|yaml} -// -// into a specified file. If file is not specified, then it will print -// on STDOUT. +// writeToFile writes the given data in the specified format {json|yaml} into +// a specified file. If file is not specified, then it will print on STDOUT. func writeToFile(data interface{}, format string, filePath string) error { - log.Println("Entering writeToFile") - defer log.Println("Exiting writeToFile") + logger.Debug.Println("Entering writeToFile") + defer logger.Debug.Println("Exiting writeToFile") var err error var out []byte @@ -92,8 +89,7 @@ func writeToFile(data interface{}, format string, filePath string) error { out, err = yaml.Marshal(data) } if err != nil { - log.Printf("Unable to marshal %s data into %s. Error: %v", - data, format, err) + logger.Error.Printf("Unable to marshal %s data into %s, err=%v", data, format, err) return err } @@ -105,11 +101,10 @@ func writeToFile(data interface{}, format string, filePath string) error { } filePath = filepath.FromSlash(filePath) - log.Printf("Output file: %s\n", filePath) + logger.Debug.Printf("Output file: %s", filePath) err = ioutil.WriteFile(filePath, out, 0764) if err != nil { - log.Printf("Unable to write to specified file %s. Error: %v", - filePath, err) + logger.Info.Printf("Unable to write to specified file %s. Error: %v", filePath, err) return err }