From 76f07f3834e0e1fc72709fbe9d95d0b2ff927f05 Mon Sep 17 00:00:00 2001 From: Nikhil Raman Date: Thu, 1 Nov 2018 15:21:27 +0530 Subject: [PATCH 1/2] Vendor new logrus which includes `SetOutput()`. --- Gopkg.lock | 12 +- .../go-windows-terminal-sequences/LICENSE | 9 + .../sequences.go | 36 ++++ vendor/github.com/sirupsen/logrus/entry.go | 196 ++++++++++++++---- vendor/github.com/sirupsen/logrus/exported.go | 60 ++++-- .../github.com/sirupsen/logrus/formatter.go | 51 ++++- .../sirupsen/logrus/hooks/test/test.go | 15 +- .../sirupsen/logrus/json_formatter.go | 54 +++-- vendor/github.com/sirupsen/logrus/logger.go | 152 +++++++++++--- vendor/github.com/sirupsen/logrus/logrus.go | 37 +++- .../sirupsen/logrus/terminal_bsd.go | 10 - .../logrus/terminal_check_appengine.go | 2 +- .../sirupsen/logrus/terminal_check_js.go | 11 + .../logrus/terminal_check_notappengine.go | 2 +- .../sirupsen/logrus/terminal_check_windows.go | 20 ++ .../sirupsen/logrus/terminal_linux.go | 14 -- .../sirupsen/logrus/terminal_notwindows.go | 8 + .../sirupsen/logrus/terminal_windows.go | 18 ++ .../sirupsen/logrus/text_formatter.go | 137 ++++++++++-- vendor/github.com/sirupsen/logrus/writer.go | 2 + 20 files changed, 677 insertions(+), 169 deletions(-) create mode 100644 vendor/github.com/konsorten/go-windows-terminal-sequences/LICENSE create mode 100644 vendor/github.com/konsorten/go-windows-terminal-sequences/sequences.go delete mode 100644 vendor/github.com/sirupsen/logrus/terminal_bsd.go create mode 100644 vendor/github.com/sirupsen/logrus/terminal_check_js.go create mode 100644 vendor/github.com/sirupsen/logrus/terminal_check_windows.go delete mode 100644 vendor/github.com/sirupsen/logrus/terminal_linux.go create mode 100644 vendor/github.com/sirupsen/logrus/terminal_notwindows.go create mode 100644 vendor/github.com/sirupsen/logrus/terminal_windows.go diff --git a/Gopkg.lock b/Gopkg.lock index 47e790f9b19..46885c38455 100644 --- a/Gopkg.lock +++ b/Gopkg.lock @@ -264,6 +264,14 @@ revision = "f611eb38b3875cc3bd991ca91c51d06446afa14c" version = "v1.3.0" +[[projects]] + digest = "1:4059c14e87a2de3a434430340521b5feece186c1469eff0834c29a63870de3ed" + name = "github.com/konsorten/go-windows-terminal-sequences" + packages = ["."] + pruneopts = "NUT" + revision = "5c8c8bd35d3832f5d134ae1e1e375b69a4d25242" + version = "v1.0.1" + [[projects]] digest = "1:2578ea84d8555a62f49e5f750848ec5d3bad2e5ba9e3977186e407c7501d3b95" name = "github.com/kubernetes/helm" @@ -413,14 +421,14 @@ [[projects]] branch = "master" - digest = "1:f9e30881a5a427fe87c58273f511fb6a10ee2c8ea55d409d7256ede192f7f4b7" + digest = "1:88925026dc080b29f50bc9c917224dac3d4fa1df614df38429c3b373130c9a56" name = "github.com/sirupsen/logrus" packages = [ ".", "hooks/test", ] pruneopts = "NUT" - revision = "90150a8ed11b6ce285e77e8af2b0109559ce4777" + revision = "7eeb7b7cbdeb0a582a5b7a1512d91f956f1674aa" [[projects]] branch = "master" diff --git a/vendor/github.com/konsorten/go-windows-terminal-sequences/LICENSE b/vendor/github.com/konsorten/go-windows-terminal-sequences/LICENSE new file mode 100644 index 00000000000..14127cd831e --- /dev/null +++ b/vendor/github.com/konsorten/go-windows-terminal-sequences/LICENSE @@ -0,0 +1,9 @@ +(The MIT License) + +Copyright (c) 2017 marvin + konsorten GmbH (open-source@konsorten.de) + +Permission is hereby granted, free of charge, to any person obtaining a copy of this software and associated documentation files (the 'Software'), to deal in the Software without restriction, including without limitation the rights to use, copy, modify, merge, publish, distribute, sublicense, and/or sell copies of the Software, and to permit persons to whom the Software is furnished to do so, subject to the following conditions: + +The above copyright notice and this permission notice shall be included in all copies or substantial portions of the Software. + +THE SOFTWARE IS PROVIDED 'AS IS', WITHOUT WARRANTY OF ANY KIND, EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. diff --git a/vendor/github.com/konsorten/go-windows-terminal-sequences/sequences.go b/vendor/github.com/konsorten/go-windows-terminal-sequences/sequences.go new file mode 100644 index 00000000000..ef18d8f9787 --- /dev/null +++ b/vendor/github.com/konsorten/go-windows-terminal-sequences/sequences.go @@ -0,0 +1,36 @@ +// +build windows + +package sequences + +import ( + "syscall" + "unsafe" +) + +var ( + kernel32Dll *syscall.LazyDLL = syscall.NewLazyDLL("Kernel32.dll") + setConsoleMode *syscall.LazyProc = kernel32Dll.NewProc("SetConsoleMode") +) + +func EnableVirtualTerminalProcessing(stream syscall.Handle, enable bool) error { + const ENABLE_VIRTUAL_TERMINAL_PROCESSING uint32 = 0x4 + + var mode uint32 + err := syscall.GetConsoleMode(syscall.Stdout, &mode) + if err != nil { + return err + } + + if enable { + mode |= ENABLE_VIRTUAL_TERMINAL_PROCESSING + } else { + mode &^= ENABLE_VIRTUAL_TERMINAL_PROCESSING + } + + ret, _, err := setConsoleMode.Call(uintptr(unsafe.Pointer(stream)), uintptr(mode)) + if ret == 0 { + return err + } + + return nil +} diff --git a/vendor/github.com/sirupsen/logrus/entry.go b/vendor/github.com/sirupsen/logrus/entry.go index 778f4c9f0d3..cc85d3aab49 100644 --- a/vendor/github.com/sirupsen/logrus/entry.go +++ b/vendor/github.com/sirupsen/logrus/entry.go @@ -4,11 +4,30 @@ import ( "bytes" "fmt" "os" + "reflect" + "runtime" + "strings" "sync" "time" ) -var bufferPool *sync.Pool +var ( + bufferPool *sync.Pool + + // qualified package name, cached at first use + logrusPackage string + + // Positions in the call stack when tracing to report the calling method + minimumCallerDepth int + + // Used for caller information initialisation + callerInitOnce sync.Once +) + +const ( + maximumCallerDepth int = 25 + knownLogrusFrames int = 4 +) func init() { bufferPool = &sync.Pool{ @@ -16,15 +35,18 @@ func init() { return new(bytes.Buffer) }, } + + // start at the bottom of the stack before the package-name cache is primed + minimumCallerDepth = 1 } // Defines the key when adding errors using WithError. var ErrorKey = "error" // An entry is the final or intermediate Logrus logging entry. It contains all -// the fields passed with WithField{,s}. It's finally logged when Debug, Info, -// Warn, Error, Fatal or Panic is called on it. These objects can be reused and -// passed around as much as you wish to avoid field duplication. +// the fields passed with WithField{,s}. It's finally logged when Trace, Debug, +// Info, Warn, Error, Fatal or Panic is called on it. These objects can be +// reused and passed around as much as you wish to avoid field duplication. type Entry struct { Logger *Logger @@ -34,22 +56,28 @@ type Entry struct { // Time at which the log entry was created Time time.Time - // Level the log entry was logged at: Debug, Info, Warn, Error, Fatal or Panic + // Level the log entry was logged at: Trace, Debug, Info, Warn, Error, Fatal or Panic // This field will be set on entry firing and the value will be equal to the one in Logger struct field. Level Level - // Message passed to Debug, Info, Warn, Error, Fatal or Panic + // Calling method, with package name + Caller *runtime.Frame + + // Message passed to Trace, Debug, Info, Warn, Error, Fatal or Panic Message string - // When formatter is called in entry.log(), an Buffer may be set to entry + // When formatter is called in entry.log(), a Buffer may be set to entry Buffer *bytes.Buffer + + // err may contain a field formatting error + err string } func NewEntry(logger *Logger) *Entry { return &Entry{ Logger: logger, - // Default is three fields, give a little extra room - Data: make(Fields, 5), + // Default is three fields, plus one optional. Give a little extra room. + Data: make(Fields, 6), } } @@ -80,19 +108,95 @@ func (entry *Entry) WithFields(fields Fields) *Entry { for k, v := range entry.Data { data[k] = v } + var field_err string for k, v := range fields { - data[k] = v + if t := reflect.TypeOf(v); t != nil && t.Kind() == reflect.Func { + field_err = fmt.Sprintf("can not add field %q", k) + if entry.err != "" { + field_err = entry.err + ", " + field_err + } + } else { + data[k] = v + } + } + return &Entry{Logger: entry.Logger, Data: data, Time: entry.Time, err: field_err} +} + +// Overrides the time of the Entry. +func (entry *Entry) WithTime(t time.Time) *Entry { + return &Entry{Logger: entry.Logger, Data: entry.Data, Time: t} +} + +// getPackageName reduces a fully qualified function name to the package name +// There really ought to be to be a better way... +func getPackageName(f string) string { + for { + lastPeriod := strings.LastIndex(f, ".") + lastSlash := strings.LastIndex(f, "/") + if lastPeriod > lastSlash { + f = f[:lastPeriod] + } else { + break + } + } + + return f +} + +// getCaller retrieves the name of the first non-logrus calling function +func getCaller() *runtime.Frame { + // Restrict the lookback frames to avoid runaway lookups + pcs := make([]uintptr, maximumCallerDepth) + depth := runtime.Callers(minimumCallerDepth, pcs) + frames := runtime.CallersFrames(pcs[:depth]) + + // cache this package's fully-qualified name + callerInitOnce.Do(func() { + logrusPackage = getPackageName(runtime.FuncForPC(pcs[0]).Name()) + + // now that we have the cache, we can skip a minimum count of known-logrus functions + // XXX this is dubious, the number of frames may vary store an entry in a logger interface + minimumCallerDepth = knownLogrusFrames + }) + + for f, again := frames.Next(); again; f, again = frames.Next() { + pkg := getPackageName(f.Function) + + // If the caller isn't part of this package, we're done + if pkg != logrusPackage { + return &f + } } - return &Entry{Logger: entry.Logger, Data: data} + + // if we got here, we failed to find the caller's context + return nil +} + +func (entry Entry) HasCaller() (has bool) { + return entry.Logger != nil && + entry.Logger.ReportCaller && + entry.Caller != nil } // This function is not declared with a pointer value because otherwise // race conditions will occur when using multiple goroutines func (entry Entry) log(level Level, msg string) { var buffer *bytes.Buffer - entry.Time = time.Now() + + // Default to now, but allow users to override if they want. + // + // We don't have to worry about polluting future calls to Entry#log() + // with this assignment because this function is declared with a + // non-pointer receiver. + if entry.Time.IsZero() { + entry.Time = time.Now() + } + entry.Level = level entry.Message = msg + if entry.Logger.ReportCaller { + entry.Caller = getCaller() + } entry.fireHooks() @@ -113,21 +217,19 @@ func (entry Entry) log(level Level, msg string) { } } -// This function is not declared with a pointer value because otherwise -// race conditions will occur when using multiple goroutines -func (entry Entry) fireHooks() { +func (entry *Entry) fireHooks() { entry.Logger.mu.Lock() defer entry.Logger.mu.Unlock() - err := entry.Logger.Hooks.Fire(entry.Level, &entry) + err := entry.Logger.Hooks.Fire(entry.Level, entry) if err != nil { fmt.Fprintf(os.Stderr, "Failed to fire hook: %v\n", err) } } func (entry *Entry) write() { - serialized, err := entry.Logger.Formatter.Format(entry) entry.Logger.mu.Lock() defer entry.Logger.mu.Unlock() + serialized, err := entry.Logger.Formatter.Format(entry) if err != nil { fmt.Fprintf(os.Stderr, "Failed to obtain reader, %v\n", err) } else { @@ -138,8 +240,14 @@ func (entry *Entry) write() { } } +func (entry *Entry) Trace(args ...interface{}) { + if entry.Logger.IsLevelEnabled(TraceLevel) { + entry.log(TraceLevel, fmt.Sprint(args...)) + } +} + func (entry *Entry) Debug(args ...interface{}) { - if entry.Logger.level() >= DebugLevel { + if entry.Logger.IsLevelEnabled(DebugLevel) { entry.log(DebugLevel, fmt.Sprint(args...)) } } @@ -149,13 +257,13 @@ func (entry *Entry) Print(args ...interface{}) { } func (entry *Entry) Info(args ...interface{}) { - if entry.Logger.level() >= InfoLevel { + if entry.Logger.IsLevelEnabled(InfoLevel) { entry.log(InfoLevel, fmt.Sprint(args...)) } } func (entry *Entry) Warn(args ...interface{}) { - if entry.Logger.level() >= WarnLevel { + if entry.Logger.IsLevelEnabled(WarnLevel) { entry.log(WarnLevel, fmt.Sprint(args...)) } } @@ -165,20 +273,20 @@ func (entry *Entry) Warning(args ...interface{}) { } func (entry *Entry) Error(args ...interface{}) { - if entry.Logger.level() >= ErrorLevel { + if entry.Logger.IsLevelEnabled(ErrorLevel) { entry.log(ErrorLevel, fmt.Sprint(args...)) } } func (entry *Entry) Fatal(args ...interface{}) { - if entry.Logger.level() >= FatalLevel { + if entry.Logger.IsLevelEnabled(FatalLevel) { entry.log(FatalLevel, fmt.Sprint(args...)) } - Exit(1) + entry.Logger.Exit(1) } func (entry *Entry) Panic(args ...interface{}) { - if entry.Logger.level() >= PanicLevel { + if entry.Logger.IsLevelEnabled(PanicLevel) { entry.log(PanicLevel, fmt.Sprint(args...)) } panic(fmt.Sprint(args...)) @@ -186,14 +294,20 @@ func (entry *Entry) Panic(args ...interface{}) { // Entry Printf family functions +func (entry *Entry) Tracef(format string, args ...interface{}) { + if entry.Logger.IsLevelEnabled(TraceLevel) { + entry.Trace(fmt.Sprintf(format, args...)) + } +} + func (entry *Entry) Debugf(format string, args ...interface{}) { - if entry.Logger.level() >= DebugLevel { + if entry.Logger.IsLevelEnabled(DebugLevel) { entry.Debug(fmt.Sprintf(format, args...)) } } func (entry *Entry) Infof(format string, args ...interface{}) { - if entry.Logger.level() >= InfoLevel { + if entry.Logger.IsLevelEnabled(InfoLevel) { entry.Info(fmt.Sprintf(format, args...)) } } @@ -203,7 +317,7 @@ func (entry *Entry) Printf(format string, args ...interface{}) { } func (entry *Entry) Warnf(format string, args ...interface{}) { - if entry.Logger.level() >= WarnLevel { + if entry.Logger.IsLevelEnabled(WarnLevel) { entry.Warn(fmt.Sprintf(format, args...)) } } @@ -213,34 +327,40 @@ func (entry *Entry) Warningf(format string, args ...interface{}) { } func (entry *Entry) Errorf(format string, args ...interface{}) { - if entry.Logger.level() >= ErrorLevel { + if entry.Logger.IsLevelEnabled(ErrorLevel) { entry.Error(fmt.Sprintf(format, args...)) } } func (entry *Entry) Fatalf(format string, args ...interface{}) { - if entry.Logger.level() >= FatalLevel { + if entry.Logger.IsLevelEnabled(FatalLevel) { entry.Fatal(fmt.Sprintf(format, args...)) } - Exit(1) + entry.Logger.Exit(1) } func (entry *Entry) Panicf(format string, args ...interface{}) { - if entry.Logger.level() >= PanicLevel { + if entry.Logger.IsLevelEnabled(PanicLevel) { entry.Panic(fmt.Sprintf(format, args...)) } } // Entry Println family functions +func (entry *Entry) Traceln(args ...interface{}) { + if entry.Logger.IsLevelEnabled(TraceLevel) { + entry.Trace(entry.sprintlnn(args...)) + } +} + func (entry *Entry) Debugln(args ...interface{}) { - if entry.Logger.level() >= DebugLevel { + if entry.Logger.IsLevelEnabled(DebugLevel) { entry.Debug(entry.sprintlnn(args...)) } } func (entry *Entry) Infoln(args ...interface{}) { - if entry.Logger.level() >= InfoLevel { + if entry.Logger.IsLevelEnabled(InfoLevel) { entry.Info(entry.sprintlnn(args...)) } } @@ -250,7 +370,7 @@ func (entry *Entry) Println(args ...interface{}) { } func (entry *Entry) Warnln(args ...interface{}) { - if entry.Logger.level() >= WarnLevel { + if entry.Logger.IsLevelEnabled(WarnLevel) { entry.Warn(entry.sprintlnn(args...)) } } @@ -260,20 +380,20 @@ func (entry *Entry) Warningln(args ...interface{}) { } func (entry *Entry) Errorln(args ...interface{}) { - if entry.Logger.level() >= ErrorLevel { + if entry.Logger.IsLevelEnabled(ErrorLevel) { entry.Error(entry.sprintlnn(args...)) } } func (entry *Entry) Fatalln(args ...interface{}) { - if entry.Logger.level() >= FatalLevel { + if entry.Logger.IsLevelEnabled(FatalLevel) { entry.Fatal(entry.sprintlnn(args...)) } - Exit(1) + entry.Logger.Exit(1) } func (entry *Entry) Panicln(args ...interface{}) { - if entry.Logger.level() >= PanicLevel { + if entry.Logger.IsLevelEnabled(PanicLevel) { entry.Panic(entry.sprintlnn(args...)) } } diff --git a/vendor/github.com/sirupsen/logrus/exported.go b/vendor/github.com/sirupsen/logrus/exported.go index 013183edabf..7342613c372 100644 --- a/vendor/github.com/sirupsen/logrus/exported.go +++ b/vendor/github.com/sirupsen/logrus/exported.go @@ -2,6 +2,7 @@ package logrus import ( "io" + "time" ) var ( @@ -15,37 +16,38 @@ func StandardLogger() *Logger { // SetOutput sets the standard logger output. func SetOutput(out io.Writer) { - std.mu.Lock() - defer std.mu.Unlock() - std.Out = out + std.SetOutput(out) } // SetFormatter sets the standard logger formatter. func SetFormatter(formatter Formatter) { - std.mu.Lock() - defer std.mu.Unlock() - std.Formatter = formatter + std.SetFormatter(formatter) +} + +// SetReportCaller sets whether the standard logger will include the calling +// method as a field. +func SetReportCaller(include bool) { + std.SetReportCaller(include) } // SetLevel sets the standard logger level. func SetLevel(level Level) { - std.mu.Lock() - defer std.mu.Unlock() std.SetLevel(level) } // GetLevel returns the standard logger level. func GetLevel() Level { - std.mu.Lock() - defer std.mu.Unlock() - return std.level() + return std.GetLevel() +} + +// IsLevelEnabled checks if the log level of the standard logger is greater than the level param +func IsLevelEnabled(level Level) bool { + return std.IsLevelEnabled(level) } // AddHook adds a hook to the standard logger hooks. func AddHook(hook Hook) { - std.mu.Lock() - defer std.mu.Unlock() - std.Hooks.Add(hook) + std.AddHook(hook) } // WithError creates an entry from the standard logger and adds an error to it, using the value defined in ErrorKey as key. @@ -72,6 +74,20 @@ func WithFields(fields Fields) *Entry { return std.WithFields(fields) } +// WithTime creats an entry from the standard logger and overrides the time of +// logs generated with it. +// +// Note that it doesn't log until you call Debug, Print, Info, Warn, Fatal +// or Panic on the Entry it returns. +func WithTime(t time.Time) *Entry { + return std.WithTime(t) +} + +// Trace logs a message at level Trace on the standard logger. +func Trace(args ...interface{}) { + std.Trace(args...) +} + // Debug logs a message at level Debug on the standard logger. func Debug(args ...interface{}) { std.Debug(args...) @@ -107,11 +123,16 @@ func Panic(args ...interface{}) { std.Panic(args...) } -// Fatal logs a message at level Fatal on the standard logger. +// Fatal logs a message at level Fatal on the standard logger then the process will exit with status set to 1. func Fatal(args ...interface{}) { std.Fatal(args...) } +// Tracef logs a message at level Trace on the standard logger. +func Tracef(format string, args ...interface{}) { + std.Tracef(format, args...) +} + // Debugf logs a message at level Debug on the standard logger. func Debugf(format string, args ...interface{}) { std.Debugf(format, args...) @@ -147,11 +168,16 @@ func Panicf(format string, args ...interface{}) { std.Panicf(format, args...) } -// Fatalf logs a message at level Fatal on the standard logger. +// Fatalf logs a message at level Fatal on the standard logger then the process will exit with status set to 1. func Fatalf(format string, args ...interface{}) { std.Fatalf(format, args...) } +// Traceln logs a message at level Trace on the standard logger. +func Traceln(args ...interface{}) { + std.Traceln(args...) +} + // Debugln logs a message at level Debug on the standard logger. func Debugln(args ...interface{}) { std.Debugln(args...) @@ -187,7 +213,7 @@ func Panicln(args ...interface{}) { std.Panicln(args...) } -// Fatalln logs a message at level Fatal on the standard logger. +// Fatalln logs a message at level Fatal on the standard logger then the process will exit with status set to 1. func Fatalln(args ...interface{}) { std.Fatalln(args...) } diff --git a/vendor/github.com/sirupsen/logrus/formatter.go b/vendor/github.com/sirupsen/logrus/formatter.go index b183ff5b1db..408883773eb 100644 --- a/vendor/github.com/sirupsen/logrus/formatter.go +++ b/vendor/github.com/sirupsen/logrus/formatter.go @@ -2,7 +2,16 @@ package logrus import "time" -const defaultTimestampFormat = time.RFC3339 +// Default key names for the default fields +const ( + defaultTimestampFormat = time.RFC3339 + FieldKeyMsg = "msg" + FieldKeyLevel = "level" + FieldKeyTime = "time" + FieldKeyLogrusError = "logrus_error" + FieldKeyFunc = "func" + FieldKeyFile = "file" +) // The Formatter interface is used to implement a custom Formatter. It takes an // `Entry`. It exposes all the fields, including the default ones: @@ -18,7 +27,7 @@ type Formatter interface { Format(*Entry) ([]byte, error) } -// This is to not silently overwrite `time`, `msg` and `level` fields when +// This is to not silently overwrite `time`, `msg`, `func` and `level` fields when // dumping it. If this code wasn't there doing: // // logrus.WithField("level", 1).Info("hello") @@ -30,16 +39,40 @@ type Formatter interface { // // It's not exported because it's still using Data in an opinionated way. It's to // avoid code duplication between the two default formatters. -func prefixFieldClashes(data Fields) { - if t, ok := data["time"]; ok { - data["fields.time"] = t +func prefixFieldClashes(data Fields, fieldMap FieldMap, reportCaller bool) { + timeKey := fieldMap.resolve(FieldKeyTime) + if t, ok := data[timeKey]; ok { + data["fields."+timeKey] = t + delete(data, timeKey) } - if m, ok := data["msg"]; ok { - data["fields.msg"] = m + msgKey := fieldMap.resolve(FieldKeyMsg) + if m, ok := data[msgKey]; ok { + data["fields."+msgKey] = m + delete(data, msgKey) } - if l, ok := data["level"]; ok { - data["fields.level"] = l + levelKey := fieldMap.resolve(FieldKeyLevel) + if l, ok := data[levelKey]; ok { + data["fields."+levelKey] = l + delete(data, levelKey) + } + + logrusErrKey := fieldMap.resolve(FieldKeyLogrusError) + if l, ok := data[logrusErrKey]; ok { + data["fields."+logrusErrKey] = l + delete(data, logrusErrKey) + } + + // If reportCaller is not set, 'func' will not conflict. + if reportCaller { + funcKey := fieldMap.resolve(FieldKeyFunc) + if l, ok := data[funcKey]; ok { + data["fields."+funcKey] = l + } + fileKey := fieldMap.resolve(FieldKeyFile) + if l, ok := data[fileKey]; ok { + data["fields."+fileKey] = l + } } } diff --git a/vendor/github.com/sirupsen/logrus/hooks/test/test.go b/vendor/github.com/sirupsen/logrus/hooks/test/test.go index 62c4845df7d..234a17dfa88 100644 --- a/vendor/github.com/sirupsen/logrus/hooks/test/test.go +++ b/vendor/github.com/sirupsen/logrus/hooks/test/test.go @@ -15,7 +15,7 @@ type Hook struct { // Entries is an array of all entries that have been received by this hook. // For safe access, use the AllEntries() method, rather than reading this // value directly. - Entries []*logrus.Entry + Entries []logrus.Entry mu sync.RWMutex } @@ -52,7 +52,7 @@ func NewNullLogger() (*logrus.Logger, *Hook) { func (t *Hook) Fire(e *logrus.Entry) error { t.mu.Lock() defer t.mu.Unlock() - t.Entries = append(t.Entries, e) + t.Entries = append(t.Entries, *e) return nil } @@ -68,9 +68,7 @@ func (t *Hook) LastEntry() *logrus.Entry { if i < 0 { return nil } - // Make a copy, for safety - e := *t.Entries[i] - return &e + return &t.Entries[i] } // AllEntries returns all entries that were logged. @@ -79,10 +77,9 @@ func (t *Hook) AllEntries() []*logrus.Entry { defer t.mu.RUnlock() // Make a copy so the returned value won't race with future log requests entries := make([]*logrus.Entry, len(t.Entries)) - for i, entry := range t.Entries { + for i := 0; i < len(t.Entries); i++ { // Make a copy, for safety - e := *entry - entries[i] = &e + entries[i] = &t.Entries[i] } return entries } @@ -91,5 +88,5 @@ func (t *Hook) AllEntries() []*logrus.Entry { func (t *Hook) Reset() { t.mu.Lock() defer t.mu.Unlock() - t.Entries = make([]*logrus.Entry, 0) + t.Entries = make([]logrus.Entry, 0) } diff --git a/vendor/github.com/sirupsen/logrus/json_formatter.go b/vendor/github.com/sirupsen/logrus/json_formatter.go index fb01c1b1040..2605753599f 100644 --- a/vendor/github.com/sirupsen/logrus/json_formatter.go +++ b/vendor/github.com/sirupsen/logrus/json_formatter.go @@ -1,6 +1,7 @@ package logrus import ( + "bytes" "encoding/json" "fmt" ) @@ -10,13 +11,6 @@ type fieldKey string // FieldMap allows customization of the key names for default fields. type FieldMap map[fieldKey]string -// Default key names for the default fields -const ( - FieldKeyMsg = "msg" - FieldKeyLevel = "level" - FieldKeyTime = "time" -) - func (f FieldMap) resolve(key fieldKey) string { if k, ok := f[key]; ok { return k @@ -33,21 +27,28 @@ type JSONFormatter struct { // DisableTimestamp allows disabling automatic timestamps in output DisableTimestamp bool + // DataKey allows users to put all the log entry parameters into a nested dictionary at a given key. + DataKey string + // FieldMap allows users to customize the names of keys for default fields. // As an example: // formatter := &JSONFormatter{ // FieldMap: FieldMap{ - // FieldKeyTime: "@timestamp", + // FieldKeyTime: "@timestamp", // FieldKeyLevel: "@level", - // FieldKeyMsg: "@message", + // FieldKeyMsg: "@message", + // FieldKeyFunc: "@caller", // }, // } FieldMap FieldMap + + // PrettyPrint will indent all json logs + PrettyPrint bool } // Format renders a single log entry func (f *JSONFormatter) Format(entry *Entry) ([]byte, error) { - data := make(Fields, len(entry.Data)+3) + data := make(Fields, len(entry.Data)+4) for k, v := range entry.Data { switch v := v.(type) { case error: @@ -58,22 +59,47 @@ func (f *JSONFormatter) Format(entry *Entry) ([]byte, error) { data[k] = v } } - prefixFieldClashes(data) + + if f.DataKey != "" { + newData := make(Fields, 4) + newData[f.DataKey] = data + data = newData + } + + prefixFieldClashes(data, f.FieldMap, entry.HasCaller()) timestampFormat := f.TimestampFormat if timestampFormat == "" { timestampFormat = defaultTimestampFormat } + if entry.err != "" { + data[f.FieldMap.resolve(FieldKeyLogrusError)] = entry.err + } if !f.DisableTimestamp { data[f.FieldMap.resolve(FieldKeyTime)] = entry.Time.Format(timestampFormat) } data[f.FieldMap.resolve(FieldKeyMsg)] = entry.Message data[f.FieldMap.resolve(FieldKeyLevel)] = entry.Level.String() + if entry.HasCaller() { + data[f.FieldMap.resolve(FieldKeyFunc)] = entry.Caller.Function + data[f.FieldMap.resolve(FieldKeyFile)] = fmt.Sprintf("%s:%d", entry.Caller.File, entry.Caller.Line) + } + + var b *bytes.Buffer + if entry.Buffer != nil { + b = entry.Buffer + } else { + b = &bytes.Buffer{} + } - serialized, err := json.Marshal(data) - if err != nil { + encoder := json.NewEncoder(b) + if f.PrettyPrint { + encoder.SetIndent("", " ") + } + if err := encoder.Encode(data); err != nil { return nil, fmt.Errorf("Failed to marshal fields to JSON, %v", err) } - return append(serialized, '\n'), nil + + return b.Bytes(), nil } diff --git a/vendor/github.com/sirupsen/logrus/logger.go b/vendor/github.com/sirupsen/logrus/logger.go index fdaf8a65341..5ceca0eab42 100644 --- a/vendor/github.com/sirupsen/logrus/logger.go +++ b/vendor/github.com/sirupsen/logrus/logger.go @@ -5,12 +5,13 @@ import ( "os" "sync" "sync/atomic" + "time" ) type Logger struct { // The logs are `io.Copy`'d to this in a mutex. It's common to set this to a // file, or leave it default which is `os.Stderr`. You can also set this to - // something more adventorous, such as logging to Kafka. + // something more adventurous, such as logging to Kafka. Out io.Writer // Hooks for the logger instance. These allow firing events based on logging // levels and log entries. For example, to send errors to an error tracking @@ -23,6 +24,10 @@ type Logger struct { // own that implements the `Formatter` interface, see the `README` or included // formatters for examples. Formatter Formatter + + // Flag for whether to log caller info (off by default) + ReportCaller bool + // The logging level the logger should log at. This is typically (and defaults // to) `logrus.Info`, which allows Info(), Warn(), Error() and Fatal() to be // logged. @@ -31,8 +36,12 @@ type Logger struct { mu MutexWrap // Reusable empty entry entryPool sync.Pool + // Function to exit the application, defaults to `os.Exit()` + ExitFunc exitFunc } +type exitFunc func(int) + type MutexWrap struct { lock sync.Mutex disabled bool @@ -68,10 +77,12 @@ func (mw *MutexWrap) Disable() { // It's recommended to make this a global instance called `log`. func New() *Logger { return &Logger{ - Out: os.Stderr, - Formatter: new(TextFormatter), - Hooks: make(LevelHooks), - Level: InfoLevel, + Out: os.Stderr, + Formatter: new(TextFormatter), + Hooks: make(LevelHooks), + Level: InfoLevel, + ExitFunc: os.Exit, + ReportCaller: false, } } @@ -84,11 +95,12 @@ func (logger *Logger) newEntry() *Entry { } func (logger *Logger) releaseEntry(entry *Entry) { + entry.Data = map[string]interface{}{} logger.entryPool.Put(entry) } // Adds a field to the log entry, note that it doesn't log until you call -// Debug, Print, Info, Warn, Fatal or Panic. It only creates a log entry. +// Debug, Print, Info, Warn, Error, Fatal or Panic. It only creates a log entry. // If you want multiple fields, use `WithFields`. func (logger *Logger) WithField(key string, value interface{}) *Entry { entry := logger.newEntry() @@ -112,8 +124,23 @@ func (logger *Logger) WithError(err error) *Entry { return entry.WithError(err) } +// Overrides the time of the log entry. +func (logger *Logger) WithTime(t time.Time) *Entry { + entry := logger.newEntry() + defer logger.releaseEntry(entry) + return entry.WithTime(t) +} + +func (logger *Logger) Tracef(format string, args ...interface{}) { + if logger.IsLevelEnabled(TraceLevel) { + entry := logger.newEntry() + entry.Tracef(format, args...) + logger.releaseEntry(entry) + } +} + func (logger *Logger) Debugf(format string, args ...interface{}) { - if logger.level() >= DebugLevel { + if logger.IsLevelEnabled(DebugLevel) { entry := logger.newEntry() entry.Debugf(format, args...) logger.releaseEntry(entry) @@ -121,7 +148,7 @@ func (logger *Logger) Debugf(format string, args ...interface{}) { } func (logger *Logger) Infof(format string, args ...interface{}) { - if logger.level() >= InfoLevel { + if logger.IsLevelEnabled(InfoLevel) { entry := logger.newEntry() entry.Infof(format, args...) logger.releaseEntry(entry) @@ -135,7 +162,7 @@ func (logger *Logger) Printf(format string, args ...interface{}) { } func (logger *Logger) Warnf(format string, args ...interface{}) { - if logger.level() >= WarnLevel { + if logger.IsLevelEnabled(WarnLevel) { entry := logger.newEntry() entry.Warnf(format, args...) logger.releaseEntry(entry) @@ -143,7 +170,7 @@ func (logger *Logger) Warnf(format string, args ...interface{}) { } func (logger *Logger) Warningf(format string, args ...interface{}) { - if logger.level() >= WarnLevel { + if logger.IsLevelEnabled(WarnLevel) { entry := logger.newEntry() entry.Warnf(format, args...) logger.releaseEntry(entry) @@ -151,7 +178,7 @@ func (logger *Logger) Warningf(format string, args ...interface{}) { } func (logger *Logger) Errorf(format string, args ...interface{}) { - if logger.level() >= ErrorLevel { + if logger.IsLevelEnabled(ErrorLevel) { entry := logger.newEntry() entry.Errorf(format, args...) logger.releaseEntry(entry) @@ -159,24 +186,32 @@ func (logger *Logger) Errorf(format string, args ...interface{}) { } func (logger *Logger) Fatalf(format string, args ...interface{}) { - if logger.level() >= FatalLevel { + if logger.IsLevelEnabled(FatalLevel) { entry := logger.newEntry() entry.Fatalf(format, args...) logger.releaseEntry(entry) } - Exit(1) + logger.Exit(1) } func (logger *Logger) Panicf(format string, args ...interface{}) { - if logger.level() >= PanicLevel { + if logger.IsLevelEnabled(PanicLevel) { entry := logger.newEntry() entry.Panicf(format, args...) logger.releaseEntry(entry) } } +func (logger *Logger) Trace(args ...interface{}) { + if logger.IsLevelEnabled(TraceLevel) { + entry := logger.newEntry() + entry.Trace(args...) + logger.releaseEntry(entry) + } +} + func (logger *Logger) Debug(args ...interface{}) { - if logger.level() >= DebugLevel { + if logger.IsLevelEnabled(DebugLevel) { entry := logger.newEntry() entry.Debug(args...) logger.releaseEntry(entry) @@ -184,7 +219,7 @@ func (logger *Logger) Debug(args ...interface{}) { } func (logger *Logger) Info(args ...interface{}) { - if logger.level() >= InfoLevel { + if logger.IsLevelEnabled(InfoLevel) { entry := logger.newEntry() entry.Info(args...) logger.releaseEntry(entry) @@ -198,7 +233,7 @@ func (logger *Logger) Print(args ...interface{}) { } func (logger *Logger) Warn(args ...interface{}) { - if logger.level() >= WarnLevel { + if logger.IsLevelEnabled(WarnLevel) { entry := logger.newEntry() entry.Warn(args...) logger.releaseEntry(entry) @@ -206,7 +241,7 @@ func (logger *Logger) Warn(args ...interface{}) { } func (logger *Logger) Warning(args ...interface{}) { - if logger.level() >= WarnLevel { + if logger.IsLevelEnabled(WarnLevel) { entry := logger.newEntry() entry.Warn(args...) logger.releaseEntry(entry) @@ -214,7 +249,7 @@ func (logger *Logger) Warning(args ...interface{}) { } func (logger *Logger) Error(args ...interface{}) { - if logger.level() >= ErrorLevel { + if logger.IsLevelEnabled(ErrorLevel) { entry := logger.newEntry() entry.Error(args...) logger.releaseEntry(entry) @@ -222,24 +257,32 @@ func (logger *Logger) Error(args ...interface{}) { } func (logger *Logger) Fatal(args ...interface{}) { - if logger.level() >= FatalLevel { + if logger.IsLevelEnabled(FatalLevel) { entry := logger.newEntry() entry.Fatal(args...) logger.releaseEntry(entry) } - Exit(1) + logger.Exit(1) } func (logger *Logger) Panic(args ...interface{}) { - if logger.level() >= PanicLevel { + if logger.IsLevelEnabled(PanicLevel) { entry := logger.newEntry() entry.Panic(args...) logger.releaseEntry(entry) } } +func (logger *Logger) Traceln(args ...interface{}) { + if logger.IsLevelEnabled(TraceLevel) { + entry := logger.newEntry() + entry.Traceln(args...) + logger.releaseEntry(entry) + } +} + func (logger *Logger) Debugln(args ...interface{}) { - if logger.level() >= DebugLevel { + if logger.IsLevelEnabled(DebugLevel) { entry := logger.newEntry() entry.Debugln(args...) logger.releaseEntry(entry) @@ -247,7 +290,7 @@ func (logger *Logger) Debugln(args ...interface{}) { } func (logger *Logger) Infoln(args ...interface{}) { - if logger.level() >= InfoLevel { + if logger.IsLevelEnabled(InfoLevel) { entry := logger.newEntry() entry.Infoln(args...) logger.releaseEntry(entry) @@ -261,7 +304,7 @@ func (logger *Logger) Println(args ...interface{}) { } func (logger *Logger) Warnln(args ...interface{}) { - if logger.level() >= WarnLevel { + if logger.IsLevelEnabled(WarnLevel) { entry := logger.newEntry() entry.Warnln(args...) logger.releaseEntry(entry) @@ -269,7 +312,7 @@ func (logger *Logger) Warnln(args ...interface{}) { } func (logger *Logger) Warningln(args ...interface{}) { - if logger.level() >= WarnLevel { + if logger.IsLevelEnabled(WarnLevel) { entry := logger.newEntry() entry.Warnln(args...) logger.releaseEntry(entry) @@ -277,7 +320,7 @@ func (logger *Logger) Warningln(args ...interface{}) { } func (logger *Logger) Errorln(args ...interface{}) { - if logger.level() >= ErrorLevel { + if logger.IsLevelEnabled(ErrorLevel) { entry := logger.newEntry() entry.Errorln(args...) logger.releaseEntry(entry) @@ -285,22 +328,30 @@ func (logger *Logger) Errorln(args ...interface{}) { } func (logger *Logger) Fatalln(args ...interface{}) { - if logger.level() >= FatalLevel { + if logger.IsLevelEnabled(FatalLevel) { entry := logger.newEntry() entry.Fatalln(args...) logger.releaseEntry(entry) } - Exit(1) + logger.Exit(1) } func (logger *Logger) Panicln(args ...interface{}) { - if logger.level() >= PanicLevel { + if logger.IsLevelEnabled(PanicLevel) { entry := logger.newEntry() entry.Panicln(args...) logger.releaseEntry(entry) } } +func (logger *Logger) Exit(code int) { + runHandlers() + if logger.ExitFunc == nil { + logger.ExitFunc = os.Exit + } + logger.ExitFunc(code) +} + //When file is opened with appending mode, it's safe to //write concurrently to a file (within 4k message on Linux). //In these cases user can choose to disable the lock. @@ -312,12 +363,53 @@ func (logger *Logger) level() Level { return Level(atomic.LoadUint32((*uint32)(&logger.Level))) } +// SetLevel sets the logger level. func (logger *Logger) SetLevel(level Level) { atomic.StoreUint32((*uint32)(&logger.Level), uint32(level)) } +// GetLevel returns the logger level. +func (logger *Logger) GetLevel() Level { + return logger.level() +} + +// AddHook adds a hook to the logger hooks. func (logger *Logger) AddHook(hook Hook) { logger.mu.Lock() defer logger.mu.Unlock() logger.Hooks.Add(hook) } + +// IsLevelEnabled checks if the log level of the logger is greater than the level param +func (logger *Logger) IsLevelEnabled(level Level) bool { + return logger.level() >= level +} + +// SetFormatter sets the logger formatter. +func (logger *Logger) SetFormatter(formatter Formatter) { + logger.mu.Lock() + defer logger.mu.Unlock() + logger.Formatter = formatter +} + +// SetOutput sets the logger output. +func (logger *Logger) SetOutput(output io.Writer) { + logger.mu.Lock() + defer logger.mu.Unlock() + logger.Out = output +} + +func (logger *Logger) SetReportCaller(reportCaller bool) { + logger.mu.Lock() + defer logger.mu.Unlock() + logger.ReportCaller = reportCaller +} + +// ReplaceHooks replaces the logger hooks and returns the old ones +func (logger *Logger) ReplaceHooks(hooks LevelHooks) LevelHooks { + logger.mu.Lock() + oldHooks := logger.Hooks + logger.Hooks = hooks + logger.mu.Unlock() + return oldHooks +} diff --git a/vendor/github.com/sirupsen/logrus/logrus.go b/vendor/github.com/sirupsen/logrus/logrus.go index dd38999741e..4ef45186620 100644 --- a/vendor/github.com/sirupsen/logrus/logrus.go +++ b/vendor/github.com/sirupsen/logrus/logrus.go @@ -15,6 +15,8 @@ type Level uint32 // Convert the Level to a string. E.g. PanicLevel becomes "panic". func (level Level) String() string { switch level { + case TraceLevel: + return "trace" case DebugLevel: return "debug" case InfoLevel: @@ -47,12 +49,26 @@ func ParseLevel(lvl string) (Level, error) { return InfoLevel, nil case "debug": return DebugLevel, nil + case "trace": + return TraceLevel, nil } var l Level return l, fmt.Errorf("not a valid logrus Level: %q", lvl) } +// UnmarshalText implements encoding.TextUnmarshaler. +func (level *Level) UnmarshalText(text []byte) error { + l, err := ParseLevel(string(text)) + if err != nil { + return err + } + + *level = Level(l) + + return nil +} + // A constant exposing all logging levels var AllLevels = []Level{ PanicLevel, @@ -61,6 +77,7 @@ var AllLevels = []Level{ WarnLevel, InfoLevel, DebugLevel, + TraceLevel, } // These are the different logging levels. You can set the logging level to log @@ -69,7 +86,7 @@ const ( // PanicLevel level, highest level of severity. Logs and then calls panic with the // message passed to Debug, Info, ... PanicLevel Level = iota - // FatalLevel level. Logs and then calls `os.Exit(1)`. It will exit even if the + // FatalLevel level. Logs and then calls `logger.Exit(1)`. It will exit even if the // logging level is set to Panic. FatalLevel // ErrorLevel level. Logs. Used for errors that should definitely be noted. @@ -82,6 +99,8 @@ const ( InfoLevel // DebugLevel level. Usually only enabled when debugging. Very verbose logging. DebugLevel + // TraceLevel level. Designates finer-grained informational events than the Debug. + TraceLevel ) // Won't compile if StdLogger can't be realized by a log.Logger @@ -140,4 +159,20 @@ type FieldLogger interface { Errorln(args ...interface{}) Fatalln(args ...interface{}) Panicln(args ...interface{}) + + // IsDebugEnabled() bool + // IsInfoEnabled() bool + // IsWarnEnabled() bool + // IsErrorEnabled() bool + // IsFatalEnabled() bool + // IsPanicEnabled() bool +} + +// Ext1FieldLogger (the first extension to FieldLogger) is superfluous, it is +// here for consistancy. Do not use. Use Logger or Entry instead. +type Ext1FieldLogger interface { + FieldLogger + Tracef(format string, args ...interface{}) + Trace(args ...interface{}) + Traceln(args ...interface{}) } diff --git a/vendor/github.com/sirupsen/logrus/terminal_bsd.go b/vendor/github.com/sirupsen/logrus/terminal_bsd.go deleted file mode 100644 index 4880d13d26d..00000000000 --- a/vendor/github.com/sirupsen/logrus/terminal_bsd.go +++ /dev/null @@ -1,10 +0,0 @@ -// +build darwin freebsd openbsd netbsd dragonfly -// +build !appengine,!gopherjs - -package logrus - -import "golang.org/x/sys/unix" - -const ioctlReadTermios = unix.TIOCGETA - -type Termios unix.Termios diff --git a/vendor/github.com/sirupsen/logrus/terminal_check_appengine.go b/vendor/github.com/sirupsen/logrus/terminal_check_appengine.go index 3de08e802fd..2403de98192 100644 --- a/vendor/github.com/sirupsen/logrus/terminal_check_appengine.go +++ b/vendor/github.com/sirupsen/logrus/terminal_check_appengine.go @@ -1,4 +1,4 @@ -// +build appengine gopherjs +// +build appengine package logrus diff --git a/vendor/github.com/sirupsen/logrus/terminal_check_js.go b/vendor/github.com/sirupsen/logrus/terminal_check_js.go new file mode 100644 index 00000000000..0c209750a33 --- /dev/null +++ b/vendor/github.com/sirupsen/logrus/terminal_check_js.go @@ -0,0 +1,11 @@ +// +build js + +package logrus + +import ( + "io" +) + +func checkIfTerminal(w io.Writer) bool { + return false +} diff --git a/vendor/github.com/sirupsen/logrus/terminal_check_notappengine.go b/vendor/github.com/sirupsen/logrus/terminal_check_notappengine.go index 067047a1233..cf309d6fb6e 100644 --- a/vendor/github.com/sirupsen/logrus/terminal_check_notappengine.go +++ b/vendor/github.com/sirupsen/logrus/terminal_check_notappengine.go @@ -1,4 +1,4 @@ -// +build !appengine,!gopherjs +// +build !appengine,!js,!windows package logrus diff --git a/vendor/github.com/sirupsen/logrus/terminal_check_windows.go b/vendor/github.com/sirupsen/logrus/terminal_check_windows.go new file mode 100644 index 00000000000..3b9d2864ca3 --- /dev/null +++ b/vendor/github.com/sirupsen/logrus/terminal_check_windows.go @@ -0,0 +1,20 @@ +// +build !appengine,!js,windows + +package logrus + +import ( + "io" + "os" + "syscall" +) + +func checkIfTerminal(w io.Writer) bool { + switch v := w.(type) { + case *os.File: + var mode uint32 + err := syscall.GetConsoleMode(syscall.Handle(v.Fd()), &mode) + return err == nil + default: + return false + } +} diff --git a/vendor/github.com/sirupsen/logrus/terminal_linux.go b/vendor/github.com/sirupsen/logrus/terminal_linux.go deleted file mode 100644 index f29a0097c81..00000000000 --- a/vendor/github.com/sirupsen/logrus/terminal_linux.go +++ /dev/null @@ -1,14 +0,0 @@ -// Based on ssh/terminal: -// Copyright 2013 The Go Authors. All rights reserved. -// Use of this source code is governed by a BSD-style -// license that can be found in the LICENSE file. - -// +build !appengine,!gopherjs - -package logrus - -import "golang.org/x/sys/unix" - -const ioctlReadTermios = unix.TCGETS - -type Termios unix.Termios diff --git a/vendor/github.com/sirupsen/logrus/terminal_notwindows.go b/vendor/github.com/sirupsen/logrus/terminal_notwindows.go new file mode 100644 index 00000000000..3dbd2372030 --- /dev/null +++ b/vendor/github.com/sirupsen/logrus/terminal_notwindows.go @@ -0,0 +1,8 @@ +// +build !windows + +package logrus + +import "io" + +func initTerminal(w io.Writer) { +} diff --git a/vendor/github.com/sirupsen/logrus/terminal_windows.go b/vendor/github.com/sirupsen/logrus/terminal_windows.go new file mode 100644 index 00000000000..b4ef5286cd4 --- /dev/null +++ b/vendor/github.com/sirupsen/logrus/terminal_windows.go @@ -0,0 +1,18 @@ +// +build !appengine,!js,windows + +package logrus + +import ( + "io" + "os" + "syscall" + + sequences "github.com/konsorten/go-windows-terminal-sequences" +) + +func initTerminal(w io.Writer) { + switch v := w.(type) { + case *os.File: + sequences.EnableVirtualTerminalProcessing(syscall.Handle(v.Fd()), true) + } +} diff --git a/vendor/github.com/sirupsen/logrus/text_formatter.go b/vendor/github.com/sirupsen/logrus/text_formatter.go index 61b21caea45..49ec92f172c 100644 --- a/vendor/github.com/sirupsen/logrus/text_formatter.go +++ b/vendor/github.com/sirupsen/logrus/text_formatter.go @@ -3,6 +3,7 @@ package logrus import ( "bytes" "fmt" + "os" "sort" "strings" "sync" @@ -20,6 +21,7 @@ const ( var ( baseTimestamp time.Time + emptyFieldMap FieldMap ) func init() { @@ -34,6 +36,9 @@ type TextFormatter struct { // Force disabling colors. DisableColors bool + // Override coloring based on CLICOLOR and CLICOLOR_FORCE. - https://bixense.com/clicolors/ + EnvironmentOverrideColors bool + // Disable timestamp logging. useful when output is redirected to logging // system that already adds timestamps. DisableTimestamp bool @@ -50,60 +55,132 @@ type TextFormatter struct { // be desired. DisableSorting bool + // The keys sorting function, when uninitialized it uses sort.Strings. + SortingFunc func([]string) + + // Disables the truncation of the level text to 4 characters. + DisableLevelTruncation bool + // QuoteEmptyFields will wrap empty fields in quotes if true QuoteEmptyFields bool // Whether the logger's out is to a terminal isTerminal bool - sync.Once + // FieldMap allows users to customize the names of keys for default fields. + // As an example: + // formatter := &TextFormatter{ + // FieldMap: FieldMap{ + // FieldKeyTime: "@timestamp", + // FieldKeyLevel: "@level", + // FieldKeyMsg: "@message"}} + FieldMap FieldMap + + terminalInitOnce sync.Once } func (f *TextFormatter) init(entry *Entry) { if entry.Logger != nil { f.isTerminal = checkIfTerminal(entry.Logger.Out) + + if f.isTerminal { + initTerminal(entry.Logger.Out) + } + } +} + +func (f *TextFormatter) isColored() bool { + isColored := f.ForceColors || f.isTerminal + + if f.EnvironmentOverrideColors { + if force, ok := os.LookupEnv("CLICOLOR_FORCE"); ok && force != "0" { + isColored = true + } else if ok && force == "0" { + isColored = false + } else if os.Getenv("CLICOLOR") == "0" { + isColored = false + } } + + return isColored && !f.DisableColors } // Format renders a single log entry func (f *TextFormatter) Format(entry *Entry) ([]byte, error) { - var b *bytes.Buffer + prefixFieldClashes(entry.Data, f.FieldMap, entry.HasCaller()) + keys := make([]string, 0, len(entry.Data)) for k := range entry.Data { keys = append(keys, k) } + fixedKeys := make([]string, 0, 4+len(entry.Data)) + if !f.DisableTimestamp { + fixedKeys = append(fixedKeys, f.FieldMap.resolve(FieldKeyTime)) + } + fixedKeys = append(fixedKeys, f.FieldMap.resolve(FieldKeyLevel)) + if entry.Message != "" { + fixedKeys = append(fixedKeys, f.FieldMap.resolve(FieldKeyMsg)) + } + if entry.err != "" { + fixedKeys = append(fixedKeys, f.FieldMap.resolve(FieldKeyLogrusError)) + } + if entry.HasCaller() { + fixedKeys = append(fixedKeys, + f.FieldMap.resolve(FieldKeyFunc), f.FieldMap.resolve(FieldKeyFile)) + } + if !f.DisableSorting { - sort.Strings(keys) + if f.SortingFunc == nil { + sort.Strings(keys) + fixedKeys = append(fixedKeys, keys...) + } else { + if !f.isColored() { + fixedKeys = append(fixedKeys, keys...) + f.SortingFunc(fixedKeys) + } else { + f.SortingFunc(keys) + } + } + } else { + fixedKeys = append(fixedKeys, keys...) } + + var b *bytes.Buffer if entry.Buffer != nil { b = entry.Buffer } else { b = &bytes.Buffer{} } - prefixFieldClashes(entry.Data) - - f.Do(func() { f.init(entry) }) - - isColored := (f.ForceColors || f.isTerminal) && !f.DisableColors + f.terminalInitOnce.Do(func() { f.init(entry) }) timestampFormat := f.TimestampFormat if timestampFormat == "" { timestampFormat = defaultTimestampFormat } - if isColored { + if f.isColored() { f.printColored(b, entry, keys, timestampFormat) } else { - if !f.DisableTimestamp { - f.appendKeyValue(b, "time", entry.Time.Format(timestampFormat)) - } - f.appendKeyValue(b, "level", entry.Level.String()) - if entry.Message != "" { - f.appendKeyValue(b, "msg", entry.Message) - } - for _, key := range keys { - f.appendKeyValue(b, key, entry.Data[key]) + for _, key := range fixedKeys { + var value interface{} + switch { + case key == f.FieldMap.resolve(FieldKeyTime): + value = entry.Time.Format(timestampFormat) + case key == f.FieldMap.resolve(FieldKeyLevel): + value = entry.Level.String() + case key == f.FieldMap.resolve(FieldKeyMsg): + value = entry.Message + case key == f.FieldMap.resolve(FieldKeyLogrusError): + value = entry.err + case key == f.FieldMap.resolve(FieldKeyFunc) && entry.HasCaller(): + value = entry.Caller.Function + case key == f.FieldMap.resolve(FieldKeyFile) && entry.HasCaller(): + value = fmt.Sprintf("%s:%d", entry.Caller.File, entry.Caller.Line) + default: + value = entry.Data[key] + } + f.appendKeyValue(b, key, value) } } @@ -114,7 +191,7 @@ func (f *TextFormatter) Format(entry *Entry) ([]byte, error) { func (f *TextFormatter) printColored(b *bytes.Buffer, entry *Entry, keys []string, timestampFormat string) { var levelColor int switch entry.Level { - case DebugLevel: + case DebugLevel, TraceLevel: levelColor = gray case WarnLevel: levelColor = yellow @@ -124,14 +201,28 @@ func (f *TextFormatter) printColored(b *bytes.Buffer, entry *Entry, keys []strin levelColor = blue } - levelText := strings.ToUpper(entry.Level.String())[0:4] + levelText := strings.ToUpper(entry.Level.String()) + if !f.DisableLevelTruncation { + levelText = levelText[0:4] + } + + // Remove a single newline if it already exists in the message to keep + // the behavior of logrus text_formatter the same as the stdlib log package + entry.Message = strings.TrimSuffix(entry.Message, "\n") + + caller := "" + + if entry.HasCaller() { + caller = fmt.Sprintf("%s:%d %s()", + entry.Caller.File, entry.Caller.Line, entry.Caller.Function) + } if f.DisableTimestamp { - fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m %-44s ", levelColor, levelText, entry.Message) + fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m%s %-44s ", levelColor, levelText, caller, entry.Message) } else if !f.FullTimestamp { - fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%04d] %-44s ", levelColor, levelText, int(entry.Time.Sub(baseTimestamp)/time.Second), entry.Message) + fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%04d]%s %-44s ", levelColor, levelText, int(entry.Time.Sub(baseTimestamp)/time.Second), caller, entry.Message) } else { - fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%s] %-44s ", levelColor, levelText, entry.Time.Format(timestampFormat), entry.Message) + fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%s]%s %-44s ", levelColor, levelText, entry.Time.Format(timestampFormat), caller, entry.Message) } for _, k := range keys { v := entry.Data[k] diff --git a/vendor/github.com/sirupsen/logrus/writer.go b/vendor/github.com/sirupsen/logrus/writer.go index 7bdebedc60b..9e1f7513597 100644 --- a/vendor/github.com/sirupsen/logrus/writer.go +++ b/vendor/github.com/sirupsen/logrus/writer.go @@ -24,6 +24,8 @@ func (entry *Entry) WriterLevel(level Level) *io.PipeWriter { var printFunc func(args ...interface{}) switch level { + case TraceLevel: + printFunc = entry.Trace case DebugLevel: printFunc = entry.Debug case InfoLevel: From b8c8aee692342ea02271cbe5f294350d5252fbea Mon Sep 17 00:00:00 2001 From: Nikhil Raman Date: Wed, 16 Jan 2019 19:42:47 +0530 Subject: [PATCH 2/2] Add console-output option. `console-output` attaches a new file based console to the VUs. This allows users to redirect all their `console.log/warn/etc.` to the given file. This prevents the stdout from getting cluttered with debug statements that may be printed in the test `.js` files. --- cmd/archive.go | 5 ++- cmd/cloud.go | 5 ++- cmd/options.go | 10 ++++++ cmd/run.go | 4 ++- js/console.go | 34 +++++++++++++----- js/console_test.go | 88 +++++++++++++++++++++++++++++++++++++++++++++- js/runner.go | 24 ++++++++++--- lib/options.go | 7 ++++ lib/runner.go | 5 +-- 9 files changed, 162 insertions(+), 20 deletions(-) diff --git a/cmd/archive.go b/cmd/archive.go index e048dadf1b0..ede0553929c 100644 --- a/cmd/archive.go +++ b/cmd/archive.go @@ -75,7 +75,10 @@ An archive is a fully self-contained test run, and can be executed identically e return err } - r.SetOptions(conf.Options) + err = r.SetOptions(conf.Options) + if err != nil { + return err + } // Archive. arc := r.MakeArchive() diff --git a/cmd/cloud.go b/cmd/cloud.go index afe313f2ddc..1850f27d93e 100644 --- a/cmd/cloud.go +++ b/cmd/cloud.go @@ -93,7 +93,10 @@ This will execute the test on the Load Impact cloud service. Use "k6 login cloud return err } - r.SetOptions(conf.Options) + err = r.SetOptions(conf.Options) + if err != nil { + return err + } // Cloud config cloudConfig := cloud.NewConfig().Apply(conf.Collectors.Cloud) diff --git a/cmd/options.go b/cmd/options.go index e827a5280ca..40164b8efb8 100644 --- a/cmd/options.go +++ b/cmd/options.go @@ -67,6 +67,7 @@ func optionFlagSet() *pflag.FlagSet { flags.String("summary-time-unit", "", "define the time unit used to display the trend stats. Possible units are: 's', 'ms' and 'us'") flags.StringSlice("system-tags", lib.DefaultSystemTagList, "only include these system tags in metrics") flags.StringSlice("tag", nil, "add a `tag` to be applied to all samples, as `[name]=[value]`") + flags.String("console-output", "", "redirects the console logging to the provided output file") flags.Bool("discard-response-bodies", false, "Read but don't process or save HTTP response bodies") return flags } @@ -174,6 +175,15 @@ func getOptions(flags *pflag.FlagSet) (lib.Options, error) { opts.RunTags = stats.IntoSampleTags(&parsedRunTags) } + redirectConFile, err := flags.GetString("console-output") + if err != nil { + return opts, err + } + + if redirectConFile != "" { + opts.ConsoleOutput = null.StringFrom(redirectConFile) + } + return opts, nil } diff --git a/cmd/run.go b/cmd/run.go index eea60bf8e40..f5b3b432302 100644 --- a/cmd/run.go +++ b/cmd/run.go @@ -171,7 +171,9 @@ a commandline interface for interacting with it.`, } // Write options back to the runner too. - r.SetOptions(conf.Options) + if err = r.SetOptions(conf.Options); err != nil { + return err + } // Create a local executor wrapping the runner. fprintf(stdout, "%s executor\r", initBar.String()) diff --git a/js/console.go b/js/console.go index aec2ffb7d4d..fd03688bb8b 100644 --- a/js/console.go +++ b/js/console.go @@ -22,21 +22,37 @@ package js import ( "context" + "os" "strconv" "github.com/dop251/goja" log "github.com/sirupsen/logrus" ) -type Console struct { +// console represents a JS console implemented as a logrus.Logger. +type console struct { Logger *log.Logger } -func NewConsole() *Console { - return &Console{log.StandardLogger()} +// Creates a console with the standard logrus logger. +func newConsole() *console { + return &console{log.StandardLogger()} } -func (c Console) log(ctx *context.Context, level log.Level, msgobj goja.Value, args ...goja.Value) { +// Creates a console logger with its output set to the file at the provided `filepath`. +func newFileConsole(filepath string) (*console, error) { + f, err := os.OpenFile(filepath, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0644) + if err != nil { + return nil, err + } + + l := log.New() + l.SetOutput(f) + + return &console{l}, nil +} + +func (c console) log(ctx *context.Context, level log.Level, msgobj goja.Value, args ...goja.Value) { if ctx != nil && *ctx != nil { select { case <-(*ctx).Done(): @@ -63,22 +79,22 @@ func (c Console) log(ctx *context.Context, level log.Level, msgobj goja.Value, a } } -func (c Console) Log(ctx *context.Context, msg goja.Value, args ...goja.Value) { +func (c console) Log(ctx *context.Context, msg goja.Value, args ...goja.Value) { c.Info(ctx, msg, args...) } -func (c Console) Debug(ctx *context.Context, msg goja.Value, args ...goja.Value) { +func (c console) Debug(ctx *context.Context, msg goja.Value, args ...goja.Value) { c.log(ctx, log.DebugLevel, msg, args...) } -func (c Console) Info(ctx *context.Context, msg goja.Value, args ...goja.Value) { +func (c console) Info(ctx *context.Context, msg goja.Value, args ...goja.Value) { c.log(ctx, log.InfoLevel, msg, args...) } -func (c Console) Warn(ctx *context.Context, msg goja.Value, args ...goja.Value) { +func (c console) Warn(ctx *context.Context, msg goja.Value, args ...goja.Value) { c.log(ctx, log.WarnLevel, msg, args...) } -func (c Console) Error(ctx *context.Context, msg goja.Value, args ...goja.Value) { +func (c console) Error(ctx *context.Context, msg goja.Value, args ...goja.Value) { c.log(ctx, log.ErrorLevel, msg, args...) } diff --git a/js/console_test.go b/js/console_test.go index 8ad55b85d86..fb6ba88e2aa 100644 --- a/js/console_test.go +++ b/js/console_test.go @@ -23,8 +23,12 @@ package js import ( "context" "fmt" + "io/ioutil" + "os" "testing" + "gopkg.in/guregu/null.v3" + "github.com/dop251/goja" "github.com/loadimpact/k6/js/common" "github.com/loadimpact/k6/lib" @@ -41,7 +45,7 @@ func TestConsoleContext(t *testing.T) { ctxPtr := new(context.Context) logger, hook := logtest.NewNullLogger() - rt.Set("console", common.Bind(rt, &Console{logger}, ctxPtr)) + rt.Set("console", common.Bind(rt, &console{logger}, ctxPtr)) _, err := common.RunString(rt, `console.log("a")`) assert.NoError(t, err) @@ -122,3 +126,85 @@ func TestConsole(t *testing.T) { }) } } + +func TestFileConsole(t *testing.T) { + logFile := "/tmp/loadtest.log" + levels := map[string]log.Level{ + "log": log.InfoLevel, + "debug": log.DebugLevel, + "info": log.InfoLevel, + "warn": log.WarnLevel, + "error": log.ErrorLevel, + } + argsets := map[string]struct { + Message string + Data log.Fields + }{ + `"string"`: {Message: "string"}, + `"string","a","b"`: {Message: "string", Data: log.Fields{"0": "a", "1": "b"}}, + `"string",1,2`: {Message: "string", Data: log.Fields{"0": "1", "1": "2"}}, + `{}`: {Message: "[object Object]"}, + } + for name, level := range levels { + t.Run(name, func(t *testing.T) { + for args, result := range argsets { + t.Run(args, func(t *testing.T) { + r, err := New(&lib.SourceData{ + Filename: "/script", + Data: []byte(fmt.Sprintf( + `export default function() { console.%s(%s); }`, + name, args, + )), + }, afero.NewMemMapFs(), lib.RuntimeOptions{}) + assert.NoError(t, err) + + err = r.SetOptions(lib.Options{ + ConsoleOutput: null.StringFrom(logFile), + }) + assert.NoError(t, err) + + samples := make(chan stats.SampleContainer, 100) + vu, err := r.newVU(samples) + assert.NoError(t, err) + + vu.Console.Logger.Level = log.DebugLevel + hook := logtest.NewLocal(vu.Console.Logger) + + err = vu.RunOnce(context.Background()) + assert.NoError(t, err) + + // Test if the file was created. + _, err = os.Stat(logFile) + assert.NoError(t, err) + + entry := hook.LastEntry() + if assert.NotNil(t, entry, "nothing logged") { + assert.Equal(t, level, entry.Level) + assert.Equal(t, result.Message, entry.Message) + + data := result.Data + if data == nil { + data = make(log.Fields) + } + assert.Equal(t, data, entry.Data) + + // Test if what we logged to the hook is the same as what we logged + // to the file. + entryStr, err := entry.String() + assert.NoError(t, err) + + f, err := os.Open(logFile) + assert.NoError(t, err) + + fileContent, err := ioutil.ReadAll(f) + assert.NoError(t, err) + + assert.Equal(t, entryStr, string(fileContent)) + } + + os.Remove(logFile) + }) + } + }) + } +} diff --git a/js/runner.go b/js/runner.go index 10ca95918a8..2ca9acf261c 100644 --- a/js/runner.go +++ b/js/runner.go @@ -58,6 +58,7 @@ type Runner struct { Resolver *dnscache.Resolver RPSLimit *rate.Limiter + console *console setupData []byte } @@ -92,10 +93,12 @@ func NewFromBundle(b *Bundle) (*Runner, error) { KeepAlive: 30 * time.Second, DualStack: true, }, + console: newConsole(), Resolver: dnscache.New(0), } - r.SetOptions(r.Bundle.Options) - return r, nil + + err = r.SetOptions(r.Bundle.Options) + return r, err } func (r *Runner) MakeArchive() *lib.Archive { @@ -179,7 +182,7 @@ func (r *Runner) newVU(samplesOut chan<- stats.SampleContainer) (*VU, error) { Dialer: dialer, CookieJar: cookieJar, TLSConfig: tlsConfig, - Console: NewConsole(), + Console: r.console, BPool: bpool.NewBufferPool(100), Samples: samplesOut, } @@ -260,13 +263,24 @@ func (r *Runner) GetOptions() lib.Options { return r.Bundle.Options } -func (r *Runner) SetOptions(opts lib.Options) { +func (r *Runner) SetOptions(opts lib.Options) error { r.Bundle.Options = opts r.RPSLimit = nil if rps := opts.RPS; rps.Valid { r.RPSLimit = rate.NewLimiter(rate.Limit(rps.Int64), 1) } + + if consoleOutputFile := opts.ConsoleOutput; consoleOutputFile.Valid { + c, err := newFileConsole(consoleOutputFile.String) + if err != nil { + return err + } + + r.console = c + } + + return nil } // Runs an exported function in its own temporary VU, optionally with an argument. Execution is @@ -322,7 +336,7 @@ type VU struct { ID int64 Iteration int64 - Console *Console + Console *console BPool *bpool.BufferPool Samples chan<- stats.SampleContainer diff --git a/lib/options.go b/lib/options.go index d5dee655c56..8285e4764d8 100644 --- a/lib/options.go +++ b/lib/options.go @@ -272,6 +272,9 @@ type Options struct { // Discard Http Responses Body DiscardResponseBodies null.Bool `json:"discardResponseBodies" envconfig:"discard_response_bodies"` + + // Redirect console logging to a file + ConsoleOutput null.String `json:"-" envconfig:"console_output"` } // Returns the result of overwriting any fields with any that are set on the argument. @@ -385,6 +388,10 @@ func (o Options) Apply(opts Options) Options { if opts.DiscardResponseBodies.Valid { o.DiscardResponseBodies = opts.DiscardResponseBodies } + if opts.ConsoleOutput.Valid { + o.ConsoleOutput = opts.ConsoleOutput + } + return o } diff --git a/lib/runner.go b/lib/runner.go index 90512f056be..e3fde944104 100644 --- a/lib/runner.go +++ b/lib/runner.go @@ -65,7 +65,7 @@ type Runner interface { // `export let options = {}`); cmd/run.go will mix this in with CLI-, config- and env-provided // values and write it back to the runner. GetOptions() Options - SetOptions(opts Options) + SetOptions(opts Options) error } // A VU is a Virtual User, that can be scheduled by an Executor. @@ -138,8 +138,9 @@ func (r MiniRunner) GetOptions() Options { return r.Options } -func (r *MiniRunner) SetOptions(opts Options) { +func (r *MiniRunner) SetOptions(opts Options) error { r.Options = opts + return nil } // A VU spawned by a MiniRunner.