Merge pull request #4503 from hashicorp/f-e2e-cli

E2E: CLI Implementation

e2e/cli/command/environment.go

@@ -0,0 +1,222 @@
+package command
+
+import (
+	"bufio"
+	"context"
+	"encoding/json"
+	"fmt"
+	"io"
+	"os"
+	"os/exec"
+	"os/signal"
+	"path"
+	"path/filepath"
+	"strings"
+	"syscall"
+	"time"
+
+	hclog "github.com/hashicorp/go-hclog"
+)
+
+// environment captures all the information needed to execute terraform
+// in order to setup a test environment
+type environment struct {
+	provider string // provider ex. aws
+	name     string // environment name ex. generic
+
+	tf      string // location of terraform binary
+	tfPath  string // path to terraform configuration
+	tfState string // path to terraform state file
+	logger  hclog.Logger
+}
+
+func (env *environment) canonicalName() string {
+	return fmt.Sprintf("%s/%s", env.provider, env.name)
+}
+
+// envResults are the fields returned after provisioning a test environment
+type envResults struct {
+	nomadAddr  string
+	consulAddr string
+	vaultAddr  string
+}
+
+// newEnv takes a path to the environments directory, environment name and provider,
+// path to terraform state file and a logger and builds the environment stuct used
+// to initial terraform calls
+func newEnv(envPath, provider, name, tfStatePath string, logger hclog.Logger) (*environment, error) {
+	// Make sure terraform is on the PATH
+	tf, err := exec.LookPath("terraform")
+	if err != nil {
+		return nil, fmt.Errorf("failed to lookup terraform binary: %v", err)
+	}
+
+	logger = logger.Named("provision").With("provider", provider, "name", name)
+
+	// set the path to the terraform module
+	tfPath := path.Join(envPath, provider, name)
+	logger.Debug("using tf path", "path", tfPath)
+	if _, err := os.Stat(tfPath); os.IsNotExist(err) {
+		return nil, fmt.Errorf("failed to lookup terraform configuration dir %s: %v", tfPath, err)
+	}
+
+	// set the path to state file
+	tfState := path.Join(tfStatePath, fmt.Sprintf("e2e.%s.%s.tfstate", provider, name))
+
+	env := &environment{
+		provider: provider,
+		name:     name,
+		tf:       tf,
+		tfPath:   tfPath,
+		tfState:  tfState,
+		logger:   logger,
+	}
+	return env, nil
+}
+
+// envsFromGlob allows for the discovery of multiple environments using globs (*).
+// ex. aws/* for all environments in aws.
+func envsFromGlob(envPath, glob, tfStatePath string, logger hclog.Logger) ([]*environment, error) {
+	results, err := filepath.Glob(filepath.Join(envPath, glob))
+	if err != nil {
+		return nil, err
+	}
+
+	envs := []*environment{}
+
+	for _, p := range results {
+		elems := strings.Split(p, "/")
+		name := elems[len(elems)-1]
+		provider := elems[len(elems)-2]
+		env, err := newEnv(envPath, provider, name, tfStatePath, logger)
+		if err != nil {
+			return nil, err
+		}
+
+		envs = append(envs, env)
+	}
+
+	return envs, nil
+}
+
+// provision calls terraform to setup the environment with the given nomad binary
+func (env *environment) provision(nomadPath string) (*envResults, error) {
+	tfArgs := []string{"apply", "-auto-approve", "-input=false", "-no-color",
+		"-state", env.tfState,
+		"-var", fmt.Sprintf("nomad_binary=%s", path.Join(nomadPath, "nomad")),
+		env.tfPath,
+	}
+
+	// Setup the 'terraform apply' command
+	ctx := context.Background()
+	cmd := exec.CommandContext(ctx, env.tf, tfArgs...)
+
+	// Funnel the stdout/stderr to logging
+	stderr, err := cmd.StderrPipe()
+	if err != nil {
+		return nil, fmt.Errorf("failed to get stderr pipe: %v", err)
+	}
+	stdout, err := cmd.StdoutPipe()
+	if err != nil {
+		return nil, fmt.Errorf("failed to get stdout pipe: %v", err)
+	}
+
+	// Run 'terraform apply'
+	cmd.Start()
+	go tfLog(env.logger.Named("tf.stderr"), stderr)
+	go tfLog(env.logger.Named("tf.stdout"), stdout)
+
+	sigChan := make(chan os.Signal)
+	signal.Notify(sigChan, os.Interrupt, syscall.SIGTERM)
+
+	cmdChan := make(chan error)
+	go func() {
+		cmdChan <- cmd.Wait()
+	}()
+
+	// if an interrupt is received before terraform finished, forward signal to
+	// child pid
+	select {
+	case sig := <-sigChan:
+		env.logger.Error("interrupt received, forwarding signal to child process",
+			"pid", cmd.Process.Pid)
+		cmd.Process.Signal(sig)
+		if err := procWaitTimeout(cmd.Process, 5*time.Second); err != nil {
+			env.logger.Error("child process did not exit in time, killing forcefully",
+				"pid", cmd.Process.Pid)
+			cmd.Process.Kill()
+		}
+		return nil, fmt.Errorf("interrupt received")
+	case err := <-cmdChan:
+		if err != nil {
+			return nil, fmt.Errorf("terraform exited with a non-zero status: %v", err)
+		}
+	}
+
+	// Setup and run 'terraform output' to get the module output
+	cmd = exec.CommandContext(ctx, env.tf, "output", "-json", "-state", env.tfState)
+	out, err := cmd.Output()
+	if err != nil {
+		return nil, fmt.Errorf("terraform exited with a non-zero status: %v", err)
+	}
+
+	// Parse the json and pull out results
+	tfOutput := make(map[string]map[string]interface{})
+	err = json.Unmarshal(out, &tfOutput)
+	if err != nil {
+		return nil, fmt.Errorf("failed to parse terraform output: %v", err)
+	}
+
+	results := &envResults{}
+	if nomadAddr, ok := tfOutput["nomad_addr"]; ok {
+		results.nomadAddr = nomadAddr["value"].(string)
+	} else {
+		return nil, fmt.Errorf("'nomad_addr' field expected in terraform output, but was missing")
+	}
+
+	return results, nil
+}
+
+// destroy calls terraform to destroy the environment
+func (env *environment) destroy() error {
+	tfArgs := []string{"destroy", "-auto-approve", "-no-color",
+		"-state", env.tfState,
+		"-var", "nomad_binary=",
+		env.tfPath,
+	}
+	cmd := exec.Command(env.tf, tfArgs...)
+
+	// Funnel the stdout/stderr to logging
+	stderr, err := cmd.StderrPipe()
+	if err != nil {
+		return fmt.Errorf("failed to get stderr pipe: %v", err)
+	}
+	stdout, err := cmd.StdoutPipe()
+	if err != nil {
+		return fmt.Errorf("failed to get stdout pipe: %v", err)
+	}
+
+	// Run 'terraform destroy'
+	cmd.Start()
+	go tfLog(env.logger.Named("tf.stderr"), stderr)
+	go tfLog(env.logger.Named("tf.stdout"), stdout)
+
+	err = cmd.Wait()
+	if err != nil {
+		return fmt.Errorf("terraform exited with a non-zero status: %v", err)
+	}
+
+	return nil
+}
+
+func tfLog(logger hclog.Logger, r io.ReadCloser) {
+	defer r.Close()
+	scanner := bufio.NewScanner(r)
+	for scanner.Scan() {
+		logger.Debug(scanner.Text())
+	}
+	if err := scanner.Err(); err != nil {
+		logger.Error("scan error", "error", err)
+	}
+
+}

