From d9ed5ad48dc62715afd3a59d4bc66eaec720cf76 Mon Sep 17 00:00:00 2001 From: fritzduchardt Date: Thu, 21 Dec 2023 01:34:42 +0100 Subject: [PATCH] fix: consistent error logging with stderr and offending cmd (#143) --- internal/myks/application.go | 33 +++++++++++++++++++++--------- internal/myks/environment.go | 11 +++++++--- internal/myks/git.go | 11 ++++++++-- internal/myks/globe.go | 30 +++++++++++++++++++++------ internal/myks/plugin_argocd.go | 3 +-- internal/myks/render.go | 4 +--- internal/myks/render_global_ytt.go | 1 - internal/myks/render_helm.go | 2 -- internal/myks/render_ytt.go | 1 - internal/myks/render_ytt_pkg.go | 13 ++++++++---- internal/myks/sync.go | 4 +--- internal/myks/util.go | 6 +++--- internal/myks/util_test.go | 4 ++-- internal/myks/vendir_secrets.go | 11 +++++++--- 14 files changed, 89 insertions(+), 45 deletions(-) diff --git a/internal/myks/application.go b/internal/myks/application.go index 4265ec9b..f9a52a2d 100644 --- a/internal/myks/application.go +++ b/internal/myks/application.go @@ -153,11 +153,21 @@ func (a *Application) Msg(step string, msg string) string { } func (a *Application) runCmd(step, purpose, cmd string, stdin io.Reader, args []string) (CmdResult, error) { - return runCmd(cmd, stdin, args, func(cmd string, args []string) { - log.Debug().Msg(a.Msg(step, msgRunCmd(purpose, cmd, args))) + return runCmd(cmd, stdin, args, func(cmd string, err error, stderr string, args []string) { + cmd = msgRunCmd(purpose, cmd, args) + a.logCmd(step, cmd, err, stderr) }) } +func (a *Application) logCmd(step string, cmd string, err error, stderr string) { + if err != nil { + log.Error().Msg(a.Msg(step, cmd)) + log.Error().Msg(a.Msg(step, stderr)) + } else { + log.Debug().Msg(a.Msg(step, cmd)) + } +} + func (a *Application) renderDataYaml(dataFiles []string) ([]byte, error) { args := []string{ "-v", "myks.context.step=init", // in the logs this step is called init @@ -168,11 +178,12 @@ func (a *Application) renderDataYaml(dataFiles []string) ([]byte, error) { if len(dataFiles) == 0 { return nil, errors.New("No data files found") } - res, err := runYttWithFilesAndStdin(dataFiles, nil, func(name string, args []string) { - log.Debug().Msg(a.Msg("init", msgRunCmd("render application data values file", name, args))) + step := "init" + res, err := runYttWithFilesAndStdin(dataFiles, nil, func(name string, err error, stderr string, args []string) { + cmd := msgRunCmd("render application data values file", name, args) + a.logCmd(step, cmd, err, stderr) }, args...) if err != nil { - log.Error().Err(err).Str("stderr", res.Stderr).Msg(a.Msg("init", "Unable to render data")) return nil, err } if res.Stdout == "" { @@ -183,9 +194,10 @@ func (a *Application) renderDataYaml(dataFiles []string) ([]byte, error) { return dataYaml, nil } -func (a *Application) mergeValuesYaml(valueFilesYaml string) (CmdResult, error) { - return runYttWithFilesAndStdin(nil, nil, func(name string, args []string) { - log.Debug().Msg(msgRunCmd("merge data values file", name, args)) +func (a *Application) mergeValuesYaml(step string, valueFilesYaml string) (CmdResult, error) { + return runYttWithFilesAndStdin(nil, nil, func(name string, err error, stderr string, args []string) { + cmd := msgRunCmd("merge data values file", name, args) + a.logCmd(step, cmd, err, stderr) }, "--data-values-file="+valueFilesYaml, "--data-values-inspect") } @@ -199,8 +211,9 @@ func (a *Application) yttS(step string, purpose string, paths []string, stdin io "-v", "myks.context.app="+a.Name, "-v", "myks.context.prototype="+a.Prototype) paths = concatenate(a.e.g.extraYttPaths, paths) - return runYttWithFilesAndStdin(paths, stdin, func(name string, args []string) { - log.Debug().Msg(a.Msg(step, msgRunCmd(purpose, name, args))) + return runYttWithFilesAndStdin(paths, stdin, func(name string, err error, stderr string, args []string) { + cmd := msgRunCmd(purpose, name, args) + a.logCmd(step, cmd, err, stderr) }, args...) } diff --git a/internal/myks/environment.go b/internal/myks/environment.go index 1b641dff..119c8fc8 100644 --- a/internal/myks/environment.go +++ b/internal/myks/environment.go @@ -270,7 +270,6 @@ func (e *Environment) renderEnvData(envDataFiles []string) ([]byte, error) { } res, err := e.ytt("render environment data values file", envDataFiles, "--data-values-inspect") if err != nil { - log.Error().Err(err).Str("stderr", res.Stderr).Msg(e.Msg("Unable to render environment data")) return nil, err } if res.Stdout == "" { @@ -404,7 +403,13 @@ func (e *Environment) ytt(purpose string, paths []string, args ...string) (CmdRe func (e *Environment) yttS(purpose string, paths []string, stdin io.Reader, args ...string) (CmdResult, error) { paths = concatenate(e.g.extraYttPaths, paths) - return runYttWithFilesAndStdin(paths, stdin, func(name string, args []string) { - log.Debug().Msg(e.Msg(msgRunCmd(purpose, name, args))) + return runYttWithFilesAndStdin(paths, stdin, func(name string, err error, stderr string, args []string) { + cmd := msgRunCmd(purpose, name, args) + if err != nil { + log.Error().Msg(e.Msg(cmd)) + log.Error().Msg(e.Msg(stderr)) + } else { + log.Debug().Msg(e.Msg(cmd)) + } }, args...) } diff --git a/internal/myks/git.go b/internal/myks/git.go index 74fd819c..2583a1c2 100644 --- a/internal/myks/git.go +++ b/internal/myks/git.go @@ -12,8 +12,15 @@ type ChangedFiles map[string]string // GetChangedFilesGit returns list of files changed since the baseRevision, if specified, and since the last commit // TODO: exclude files that are outside of the myks root directory func GetChangedFilesGit(baseRevision string) (ChangedFiles, error) { - logFn := func(name string, args []string) { - log.Debug().Msg(msgRunCmd("collect changed files for smart-mode", name, args)) + logFn := func(name string, err error, stderr string, args []string) { + cmd := msgRunCmd("collect changed files for smart-mode", name, args) + if err != nil { + log.Error().Msg(cmd) + log.Error().Msg(stderr) + + } else { + log.Debug().Msg(cmd) + } } files := ChangedFiles{} diff --git a/internal/myks/globe.go b/internal/myks/globe.go index 8d655f19..0a1171a0 100644 --- a/internal/myks/globe.go +++ b/internal/myks/globe.go @@ -349,8 +349,14 @@ func (g *Globe) setGitPathPrefix() error { gitArgs = append(gitArgs, "-C", g.RootDir) } gitArgs = append(gitArgs, "rev-parse", "--show-prefix") - result, err := runCmd("git", nil, gitArgs, func(name string, args []string) { - log.Debug().Msg(msgRunCmd("set git path prefix", name, args)) + result, err := runCmd("git", nil, gitArgs, func(name string, err error, stderr string, args []string) { + cmd := msgRunCmd("set git path prefix", name, args) + if err != nil { + log.Error().Msg(cmd) + log.Error().Msg(stderr) + } else { + log.Debug().Msg(cmd) + } }) if err != nil { return err @@ -362,8 +368,14 @@ func (g *Globe) setGitPathPrefix() error { func (g *Globe) setGitRepoUrl() error { if g.GitRepoUrl == "" { - result, err := runCmd("git", nil, []string{"remote", "get-url", "origin"}, func(name string, args []string) { - log.Debug().Msg(msgRunCmd("set git repository url", name, args)) + result, err := runCmd("git", nil, []string{"remote", "get-url", "origin"}, func(name string, err error, stderr string, args []string) { + cmd := msgRunCmd("set git repository url", name, args) + if err != nil { + log.Error().Msg(cmd) + log.Error().Msg(stderr) + } else { + log.Debug().Msg(cmd) + } }) if err != nil { return err @@ -375,8 +387,14 @@ func (g *Globe) setGitRepoUrl() error { func (g *Globe) setGitRepoBranch() error { if g.GitRepoBranch == "" { - result, err := runCmd("git", nil, []string{"rev-parse", "--abbrev-ref", "HEAD"}, func(name string, args []string) { - log.Debug().Msg(msgRunCmd("set git repository branch", name, args)) + result, err := runCmd("git", nil, []string{"rev-parse", "--abbrev-ref", "HEAD"}, func(name string, err error, stderr string, args []string) { + cmd := msgRunCmd("set git repository branch", name, args) + if err != nil { + log.Error().Msg(cmd) + log.Error().Msg(stderr) + } else { + log.Debug().Msg(cmd) + } }) if err != nil { return err diff --git a/internal/myks/plugin_argocd.go b/internal/myks/plugin_argocd.go index 00b4478c..fbb05a73 100644 --- a/internal/myks/plugin_argocd.go +++ b/internal/myks/plugin_argocd.go @@ -47,8 +47,7 @@ func (e *Environment) renderArgoCD() (err error) { bytes.NewReader(argocd_appproject_template), ) if err != nil { - log.Error().Err(err).Str("stdout", res.Stdout).Str("stderr", res.Stderr).Msg(e.Msg("failed to render ArgoCD project yaml")) - return + return err } argoDestinationPath := filepath.Join(e.getArgoCDDestinationDir(), getArgoCDEnvFileName(e.Id)) diff --git a/internal/myks/render.go b/internal/myks/render.go index eaab39b8..c0cd6643 100644 --- a/internal/myks/render.go +++ b/internal/myks/render.go @@ -202,7 +202,6 @@ func (a *Application) prepareValuesFile(dirName string, resourceName string) (st resourceValuesYaml, err := a.ytt(renderStepName, "collect data values file", concatenate(a.yttDataFiles, valuesFiles)) if err != nil { - log.Warn().Err(err).Msg(a.Msg(renderStepName, "Unable to render resource values templates")) return "", err } @@ -217,9 +216,8 @@ func (a *Application) prepareValuesFile(dirName string, resourceName string) (st return "", err } - resourceValues, err := a.mergeValuesYaml(a.expandTempPath(valuesFileName)) + resourceValues, err := a.mergeValuesYaml(renderStepName, a.expandTempPath(valuesFileName)) if err != nil { - log.Warn().Err(err).Msg(a.Msg(renderStepName, "Unable to render resource values")) return "", err } diff --git a/internal/myks/render_global_ytt.go b/internal/myks/render_global_ytt.go index 344e8eee..49359fd5 100644 --- a/internal/myks/render_global_ytt.go +++ b/internal/myks/render_global_ytt.go @@ -38,7 +38,6 @@ func (g *GlobalYtt) Render(previousStepFile string) (string, error) { yttOutput, err := g.app.ytt(globalYttStepName, "render global ytt directory", yttFiles) if err != nil { - log.Warn().Err(err).Str("stderr", yttOutput.Stderr).Msg(g.app.Msg(globalYttStepName, "Unable to render ytt files")) return "", err } diff --git a/internal/myks/render_helm.go b/internal/myks/render_helm.go index 6b39e537..9f677f54 100644 --- a/internal/myks/render_helm.go +++ b/internal/myks/render_helm.go @@ -94,7 +94,6 @@ func (h *Helm) Render(_ string) (string, error) { res, err := h.app.runCmd(helmStepName, "helm template chart", "helm", nil, append(helmArgs, commonHelmArgs...)) if err != nil { - log.Error().Msg(h.app.Msg(helmStepName, res.Stderr)) return "", err } @@ -115,7 +114,6 @@ func (h *Helm) Render(_ string) (string, error) { func (h *Helm) getHelmConfig() (HelmConfig, error) { dataValuesYaml, err := h.app.ytt(helmStepName, "get helm config", h.app.yttDataFiles, "--data-values-inspect") if err != nil { - log.Warn().Err(err).Msg(h.app.Msg(helmStepName, "Unable to inspect data values")) return HelmConfig{}, err } diff --git a/internal/myks/render_ytt.go b/internal/myks/render_ytt.go index 721489db..4b0e307a 100644 --- a/internal/myks/render_ytt.go +++ b/internal/myks/render_ytt.go @@ -65,7 +65,6 @@ func (y *Ytt) Render(previousStepFile string) (string, error) { res, err := y.app.ytt(yttStepName, "render local ytt", yttFiles) if err != nil { - log.Error().Msg(y.app.Msg(yttStepName, res.Stderr)) return "", err } diff --git a/internal/myks/render_ytt_pkg.go b/internal/myks/render_ytt_pkg.go index 0f18dbfd..53973650 100644 --- a/internal/myks/render_ytt_pkg.go +++ b/internal/myks/render_ytt_pkg.go @@ -63,12 +63,17 @@ func (y *YttPkg) Render(_ string) (string, error) { yttArgs = []string{"--data-values-file=" + pkgValuesFile} } - res, err := runYttWithFilesAndStdin(yttFiles, nil, func(name string, args []string) { - // make this copy-n-pastable - log.Debug().Msg(msgRunCmd(yttPkgStepName+" render step", name, args)) + res, err := runYttWithFilesAndStdin(yttFiles, nil, func(name string, err error, stderr string, args []string) { + purpose := yttPkgStepName + " render step" + cmd := msgRunCmd(purpose, name, args) + if err != nil { + log.Error().Msg(cmd) + log.Error().Msg(stderr) + } else { + log.Debug().Msg(cmd) + } }, yttArgs...) if err != nil { - log.Error().Msg(y.app.Msg(yttPkgStepName, res.Stderr)) return "", err } diff --git a/internal/myks/sync.go b/internal/myks/sync.go index e1d4159e..d236317c 100644 --- a/internal/myks/sync.go +++ b/internal/myks/sync.go @@ -53,7 +53,6 @@ func (a *Application) prepareSync() error { vendirConfig, err := a.ytt(syncStepName, "creating vendir config", yttFiles) if err != nil { - log.Warn().Err(err).Msg(a.Msg(syncStepName, "Unable to render vendir config")) return err } @@ -162,9 +161,8 @@ func (a *Application) runVendirSync(targetDir string, vendirConfig string, vendi if directory != "" { args = append(args, "--directory="+directory) } - res, err := a.runCmd(syncStepName, "vendir sync", "vendir", strings.NewReader(vendirSecrets), args) + _, err := a.runCmd(syncStepName, "vendir sync", "vendir", strings.NewReader(vendirSecrets), args) if err != nil { - log.Error().Err(err).Str("stdout", res.Stdout).Str("stderr", res.Stderr).Msg(a.Msg(syncStepName, "Unable to sync vendir")) return err } log.Info().Msg(a.Msg(syncStepName, "Synced")) diff --git a/internal/myks/util.go b/internal/myks/util.go index 1ab21c5d..005a4c18 100644 --- a/internal/myks/util.go +++ b/internal/myks/util.go @@ -247,7 +247,7 @@ func getSubDirs(dir string) (subDirs []string, err error) { return } -func runCmd(name string, stdin io.Reader, args []string, logFn func(name string, args []string)) (CmdResult, error) { +func runCmd(name string, stdin io.Reader, args []string, logFn func(name string, err error, stderr string, args []string)) (CmdResult, error) { cmd := exec.Command(name, args...) if stdin != nil { @@ -261,7 +261,7 @@ func runCmd(name string, stdin io.Reader, args []string, logFn func(name string, err := cmd.Run() if logFn != nil { - logFn(name, args) + logFn(name, err, stderrBs.String(), args) } return CmdResult{ @@ -275,7 +275,7 @@ func msgRunCmd(purpose string, cmd string, args []string) string { return "Running \u001B[34m" + cmd + "\u001B[0m to: \u001B[3m" + purpose + "\u001B[0m\n\u001B[37m" + msg + "\u001B[0m" } -func runYttWithFilesAndStdin(paths []string, stdin io.Reader, logFn func(name string, args []string), args ...string) (CmdResult, error) { +func runYttWithFilesAndStdin(paths []string, stdin io.Reader, logFn func(name string, err error, stderr string, args []string), args ...string) (CmdResult, error) { if stdin != nil { paths = append(paths, "-") } diff --git a/internal/myks/util_test.go b/internal/myks/util_test.go index c8315467..0bf8d20a 100644 --- a/internal/myks/util_test.go +++ b/internal/myks/util_test.go @@ -225,7 +225,7 @@ func Test_runCmd(t *testing.T) { name string stdin io.Reader args []string - log func(name string, args []string) + log func(name string, err error, stderr string, args []string) } tests := []struct { name string @@ -254,7 +254,7 @@ func Test_runYttWithFilesAndStdin(t *testing.T) { type args struct { paths []string stdin io.Reader - log func(name string, args []string) + log func(name string, err error, stderr string, args []string) args []string } tests := []struct { diff --git a/internal/myks/vendir_secrets.go b/internal/myks/vendir_secrets.go index 5ee782c7..ab081832 100644 --- a/internal/myks/vendir_secrets.go +++ b/internal/myks/vendir_secrets.go @@ -86,15 +86,20 @@ func (g *Globe) generateVendirSecretYaml(secretName string, username string, pas res, err := runYttWithFilesAndStdin( nil, bytes.NewReader(vendirSecretTemplate), - func(name string, args []string) { - log.Debug().Msg(g.Msg(msgRunCmd("render vendir secret yaml", name, args))) + func(name string, err error, stderr string, args []string) { + cmd := msgRunCmd("render vendir secret yaml", name, args) + if err != nil { + log.Error().Msg(g.Msg(cmd)) + log.Error().Err(err).Msg(g.Msg(stderr)) + } else { + log.Debug().Msg(g.Msg(stderr)) + } }, "--data-value=secret_name="+secretName, "--data-value=username="+username, "--data-value=password="+password, ) if err != nil { - log.Error().Err(err).Msg(g.Msg(res.Stderr)) return "", err }