From e5736419955b59f930a36c36ab78f9c57540aac5 Mon Sep 17 00:00:00 2001 From: Daniel Nephin Date: Wed, 2 Jun 2021 16:29:29 -0400 Subject: [PATCH 1/6] cmd: remove unnecessary args to agent.New The version args are static and passed in from the caller. Instead read the static values in New. The shutdownCh was never closed, so did nothing. Remove it as a field and an arg. --- command/agent/agent.go | 15 ++++++--------- command/agent/agent_test.go | 12 ++++++------ command/commands_oss.go | 10 +--------- 3 files changed, 13 insertions(+), 24 deletions(-) diff --git a/command/agent/agent.go b/command/agent/agent.go index b7574f0397..4a1f8314f8 100644 --- a/command/agent/agent.go +++ b/command/agent/agent.go @@ -21,9 +21,10 @@ import ( "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 { +func New(ui cli.Ui) *cmd { ui = &cli.PrefixedUi{ OutputPrefix: "==> ", InfoPrefix: " ", @@ -33,11 +34,10 @@ func New(ui cli.Ui, revision, version, versionPre, versionHuman string, shutdown c := &cmd{ UI: ui, - revision: revision, - version: version, - versionPrerelease: versionPre, - versionHuman: versionHuman, - shutdownCh: shutdownCh, + revision: consulversion.GitCommit, + version: consulversion.Version, + versionPrerelease: consulversion.VersionPrerelease, + versionHuman: consulversion.GetHumanVersion(), flags: flag.NewFlagSet("", flag.ContinueOnError), } config.AddFlags(c.flags, &c.configLoadOpts) @@ -58,7 +58,6 @@ type cmd struct { version string versionPrerelease string versionHuman string - shutdownCh <-chan struct{} configLoadOpts config.LoadOpts logger hclog.InterceptLogger } @@ -281,8 +280,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 diff --git a/command/agent/agent_test.go b/command/agent/agent_test.go index 4a051294f9..d6b9f0a646 100644 --- a/command/agent/agent_test.go +++ b/command/agent/agent_test.go @@ -8,12 +8,12 @@ import ( "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. @@ -121,7 +121,7 @@ func TestRetryJoinFail(t *testing.T) { tmpDir := testutil.TempDir(t, "consul") ui := cli.NewMockUi() - cmd := New(ui, "", "", "", "", nil) + cmd := New(ui) args := []string{ "-bind", "127.0.0.1", @@ -145,7 +145,7 @@ func TestRetryJoinWanFail(t *testing.T) { tmpDir := testutil.TempDir(t, "consul") ui := cli.NewMockUi() - cmd := New(ui, "", "", "", "", nil) + cmd := New(ui) args := []string{ "-server", @@ -184,7 +184,7 @@ func TestProtectDataDir(t *testing.T) { } ui := cli.NewMockUi() - cmd := New(ui, "", "", "", "", nil) + cmd := New(ui) args := []string{"-config-file=" + cfgFile.Name()} if code := cmd.Run(args); code == 0 { t.Fatalf("should fail") @@ -203,7 +203,7 @@ func TestBadDataDirPermissions(t *testing.T) { } ui := cli.NewMockUi() - cmd := New(ui, "", "", "", "", nil) + 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") diff --git a/command/commands_oss.go b/command/commands_oss.go index facdb51193..07866a0e78 100644 --- a/command/commands_oss.go +++ b/command/commands_oss.go @@ -108,17 +108,11 @@ 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 +148,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 }) From 2fc988d51d93f3ca212fac3209fbd4e80b67db46 Mon Sep 17 00:00:00 2001 From: Daniel Nephin Date: Wed, 2 Jun 2021 16:51:34 -0400 Subject: [PATCH 2/6] cmd: introduce a shim to expose Stdout/Stderr writers This will allow commands to do the right thing, and write to the proper output stream. --- command/cli/cli.go | 32 ++++++++++++++++++++++++++++++++ command/commands_oss.go | 3 +-- command/registry.go | 12 +++++++----- main.go | 14 +++++++++----- 4 files changed, 49 insertions(+), 12 deletions(-) create mode 100644 command/cli/cli.go diff --git a/command/cli/cli.go b/command/cli/cli.go new file mode 100644 index 0000000000..6a7edd7202 --- /dev/null +++ b/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 diff --git a/command/commands_oss.go b/command/commands_oss.go index 07866a0e78..cfa8a7e621 100644 --- a/command/commands_oss.go +++ b/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,8 +109,6 @@ import ( "github.com/hashicorp/consul/command/validate" "github.com/hashicorp/consul/command/version" "github.com/hashicorp/consul/command/watch" - - "github.com/mitchellh/cli" ) func init() { diff --git a/command/registry.go b/command/registry.go index 2b092ae722..a96818c2f3 100644 --- a/command/registry.go +++ b/command/registry.go @@ -6,7 +6,9 @@ import ( "os/signal" "syscall" - "github.com/mitchellh/cli" + mcli "github.com/mitchellh/cli" + + "github.com/hashicorp/consul/command/cli" ) // Factory is a function that returns a new instance of a CLI-sub command. @@ -24,14 +26,14 @@ func Register(name string, fn Factory) { registry[name] = fn } -// Map returns a realized mapping of available CLI commands in a format that +// CommandsFromRegistry returns a realized mapping of available CLI commands in a format that // the CLI class can consume. This should be called after all registration is // complete. -func Map(ui cli.Ui) map[string]cli.CommandFactory { - m := make(map[string]cli.CommandFactory) +func CommandsFromRegistry(ui cli.Ui) map[string]mcli.CommandFactory { + m := make(map[string]mcli.CommandFactory) for name, fn := range registry { thisFn := fn - m[name] = func() (cli.Command, error) { + m[name] = func() (mcli.Command, error) { return thisFn(ui) } } diff --git a/main.go b/main.go index 6ffcd431f0..9505f2906e 100644 --- a/main.go +++ b/main.go @@ -6,11 +6,13 @@ import ( "log" "os" + mcli "github.com/mitchellh/cli" + "github.com/hashicorp/consul/command" + "github.com/hashicorp/consul/command/cli" "github.com/hashicorp/consul/command/version" "github.com/hashicorp/consul/lib" _ "github.com/hashicorp/consul/service_os" - "github.com/mitchellh/cli" ) func init() { @@ -24,19 +26,21 @@ func main() { func realMain() int { log.SetOutput(ioutil.Discard) - ui := &cli.BasicUi{Writer: os.Stdout, ErrorWriter: os.Stderr} - cmds := command.Map(ui) + ui := &cli.BasicUI{ + BasicUi: mcli.BasicUi{Writer: os.Stdout, ErrorWriter: os.Stderr}, + } + cmds := command.CommandsFromRegistry(ui) var names []string for c := range cmds { names = append(names, c) } - cli := &cli.CLI{ + cli := &mcli.CLI{ Args: os.Args[1:], Commands: cmds, Autocomplete: true, Name: "consul", - HelpFunc: cli.FilteredHelpFunc(names, cli.BasicHelpFunc("consul")), + HelpFunc: mcli.FilteredHelpFunc(names, mcli.BasicHelpFunc("consul")), HelpWriter: os.Stdout, ErrorWriter: os.Stderr, } From b4b85bd83add340655779d1c3e58afde6e0011cf Mon Sep 17 00:00:00 2001 From: Daniel Nephin Date: Wed, 2 Jun 2021 17:12:44 -0400 Subject: [PATCH 3/6] agent: fix agent logging Remove the leading whitespace on every log line. This was causing problems for a customer because their logging system was interpretting the logs as a single multi-line log. --- command/agent/agent.go | 47 ++++++++++++++++++++----------------- command/agent/agent_test.go | 25 ++++++++++++++++---- 2 files changed, 46 insertions(+), 26 deletions(-) diff --git a/command/agent/agent.go b/command/agent/agent.go index 4a1f8314f8..cbf3d78583 100644 --- a/command/agent/agent.go +++ b/command/agent/agent.go @@ -13,10 +13,11 @@ 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" @@ -25,15 +26,8 @@ import ( ) func New(ui cli.Ui) *cmd { - ui = &cli.PrefixedUi{ - OutputPrefix: "==> ", - InfoPrefix: " ", - ErrorPrefix: "==> ", - Ui: ui, - } - c := &cmd{ - UI: ui, + ui: ui, revision: consulversion.GitCommit, version: consulversion.Version, versionPrerelease: consulversion.VersionPrerelease, @@ -50,7 +44,7 @@ func New(ui cli.Ui) *cmd { // 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 @@ -118,7 +112,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 @@ -134,43 +128,52 @@ 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 } @@ -179,7 +182,7 @@ func (c *cmd) run(args []string) int { // Setup gate to check if we should output CLI information cli := GatedUi{ JSONoutput: config.Logging.LogJSON, - ui: c.UI, + ui: ui, } // Create the agent @@ -255,12 +258,12 @@ 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 } @@ -340,7 +343,7 @@ func (c *cmd) run(args []string) int { type GatedUi struct { JSONoutput bool - ui cli.Ui + ui mcli.Ui } func (g *GatedUi) output(s string) { diff --git a/command/agent/agent_test.go b/command/agent/agent_test.go index d6b9f0a646..074702130a 100644 --- a/command/agent/agent_test.go +++ b/command/agent/agent_test.go @@ -2,6 +2,7 @@ package agent import ( "fmt" + "io" "os" "os/exec" "path/filepath" @@ -120,7 +121,7 @@ func TestRetryJoinFail(t *testing.T) { t.Parallel() tmpDir := testutil.TempDir(t, "consul") - ui := cli.NewMockUi() + ui := newCaptureUI() cmd := New(ui) args := []string{ @@ -144,7 +145,7 @@ func TestRetryJoinWanFail(t *testing.T) { t.Parallel() tmpDir := testutil.TempDir(t, "consul") - ui := cli.NewMockUi() + ui := newCaptureUI() cmd := New(ui) args := []string{ @@ -183,7 +184,7 @@ func TestProtectDataDir(t *testing.T) { t.Fatalf("err: %v", err) } - ui := cli.NewMockUi() + ui := newCaptureUI() cmd := New(ui) args := []string{"-config-file=" + cfgFile.Name()} if code := cmd.Run(args); code == 0 { @@ -202,7 +203,7 @@ func TestBadDataDirPermissions(t *testing.T) { t.Fatalf("err: %v", err) } - ui := cli.NewMockUi() + ui := newCaptureUI() cmd := New(ui) args := []string{"-data-dir=" + dataDir, "-server=true", "-bind=10.0.0.1"} if code := cmd.Run(args); code == 0 { @@ -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()} +} From 2261a469e3c78fdde72daea72047da19f0676c33 Mon Sep 17 00:00:00 2001 From: Daniel Nephin Date: Wed, 2 Jun 2021 17:17:43 -0400 Subject: [PATCH 4/6] cmd: move agent running message to logs Previously this line was mixed up with logging, which made the output quite ugly. Use the logger to output this message, instead of printing directly to stdout. This has the advantage that the message will be visible when json logs are enabled. --- command/agent/agent.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/command/agent/agent.go b/command/agent/agent.go index cbf3d78583..ef65a025e7 100644 --- a/command/agent/agent.go +++ b/command/agent/agent.go @@ -270,7 +270,7 @@ func (c *cmd) run(args []string) int { // 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) From cec8bc88a96b2318d4c3cf1e7164fe389ca5649d Mon Sep 17 00:00:00 2001 From: Daniel Nephin Date: Wed, 2 Jun 2021 17:26:50 -0400 Subject: [PATCH 5/6] cmd: remove unnecessary GatedUi The intent of this struct was to prevent non-json output to stdout. With the previous cleanup, this can now be done by simply changing the stdout stream to io.Discard. This is just one example of why passing around io.Writers for the streams is better than the UI interface. --- command/agent/agent.go | 51 ++++++++++++++---------------------------- 1 file changed, 17 insertions(+), 34 deletions(-) diff --git a/command/agent/agent.go b/command/agent/agent.go index ef65a025e7..a0a3601c64 100644 --- a/command/agent/agent.go +++ b/command/agent/agent.go @@ -4,6 +4,7 @@ import ( "context" "flag" "fmt" + "io" "os" "os/signal" "path/filepath" @@ -178,34 +179,33 @@ func (c *cmd) run(args []string) int { } config := bd.RuntimeConfig - - // Setup gate to check if we should output CLI information - cli := GatedUi{ - JSONoutput: config.Logging.LogJSON, - ui: 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 = "" } - 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 @@ -341,23 +341,6 @@ func (c *cmd) run(args []string) int { } } -type GatedUi struct { - JSONoutput bool - ui mcli.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 } From 99956cde374816e0ea43de66c6addc7e9834288f Mon Sep 17 00:00:00 2001 From: Daniel Nephin Date: Wed, 2 Jun 2021 17:39:30 -0400 Subject: [PATCH 6/6] Add changelog --- .changelog/10338.txt | 3 +++ 1 file changed, 3 insertions(+) create mode 100644 .changelog/10338.txt diff --git a/.changelog/10338.txt b/.changelog/10338.txt new file mode 100644 index 0000000000..2b0b955b28 --- /dev/null +++ b/.changelog/10338.txt @@ -0,0 +1,3 @@ +```release-note:bug +agent: fix logging output by removing leading whitespace from every log line +```