e2e/cli/command/meta.go

@@ -0,0 +1,39 @@
+package command
+
+import (
+	"flag"
+	"strings"
+
+	hclog "github.com/hashicorp/go-hclog"
+	"github.com/mitchellh/cli"
+)
+
+type Meta struct {
+	Ui     cli.Ui
+	logger hclog.Logger
+
+	verbose bool
+}
+
+func NewMeta(ui cli.Ui, logger hclog.Logger) Meta {
+	return Meta{
+		Ui:     ui,
+		logger: logger,
+	}
+}
+
+func (m *Meta) FlagSet(n string) *flag.FlagSet {
+	f := flag.NewFlagSet(n, flag.ContinueOnError)
+
+	f.BoolVar(&m.verbose, "verbose", false, "Toggle verbose output")
+	return f
+}
+
+// generalOptionsUsage return the help string for the global options
+func generalOptionsUsage() string {
+	helpText := `
+  -verbose
+    Enables verbose logging.
+`
+	return strings.TrimSpace(helpText)
+}

e2e/cli/command/provision.go

@@ -0,0 +1,129 @@
+package command
+
+import (
+	"fmt"
+	"os"
+	"strings"
+
+	getter "github.com/hashicorp/go-getter"
+	hclog "github.com/hashicorp/go-hclog"
+	"github.com/mitchellh/cli"
+)
+
+const (
+	DefaultEnvironmentsPath = "./environments/"
+)
+
+func init() {
+	getter.Getters["file"].(*getter.FileGetter).Copy = true
+}
+
+func ProvisionCommandFactory(meta Meta) cli.CommandFactory {
+	return func() (cli.Command, error) {
+		return &Provision{Meta: meta}, nil
+	}
+}
+
+type Provision struct {
+	Meta
+}
+
+func (c *Provision) Help() string {
+	helpText := `
+Usage: nomad-e2e provision <provider> <environment>
+
+  Uses terraform to provision a target test environment to use
+  for end-to-end testing.
+
+  The output is a list of environment variables used to configure
+  various api clients such as Nomad, Consul and Vault.
+
+General Options:
+
+` + generalOptionsUsage() + `
+
+Provision Options:
+
+  -env-path
+    Sets the path for where to search for test environment configuration.
+    This defaults to './environments/'.
+
+  -nomad-binary
+    Sets the target nomad-binary to use when provisioning a nomad cluster.
+	The binary is retrieved by go-getter and can therefore be a local file
+	path, remote http url, or other support go-getter uri.
+
+  -destroy
+    If set, will destroy the target environment.
+
+  -tf-path
+    Sets the path for which terraform state files are stored. Defaults to
+	the current working directory.
+`
+	return strings.TrimSpace(helpText)
+}
+
+func (c *Provision) Synopsis() string {
+	return "Provisions the target testing environment"
+}
+
+func (c *Provision) Run(args []string) int {
+	var envPath string
+	var nomadBinary string
+	var destroy bool
+	var tfPath string
+	cmdFlags := c.FlagSet("provision")
+	cmdFlags.Usage = func() { c.Ui.Output(c.Help()) }
+	cmdFlags.StringVar(&envPath, "env-path", DefaultEnvironmentsPath, "Path to e2e environment terraform configs")
+	cmdFlags.StringVar(&nomadBinary, "nomad-binary", "", "")
+	cmdFlags.BoolVar(&destroy, "destroy", false, "")
+	cmdFlags.StringVar(&tfPath, "tf-path", "", "")
+
+	if err := cmdFlags.Parse(args); err != nil {
+		c.logger.Error("failed to parse flags:", "error", err)
+		return 1
+	}
+	if c.verbose {
+		c.logger.SetLevel(hclog.Debug)
+	}
+
+	args = cmdFlags.Args()
+	if len(args) != 2 {
+		c.logger.Error("expected 2 args (provider and environment)", "args", args)
+	}
+
+	env, err := newEnv(envPath, args[0], args[1], tfPath, c.logger)
+	if err != nil {
+		c.logger.Error("failed to build environment", "error", err)
+		return 1
+	}
+
+	if destroy {
+		if err := env.destroy(); err != nil {
+			c.logger.Error("failed to destroy environment", "error", err)
+			return 1
+		}
+		c.logger.Debug("environment successfully destroyed")
+		return 0
+	}
+
+	// Use go-getter to fetch the nomad binary
+	nomadPath, err := fetchBinary(nomadBinary)
+	defer os.RemoveAll(nomadPath)
+	if err != nil {
+		c.logger.Error("failed to fetch nomad binary", "error", err)
+		return 1
+	}
+
+	results, err := env.provision(nomadPath)
+	if err != nil {
+		c.logger.Error("", "error", err)
+		return 1
+	}
+
+	c.Ui.Output(strings.TrimSpace(fmt.Sprintf(`
+NOMAD_ADDR=%s
+	`, results.nomadAddr)))
+
+	return 0
+}

