Merge pull request #10338 from hashicorp/dnephin/fix-logging-indent

agent: remove leading whitespace from agent log lines

.changelog/10338.txt

@@ -0,0 +1,3 @@
+```release-note:bug
+agent: fix logging output by removing leading whitespace from every log line
+```

command/agent/agent.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"flag"
 	"fmt"
+	"io"
 	"os"
 	"os/signal"
 	"path/filepath"
@@ -13,31 +14,25 @@ import (
 
 	"github.com/hashicorp/go-checkpoint"
 	"github.com/hashicorp/go-hclog"
-	"github.com/mitchellh/cli"
+	mcli "github.com/mitchellh/cli"
 
 	"github.com/hashicorp/consul/agent"
 	"github.com/hashicorp/consul/agent/config"
+	"github.com/hashicorp/consul/command/cli"
 	"github.com/hashicorp/consul/command/flags"
 	"github.com/hashicorp/consul/lib"
 	"github.com/hashicorp/consul/logging"
 	"github.com/hashicorp/consul/service_os"
+	consulversion "github.com/hashicorp/consul/version"
 )
 
-func New(ui cli.Ui, revision, version, versionPre, versionHuman string, shutdownCh <-chan struct{}) *cmd {
-	ui = &cli.PrefixedUi{
-		OutputPrefix: "==> ",
-		InfoPrefix:   "    ",
-		ErrorPrefix:  "==> ",
-		Ui:           ui,
-	}
-
+func New(ui cli.Ui) *cmd {
 	c := &cmd{
-		UI:                ui,
-		revision:          revision,
-		version:           version,
-		versionPrerelease: versionPre,
-		versionHuman:      versionHuman,
-		shutdownCh:        shutdownCh,
+		ui:                ui,
+		revision:          consulversion.GitCommit,
+		version:           consulversion.Version,
+		versionPrerelease: consulversion.VersionPrerelease,
+		versionHuman:      consulversion.GetHumanVersion(),
 		flags:             flag.NewFlagSet("", flag.ContinueOnError),
 	}
 	config.AddFlags(c.flags, &c.configLoadOpts)
@@ -50,15 +45,14 @@ func New(ui cli.Ui, revision, version, versionPre, versionHuman string, shutdown
 // ShutdownCh. If two messages are sent on the ShutdownCh it will forcibly
 // exit.
 type cmd struct {
-	UI                cli.Ui
+	ui                cli.Ui
 	flags             *flag.FlagSet
 	http              *flags.HTTPFlags
 	help              string
 	revision          string
 	version           string
 	versionPrerelease string
 	versionHuman      string
-	shutdownCh        <-chan struct{}
 	configLoadOpts    config.LoadOpts
 	logger            hclog.InterceptLogger
 }
@@ -119,7 +113,7 @@ func (c *cmd) startupJoin(agent *agent.Agent, cfg *config.RuntimeConfig) error {
 		return nil
 	}
 
-	c.UI.Output("Joining cluster...")
+	c.logger.Info("Joining cluster")
 	n, err := agent.JoinLAN(cfg.StartJoinAddrsLAN)
 	if err != nil {
 		return err
@@ -135,75 +129,83 @@ func (c *cmd) startupJoinWan(agent *agent.Agent, cfg *config.RuntimeConfig) erro
 		return nil
 	}
 
-	c.UI.Output("Joining -wan cluster...")
+	c.logger.Info("Joining wan cluster")
 	n, err := agent.JoinWAN(cfg.StartJoinAddrsWAN)
 	if err != nil {
 		return err
 	}
 
-	c.logger.Info("Join -wan completed. Initial agents synced with", "agent_count", n)
+	c.logger.Info("Join wan completed. Initial agents synced with", "agent_count", n)
 	return nil
 }
 
 func (c *cmd) run(args []string) int {
+	ui := &mcli.PrefixedUi{
+		OutputPrefix: "==> ",
+		InfoPrefix:   "    ",
+		ErrorPrefix:  "==> ",
+		Ui:           c.ui,
+	}
+
 	if err := c.flags.Parse(args); err != nil {
 		if !strings.Contains(err.Error(), "help requested") {
-			c.UI.Error(fmt.Sprintf("error parsing flags: %v", err))
+			ui.Error(fmt.Sprintf("error parsing flags: %v", err))
 		}
 		return 1
 	}
 	if len(c.flags.Args()) > 0 {
-		c.UI.Error(fmt.Sprintf("Unexpected extra arguments: %v", c.flags.Args()))
+		ui.Error(fmt.Sprintf("Unexpected extra arguments: %v", c.flags.Args()))
 		return 1
 	}
 
-	logGate := &logging.GatedWriter{Writer: &cli.UiWriter{Ui: c.UI}}
+	// FIXME: logs should always go to stderr, but previously they were sent to
+	// stdout, so continue to use Stdout for now, and fix this in a future release.
+	logGate := &logging.GatedWriter{Writer: c.ui.Stdout()}
 	loader := func(source config.Source) (config.LoadResult, error) {
 		c.configLoadOpts.DefaultConfig = source
 		return config.Load(c.configLoadOpts)
 	}
 	bd, err := agent.NewBaseDeps(loader, logGate)
 	if err != nil {
-		c.UI.Error(err.Error())
+		ui.Error(err.Error())
 		return 1
 	}
 
 	c.logger = bd.Logger
 	agent, err := agent.New(bd)
 	if err != nil {
-		c.UI.Error(err.Error())
+		ui.Error(err.Error())
 		return 1
 	}
 
 	config := bd.RuntimeConfig
-
-	// Setup gate to check if we should output CLI information
-	cli := GatedUi{
-		JSONoutput: config.Logging.LogJSON,
-		ui:         c.UI,
+	if config.Logging.LogJSON {
+		// Hide all non-error output when JSON logging is enabled.
+		ui.Ui = &cli.BasicUI{
+			BasicUi: mcli.BasicUi{ErrorWriter: c.ui.Stderr(), Writer: io.Discard},
+		}
 	}
 
-	// Create the agent
-	cli.output("Starting Consul agent...")
+	ui.Output("Starting Consul agent...")
 
 	segment := config.SegmentName
 	if config.ServerMode {
 		segment = "<all>"
 	}
-	cli.info(fmt.Sprintf("       Version: '%s'", c.versionHuman))
-	cli.info(fmt.Sprintf("       Node ID: '%s'", config.NodeID))
-	cli.info(fmt.Sprintf("     Node name: '%s'", config.NodeName))
-	cli.info(fmt.Sprintf("    Datacenter: '%s' (Segment: '%s')", config.Datacenter, segment))
-	cli.info(fmt.Sprintf("        Server: %v (Bootstrap: %v)", config.ServerMode, config.Bootstrap))
-	cli.info(fmt.Sprintf("   Client Addr: %v (HTTP: %d, HTTPS: %d, gRPC: %d, DNS: %d)", config.ClientAddrs,
+	ui.Info(fmt.Sprintf("       Version: '%s'", c.versionHuman))
+	ui.Info(fmt.Sprintf("       Node ID: '%s'", config.NodeID))
+	ui.Info(fmt.Sprintf("     Node name: '%s'", config.NodeName))
+	ui.Info(fmt.Sprintf("    Datacenter: '%s' (Segment: '%s')", config.Datacenter, segment))
+	ui.Info(fmt.Sprintf("        Server: %v (Bootstrap: %v)", config.ServerMode, config.Bootstrap))
+	ui.Info(fmt.Sprintf("   Client Addr: %v (HTTP: %d, HTTPS: %d, gRPC: %d, DNS: %d)", config.ClientAddrs,
 		config.HTTPPort, config.HTTPSPort, config.GRPCPort, config.DNSPort))
-	cli.info(fmt.Sprintf("  Cluster Addr: %v (LAN: %d, WAN: %d)", config.AdvertiseAddrLAN,
+	ui.Info(fmt.Sprintf("  Cluster Addr: %v (LAN: %d, WAN: %d)", config.AdvertiseAddrLAN,
 		config.SerfPortLAN, config.SerfPortWAN))
-	cli.info(fmt.Sprintf("       Encrypt: Gossip: %v, TLS-Outgoing: %v, TLS-Incoming: %v, Auto-Encrypt-TLS: %t",
+	ui.Info(fmt.Sprintf("       Encrypt: Gossip: %v, TLS-Outgoing: %v, TLS-Incoming: %v, Auto-Encrypt-TLS: %t",
 		config.EncryptKey != "", config.VerifyOutgoing, config.VerifyIncoming, config.AutoEncryptTLS || config.AutoEncryptAllowTLS))
 	// Enable log streaming
-	cli.output("")
-	cli.output("Log data will now stream in as it occurs:\n")
+	ui.Output("")
+	ui.Output("Log data will now stream in as it occurs:\n")
 	logGate.Flush()
 
 	// wait for signal
@@ -256,19 +258,19 @@ func (c *cmd) run(args []string) int {
 	}
 
 	if err := c.startupJoin(agent, config); err != nil {
-		c.logger.Error((err.Error()))
+		c.logger.Error(err.Error())
 		return 1
 	}
 
 	if err := c.startupJoinWan(agent, config); err != nil {
-		c.logger.Error((err.Error()))
+		c.logger.Error(err.Error())
 		return 1
 	}
 
 	// Let the agent know we've finished registration
 	agent.StartSync()
 
-	cli.output("Consul agent running!")
+	c.logger.Info("Consul agent running!")
 
 	// wait for signal
 	signalCh = make(chan os.Signal, 10)
@@ -281,8 +283,6 @@ func (c *cmd) run(args []string) int {
 			sig = s
 		case <-service_os.Shutdown_Channel():
 			sig = os.Interrupt
-		case <-c.shutdownCh:
-			sig = os.Interrupt
 		case err := <-agent.RetryJoinCh():
 			c.logger.Error("Retry join failed", "error", err)
 			return 1
@@ -341,23 +341,6 @@ func (c *cmd) run(args []string) int {
 	}
 }
 
-type GatedUi struct {
-	JSONoutput bool
-	ui         cli.Ui
-}
-
-func (g *GatedUi) output(s string) {
-	if !g.JSONoutput {
-		g.ui.Output(s)
-	}
-}
-
-func (g *GatedUi) info(s string) {
-	if !g.JSONoutput {
-		g.ui.Info(s)
-	}
-}
-
 func (c *cmd) Synopsis() string {
 	return synopsis
 }

command/agent/agent_test.go

@@ -2,18 +2,19 @@ package agent
 
 import (
 	"fmt"
+	"io"
 	"os"
 	"os/exec"
 	"path/filepath"
 	"strings"
 	"testing"
 
-	"github.com/hashicorp/consul/testrpc"
+	"github.com/mitchellh/cli"
 
 	"github.com/hashicorp/consul/agent"
 	"github.com/hashicorp/consul/sdk/testutil"
 	"github.com/hashicorp/consul/sdk/testutil/retry"
-	"github.com/mitchellh/cli"
+	"github.com/hashicorp/consul/testrpc"
 )
 
 // TestConfigFail should test command line flags that lead to an immediate error.
@@ -120,8 +121,8 @@ func TestRetryJoinFail(t *testing.T) {
 	t.Parallel()
 	tmpDir := testutil.TempDir(t, "consul")
 
-	ui := cli.NewMockUi()
-	cmd := New(ui, "", "", "", "", nil)
+	ui := newCaptureUI()
+	cmd := New(ui)
 
 	args := []string{
 		"-bind", "127.0.0.1",
@@ -144,8 +145,8 @@ func TestRetryJoinWanFail(t *testing.T) {
 	t.Parallel()
 	tmpDir := testutil.TempDir(t, "consul")
 
-	ui := cli.NewMockUi()
-	cmd := New(ui, "", "", "", "", nil)
+	ui := newCaptureUI()
+	cmd := New(ui)
 
 	args := []string{
 		"-server",
@@ -183,8 +184,8 @@ func TestProtectDataDir(t *testing.T) {
 		t.Fatalf("err: %v", err)
 	}
 
-	ui := cli.NewMockUi()
-	cmd := New(ui, "", "", "", "", nil)
+	ui := newCaptureUI()
+	cmd := New(ui)
 	args := []string{"-config-file=" + cfgFile.Name()}
 	if code := cmd.Run(args); code == 0 {
 		t.Fatalf("should fail")
@@ -202,8 +203,8 @@ func TestBadDataDirPermissions(t *testing.T) {
 		t.Fatalf("err: %v", err)
 	}
 
-	ui := cli.NewMockUi()
-	cmd := New(ui, "", "", "", "", nil)
+	ui := newCaptureUI()
+	cmd := New(ui)
 	args := []string{"-data-dir=" + dataDir, "-server=true", "-bind=10.0.0.1"}
 	if code := cmd.Run(args); code == 0 {
 		t.Fatalf("Should fail with bad data directory permissions")
@@ -212,3 +213,19 @@ func TestBadDataDirPermissions(t *testing.T) {
 		t.Fatalf("expected permission denied error, got: %s", out)
 	}
 }
+
+type captureUI struct {
+	*cli.MockUi
+}
+
+func (c *captureUI) Stdout() io.Writer {
+	return c.MockUi.OutputWriter
+}
+
+func (c *captureUI) Stderr() io.Writer {
+	return c.MockUi.ErrorWriter
+}
+
+func newCaptureUI() *captureUI {
+	return &captureUI{MockUi: cli.NewMockUi()}
+}

command/cli/cli.go

@@ -0,0 +1,32 @@
+package cli
+
+import (
+	"io"
+
+	mcli "github.com/mitchellh/cli"
+)
+
+// Ui implements the mitchellh/cli.Ui interface, while exposing the underlying
+// io.Writer used for stdout and stderr.
+// TODO: rename to UI to match golang style guide
+type Ui interface {
+	mcli.Ui
+	Stdout() io.Writer
+	Stderr() io.Writer
+}
+
+// BasicUI augments mitchellh/cli.BasicUi by exposing the underlying io.Writer.
+type BasicUI struct {
+	mcli.BasicUi
+}
+
+func (b *BasicUI) Stdout() io.Writer {
+	return b.BasicUi.Writer
+}
+
+func (b *BasicUI) Stderr() io.Writer {
+	return b.BasicUi.ErrorWriter
+}
+
+// Command is an alias to reduce the diff. It can be removed at any time.
+type Command mcli.Command

command/commands_oss.go

@@ -41,6 +41,7 @@ import (
 	catlistdc "github.com/hashicorp/consul/command/catalog/list/dc"
 	catlistnodes "github.com/hashicorp/consul/command/catalog/list/nodes"
 	catlistsvc "github.com/hashicorp/consul/command/catalog/list/services"
+	"github.com/hashicorp/consul/command/cli"
 	"github.com/hashicorp/consul/command/config"
 	configdelete "github.com/hashicorp/consul/command/config/delete"
 	configlist "github.com/hashicorp/consul/command/config/list"
@@ -108,17 +109,9 @@ import (
 	"github.com/hashicorp/consul/command/validate"
 	"github.com/hashicorp/consul/command/version"
 	"github.com/hashicorp/consul/command/watch"
-	consulversion "github.com/hashicorp/consul/version"
-
-	"github.com/mitchellh/cli"
 )
 
 func init() {
-	rev := consulversion.GitCommit
-	ver := consulversion.Version
-	verPre := consulversion.VersionPrerelease
-	verHuman := consulversion.GetHumanVersion()
-
 	Register("acl", func(cli.Ui) (cli.Command, error) { return acl.New(), nil })
 	Register("acl bootstrap", func(ui cli.Ui) (cli.Command, error) { return aclbootstrap.New(ui), nil })
 	Register("acl policy", func(cli.Ui) (cli.Command, error) { return aclpolicy.New(), nil })
@@ -154,9 +147,7 @@ func init() {
 	Register("acl binding-rule read", func(ui cli.Ui) (cli.Command, error) { return aclbrread.New(ui), nil })
 	Register("acl binding-rule update", func(ui cli.Ui) (cli.Command, error) { return aclbrupdate.New(ui), nil })
 	Register("acl binding-rule delete", func(ui cli.Ui) (cli.Command, error) { return aclbrdelete.New(ui), nil })
-	Register("agent", func(ui cli.Ui) (cli.Command, error) {
-		return agent.New(ui, rev, ver, verPre, verHuman, make(chan struct{})), nil
-	})
+	Register("agent", func(ui cli.Ui) (cli.Command, error) { return agent.New(ui), nil })
 	Register("catalog", func(cli.Ui) (cli.Command, error) { return catalog.New(), nil })
 	Register("catalog datacenters", func(ui cli.Ui) (cli.Command, error) { return catlistdc.New(ui), nil })
 	Register("catalog nodes", func(ui cli.Ui) (cli.Command, error) { return catlistnodes.New(ui), nil })