Adding context.Context support and a logger

Signed-off-by: Dave Henderson <dhenderson@gmail.com>

cmd/gomplate/logger.go

@@ -0,0 +1,33 @@
+package main
+
+import (
+	"context"
+	stdlog "log"
+	"os"
+	"time"
+
+	"github.com/rs/zerolog"
+	"github.com/rs/zerolog/log"
+	"golang.org/x/crypto/ssh/terminal"
+)
+
+func initLogger(ctx context.Context) context.Context {
+	zerolog.SetGlobalLevel(zerolog.InfoLevel)
+	zerolog.DurationFieldUnit = time.Second
+
+	stdlogger := log.With().Bool("stdlog", true).Logger()
+	stdlog.SetFlags(0)
+	stdlog.SetOutput(stdlogger)
+
+	if terminal.IsTerminal(int(os.Stderr.Fd())) {
+		log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stderr, TimeFormat: "15:04:05"})
+		noLevelWriter := zerolog.ConsoleWriter{
+			Out:         os.Stderr,
+			FormatLevel: func(i interface{}) string { return "" },
+		}
+		stdlogger = stdlogger.Output(noLevelWriter)
+		stdlog.SetOutput(stdlogger)
+	}
+
+	return log.Logger.WithContext(ctx)
+}

cmd/gomplate/main.go