e2e/cli/command/run.go

@@ -0,0 +1,272 @@
+package command
+
+import (
+	"fmt"
+	"os"
+	"os/exec"
+	"strings"
+
+	capi "github.com/hashicorp/consul/api"
+	hclog "github.com/hashicorp/go-hclog"
+	vapi "github.com/hashicorp/vault/api"
+	"github.com/mitchellh/cli"
+)
+
+func RunCommandFactory(meta Meta) cli.CommandFactory {
+	return func() (cli.Command, error) {
+		return &Run{Meta: meta}, nil
+	}
+}
+
+type Run struct {
+	Meta
+}
+
+func (c *Run) Help() string {
+	helpText := `
+Usage: nomad-e2e run (<provider>/<name>)...
+
+  Two modes exist when using the run command.
+
+  When no arguments are given to the run command, it will launch
+  the e2e test suite against the Nomad cluster specified by the
+  NOMAD_ADDR environment variable. If this is not set, it defaults
+  to 'http://localhost:4646'
+
+  Multiple arguments may be given to specify one or more environments to
+  provision and run the e2e tests against. These are given in the form of
+  <provider>/<name>. Globs are support, for example 'aws/*' would run tests
+  against all of the environments under the aws provider. When using this mode,
+  all of the provision flags are supported.
+
+General Options:
+
+` + generalOptionsUsage() + `
+
+Run Options:
+
+  -run regex
+    Sets a regular expression for what tests to run. Uses '/' as a separator
+	to allow hierarchy between Suite/Case/Test.
+
+	Example '-run MyTestSuite' would only run tests under the MyTestSuite suite.
+
+  -slow
+    If set, will only run test suites marked as slow.
+`
+	return strings.TrimSpace(helpText)
+}
+
+func (c *Run) Synopsis() string {
+	return "Runs the e2e test suite"
+}
+
+func (c *Run) Run(args []string) int {
+	var envPath string
+	var nomadBinary string
+	var tfPath string
+	var slow bool
+	var run string
+	cmdFlags := c.FlagSet("run")
+	cmdFlags.Usage = func() { c.Ui.Output(c.Help()) }
+	cmdFlags.StringVar(&envPath, "env-path", DefaultEnvironmentsPath, "Path to e2e environment terraform configs")
+	cmdFlags.StringVar(&nomadBinary, "nomad-binary", "", "")
+	cmdFlags.StringVar(&tfPath, "tf-path", "", "")
+	cmdFlags.StringVar(&run, "run", "", "Regex to target specific test suites/cases")
+	cmdFlags.BoolVar(&slow, "slow", false, "Toggle slow running suites")
+
+	if err := cmdFlags.Parse(args); err != nil {
+		c.logger.Error("failed to parse flags", "error", err)
+		return 1
+	}
+	if c.verbose {
+		c.logger.SetLevel(hclog.Debug)
+	}
+
+	args = cmdFlags.Args()
+
+	if len(args) == 0 {
+		c.logger.Info("no environments specified, running test suite locally")
+		report, err := c.runTest(&runOpts{
+			run:     run,
+			slow:    slow,
+			verbose: c.verbose,
+		})
+		if err != nil {
+			c.logger.Error("failed to run test suite", "error", err)
+			return 1
+		}
+		if report.TotalFailedTests > 0 {
+			c.Ui.Error("***FAILED***")
+			c.Ui.Error(report.Summary())
+			return 1
+		}
+		c.Ui.Output("PASSED!")
+		if c.verbose {
+			c.Ui.Output(report.Summary())
+		}
+		return 0
+	}
+
+	environments := []*environment{}
+	for _, e := range args {
+		if len(strings.Split(e, "/")) != 2 {
+			c.logger.Error("argument should be formated as <provider>/<environment>", "args", e)
+			return 1
+		}
+		envs, err := envsFromGlob(envPath, e, tfPath, c.logger)
+		if err != nil {
+			c.logger.Error("failed to build environment", "environment", e, "error", err)
+			return 1
+		}
+		environments = append(environments, envs...)
+
+	}
+
+	// Use go-getter to fetch the nomad binary
+	nomadPath, err := fetchBinary(nomadBinary)
+	defer os.RemoveAll(nomadPath)
+	if err != nil {
+		c.logger.Error("failed to fetch nomad binary", "error", err)
+		return 1
+	}
+
+	envCount := len(environments)
+	c.logger.Debug("starting tests", "totalEnvironments", envCount)
+	failedEnvs := map[string]*TestReport{}
+	for i, env := range environments {
+		logger := c.logger.With("name", env.name, "provider", env.provider)
+		logger.Debug("provisioning environment")
+		results, err := env.provision(nomadPath)
+		if err != nil {
+			logger.Error("failed to provision environment", "error", err)
+			return 1
+		}
+
+		opts := &runOpts{
+			provider:   env.provider,
+			env:        env.name,
+			slow:       slow,
+			run:        run,
+			verbose:    c.verbose,
+			nomadAddr:  results.nomadAddr,
+			consulAddr: results.consulAddr,
+			vaultAddr:  results.vaultAddr,
+		}
+
+		var report *TestReport
+		if report, err = c.runTest(opts); err != nil {
+			logger.Error("failed to run tests against environment", "error", err)
+			return 1
+		}
+		if report.TotalFailedTests > 0 {
+			c.Ui.Error(fmt.Sprintf("[%d/%d] %s: ***FAILED***", i+1, envCount, env.canonicalName()))
+			c.Ui.Error(fmt.Sprintf("[%d/%d] %s: %s", i+1, envCount, env.canonicalName(), report.Summary()))
+			failedEnvs[env.canonicalName()] = report
+		}
+
+		c.Ui.Output(fmt.Sprintf("[%d/%d] %s: PASSED!", i+1, envCount, env.canonicalName()))
+		if c.verbose {
+			c.Ui.Output(fmt.Sprintf("[%d/%d] %s: %s", i+1, envCount, env.canonicalName(), report.Summary()))
+		}
+	}
+
+	if len(failedEnvs) > 0 {
+		c.Ui.Error(fmt.Sprintf("The following environments ***FAILED***"))
+		for name, report := range failedEnvs {
+			c.Ui.Error(fmt.Sprintf("  [%s]: %d out of %d suite failures",
+				name, report.TotalFailedSuites, report.TotalSuites))
+		}
+		return 1
+	}
+	c.Ui.Output("All Environments PASSED!")
+	return 0
+}
+
+func (c *Run) runTest(opts *runOpts) (*TestReport, error) {
+	goBin, err := exec.LookPath("go")
+	if err != nil {
+		return nil, err
+	}
+
+	cmd := exec.Command(goBin, opts.goArgs()...)
+	cmd.Env = opts.goEnv()
+	out, err := cmd.StdoutPipe()
+	defer out.Close()
+	if err != nil {
+		return nil, err
+	}
+
+	err = cmd.Start()
+	if err != nil {
+		return nil, err
+	}
+
+	dec := NewDecoder(out)
+	report, err := dec.Decode(c.logger.Named("run.gotest"))
+	if err != nil {
+		return nil, err
+	}
+
+	return report, nil
+
+}
+
+// runOpts contains fields used to build the arguments and environment variabled
+// nessicary to run go test and initialize the e2e framework
+type runOpts struct {
+	nomadAddr  string
+	consulAddr string
+	vaultAddr  string
+	provider   string
+	env        string
+	run        string
+	local      bool
+	slow       bool
+	verbose    bool
+}
+
+// goArgs returns the list of arguments passed to the go command to start the
+// e2e test framework
+func (opts *runOpts) goArgs() []string {
+	a := []string{
+		"test",
+		"-json",
+	}
+
+	if opts.run != "" {
+		a = append(a, "-run=TestE2E/"+opts.run)
+	}
+
+	a = append(a, []string{
+		"github.com/hashicorp/nomad/e2e",
+		"-env=" + opts.env,
+		"-env.provider=" + opts.provider,
+	}...)
+
+	if opts.slow {
+		a = append(a, "-slow")
+	}
+
+	if opts.local {
+		a = append(a, "-local")
+	}
+	return a
+}
+
+// goEnv returns the list of environment variabled passed to the go command to start
+// the e2e test framework
+func (opts *runOpts) goEnv() []string {
+	env := append(os.Environ(), "NOMAD_E2E=1")
+	if opts.nomadAddr != "" {
+		env = append(env, "NOMAD_ADDR="+opts.nomadAddr)
+	}
+	if opts.consulAddr != "" {
+		env = append(env, fmt.Sprintf("%s=%s", capi.HTTPAddrEnvName, opts.consulAddr))
+	}
+	if opts.vaultAddr != "" {
+		env = append(env, fmt.Sprintf("%s=%s", vapi.EnvVaultAddress, opts.consulAddr))
+	}
+
+	return env
+}

