From 74cfdf55bb252a8b74ece90837755353d5cfa8ee Mon Sep 17 00:00:00 2001 From: Drew Bailey <2614075+drewbailey@users.noreply.github.com> Date: Mon, 7 Oct 2019 16:41:52 -0400 Subject: [PATCH] Adds nomad monitor command Adds nomad monitor command. Like consul monitor, this command allows you to stream logs from a nomad agent in real time with a a specified log level add endpoint tests Upgrade go-hclog to latest version The current version of go-hclog pads log prefixes to equal lengths so info becomes [INFO ] and debug becomes [DEBUG]. This breaks hashicorp/logutils/level.go Check function. Upgrading to the latest version removes this padding and fixes log filtering that uses logutils Check --- command/agent/agent_endpoint.go | 2 +- command/agent/agent_endpoint_test.go | 66 +++ command/agent/http.go | 1 + command/agent/testagent.go | 10 +- command/agent_monitor.go | 85 ++++ command/agent_monitor_test.go | 34 ++ command/commands.go | 5 + .../github.com/hashicorp/go-hclog/README.md | 15 + .../github.com/hashicorp/go-hclog/context.go | 38 ++ .../github.com/hashicorp/go-hclog/global.go | 40 +- vendor/github.com/hashicorp/go-hclog/go.mod | 7 + vendor/github.com/hashicorp/go-hclog/go.sum | 6 + .../go-hclog/{int.go => intlogger.go} | 380 +++++++++++------- .../hashicorp/go-hclog/{log.go => logger.go} | 47 ++- .../hashicorp/go-hclog/nulllogger.go | 7 +- .../hashicorp/go-hclog/stacktrace.go | 9 +- .../github.com/hashicorp/go-hclog/stdlog.go | 50 ++- .../github.com/hashicorp/go-hclog/writer.go | 74 ++++ vendor/vendor.json | 2 +- 19 files changed, 673 insertions(+), 205 deletions(-) create mode 100644 command/agent_monitor.go create mode 100644 command/agent_monitor_test.go create mode 100644 vendor/github.com/hashicorp/go-hclog/context.go create mode 100644 vendor/github.com/hashicorp/go-hclog/go.mod create mode 100644 vendor/github.com/hashicorp/go-hclog/go.sum rename vendor/github.com/hashicorp/go-hclog/{int.go => intlogger.go} (54%) rename vendor/github.com/hashicorp/go-hclog/{log.go => logger.go} (72%) create mode 100644 vendor/github.com/hashicorp/go-hclog/writer.go diff --git a/command/agent/agent_endpoint.go b/command/agent/agent_endpoint.go index cdf7a50ad..ffb505c0e 100644 --- a/command/agent/agent_endpoint.go +++ b/command/agent/agent_endpoint.go @@ -167,7 +167,7 @@ func (s *HTTPServer) AgentMonitor(resp http.ResponseWriter, req *http.Request) ( // Create a level filter and flusher. filter := LevelFilter() - filter.MinLevel = logutils.LogLevel(strings.ToUpper(logLevel)) + filter.SetMinLevel(logutils.LogLevel(strings.ToUpper(logLevel))) if !ValidateLevelFilter(filter.MinLevel, filter) { return nil, CodedError(400, fmt.Sprintf("Unknown log level: %s", filter.MinLevel)) diff --git a/command/agent/agent_endpoint_test.go b/command/agent/agent_endpoint_test.go index d9e26f186..5714b1c7b 100644 --- a/command/agent/agent_endpoint_test.go +++ b/command/agent/agent_endpoint_test.go @@ -8,6 +8,7 @@ import ( "net/http" "net/http/httptest" "net/url" + "strings" "testing" "time" @@ -249,11 +250,76 @@ func TestHTTP_AgentMembers_ACL(t *testing.T) { }) } +func TestHTTP_AgentMonitor(t *testing.T) { + t.Parallel() + + httpTest(t, nil, func(s *TestAgent) { + { + req, err := http.NewRequest("GET", "/v1/agent/monitor?loglevel=unkown", nil) + require.Nil(t, err) + resp := newClosableRecorder() + + // Make the request + _, err = s.Server.AgentMonitor(resp, req) + if err.(HTTPCodedError).Code() != 400 { + t.Fatalf("expected 400 response, got: %v", resp.Code) + } + } + + // check for a specific log + { + req, err := http.NewRequest("GET", "/v1/agent/monitor?loglevel=warn", nil) + require.Nil(t, err) + resp := newClosableRecorder() + defer resp.Close() + + go func() { + s.Server.logger.Debug("log that should not be sent") + s.Server.logger.Warn("log that should be sent") + _, err = s.Server.AgentMonitor(resp, req) + require.NoError(t, err) + }() + + testutil.WaitForResult(func() (bool, error) { + got := resp.Body.String() + want := "[WARN ] http: log that should be sent" + if strings.Contains(got, want) { + require.NotContains(t, resp.Body.String(), "[INFO ]") + return true, nil + } + return false, fmt.Errorf("missing expected log, got: %v, want: %v", got, want) + }, func(err error) { + require.Fail(t, err.Error()) + }) + } + }) +} + +type closableRecorder struct { + *httptest.ResponseRecorder + closer chan bool +} + +func newClosableRecorder() *closableRecorder { + r := httptest.NewRecorder() + closer := make(chan bool) + return &closableRecorder{r, closer} +} + +func (r *closableRecorder) Close() { + close(r.closer) +} + +func (r *closableRecorder) CloseNotify() <-chan bool { + return r.closer +} + func TestHTTP_AgentForceLeave(t *testing.T) { t.Parallel() httpTest(t, nil, func(s *TestAgent) { // Make the HTTP request req, err := http.NewRequest("PUT", "/v1/agent/force-leave?node=foo", nil) + require.Nil(t, err) if err != nil { t.Fatalf("err: %v", err) } diff --git a/command/agent/http.go b/command/agent/http.go index 6ea45dcff..045a2fa49 100644 --- a/command/agent/http.go +++ b/command/agent/http.go @@ -185,6 +185,7 @@ func (s *HTTPServer) registerHandlers(enableDebug bool) { s.mux.HandleFunc("/v1/agent/servers", s.wrap(s.AgentServersRequest)) s.mux.HandleFunc("/v1/agent/keyring/", s.wrap(s.KeyringOperationRequest)) s.mux.HandleFunc("/v1/agent/health", s.wrap(s.HealthRequest)) + s.mux.HandleFunc("/v1/agent/monitor", s.wrap(s.AgentMonitor)) s.mux.HandleFunc("/v1/metrics", s.wrap(s.MetricsRequest)) diff --git a/command/agent/testagent.go b/command/agent/testagent.go index 93c41be5b..b773cda18 100644 --- a/command/agent/testagent.go +++ b/command/agent/testagent.go @@ -60,6 +60,8 @@ type TestAgent struct { // to os.Stderr. LogOutput io.Writer + logWriter *logWriter + // DataDir is the data directory which is used when Config.DataDir // is not set. It is created automatically and removed when // Shutdown() is called. @@ -205,8 +207,12 @@ RETRY: } func (a *TestAgent) start() (*Agent, error) { + if a.logWriter == nil { + a.logWriter = NewLogWriter(512) + } + if a.LogOutput == nil { - a.LogOutput = testlog.NewWriter(a.T) + a.LogOutput = io.MultiWriter(testlog.NewWriter(a.T), a.logWriter) } inm := metrics.NewInmemSink(10*time.Second, time.Minute) @@ -223,7 +229,7 @@ func (a *TestAgent) start() (*Agent, error) { JSONFormat: a.Config.LogJson, }) - agent, err := NewAgent(a.Config, logger, a.LogOutput, NewLogWriter(512), inm) + agent, err := NewAgent(a.Config, logger, a.LogOutput, a.logWriter, inm) if err != nil { return nil, err } diff --git a/command/agent_monitor.go b/command/agent_monitor.go new file mode 100644 index 000000000..cc58dbbe9 --- /dev/null +++ b/command/agent_monitor.go @@ -0,0 +1,85 @@ +package command + +import ( + "fmt" + "os" + "os/signal" + "strings" + "syscall" +) + +type MonitorCommand struct { + Meta +} + +func (c *MonitorCommand) Help() string { + helpText := ` +Usage: nomad monitor [options] + + Shows recent log messages of a nomad agent, and attaches to the agent, + outputting log messagse as they occur in real time. The monitor lets you + listen for log levels that may be filtered out of the Nomad agent. For + example your agent may only be logging at INFO level, but with the monitor + command you can set -log-level DEBUG + +General Options: + + ` + generalOptionsUsage() + return strings.TrimSpace(helpText) +} + +func (c *MonitorCommand) Synopsis() string { + return "stream logs from a nomad agent" +} + +func (c *MonitorCommand) Name() string { return "monitor" } + +func (c *MonitorCommand) Run(args []string) int { + var logLevel string + + flags := c.Meta.FlagSet(c.Name(), FlagSetClient) + flags.Usage = func() { c.Ui.Output(c.Help()) } + flags.StringVar(&logLevel, "log-level", "", "") + + if err := flags.Parse(args); err != nil { + return 1 + } + + client, err := c.Meta.Client() + if err != nil { + c.Ui.Error(fmt.Sprintf("Error initializing client: %s", err)) + c.Ui.Error(commandErrorText(c)) + return 1 + } + + eventDoneCh := make(chan struct{}) + logCh, err := client.Agent().Monitor(logLevel, eventDoneCh, nil) + if err != nil { + c.Ui.Error(fmt.Sprintf("Error starting monitor: %s", err)) + c.Ui.Error(commandErrorText(c)) + return 1 + } + + go func() { + defer close(eventDoneCh) + OUTER: + for { + select { + case log := <-logCh: + if log == "" { + break OUTER + } + c.Ui.Output(log) + } + } + + }() + + signalCh := make(chan os.Signal, 1) + signal.Notify(signalCh, os.Interrupt, syscall.SIGTERM) + + select { + case <-signalCh: + return 0 + } +} diff --git a/command/agent_monitor_test.go b/command/agent_monitor_test.go new file mode 100644 index 000000000..eb49e92c3 --- /dev/null +++ b/command/agent_monitor_test.go @@ -0,0 +1,34 @@ +package command + +import ( + "strings" + "testing" + + "github.com/mitchellh/cli" +) + +func TestMonitorCommand_Implements(t *testing.T) { + t.Parallel() + var _ cli.Command = &MonitorCommand{} +} + +func TestMonitorCommand_Fails(t *testing.T) { + t.Parallel() + + ui := new(cli.MockUi) + cmd := &MonitorCommand{Meta: Meta{Ui: ui}} + + // Fails on misuse + if code := cmd.Run([]string{"some", "bad", "args"}); code != 1 { + t.Fatalf("exepected exit code 1, got: %d", code) + } + if out := ui.ErrorWriter.String(); !strings.Contains(out, commandErrorText(cmd)) { + t.Fatalf("expected help output, got: %s", out) + } + + ui.ErrorWriter.Reset() + + if code := cmd.Run([]string{"-address=nope"}); code != 1 { + t.Fatalf("exepected exit code 1, got: %d", code) + } +} diff --git a/command/commands.go b/command/commands.go index 0eeade107..2c2d3052a 100644 --- a/command/commands.go +++ b/command/commands.go @@ -366,6 +366,11 @@ func Commands(metaPtr *Meta, agentUi cli.Ui) map[string]cli.CommandFactory { Meta: meta, }, nil }, + "monitor": func() (cli.Command, error) { + return &MonitorCommand{ + Meta: meta, + }, nil + }, "namespace": func() (cli.Command, error) { return &NamespaceCommand{ Meta: meta, diff --git a/vendor/github.com/hashicorp/go-hclog/README.md b/vendor/github.com/hashicorp/go-hclog/README.md index 1153e2853..9b6845e98 100644 --- a/vendor/github.com/hashicorp/go-hclog/README.md +++ b/vendor/github.com/hashicorp/go-hclog/README.md @@ -128,6 +128,21 @@ stdLogger.Printf("[DEBUG] %+v", stdLogger) ... [DEBUG] my-app: &{mu:{state:0 sema:0} prefix: flag:0 out:0xc42000a0a0 buf:[]} ``` +Alternatively, you may configure the system-wide logger: + +```go +// log the standard logger from 'import "log"' +log.SetOutput(appLogger.Writer(&hclog.StandardLoggerOptions{InferLevels: true})) +log.SetPrefix("") +log.SetFlags(0) + +log.Printf("[DEBUG] %d", 42) +``` + +```text +... [DEBUG] my-app: 42 +``` + Notice that if `appLogger` is initialized with the `INFO` log level _and_ you specify `InferLevels: true`, you will not see any output here. You must change `appLogger` to `DEBUG` to see output. See the docs for more information. diff --git a/vendor/github.com/hashicorp/go-hclog/context.go b/vendor/github.com/hashicorp/go-hclog/context.go new file mode 100644 index 000000000..7815f5019 --- /dev/null +++ b/vendor/github.com/hashicorp/go-hclog/context.go @@ -0,0 +1,38 @@ +package hclog + +import ( + "context" +) + +// WithContext inserts a logger into the context and is retrievable +// with FromContext. The optional args can be set with the same syntax as +// Logger.With to set fields on the inserted logger. This will not modify +// the logger argument in-place. +func WithContext(ctx context.Context, logger Logger, args ...interface{}) context.Context { + // While we could call logger.With even with zero args, we have this + // check to avoid unnecessary allocations around creating a copy of a + // logger. + if len(args) > 0 { + logger = logger.With(args...) + } + + return context.WithValue(ctx, contextKey, logger) +} + +// FromContext returns a logger from the context. This will return L() +// (the default logger) if no logger is found in the context. Therefore, +// this will never return a nil value. +func FromContext(ctx context.Context) Logger { + logger, _ := ctx.Value(contextKey).(Logger) + if logger == nil { + return L() + } + + return logger +} + +// Unexported new type so that our context key never collides with another. +type contextKeyType struct{} + +// contextKey is the key used for the context to store the logger. +var contextKey = contextKeyType{} diff --git a/vendor/github.com/hashicorp/go-hclog/global.go b/vendor/github.com/hashicorp/go-hclog/global.go index 55ce43960..22ebc57d8 100644 --- a/vendor/github.com/hashicorp/go-hclog/global.go +++ b/vendor/github.com/hashicorp/go-hclog/global.go @@ -8,27 +8,55 @@ var ( protect sync.Once def Logger - // The options used to create the Default logger. These are - // read only when the Default logger is created, so set them - // as soon as the process starts. + // DefaultOptions is used to create the Default logger. These are read + // only when the Default logger is created, so set them as soon as the + // process starts. DefaultOptions = &LoggerOptions{ Level: DefaultLevel, Output: DefaultOutput, } ) -// Return a logger that is held globally. This can be a good starting +// Default returns a globally held logger. This can be a good starting // place, and then you can use .With() and .Name() to create sub-loggers // to be used in more specific contexts. +// The value of the Default logger can be set via SetDefault() or by +// changing the options in DefaultOptions. +// +// This method is goroutine safe, returning a global from memory, but +// cause should be used if SetDefault() is called it random times +// in the program as that may result in race conditions and an unexpected +// Logger being returned. func Default() Logger { protect.Do(func() { - def = New(DefaultOptions) + // If SetDefault was used before Default() was called, we need to + // detect that here. + if def == nil { + def = New(DefaultOptions) + } }) return def } -// A short alias for Default() +// L is a short alias for Default(). func L() Logger { return Default() } + +// SetDefault changes the logger to be returned by Default()and L() +// to the one given. This allows packages to use the default logger +// and have higher level packages change it to match the execution +// environment. It returns any old default if there is one. +// +// NOTE: This is expected to be called early in the program to setup +// a default logger. As such, it does not attempt to make itself +// not racy with regard to the value of the default logger. Ergo +// if it is called in goroutines, you may experience race conditions +// with other goroutines retrieving the default logger. Basically, +// don't do that. +func SetDefault(log Logger) Logger { + old := def + def = log + return old +} diff --git a/vendor/github.com/hashicorp/go-hclog/go.mod b/vendor/github.com/hashicorp/go-hclog/go.mod new file mode 100644 index 000000000..0d079a654 --- /dev/null +++ b/vendor/github.com/hashicorp/go-hclog/go.mod @@ -0,0 +1,7 @@ +module github.com/hashicorp/go-hclog + +require ( + github.com/davecgh/go-spew v1.1.1 // indirect + github.com/pmezard/go-difflib v1.0.0 // indirect + github.com/stretchr/testify v1.2.2 +) diff --git a/vendor/github.com/hashicorp/go-hclog/go.sum b/vendor/github.com/hashicorp/go-hclog/go.sum new file mode 100644 index 000000000..e03ee77d9 --- /dev/null +++ b/vendor/github.com/hashicorp/go-hclog/go.sum @@ -0,0 +1,6 @@ +github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= +github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= +github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= +github.com/stretchr/testify v1.2.2 h1:bSDNvY7ZPG5RlJ8otE/7V6gMiyenm9RtJ7IUVIAoJ1w= +github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= diff --git a/vendor/github.com/hashicorp/go-hclog/int.go b/vendor/github.com/hashicorp/go-hclog/intlogger.go similarity index 54% rename from vendor/github.com/hashicorp/go-hclog/int.go rename to vendor/github.com/hashicorp/go-hclog/intlogger.go index 7d17d81cb..219656c4c 100644 --- a/vendor/github.com/hashicorp/go-hclog/int.go +++ b/vendor/github.com/hashicorp/go-hclog/intlogger.go @@ -1,12 +1,13 @@ package hclog import ( - "bufio" + "bytes" "encoding" "encoding/json" "fmt" + "io" "log" - "os" + "reflect" "runtime" "sort" "strconv" @@ -16,17 +17,44 @@ import ( "time" ) +// TimeFormat to use for logging. This is a version of RFC3339 that contains +// contains millisecond precision +const TimeFormat = "2006-01-02T15:04:05.000Z0700" + +// errJsonUnsupportedTypeMsg is included in log json entries, if an arg cannot be serialized to json +const errJsonUnsupportedTypeMsg = "logging contained values that don't serialize to json" + var ( _levelToBracket = map[Level]string{ Debug: "[DEBUG]", Trace: "[TRACE]", - Info: "[INFO ]", - Warn: "[WARN ]", + Info: "[INFO] ", + Warn: "[WARN] ", Error: "[ERROR]", } ) -// Given the options (nil for defaults), create a new Logger +// Make sure that intLogger is a Logger +var _ Logger = &intLogger{} + +// intLogger is an internal logger implementation. Internal in that it is +// defined entirely by this package. +type intLogger struct { + 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. + mutex *sync.Mutex + writer *writer + level *int32 + + implied []interface{} +} + +// New returns a configured logger. func New(opts *LoggerOptions) Logger { if opts == nil { opts = &LoggerOptions{} @@ -34,7 +62,7 @@ func New(opts *LoggerOptions) Logger { output := opts.Output if output == nil { - output = os.Stderr + output = DefaultOutput } level := opts.Level @@ -42,70 +70,49 @@ func New(opts *LoggerOptions) Logger { level = DefaultLevel } - mtx := opts.Mutex - if mtx == nil { - mtx = new(sync.Mutex) + mutex := opts.Mutex + if mutex == nil { + mutex = new(sync.Mutex) } - ret := &intLogger{ - m: mtx, + l := &intLogger{ json: opts.JSONFormat, caller: opts.IncludeLocation, name: opts.Name, timeFormat: TimeFormat, - w: bufio.NewWriter(output), + mutex: mutex, + writer: newWriter(output), level: new(int32), } + if opts.TimeFormat != "" { - ret.timeFormat = opts.TimeFormat + l.timeFormat = opts.TimeFormat } - atomic.StoreInt32(ret.level, int32(level)) - return ret + + atomic.StoreInt32(l.level, int32(level)) + + return l } -// The internal logger implementation. Internal in that it is defined entirely -// by this package. -type intLogger struct { - 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 *int32 - - implied []interface{} -} - -// Make sure that intLogger is a Logger -var _ Logger = &intLogger{} - -// The time format to use for logging. This is a version of RFC3339 that -// contains millisecond precision -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 < Level(atomic.LoadInt32(z.level)) { +func (l *intLogger) Log(level Level, msg string, args ...interface{}) { + if level < Level(atomic.LoadInt32(l.level)) { return } t := time.Now() - z.m.Lock() - defer z.m.Unlock() + l.mutex.Lock() + defer l.mutex.Unlock() - if z.json { - z.logJson(t, level, msg, args...) + if l.json { + l.logJSON(t, level, msg, args...) } else { - z.log(t, level, msg, args...) + l.log(t, level, msg, args...) } - z.w.Flush() + l.writer.Flush(level) } // Cleanup a path by returning the last 2 segments of the path only. @@ -121,10 +128,8 @@ func trimCallerPath(path string) string { // and https://github.com/golang/go/issues/18151 // // for discussion on the issue on Go side. - // // Find the last separator. - // idx := strings.LastIndexByte(path, '/') if idx == -1 { return path @@ -140,37 +145,37 @@ 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(z.timeFormat)) - z.w.WriteByte(' ') +func (l *intLogger) log(t time.Time, level Level, msg string, args ...interface{}) { + l.writer.WriteString(t.Format(l.timeFormat)) + l.writer.WriteByte(' ') s, ok := _levelToBracket[level] if ok { - z.w.WriteString(s) + l.writer.WriteString(s) } else { - z.w.WriteString("[UNKN ]") + l.writer.WriteString("[?????]") } - if z.caller { + if l.caller { if _, file, line, ok := runtime.Caller(3); ok { - z.w.WriteByte(' ') - z.w.WriteString(trimCallerPath(file)) - z.w.WriteByte(':') - z.w.WriteString(strconv.Itoa(line)) - z.w.WriteByte(':') + l.writer.WriteByte(' ') + l.writer.WriteString(trimCallerPath(file)) + l.writer.WriteByte(':') + l.writer.WriteString(strconv.Itoa(line)) + l.writer.WriteByte(':') } } - z.w.WriteByte(' ') + l.writer.WriteByte(' ') - if z.name != "" { - z.w.WriteString(z.name) - z.w.WriteString(": ") + if l.name != "" { + l.writer.WriteString(l.name) + l.writer.WriteString(": ") } - z.w.WriteString(msg) + l.writer.WriteString(msg) - args = append(z.implied, args...) + args = append(l.implied, args...) var stacktrace CapturedStacktrace @@ -185,11 +190,14 @@ func (z *intLogger) log(t time.Time, level Level, msg string, args ...interface{ } } - z.w.WriteByte(':') + l.writer.WriteByte(':') FOR: for i := 0; i < len(args); i = i + 2 { - var val string + var ( + val string + raw bool + ) switch st := args[i+1].(type) { case string: @@ -220,66 +228,79 @@ func (z *intLogger) log(t time.Time, level Level, msg string, args ...interface{ case Format: val = fmt.Sprintf(st[0].(string), st[1:]...) default: - val = fmt.Sprintf("%v", st) + v := reflect.ValueOf(st) + if v.Kind() == reflect.Slice { + val = l.renderSlice(v) + raw = true + } else { + val = fmt.Sprintf("%v", st) + } } - z.w.WriteByte(' ') - z.w.WriteString(args[i].(string)) - z.w.WriteByte('=') + l.writer.WriteByte(' ') + l.writer.WriteString(args[i].(string)) + l.writer.WriteByte('=') - if strings.ContainsAny(val, " \t\n\r") { - z.w.WriteByte('"') - z.w.WriteString(val) - z.w.WriteByte('"') + if !raw && strings.ContainsAny(val, " \t\n\r") { + l.writer.WriteByte('"') + l.writer.WriteString(val) + l.writer.WriteByte('"') } else { - z.w.WriteString(val) + l.writer.WriteString(val) } } } - z.w.WriteString("\n") + l.writer.WriteString("\n") if stacktrace != "" { - z.w.WriteString(string(stacktrace)) + l.writer.WriteString(string(stacktrace)) } } -// JSON logging function -func (z *intLogger) logJson(t time.Time, level Level, msg string, args ...interface{}) { - vals := map[string]interface{}{ - "@message": msg, - "@timestamp": t.Format("2006-01-02T15:04:05.000000Z07:00"), - } +func (l *intLogger) renderSlice(v reflect.Value) string { + var buf bytes.Buffer - var levelStr string - switch level { - case Error: - levelStr = "error" - case Warn: - levelStr = "warn" - case Info: - levelStr = "info" - case Debug: - levelStr = "debug" - case Trace: - levelStr = "trace" - default: - levelStr = "all" - } + buf.WriteRune('[') - vals["@level"] = levelStr + for i := 0; i < v.Len(); i++ { + if i > 0 { + buf.WriteString(", ") + } - if z.name != "" { - vals["@module"] = z.name - } + sv := v.Index(i) - if z.caller { - if _, file, line, ok := runtime.Caller(3); ok { - vals["@caller"] = fmt.Sprintf("%s:%d", file, line) + var val string + + switch sv.Kind() { + case reflect.String: + val = sv.String() + case reflect.Int, reflect.Int16, reflect.Int32, reflect.Int64: + val = strconv.FormatInt(sv.Int(), 10) + case reflect.Uint, reflect.Uint16, reflect.Uint32, reflect.Uint64: + val = strconv.FormatUint(sv.Uint(), 10) + default: + val = fmt.Sprintf("%v", sv.Interface()) + } + + if strings.ContainsAny(val, " \t\n\r") { + buf.WriteByte('"') + buf.WriteString(val) + buf.WriteByte('"') + } else { + buf.WriteString(val) } } - args = append(z.implied, args...) + buf.WriteRune(']') + + return buf.String() +} + +// JSON logging function +func (l *intLogger) logJSON(t time.Time, level Level, msg string, args ...interface{}) { + vals := l.jsonMapEntry(t, level, msg) + args = append(l.implied, args...) if args != nil && len(args) > 0 { if len(args)%2 != 0 { @@ -317,80 +338,121 @@ func (z *intLogger) logJson(t time.Time, level Level, msg string, args ...interf } } - err := json.NewEncoder(z.w).Encode(vals) + err := json.NewEncoder(l.writer).Encode(vals) if err != nil { - panic(err) + if _, ok := err.(*json.UnsupportedTypeError); ok { + plainVal := l.jsonMapEntry(t, level, msg) + plainVal["@warn"] = errJsonUnsupportedTypeMsg + + json.NewEncoder(l.writer).Encode(plainVal) + } } } +func (l intLogger) jsonMapEntry(t time.Time, level Level, msg string) map[string]interface{} { + vals := map[string]interface{}{ + "@message": msg, + "@timestamp": t.Format("2006-01-02T15:04:05.000000Z07:00"), + } + + var levelStr string + switch level { + case Error: + levelStr = "error" + case Warn: + levelStr = "warn" + case Info: + levelStr = "info" + case Debug: + levelStr = "debug" + case Trace: + levelStr = "trace" + default: + levelStr = "all" + } + + vals["@level"] = levelStr + + if l.name != "" { + vals["@module"] = l.name + } + + if l.caller { + if _, file, line, ok := runtime.Caller(4); ok { + vals["@caller"] = fmt.Sprintf("%s:%d", file, line) + } + } + return vals +} + // Emit the message and args at DEBUG level -func (z *intLogger) Debug(msg string, args ...interface{}) { - z.Log(Debug, msg, args...) +func (l *intLogger) Debug(msg string, args ...interface{}) { + l.Log(Debug, msg, args...) } // Emit the message and args at TRACE level -func (z *intLogger) Trace(msg string, args ...interface{}) { - z.Log(Trace, msg, args...) +func (l *intLogger) Trace(msg string, args ...interface{}) { + l.Log(Trace, msg, args...) } // Emit the message and args at INFO level -func (z *intLogger) Info(msg string, args ...interface{}) { - z.Log(Info, msg, args...) +func (l *intLogger) Info(msg string, args ...interface{}) { + l.Log(Info, msg, args...) } // Emit the message and args at WARN level -func (z *intLogger) Warn(msg string, args ...interface{}) { - z.Log(Warn, msg, args...) +func (l *intLogger) Warn(msg string, args ...interface{}) { + l.Log(Warn, msg, args...) } // Emit the message and args at ERROR level -func (z *intLogger) Error(msg string, args ...interface{}) { - z.Log(Error, msg, args...) +func (l *intLogger) Error(msg string, args ...interface{}) { + l.Log(Error, msg, args...) } // Indicate that the logger would emit TRACE level logs -func (z *intLogger) IsTrace() bool { - return Level(atomic.LoadInt32(z.level)) == Trace +func (l *intLogger) IsTrace() bool { + return Level(atomic.LoadInt32(l.level)) == Trace } // Indicate that the logger would emit DEBUG level logs -func (z *intLogger) IsDebug() bool { - return Level(atomic.LoadInt32(z.level)) <= Debug +func (l *intLogger) IsDebug() bool { + return Level(atomic.LoadInt32(l.level)) <= Debug } // Indicate that the logger would emit INFO level logs -func (z *intLogger) IsInfo() bool { - return Level(atomic.LoadInt32(z.level)) <= Info +func (l *intLogger) IsInfo() bool { + return Level(atomic.LoadInt32(l.level)) <= Info } // Indicate that the logger would emit WARN level logs -func (z *intLogger) IsWarn() bool { - return Level(atomic.LoadInt32(z.level)) <= Warn +func (l *intLogger) IsWarn() bool { + return Level(atomic.LoadInt32(l.level)) <= Warn } // Indicate that the logger would emit ERROR level logs -func (z *intLogger) IsError() bool { - return Level(atomic.LoadInt32(z.level)) <= Error +func (l *intLogger) IsError() bool { + return Level(atomic.LoadInt32(l.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 { +func (l *intLogger) With(args ...interface{}) Logger { if len(args)%2 != 0 { panic("With() call requires paired arguments") } - var nz intLogger = *z + sl := *l - result := make(map[string]interface{}, len(z.implied)+len(args)) - keys := make([]string, 0, len(z.implied)+len(args)) + result := make(map[string]interface{}, len(l.implied)+len(args)) + keys := make([]string, 0, len(l.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) + for i := 0; i < len(l.implied); i += 2 { + key := l.implied[i].(string) keys = append(keys, key) - result[key] = z.implied[i+1] + result[key] = l.implied[i+1] } // Read new args, store map and key for consistent sorting for i := 0; i < len(args); i += 2 { @@ -405,53 +467,61 @@ func (z *intLogger) With(args ...interface{}) Logger { // Sort keys to be consistent sort.Strings(keys) - nz.implied = make([]interface{}, 0, len(z.implied)+len(args)) + sl.implied = make([]interface{}, 0, len(l.implied)+len(args)) for _, k := range keys { - nz.implied = append(nz.implied, k) - nz.implied = append(nz.implied, result[k]) + sl.implied = append(sl.implied, k) + sl.implied = append(sl.implied, result[k]) } - return &nz + return &sl } // Create a new sub-Logger that a name decending from the current name. // This is used to create a subsystem specific Logger. -func (z *intLogger) Named(name string) Logger { - var nz intLogger = *z +func (l *intLogger) Named(name string) Logger { + sl := *l - if nz.name != "" { - nz.name = nz.name + "." + name + if sl.name != "" { + sl.name = sl.name + "." + name } else { - nz.name = name + sl.name = name } - return &nz + return &sl } // Create a new sub-Logger with an explicit name. This ignores the current // name. This is used to create a standalone logger that doesn't fall // within the normal hierarchy. -func (z *intLogger) ResetNamed(name string) Logger { - var nz intLogger = *z +func (l *intLogger) ResetNamed(name string) Logger { + sl := *l - nz.name = name + sl.name = name - return &nz + return &sl } // 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)) +func (l *intLogger) SetLevel(level Level) { + atomic.StoreInt32(l.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. -func (z *intLogger) StandardLogger(opts *StandardLoggerOptions) *log.Logger { +func (l *intLogger) StandardLogger(opts *StandardLoggerOptions) *log.Logger { if opts == nil { opts = &StandardLoggerOptions{} } - return log.New(&stdlogAdapter{z, opts.InferLevels}, "", 0) + return log.New(l.StandardWriter(opts), "", 0) +} + +func (l *intLogger) StandardWriter(opts *StandardLoggerOptions) io.Writer { + return &stdlogAdapter{ + log: l, + inferLevels: opts.InferLevels, + forceLevel: opts.ForceLevel, + } } diff --git a/vendor/github.com/hashicorp/go-hclog/log.go b/vendor/github.com/hashicorp/go-hclog/logger.go similarity index 72% rename from vendor/github.com/hashicorp/go-hclog/log.go rename to vendor/github.com/hashicorp/go-hclog/logger.go index 894e8461b..080ed7999 100644 --- a/vendor/github.com/hashicorp/go-hclog/log.go +++ b/vendor/github.com/hashicorp/go-hclog/logger.go @@ -9,38 +9,42 @@ import ( ) var ( - DefaultOutput = os.Stderr - DefaultLevel = Info + //DefaultOutput is used as the default log output. + DefaultOutput io.Writer = os.Stderr + + // DefaultLevel is used as the default log level. + DefaultLevel = Info ) +// Level represents a log level. type Level int32 const ( - // This is a special level used to indicate that no level has been + // NoLevel is a special level used to indicate that no level has been // set and allow for a default to be used. NoLevel Level = 0 - // The most verbose level. Intended to be used for the tracing of actions - // in code, such as function enters/exits, etc. + // Trace is the most verbose level. Intended to be used for the tracing + // of actions in code, such as function enters/exits, etc. Trace Level = 1 - // For programmer lowlevel analysis. + // Debug information for programmer lowlevel analysis. Debug Level = 2 - // For information about steady state operations. + // Info information about steady state operations. Info Level = 3 - // For information about rare but handled events. + // Warn information about rare but handled events. Warn Level = 4 - // For information about unrecoverable events. + // Error information about unrecoverable events. 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. +// Format is a simple convience type for when formatting is required. 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}). type Format []interface{} // Fmt returns a Format type. This is a convience function for creating a Format @@ -53,7 +57,7 @@ func Fmt(str string, args ...interface{}) Format { // the level string is invalid. This facilitates setting the log level via // config or environment variable by name in a predictable way. func LevelFromString(levelStr string) Level { - // We don't care about case. Accept "INFO" or "info" + // We don't care about case. Accept both "INFO" and "info". levelStr = strings.ToLower(strings.TrimSpace(levelStr)) switch levelStr { case "trace": @@ -71,7 +75,7 @@ func LevelFromString(levelStr string) Level { } } -// The main Logger interface. All code should code against this interface only. +// Logger describes the interface that must be implemeted by all loggers. type Logger interface { // Args are alternating key, val pairs // keys must be strings @@ -127,16 +131,27 @@ type Logger interface { // Return a value that conforms to the stdlib log.Logger interface StandardLogger(opts *StandardLoggerOptions) *log.Logger + + // Return a value that conforms to io.Writer, which can be passed into log.SetOutput() + StandardWriter(opts *StandardLoggerOptions) io.Writer } +// StandardLoggerOptions can be used to configure a new standard logger. type StandardLoggerOptions struct { // Indicate that some minimal parsing should be done on strings to try // and detect their level and re-emit them. // This supports the strings like [ERROR], [ERR] [TRACE], [WARN], [INFO], // [DEBUG] and strip it off before reapplying it. InferLevels bool + + // ForceLevel is used to force all output from the standard logger to be at + // the specified level. Similar to InferLevels, this will strip any level + // prefix contained in the logged string before applying the forced level. + // If set, this override InferLevels. + ForceLevel Level } +// LoggerOptions can be used to configure a new logger. type LoggerOptions struct { // Name of the subsystem to prefix logs with Name string @@ -144,7 +159,7 @@ type LoggerOptions struct { // The threshold for the logger. Anything less severe is supressed Level Level - // Where to write the logs to. Defaults to os.Stdout if nil + // Where to write the logs to. Defaults to os.Stderr if nil Output io.Writer // An optional mutex pointer in case Output is shared diff --git a/vendor/github.com/hashicorp/go-hclog/nulllogger.go b/vendor/github.com/hashicorp/go-hclog/nulllogger.go index 0942361a5..7ad6b351e 100644 --- a/vendor/github.com/hashicorp/go-hclog/nulllogger.go +++ b/vendor/github.com/hashicorp/go-hclog/nulllogger.go @@ -1,6 +1,7 @@ package hclog import ( + "io" "io/ioutil" "log" ) @@ -43,5 +44,9 @@ 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) + return log.New(l.StandardWriter(opts), "", log.LstdFlags) +} + +func (l *nullLogger) StandardWriter(opts *StandardLoggerOptions) io.Writer { + return ioutil.Discard } diff --git a/vendor/github.com/hashicorp/go-hclog/stacktrace.go b/vendor/github.com/hashicorp/go-hclog/stacktrace.go index 8af1a3be4..9b27bd3d3 100644 --- a/vendor/github.com/hashicorp/go-hclog/stacktrace.go +++ b/vendor/github.com/hashicorp/go-hclog/stacktrace.go @@ -40,12 +40,13 @@ var ( } ) -// A stacktrace gathered by a previous call to log.Stacktrace. If passed -// to a logging function, the stacktrace will be appended. +// CapturedStacktrace represents a stacktrace captured by a previous call +// to log.Stacktrace. If passed to a logging function, the stacktrace +// will be appended. type CapturedStacktrace string -// Gather a stacktrace of the current goroutine and return it to be passed -// to a logging function. +// Stacktrace captures a stacktrace of the current goroutine and returns +// it to be passed to a logging function. func Stacktrace() CapturedStacktrace { return CapturedStacktrace(takeStacktrace()) } diff --git a/vendor/github.com/hashicorp/go-hclog/stdlog.go b/vendor/github.com/hashicorp/go-hclog/stdlog.go index 2bb927fc9..2cf0456a0 100644 --- a/vendor/github.com/hashicorp/go-hclog/stdlog.go +++ b/vendor/github.com/hashicorp/go-hclog/stdlog.go @@ -9,39 +9,51 @@ import ( // and back into our Logger. This is basically the only way to // build upon *log.Logger. type stdlogAdapter struct { - hl Logger + log Logger inferLevels bool + forceLevel Level } // Take the data, infer the levels if configured, and send it through -// a regular Logger +// a regular Logger. func (s *stdlogAdapter) Write(data []byte) (int, error) { str := string(bytes.TrimRight(data, " \t\n")) - if s.inferLevels { + if s.forceLevel != NoLevel { + // Use pickLevel to strip log levels included in the line since we are + // forcing the level + _, str := s.pickLevel(str) + + // Log at the forced level + s.dispatch(str, s.forceLevel) + } else if s.inferLevels { level, str := s.pickLevel(str) - switch level { - case Trace: - s.hl.Trace(str) - case Debug: - s.hl.Debug(str) - case Info: - s.hl.Info(str) - case Warn: - s.hl.Warn(str) - case Error: - s.hl.Error(str) - default: - s.hl.Info(str) - } + s.dispatch(str, level) } else { - s.hl.Info(str) + s.log.Info(str) } return len(data), nil } -// Detect, based on conventions, what log level this is +func (s *stdlogAdapter) dispatch(str string, level Level) { + switch level { + case Trace: + s.log.Trace(str) + case Debug: + s.log.Debug(str) + case Info: + s.log.Info(str) + case Warn: + s.log.Warn(str) + case Error: + s.log.Error(str) + default: + s.log.Info(str) + } +} + +// Detect, based on conventions, what log level this is. func (s *stdlogAdapter) pickLevel(str string) (Level, string) { switch { case strings.HasPrefix(str, "[DEBUG]"): diff --git a/vendor/github.com/hashicorp/go-hclog/writer.go b/vendor/github.com/hashicorp/go-hclog/writer.go new file mode 100644 index 000000000..7e8ec729d --- /dev/null +++ b/vendor/github.com/hashicorp/go-hclog/writer.go @@ -0,0 +1,74 @@ +package hclog + +import ( + "bytes" + "io" +) + +type writer struct { + b bytes.Buffer + w io.Writer +} + +func newWriter(w io.Writer) *writer { + return &writer{w: w} +} + +func (w *writer) Flush(level Level) (err error) { + if lw, ok := w.w.(LevelWriter); ok { + _, err = lw.LevelWrite(level, w.b.Bytes()) + } else { + _, err = w.w.Write(w.b.Bytes()) + } + w.b.Reset() + return err +} + +func (w *writer) Write(p []byte) (int, error) { + return w.b.Write(p) +} + +func (w *writer) WriteByte(c byte) error { + return w.b.WriteByte(c) +} + +func (w *writer) WriteString(s string) (int, error) { + return w.b.WriteString(s) +} + +// LevelWriter is the interface that wraps the LevelWrite method. +type LevelWriter interface { + LevelWrite(level Level, p []byte) (n int, err error) +} + +// LeveledWriter writes all log messages to the standard writer, +// except for log levels that are defined in the overrides map. +type LeveledWriter struct { + standard io.Writer + overrides map[Level]io.Writer +} + +// NewLeveledWriter returns an initialized LeveledWriter. +// +// standard will be used as the default writer for all log levels, +// except for log levels that are defined in the overrides map. +func NewLeveledWriter(standard io.Writer, overrides map[Level]io.Writer) *LeveledWriter { + return &LeveledWriter{ + standard: standard, + overrides: overrides, + } +} + +// Write implements io.Writer. +func (lw *LeveledWriter) Write(p []byte) (int, error) { + return lw.standard.Write(p) +} + +// LevelWrite implements LevelWriter. +func (lw *LeveledWriter) LevelWrite(level Level, p []byte) (int, error) { + w, ok := lw.overrides[level] + if !ok { + w = lw.standard + } + return w.Write(p) +} diff --git a/vendor/vendor.json b/vendor/vendor.json index 4bd094abf..8c1adba27 100644 --- a/vendor/vendor.json +++ b/vendor/vendor.json @@ -209,7 +209,7 @@ {"path":"github.com/hashicorp/go-envparse","checksumSHA1":"FKmqR4DC3nCXtnT9pe02z5CLNWo=","revision":"310ca1881b22af3522e3a8638c0b426629886196","revisionTime":"2018-01-19T21:58:41Z"}, {"path":"github.com/hashicorp/go-getter","checksumSHA1":"d4brua17AGQqMNtngK4xKOUwboY=","revision":"f5101da0117392c6e7960c934f05a2fd689a5b5f","revisionTime":"2019-08-22T19:45:07Z"}, {"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":"dOP7kCX3dACHc9mU79826N411QA=","revision":"ff2cf002a8dd750586d91dddd4470c341f981fe1","revisionTime":"2018-07-09T16:53:50Z"}, + {"path":"github.com/hashicorp/go-hclog","checksumSHA1":"Iv7QhhSWySasqGcwbFyq0XrgYOQ=","revision":"3a6b159e7c8be95d9af1c989e4dcb730567f5c9c","revisionTime":"2019-08-26T16:23:21Z"}, {"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","checksumSHA1":"CKGYNUDKre3Z2g4hHNVfp5nTcfA=","revision":"23165f7bc3c2dda1891434ebb9da1511a7bafc1c","revisionTime":"2019-09-27T12:33:13Z","version":"upstream-08f7b40","versionExact":"upstream-08f7b40"},