@@ -6,6 +6,7 @@ package main
 
 import (
 	"bytes"
+	"context"
 	"fmt"
 	"os"
 	"os/exec"
@@ -14,6 +15,8 @@ import (
 	"github.com/hairyhenderson/gomplate/v3"
 	"github.com/hairyhenderson/gomplate/v3/env"
 	"github.com/hairyhenderson/gomplate/v3/version"
+
+	"github.com/rs/zerolog"
 	"github.com/spf13/cobra"
 )
 
@@ -34,10 +37,14 @@ func printVersion(name string) {
 // postRunExec - if templating succeeds, the command following a '--' will be executed
 func postRunExec(cmd *cobra.Command, args []string) error {
 	if len(args) > 0 {
+		ctx := cmd.Context()
+		log := zerolog.Ctx(ctx)
+		log.Debug().Strs("args", args).Msg("running post-exec command")
+
 		name := args[0]
 		args = args[1:]
 		// nolint: gosec
-		c := exec.Command(name, args...)
+		c := exec.CommandContext(ctx, name, args...)
 		if execPipe {
 			c.Stdin = postRunInput
 		} else {
@@ -99,12 +106,16 @@ func newGomplateCmd() *cobra.Command {
 				printVersion(cmd.Name())
 				return nil
 			}
-			if verbose {
-				// nolint: errcheck
-				fmt.Fprintf(os.Stderr, "%s version %s, build %s\nconfig is:\n%s\n\n",
-					cmd.Name(), version.Version, version.GitCommit,
-					&opts)
+
+			if v, _ := cmd.Flags().GetBool("verbose"); v {
+				zerolog.SetGlobalLevel(zerolog.DebugLevel)
 			}
+			ctx := cmd.Context()
+			log := zerolog.Ctx(ctx)
+
+			log.Debug().Msgf("%s version %s, build %s\nconfig is:\n%s",
+				cmd.Name(), version.Version, version.GitCommit,
+				&opts)
 
 			// support --include
 			opts.ExcludeGlob = processIncludes(includes, opts.ExcludeGlob)
@@ -116,11 +127,9 @@ func newGomplateCmd() *cobra.Command {
 			err := gomplate.RunTemplates(&opts)
 			cmd.SilenceErrors = true
 			cmd.SilenceUsage = true
-			if verbose {
-				// nolint: errcheck
-				fmt.Fprintf(os.Stderr, "rendered %d template(s) with %d error(s) in %v\n",
-					gomplate.Metrics.TemplatesProcessed, gomplate.Metrics.Errors, gomplate.Metrics.TotalRenderDuration)
-			}
+
+			log.Debug().Msgf("rendered %d template(s) with %d error(s) in %v",
+				gomplate.Metrics.TemplatesProcessed, gomplate.Metrics.Errors, gomplate.Metrics.TotalRenderDuration)
 			return err
 		},
 		PostRunE: postRunExec,
@@ -165,11 +174,14 @@ func initFlags(command *cobra.Command) {
 }
 
 func main() {
+	ctx, cancel := context.WithCancel(context.Background())
+	defer cancel()
+	ctx = initLogger(ctx)
+
 	command := newGomplateCmd()
 	initFlags(command)
-	if err := command.Execute(); err != nil {
-		// nolint: errcheck
-		fmt.Fprintln(os.Stderr, err)
-		os.Exit(1)
+	if err := command.ExecuteContext(ctx); err != nil {
+		log := zerolog.Ctx(ctx)
+		log.Fatal().Err(err).Send()
 	}
 }

go.mod

@@ -29,6 +29,7 @@ require (
 	github.com/joho/godotenv v1.3.0
 	github.com/pierrec/lz4 v2.4.1+incompatible // indirect
 	github.com/pkg/errors v0.9.1
+	github.com/rs/zerolog v1.18.0
 	github.com/sergi/go-diff v1.1.0 // indirect
 	github.com/smartystreets/goconvey v1.6.4 // indirect
 	github.com/spf13/afero v1.2.2

go.sum

@@ -377,6 +377,9 @@ github.com/rainycape/unidecode v0.0.0-20150907023854-cb7f23ec59be h1:ta7tUOvsPHV
 github.com/rainycape/unidecode v0.0.0-20150907023854-cb7f23ec59be/go.mod h1:MIDFMn7db1kT65GmV94GzpX9Qdi7N/pQlwb+AN8wh+Q=
 github.com/rogpeppe/fastuuid v0.0.0-20150106093220-6724a57986af/go.mod h1:XWv6SoW27p1b0cqNHllgS5HIMJraePCO15w5zCzIWYg=
 github.com/rogpeppe/go-internal v1.3.0/go.mod h1:M8bDsm7K2OlrFYOpmOWEs/qY81heoFRclV5y23lUDJ4=
+github.com/rs/xid v1.2.1/go.mod h1:+uKXf+4Djp6Md1KODXJxgGQPKngRmWyn10oCKFzNHOQ=
+github.com/rs/zerolog v1.18.0 h1:CbAm3kP2Tptby1i9sYy2MGRg0uxIN9cyDb59Ys7W8z8=
+github.com/rs/zerolog v1.18.0/go.mod h1:9nvC1axdVrAHcu/s9taAVfBuIdTZLVQmKQyvrUjF5+I=
 github.com/russross/blackfriday/v2 v2.0.1/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM=
 github.com/ryanuber/columnize v0.0.0-20160712163229-9b3edd62028f/go.mod h1:sm1tb6uqfes/u+d4ooFouqFdy9/2g9QGwK3SQygK0Ts=
 github.com/ryanuber/columnize v2.1.0+incompatible/go.mod h1:sm1tb6uqfes/u+d4ooFouqFdy9/2g9QGwK3SQygK0Ts=
@@ -435,6 +438,7 @@ github.com/xiang90/probing v0.0.0-20190116061207-43a291ad63a2/go.mod h1:UETIi67q
 github.com/xordataexchange/crypt v0.0.3-0.20170626215501-b2862e3d0a77/go.mod h1:aYKd//L2LvnjZzWKhF00oedf4jCCReLcmhLdhm1A27Q=
 github.com/zealic/xignore v0.3.3 h1:EpLXUgZY/JEzFkTc+Y/VYypzXtNz+MSOMVCGW5Q4CKQ=
 github.com/zealic/xignore v0.3.3/go.mod h1:lhS8V7fuSOtJOKsvKI7WfsZE276/7AYEqokv3UiqEAU=
+github.com/zenazn/goji v0.9.0/go.mod h1:7S9M489iMyHBNxwZnk9/EHS098H4/F6TATF2mIxtB1Q=
 go.etcd.io/bbolt v1.3.2/go.mod h1:IbVyRI1SCnLcuJnV2u8VeU0CEYM7e686BmAb1XKL+uU=
 go.opencensus.io v0.15.0/go.mod h1:UffZAU+4sDEINUGP/B7UfBBkq4fqLu9zXAX7ke6CHW0=
 go.opencensus.io v0.21.0/go.mod h1:mSImk1erAIZhrmZN+AvHh14ztQfjbGwt4TtuofqLduU=
@@ -591,6 +595,7 @@ golang.org/x/tools v0.0.0-20190624222133-a101b041ded4/go.mod h1:/rFqwRUd4F7ZHNgw
 golang.org/x/tools v0.0.0-20190628153133-6cdbf07be9d0/go.mod h1:/rFqwRUd4F7ZHNgwSSTFct+R/Kf4OFW1sUzUTQQTgfc=
 golang.org/x/tools v0.0.0-20190729092621-ff9f1409240a/go.mod h1:jcCCGcm9btYwXyDqrUWc6MKQKKGJCWEQ3AfLSRIbEuI=
 golang.org/x/tools v0.0.0-20190816200558-6889da9d5479/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
+golang.org/x/tools v0.0.0-20190828213141-aed303cbaa74/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
 golang.org/x/tools v0.0.0-20190911174233-4f2ddba30aff/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
 golang.org/x/tools v0.0.0-20191012152004-8de300cfc20a/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
 golang.org/x/tools v0.0.0-20191113191852-77e3bb0ad9e7/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=

gomplate.go

@@ -4,6 +4,7 @@ package gomplate
 
 import (
 	"bytes"
+	"context"
 	"io"
 	"os"
 	"path"
@@ -28,7 +29,7 @@ type gomplate struct {
 }
 
 // runTemplate -
-func (g *gomplate) runTemplate(t *tplate) error {
+func (g *gomplate) runTemplate(_ context.Context, t *tplate) error {
 	tmpl, err := t.toGoTemplate(g)
 	if err != nil {
 		return err
@@ -108,6 +109,11 @@ func parseTemplateArg(templateArg string, ta templateAliases) error {
 
 // RunTemplates - run all gomplate templates specified by the given configuration
 func RunTemplates(o *Config) error {
+	return RunTemplatesWithContext(context.Background(), o)
+}
+
+// RunTemplatesWithContext - run all gomplate templates specified by the given configuration
+func RunTemplatesWithContext(ctx context.Context, o *Config) error {
 	Metrics = newMetrics()
 	defer runCleanupHooks()
 	// make sure config is sane
@@ -127,16 +133,16 @@ func RunTemplates(o *Config) error {
 		return err
 	}
 	funcMap := Funcs(d)
-	err = bindPlugins(o.Plugins, funcMap)
+	err = bindPlugins(ctx, o.Plugins, funcMap)
 	if err != nil {
 		return err
 	}
 	g := newGomplate(funcMap, o.LDelim, o.RDelim, nested, c)
 
-	return g.runTemplates(o)
+	return g.runTemplates(ctx, o)
 }
 
-func (g *gomplate) runTemplates(o *Config) error {
+func (g *gomplate) runTemplates(ctx context.Context, o *Config) error {
 	start := time.Now()
 	tmpl, err := gatherTemplates(o, chooseNamer(o, g))
 	Metrics.GatherDuration = time.Since(start)
@@ -149,7 +155,7 @@ func (g *gomplate) runTemplates(o *Config) error {
 	defer func() { Metrics.TotalRenderDuration = time.Since(start) }()
 	for _, t := range tmpl {
 		tstart := time.Now()
-		err := g.runTemplate(t)
+		err := g.runTemplate(ctx, t)
 		Metrics.RenderDuration[t.name] = time.Since(tstart)
 		if err != nil {
 			Metrics.Errors++

gomplate_test.go

@@ -2,6 +2,7 @@ package gomplate
 
 import (
 	"bytes"
+	"context"
 	"net/http/httptest"
 	"os"
 	"path/filepath"
@@ -20,7 +21,7 @@ import (
 
 func testTemplate(g *gomplate, tmpl string) string {
 	var out bytes.Buffer
-	err := g.runTemplate(&tplate{name: "testtemplate", contents: tmpl, target: &out})
+	err := g.runTemplate(context.TODO(), &tplate{name: "testtemplate", contents: tmpl, target: &out})
 	if err != nil {
 		panic(err)
 	}

plugins.go

@@ -18,9 +18,9 @@ import (
 	"github.com/hairyhenderson/gomplate/v3/env"
 )
 
-func bindPlugins(plugins []string, funcMap template.FuncMap) error {
+func bindPlugins(ctx context.Context, plugins []string, funcMap template.FuncMap) error {
 	for _, p := range plugins {
-		plugin, err := newPlugin(p)
+		plugin, err := newPlugin(ctx, p)
 		if err != nil {
 			return err
 		}
@@ -35,15 +35,17 @@ func bindPlugins(plugins []string, funcMap template.FuncMap) error {
 // plugin represents a custom function that binds to an external process to be executed
 type plugin struct {
 	name, path string
+	ctx        context.Context
 }
 
-func newPlugin(value string) (*plugin, error) {
+func newPlugin(ctx context.Context, value string) (*plugin, error) {
 	parts := strings.SplitN(value, "=", 2)
 	if len(parts) < 2 {
 		return nil, errors.New("plugin requires both name and path")
 	}
 
 	p := &plugin{
+		ctx:  ctx,
 		name: parts[0],
 		path: parts[1],
 	}
@@ -90,7 +92,7 @@ func (p *plugin) run(args ...interface{}) (interface{}, error) {
 		return nil, err
 	}
 
-	ctx, cancel := context.WithTimeout(context.Background(), t)
+	ctx, cancel := context.WithTimeout(p.ctx, t)
 	defer cancel()
 	c := exec.CommandContext(ctx, name, a...)
 	c.Stdin = nil

plugins_test.go

@@ -1,6 +1,7 @@
 package gomplate
 
 import (
+	"context"
 	"testing"
 	"text/template"
 
@@ -9,34 +10,37 @@ import (
 )
 
 func TestNewPlugin(t *testing.T) {
+	ctx := context.TODO()
 	in := "foo"
-	_, err := newPlugin(in)
+	_, err := newPlugin(ctx, in)
 	assert.ErrorContains(t, err, "")
 
 	in = "foo=/bin/bar"
-	out, err := newPlugin(in)
+	out, err := newPlugin(ctx, in)
 	assert.NilError(t, err)
 	assert.Equal(t, "foo", out.name)
 	assert.Equal(t, "/bin/bar", out.path)
 }
 
 func TestBindPlugins(t *testing.T) {
+	ctx := context.TODO()
 	fm := template.FuncMap{}
 	in := []string{}
-	err := bindPlugins(in, fm)
+	err := bindPlugins(ctx, in, fm)
 	assert.NilError(t, err)
 	assert.DeepEqual(t, template.FuncMap{}, fm)
 
 	in = []string{"foo=bar"}
-	err = bindPlugins(in, fm)
+	err = bindPlugins(ctx, in, fm)
 	assert.NilError(t, err)
 	assert.Check(t, cmp.Contains(fm, "foo"))
 
-	err = bindPlugins(in, fm)
+	err = bindPlugins(ctx, in, fm)
 	assert.ErrorContains(t, err, "already bound")
 }
 
 func TestBuildCommand(t *testing.T) {
+	ctx := context.TODO()
 	data := []struct {
 		plugin   string
 		args     []string
@@ -49,7 +53,7 @@ func TestBuildCommand(t *testing.T) {
 		{"foo=foo.ps1", []string{"bar", "baz"}, []string{"pwsh", "-File", "foo.ps1", "bar", "baz"}},
 	}
 	for _, d := range data {
-		p, err := newPlugin(d.plugin)
+		p, err := newPlugin(ctx, d.plugin)
 		assert.NilError(t, err)
 		name, args := p.buildCommand(d.args)
 		actual := append([]string{name}, args...)

tests/integration/inputdir_test.go

@@ -253,6 +253,6 @@ func (s *InputDirSuite) TestReportsFilenameWithBadInputFile(c *C) {
 	)
 	result.Assert(c, icmd.Expected{
 		ExitCode: 1,
-		Err:      "template: " + s.tmpDir.Join("bad_in", "bad.tmpl") + ":1: unexpected {{end}}",
+		Err:      "bad.tmpl:1: unexpected {{end}}",
 	})
 }

tests/integration/tmpl_test.go

@@ -57,7 +57,7 @@ func (s *TmplSuite) TestExec(c *C) {
 	result := icmd.RunCmd(icmd.Command(GomplateBin,
 		"-i", `{{ tmpl.Exec "Nope" }}`,
 	))
-	result.Assert(c, icmd.Expected{ExitCode: 1, Err: `template "Nope" not defined`})
+	result.Assert(c, icmd.Expected{ExitCode: 1, Err: `template \"Nope\" not defined`})
 
 	result = icmd.RunCmd(icmd.Command(GomplateBin,
 		"-i", `{{define "T1"}}hello world{{end}}{{ tmpl.Exec "T1" | strings.ToUpper }}`,