e2e/cli/command/test_decoder.go

@@ -0,0 +1,232 @@
+package command
+
+import (
+	"encoding/json"
+	"fmt"
+	"io"
+	"strings"
+	"text/tabwriter"
+	"time"
+
+	"github.com/fatih/color"
+	hclog "github.com/hashicorp/go-hclog"
+)
+
+type EventDecoder struct {
+	r io.Reader
+
+	dec    *json.Decoder
+	report *TestReport
+}
+
+type TestReport struct {
+	Events            []*TestEvent
+	Suites            map[string]*TestSuite
+	TotalSuites       int
+	TotalFailedSuites int
+	TotalCases        int
+	TotalFailedCases  int
+	TotalTests        int
+	TotalFailedTests  int
+	Elapsed           float64
+	Output            []string
+}
+
+type TestEvent struct {
+	Time    time.Time // encodes as an RFC3339-format string
+	Action  string
+	Package string
+	Test    string
+	Elapsed float64 // seconds
+	Output  string
+
+	suiteName string
+	caseName  string
+	testName  string
+}
+
+type TestSuite struct {
+	Name    string
+	Cases   map[string]*TestCase
+	Failed  int
+	Elapsed float64
+	Output  []string
+}
+
+type TestCase struct {
+	Name    string
+	Tests   map[string]*Test
+	Failed  int
+	Elapsed float64
+	Output  []string
+}
+
+type Test struct {
+	Name    string
+	Output  []string
+	Failed  bool
+	Elapsed float64
+}
+
+func NewDecoder(r io.Reader) *EventDecoder {
+	return &EventDecoder{
+		r:   r,
+		dec: json.NewDecoder(r),
+		report: &TestReport{
+			Suites: map[string]*TestSuite{},
+			Events: []*TestEvent{},
+		},
+	}
+}
+
+func (d *EventDecoder) Decode(logger hclog.Logger) (*TestReport, error) {
+	for d.dec.More() {
+		var e TestEvent
+		err := d.dec.Decode(&e)
+		if err != nil {
+			return nil, err
+		}
+
+		d.report.record(&e)
+		if logger != nil && e.Output != "" {
+			logger.Debug(strings.TrimRight(e.Output, "\n"))
+		}
+	}
+	return d.report, nil
+}
+
+func (r *TestReport) record(event *TestEvent) {
+	if !strings.HasPrefix(event.Test, "TestE2E") {
+		return
+	}
+	parts := strings.Split(event.Test, "/")
+	switch len(parts) {
+	case 1:
+		r.recordRoot(event)
+	case 2:
+		event.suiteName = parts[1]
+		r.recordSuite(event)
+	case 3:
+		event.suiteName = parts[1]
+		event.caseName = parts[2]
+		r.recordCase(event, r.Suites[event.suiteName])
+	case 4:
+		event.suiteName = parts[1]
+		event.caseName = parts[2]
+		event.testName = strings.Join(parts[3:], "/")
+		suite := r.Suites[event.suiteName]
+		r.recordTest(event, suite, suite.Cases[event.caseName])
+	}
+	r.Events = append(r.Events, event)
+
+}
+
+func (r *TestReport) recordRoot(event *TestEvent) {
+	switch event.Action {
+	case "run":
+	case "output":
+		r.Output = append(r.Output, event.Output)
+	case "pass", "fail":
+		r.Elapsed = event.Elapsed
+	}
+}
+func (r *TestReport) recordSuite(event *TestEvent) {
+	switch event.Action {
+	case "run":
+		r.Suites[event.suiteName] = &TestSuite{
+			Name:  event.suiteName,
+			Cases: map[string]*TestCase{},
+		}
+		r.TotalSuites += 1
+	case "output":
+		r.Suites[event.suiteName].Output = append(r.Suites[event.suiteName].Output, event.Output)
+	case "pass":
+		r.Suites[event.suiteName].Elapsed = event.Elapsed
+	case "fail":
+		r.Suites[event.suiteName].Elapsed = event.Elapsed
+		r.TotalFailedSuites += 1
+	}
+}
+func (r *TestReport) recordCase(event *TestEvent, suite *TestSuite) {
+	switch event.Action {
+	case "run":
+		suite.Cases[event.caseName] = &TestCase{
+			Name:  event.caseName,
+			Tests: map[string]*Test{},
+		}
+		r.TotalCases += 1
+	case "output":
+		suite.Cases[event.caseName].Output = append(suite.Cases[event.caseName].Output, event.Output)
+	case "pass":
+		suite.Cases[event.caseName].Elapsed = event.Elapsed
+	case "fail":
+		suite.Cases[event.caseName].Elapsed = event.Elapsed
+		suite.Failed += 1
+		r.TotalFailedCases += 1
+	}
+}
+func (r *TestReport) recordTest(event *TestEvent, suite *TestSuite, c *TestCase) {
+	switch event.Action {
+	case "run":
+		c.Tests[event.testName] = &Test{
+			Name: event.testName,
+		}
+		r.TotalTests += 1
+	case "output":
+		c.Tests[event.testName].Output = append(c.Tests[event.testName].Output, event.Output)
+	case "pass":
+		c.Tests[event.testName].Elapsed = event.Elapsed
+	case "fail":
+		c.Tests[event.testName].Elapsed = event.Elapsed
+		c.Tests[event.testName].Failed = true
+		c.Failed += 1
+		r.TotalFailedTests += 1
+	}
+}
+
+func (r *TestReport) Summary() string {
+	green := color.New(color.FgGreen).SprintFunc()
+	red := color.New(color.FgRed).SprintFunc()
+
+	sb := strings.Builder{}
+	sb.WriteString(
+		fmt.Sprintf("Summary:  %v/%v suites failed  |  %v/%v cases failed  |  %v/%v tests failed\n",
+			r.TotalFailedSuites, r.TotalSuites,
+			r.TotalFailedCases, r.TotalCases,
+			r.TotalFailedTests, r.TotalTests))
+
+	sb.WriteString("Details:\n")
+	w := tabwriter.NewWriter(&sb, 0, 0, 1, ' ', tabwriter.AlignRight)
+	for sname, suite := range r.Suites {
+		status := red("FAIL")
+		if suite.Failed == 0 {
+			status = green("PASS")
+		}
+
+		fmt.Fprintf(w, "[%s]\t%s\t\t\t (%vs)\n", status, sname, suite.Elapsed)
+		for cname, c := range suite.Cases {
+			status := red("FAIL")
+			if c.Failed == 0 {
+				status = green("PASS")
+			}
+			fmt.Fprintf(w, "[%s]\t↳\t%s\t\t (%vs)\n", status, cname, c.Elapsed)
+			for tname, test := range c.Tests {
+				status := red("FAIL")
+				if !test.Failed {
+					status = green("PASS")
+				}
+				fmt.Fprintf(w, "[%s]\t\t↳\t%s\t (%vs)\n", status, tname, test.Elapsed)
+				if test.Failed {
+					for _, line := range test.Output[2:] {
+						fmt.Fprintf(w, "\t\t\t%s\n", strings.Replace(strings.TrimSpace(line), "\t", "  ", -1))
+					}
+					fmt.Fprintln(w, "\t\t\t----------")
+				}
+
+			}
+		}
+	}
+
+	w.Flush()
+	return sb.String()
+}

e2e/cli/command/util.go

@@ -0,0 +1,55 @@
+package command
+
+import (
+	"fmt"
+	"io/ioutil"
+	"os"
+	"path"
+	"runtime"
+	"time"
+
+	getter "github.com/hashicorp/go-getter"
+	"github.com/hashicorp/nomad/helper/discover"
+)
+
+// fetchBinary fetches the nomad binary and returns the temporary directory where it exists
+func fetchBinary(bin string) (string, error) {
+	nomadBinaryDir, err := ioutil.TempDir("", "")
+	if err != nil {
+		return "", fmt.Errorf("failed to create temp dir: %v", err)
+	}
+
+	if bin == "" {
+		bin, err = discover.NomadExecutable()
+		if err != nil {
+			return "", fmt.Errorf("failed to discover nomad binary: %v", err)
+		}
+	}
+
+	dest := path.Join(nomadBinaryDir, "nomad")
+	if runtime.GOOS == "windows" {
+		dest = dest + ".exe"
+	}
+
+	if err = getter.GetFile(dest, bin); err != nil {
+		return "", fmt.Errorf("failed to get nomad binary: %v", err)
+	}
+
+	return nomadBinaryDir, nil
+}
+
+func procWaitTimeout(p *os.Process, d time.Duration) error {
+	stop := make(chan struct{})
+
+	go func() {
+		p.Wait()
+		stop <- struct{}{}
+	}()
+
+	select {
+	case <-stop:
+		return nil
+	case <-time.NewTimer(d).C:
+		return fmt.Errorf("timeout waiting for process %d to exit", p.Pid)
+	}
+}

e2e/cli/environments/mock/mock/main.tf

@@ -0,0 +1,5 @@
+variable "nomad_binary" {}
+
+output "nomad_addr" {
+  value = "${var.nomad_binary}"
+}

e2e/cli/environments/mock/mock/terraform.tfvars

@@ -0,0 +1 @@
+nomad_addr = "http://localhost:4646"

e2e/cli/main.go

@@ -0,0 +1,43 @@
+package main
+
+import (
+	"os"
+
+	hclog "github.com/hashicorp/go-hclog"
+	"github.com/hashicorp/nomad/e2e/cli/command"
+	"github.com/mitchellh/cli"
+)
+
+const (
+	NomadE2ECli        = "nomad-e2e"
+	NomadE2ECliVersion = "0.0.1"
+)
+
+func main() {
+
+	ui := &cli.BasicUi{
+		Reader:      os.Stdin,
+		Writer:      os.Stdout,
+		ErrorWriter: os.Stderr,
+	}
+
+	logger := hclog.New(&hclog.LoggerOptions{
+		Name:   NomadE2ECli,
+		Output: &cli.UiWriter{Ui: ui},
+	})
+
+	c := cli.NewCLI(NomadE2ECli, NomadE2ECliVersion)
+	c.Args = os.Args[1:]
+
+	meta := command.NewMeta(ui, logger)
+	c.Commands = map[string]cli.CommandFactory{
+		"provision": command.ProvisionCommandFactory(meta),
+		"run":       command.RunCommandFactory(meta),
+	}
+
+	exitStatus, err := c.Run()
+	if err != nil {
+		logger.Error("command exited with non-zero status", "status", exitStatus, "error", err)
+	}
+	os.Exit(exitStatus)
+}

e2e/example/example.go

@@ -10,6 +10,7 @@ func init() {
 		CanRunLocal: true,
 		Cases: []framework.TestCase{
 			new(SimpleExampleTestCase),
+			new(ExampleLongSetupCase),
 		},
 	})
 }
@@ -19,7 +20,21 @@ type SimpleExampleTestCase struct {
 }
 
 func (tc *SimpleExampleTestCase) TestExample(f *framework.F) {
+	f.T().Log("Logging foo")
 	jobs, _, err := tc.Nomad().Jobs().List(nil)
 	f.NoError(err)
 	f.Empty(jobs)
 }
+
+func (tc *SimpleExampleTestCase) TestParallelExample(f *framework.F) {
+	f.T().Log("this one can run in parallel with other tests")
+	f.T().Parallel()
+}
+
+type ExampleLongSetupCase struct {
+	framework.TC
+}
+
+func (tc *ExampleLongSetupCase) BeforeEach(f *framework.F) {
+	f.T().Log("Logging before each")
+}

vendor/github.com/hashicorp/go-hclog/README.md

@@ -10,8 +10,7 @@ interface for use in development and production environments.
 It provides logging levels that provide decreased output based upon the
 desired amount of output, unlike the standard library `log` package.
 
-It does not provide `Printf` style logging, only key/value logging that is
-exposed as arguments to the logging functions for simplicity.
+It provides `Printf` style logging of values via `hclog.Fmt()`.
 
 It provides a human readable output mode for use in development as well as
 JSON output mode for production.
@@ -100,6 +99,17 @@ requestLogger.Info("we are transporting a request")
 This allows sub Loggers to be context specific without having to thread that
 into all the callers.
 
+### Using `hclog.Fmt()`
+
+```go
+var int totalBandwidth = 200
+appLogger.Info("total bandwidth exceeded", "bandwidth", hclog.Fmt("%d GB/s", totalBandwidth))
+```
+
+```text
+... [INFO ] my-app: total bandwidth exceeded: bandwidth="200 GB/s"
+```
+
 ### Use this with code that uses the standard library logger
 
 If you want to use the standard library's `log.Logger` interface you can wrap

vendor/github.com/hashicorp/go-hclog/int.go

@@ -2,14 +2,17 @@ package hclog
 
 import (
 	"bufio"
+	"encoding"
 	"encoding/json"
 	"fmt"
 	"log"
 	"os"
 	"runtime"
+	"sort"
 	"strconv"
 	"strings"
 	"sync"
+	"sync/atomic"
 	"time"
 )
 
@@ -39,28 +42,40 @@ func New(opts *LoggerOptions) Logger {
 		level = DefaultLevel
 	}
 
-	return &intLogger{
-		m:      new(sync.Mutex),
-		json:   opts.JSONFormat,
-		caller: opts.IncludeLocation,
-		name:   opts.Name,
-		w:      bufio.NewWriter(output),
-		level:  level,
+	mtx := opts.Mutex
+	if mtx == nil {
+		mtx = new(sync.Mutex)
 	}
+
+	ret := &intLogger{
+		m:          mtx,
+		json:       opts.JSONFormat,
+		caller:     opts.IncludeLocation,
+		name:       opts.Name,
+		timeFormat: TimeFormat,
+		w:          bufio.NewWriter(output),
+		level:      new(int32),
+	}
+	if opts.TimeFormat != "" {
+		ret.timeFormat = opts.TimeFormat
+	}
+	atomic.StoreInt32(ret.level, int32(level))
+	return ret
 }
 
 // The internal logger implementation. Internal in that it is defined entirely
 // by this package.
 type intLogger struct {
-	json   bool
-	caller bool
-	name   string
+	json       bool
+	caller     bool
+	name       string
+	timeFormat string
 
 	// this is a pointer so that it's shared by any derived loggers, since
 	// those derived loggers share the bufio.Writer as well.
 	m     *sync.Mutex
 	w     *bufio.Writer
-	level Level
+	level *int32
 
 	implied []interface{}
 }
@@ -75,7 +90,7 @@ const TimeFormat = "2006-01-02T15:04:05.000Z0700"
 // Log a message and a set of key/value pairs if the given level is at
 // or more severe that the threshold configured in the Logger.
 func (z *intLogger) Log(level Level, msg string, args ...interface{}) {
-	if level < z.level {
+	if level < Level(atomic.LoadInt32(z.level)) {
 		return
 	}
 
@@ -126,7 +141,7 @@ func trimCallerPath(path string) string {
 
 // Non-JSON logging format function
 func (z *intLogger) log(t time.Time, level Level, msg string, args ...interface{}) {
-	z.w.WriteString(t.Format(TimeFormat))
+	z.w.WriteString(t.Format(z.timeFormat))
 	z.w.WriteByte(' ')
 
 	s, ok := _levelToBracket[level]
@@ -202,6 +217,8 @@ func (z *intLogger) log(t time.Time, level Level, msg string, args ...interface{
 			case CapturedStacktrace:
 				stacktrace = st
 				continue FOR
+			case Format:
+				val = fmt.Sprintf(st[0].(string), st[1:]...)
 			default:
 				val = fmt.Sprintf("%v", st)
 			}
@@ -262,6 +279,8 @@ func (z *intLogger) logJson(t time.Time, level Level, msg string, args ...interf
 		}
 	}
 
+	args = append(z.implied, args...)
+
 	if args != nil && len(args) > 0 {
 		if len(args)%2 != 0 {
 			cs, ok := args[len(args)-1].(CapturedStacktrace)
@@ -279,7 +298,22 @@ func (z *intLogger) logJson(t time.Time, level Level, msg string, args ...interf
 				// without injecting into logs...
 				continue
 			}
-			vals[args[i].(string)] = args[i+1]
+			val := args[i+1]
+			switch sv := val.(type) {
+			case error:
+				// Check if val is of type error. If error type doesn't
+				// implement json.Marshaler or encoding.TextMarshaler
+				// then set val to err.Error() so that it gets marshaled
+				switch sv.(type) {
+				case json.Marshaler, encoding.TextMarshaler:
+				default:
+					val = sv.Error()
+				}
+			case Format:
+				val = fmt.Sprintf(sv[0].(string), sv[1:]...)
+			}
+
+			vals[args[i].(string)] = val
 		}
 	}
 
@@ -316,36 +350,66 @@ func (z *intLogger) Error(msg string, args ...interface{}) {
 
 // Indicate that the logger would emit TRACE level logs
 func (z *intLogger) IsTrace() bool {
-	return z.level == Trace
+	return Level(atomic.LoadInt32(z.level)) == Trace
 }
 
 // Indicate that the logger would emit DEBUG level logs
 func (z *intLogger) IsDebug() bool {
-	return z.level <= Debug
+	return Level(atomic.LoadInt32(z.level)) <= Debug
 }
 
 // Indicate that the logger would emit INFO level logs
 func (z *intLogger) IsInfo() bool {
-	return z.level <= Info
+	return Level(atomic.LoadInt32(z.level)) <= Info
 }
 
 // Indicate that the logger would emit WARN level logs
 func (z *intLogger) IsWarn() bool {
-	return z.level <= Warn
+	return Level(atomic.LoadInt32(z.level)) <= Warn
 }
 
 // Indicate that the logger would emit ERROR level logs
 func (z *intLogger) IsError() bool {
-	return z.level <= Error
+	return Level(atomic.LoadInt32(z.level)) <= Error
 }
 
 // Return a sub-Logger for which every emitted log message will contain
 // the given key/value pairs. This is used to create a context specific
 // Logger.
 func (z *intLogger) With(args ...interface{}) Logger {
+	if len(args)%2 != 0 {
+		panic("With() call requires paired arguments")
+	}
+
 	var nz intLogger = *z
 
-	nz.implied = append(nz.implied, args...)
+	result := make(map[string]interface{}, len(z.implied)+len(args))
+	keys := make([]string, 0, len(z.implied)+len(args))
+
+	// Read existing args, store map and key for consistent sorting
+	for i := 0; i < len(z.implied); i += 2 {
+		key := z.implied[i].(string)
+		keys = append(keys, key)
+		result[key] = z.implied[i+1]
+	}
+	// Read new args, store map and key for consistent sorting
+	for i := 0; i < len(args); i += 2 {
+		key := args[i].(string)
+		_, exists := result[key]
+		if !exists {
+			keys = append(keys, key)
+		}
+		result[key] = args[i+1]
+	}
+
+	// Sort keys to be consistent
+	sort.Strings(keys)
+
+	nz.implied = make([]interface{}, 0, len(z.implied)+len(args))
+	for _, k := range keys {
+		nz.implied = append(nz.implied, k)
+		nz.implied = append(nz.implied, result[k])
+	}
 
 	return &nz
 }
@@ -357,6 +421,8 @@ func (z *intLogger) Named(name string) Logger {
 
 	if nz.name != "" {
 		nz.name = nz.name + "." + name
+	} else {
+		nz.name = name
 	}
 
 	return &nz
@@ -373,6 +439,12 @@ func (z *intLogger) ResetNamed(name string) Logger {
 	return &nz
 }
 
+// Update the logging level on-the-fly. This will affect all subloggers as
+// well.
+func (z *intLogger) SetLevel(level Level) {
+	atomic.StoreInt32(z.level, int32(level))
+}
+
 // Create a *log.Logger that will send it's data through this Logger. This
 // allows packages that expect to be using the standard library log to actually
 // use this logger.

vendor/github.com/hashicorp/go-hclog/log.go

@@ -5,6 +5,7 @@ import (
 	"log"
 	"os"
 	"strings"
+	"sync"
 )
 
 var (
@@ -12,7 +13,7 @@ var (
 	DefaultLevel  = Info
 )
 
-type Level int
+type Level int32
 
 const (
 	// This is a special level used to indicate that no level has been
@@ -36,6 +37,18 @@ const (
 	Error Level = 5
 )
 
+// When processing a value of this type, the logger automatically treats the first
+// argument as a Printf formatting string and passes the rest as the values to be
+// formatted. For example: L.Info(Fmt{"%d beans/day", beans}). This is a simple
+// convience type for when formatting is required.
+type Format []interface{}
+
+// Fmt returns a Format type. This is a convience function for creating a Format
+// type.
+func Fmt(str string, args ...interface{}) Format {
+	return append(Format{str}, args...)
+}
+
 // LevelFromString returns a Level type for the named log level, or "NoLevel" if
 // the level string is invalid. This facilitates setting the log level via
 // config or environment variable by name in a predictable way.
@@ -108,6 +121,10 @@ type Logger interface {
 	// the current name as well.
 	ResetNamed(name string) Logger
 
+	// Updates the level. This should affect all sub-loggers as well. If an
+	// implementation cannot update the level on the fly, it should no-op.
+	SetLevel(level Level)
+
 	// Return a value that conforms to the stdlib log.Logger interface
 	StandardLogger(opts *StandardLoggerOptions) *log.Logger
 }
@@ -130,9 +147,15 @@ type LoggerOptions struct {
 	// Where to write the logs to. Defaults to os.Stdout if nil
 	Output io.Writer
 
+	// An optional mutex pointer in case Output is shared
+	Mutex *sync.Mutex
+
 	// Control if the output should be in JSON.
 	JSONFormat bool
 
-	// Intclude file and line information in each log line
+	// Include file and line information in each log line
 	IncludeLocation bool
+
+	// The time format to use instead of the default
+	TimeFormat string
 }

vendor/github.com/hashicorp/go-hclog/nulllogger.go

@@ -0,0 +1,47 @@
+package hclog
+
+import (
+	"io/ioutil"
+	"log"
+)
+
+// NewNullLogger instantiates a Logger for which all calls
+// will succeed without doing anything.
+// Useful for testing purposes.
+func NewNullLogger() Logger {
+	return &nullLogger{}
+}
+
+type nullLogger struct{}
+
+func (l *nullLogger) Trace(msg string, args ...interface{}) {}
+
+func (l *nullLogger) Debug(msg string, args ...interface{}) {}
+
+func (l *nullLogger) Info(msg string, args ...interface{}) {}
+
+func (l *nullLogger) Warn(msg string, args ...interface{}) {}
+
+func (l *nullLogger) Error(msg string, args ...interface{}) {}
+
+func (l *nullLogger) IsTrace() bool { return false }
+
+func (l *nullLogger) IsDebug() bool { return false }
+
+func (l *nullLogger) IsInfo() bool { return false }
+
+func (l *nullLogger) IsWarn() bool { return false }
+
+func (l *nullLogger) IsError() bool { return false }
+
+func (l *nullLogger) With(args ...interface{}) Logger { return l }
+
+func (l *nullLogger) Named(name string) Logger { return l }
+
+func (l *nullLogger) ResetNamed(name string) Logger { return l }
+
+func (l *nullLogger) SetLevel(level Level) {}
+
+func (l *nullLogger) StandardLogger(opts *StandardLoggerOptions) *log.Logger {
+	return log.New(ioutil.Discard, "", log.LstdFlags)
+}

vendor/vendor.json

@@ -150,7 +150,7 @@
 		{"path":"github.com/hashicorp/go-envparse","checksumSHA1":"FKmqR4DC3nCXtnT9pe02z5CLNWo=","revision":"310ca1881b22af3522e3a8638c0b426629886196","revisionTime":"2018-01-19T21:58:41Z"},
 		{"path":"github.com/hashicorp/go-getter","checksumSHA1":"uGH6AI982csQJoRPsSooK7FoWqo=","revision":"3f60ec5cfbb2a39731571b9ddae54b303bb0a969","revisionTime":"2018-04-25T22:41:30Z"},
 		{"path":"github.com/hashicorp/go-getter/helper/url","checksumSHA1":"9J+kDr29yDrwsdu2ULzewmqGjpA=","revision":"b345bfcec894fb7ff3fdf9b21baf2f56ea423d98","revisionTime":"2018-04-10T17:49:45Z"},
-		{"path":"github.com/hashicorp/go-hclog","checksumSHA1":"miVF4/7JP0lRwZvFJGKwZWk7aAQ=","revision":"b4e5765d1e5f00a0550911084f45f8214b5b83b9","revisionTime":"2017-07-16T17:45:23Z"},
+		{"path":"github.com/hashicorp/go-hclog","checksumSHA1":"dOP7kCX3dACHc9mU79826N411QA=","revision":"ff2cf002a8dd750586d91dddd4470c341f981fe1","revisionTime":"2018-07-09T16:53:50Z"},
 		{"path":"github.com/hashicorp/go-immutable-radix","checksumSHA1":"Cas2nprG6pWzf05A2F/OlnjUu2Y=","revision":"8aac2701530899b64bdea735a1de8da899815220","revisionTime":"2017-07-25T22:12:15Z"},
 		{"path":"github.com/hashicorp/go-memdb","checksumSHA1":"FMAvwDar2bQyYAW4XMFhAt0J5xA=","revision":"20ff6434c1cc49b80963d45bf5c6aa89c78d8d57","revisionTime":"2017-08-31T20:15:40Z"},
 		{"path":"github.com/hashicorp/go-msgpack/codec","revision":"fa3f63826f7c23912c15263591e65d54d080b458"},