package log import ( "bytes" "encoding/json" "fmt" "reflect" "strconv" "strings" "sync" "sync/atomic" "time" "unicode/utf8" ) const ( timeFormat = "2006-01-02T15:04:05-0700" termTimeFormat = "01-02|15:04:05.000" floatFormat = 'f' termMsgJust = 40 ) // locationTrims are trimmed for display to avoid unwieldy log lines. var locationTrims = []string{ "github.com/tangerine-network/go-tangerine/", } // PrintOrigins sets or unsets log location (file:line) printing for terminal // format output. func PrintOrigins(print bool) { if print { atomic.StoreUint32(&locationEnabled, 1) } else { atomic.StoreUint32(&locationEnabled, 0) } } // locationEnabled is an atomic flag controlling whether the terminal formatter // should append the log locations too when printing entries. var locationEnabled uint32 // locationLength is the maxmimum path length encountered, which all logs are // padded to to aid in alignment. var locationLength uint32 // fieldPadding is a global map with maximum field value lengths seen until now // to allow padding log contexts in a bit smarter way. var fieldPadding = make(map[string]int) // fieldPaddingLock is a global mutex protecting the field padding map. var fieldPaddingLock sync.RWMutex type Format interface { Format(r *Record) []byte } // FormatFunc returns a new Format object which uses // the given function to perform record formatting. func FormatFunc(f func(*Record) []byte) Format { return formatFunc(f) } type formatFunc func(*Record) []byte func (f formatFunc) Format(r *Record) []byte { return f(r) } // TerminalStringer is an analogous interface to the stdlib stringer, allowing // own types to have custom shortened serialization formats when printed to the // screen. type TerminalStringer interface { TerminalString() string } // TerminalFormat formats log records optimized for human readability on // a terminal with color-coded level output and terser human friendly timestamp. // This format should only be used for interactive programs or while developing. // // [LEVEL] [TIME] MESAGE key=value key=value ... // // Example: // // [DBUG] [May 16 20:58:45] remove route ns=haproxy addr=127.0.0.1:50002 // func TerminalFormat(usecolor bool) Format { return FormatFunc(func(r *Record) []byte { var color = 0 if usecolor { switch r.Lvl { case LvlCrit: color = 35 case LvlError: color = 31 case LvlWarn: color = 33 case LvlInfo: color = 32 case LvlDebug: color = 36 case LvlTrace: color = 34 } } b := &bytes.Buffer{} lvl := r.Lvl.AlignedString() if atomic.LoadUint32(&locationEnabled) != 0 { // Log origin printing was requested, format the location path and line number location := fmt.Sprintf("%+v", r.Call) for _, prefix := range locationTrims { location = strings.TrimPrefix(location, prefix) } // Maintain the maximum location length for fancyer alignment align := int(atomic.LoadUint32(&locationLength)) if align < len(location) { align = len(location) atomic.StoreUint32(&locationLength, uint32(align)) } padding := strings.Repeat(" ", align-len(location)) // Assemble and print the log heading if color > 0 { fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%s|%s]%s %s ", color, lvl, r.Time.Format(termTimeFormat), location, padding, r.Msg) } else { fmt.Fprintf(b, "%s[%s|%s]%s %s ", lvl, r.Time.Format(termTimeFormat), location, padding, r.Msg) } } else { if color > 0 { fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%s] %s ", color, lvl, r.Time.Format(termTimeFormat), r.Msg) } else { fmt.Fprintf(b, "%s[%s] %s ", lvl, r.Time.Format(termTimeFormat), r.Msg) } } // try to justify the log output for short messages length := utf8.RuneCountInString(r.Msg) if len(r.Ctx) > 0 && length < termMsgJust { b.Write(bytes.Repeat([]byte{' '}, termMsgJust-length)) } // print the keys logfmt style logfmt(b, r.Ctx, color, true) return b.Bytes() }) } // LogfmtFormat prints records in logfmt format, an easy machine-parseable but human-readable // format for key/value pairs. // // For more details see: http://godoc.org/github.com/kr/logfmt // func LogfmtFormat() Format { return FormatFunc(func(r *Record) []byte { common := []interface{}{r.KeyNames.Time, r.Time, r.KeyNames.Lvl, r.Lvl, r.KeyNames.Msg, r.Msg} buf := &bytes.Buffer{} logfmt(buf, append(common, r.Ctx...), 0, false) return buf.Bytes() }) } func logfmt(buf *bytes.Buffer, ctx []interface{}, color int, term bool) { for i := 0; i < len(ctx); i += 2 { if i != 0 { buf.WriteByte(' ') } k, ok := ctx[i].(string) v := formatLogfmtValue(ctx[i+1], term) if !ok { k, v = errorKey, formatLogfmtValue(k, term) } // XXX: we should probably check that all of your key bytes aren't invalid fieldPaddingLock.RLock() padding := fieldPadding[k] fieldPaddingLock.RUnlock() length := utf8.RuneCountInString(v) if padding < length { padding = length fieldPaddingLock.Lock() fieldPadding[k] = padding fieldPaddingLock.Unlock() } if color > 0 { fmt.Fprintf(buf, "\x1b[%dm%s\x1b[0m=", color, k) } else { buf.WriteString(k) buf.WriteByte('=') } buf.WriteString(v) if i < len(ctx)-2 { buf.Write(bytes.Repeat([]byte{' '}, padding-length)) } } buf.WriteByte('\n') } // JSONFormat formats log records as JSON objects separated by newlines. // It is the equivalent of JSONFormatEx(false, true). func JSONFormat() Format { return JSONFormatEx(false, true) } // JSONFormatOrderedEx formats log records as JSON arrays. If pretty is true, // records will be pretty-printed. If lineSeparated is true, records // will be logged with a new line between each record. func JSONFormatOrderedEx(pretty, lineSeparated bool) Format { jsonMarshal := json.Marshal if pretty { jsonMarshal = func(v interface{}) ([]byte, error) { return json.MarshalIndent(v, "", " ") } } return FormatFunc(func(r *Record) []byte { props := make(map[string]interface{}) props[r.KeyNames.Time] = r.Time props[r.KeyNames.Lvl] = r.Lvl.String() props[r.KeyNames.Msg] = r.Msg ctx := make([]string, len(r.Ctx)) for i := 0; i < len(r.Ctx); i += 2 { k, ok := r.Ctx[i].(string) if !ok { props[errorKey] = fmt.Sprintf("%+v is not a string key,", r.Ctx[i]) } ctx[i] = k ctx[i+1] = formatLogfmtValue(r.Ctx[i+1], true) } props[r.KeyNames.Ctx] = ctx b, err := jsonMarshal(props) if err != nil { b, _ = jsonMarshal(map[string]string{ errorKey: err.Error(), }) return b } if lineSeparated { b = append(b, '\n') } return b }) } // JSONFormatEx formats log records as JSON objects. If pretty is true, // records will be pretty-printed. If lineSeparated is true, records // will be logged with a new line between each record. func JSONFormatEx(pretty, lineSeparated bool) Format { jsonMarshal := json.Marshal if pretty { jsonMarshal = func(v interface{}) ([]byte, error) { return json.MarshalIndent(v, "", " ") } } return FormatFunc(func(r *Record) []byte { props := make(map[string]interface{}) props[r.KeyNames.Time] = r.Time props[r.KeyNames.Lvl] = r.Lvl.String() props[r.KeyNames.Msg] = r.Msg for i := 0; i < len(r.Ctx); i += 2 { k, ok := r.Ctx[i].(string) if !ok { props[errorKey] = fmt.Sprintf("%+v is not a string key", r.Ctx[i]) } props[k] = formatJSONValue(r.Ctx[i+1]) } b, err := jsonMarshal(props) if err != nil { b, _ = jsonMarshal(map[string]string{ errorKey: err.Error(), }) return b } if lineSeparated { b = append(b, '\n') } return b }) } func formatShared(value interface{}) (result interface{}) { defer func() { if err := recover(); err != nil { if v := reflect.ValueOf(value); v.Kind() == reflect.Ptr && v.IsNil() { result = "nil" } else { panic(err) } } }() switch v := value.(type) { case time.Time: return v.Format(timeFormat) case error: return v.Error() case fmt.Stringer: return v.String() default: return v } } func formatJSONValue(value interface{}) interface{} { value = formatShared(value) switch value.(type) { case int, int8, int16, int32, int64, float32, float64, uint, uint8, uint16, uint32, uint64, string: return value default: return fmt.Sprintf("%+v", value) } } // formatValue formats a value for serialization func formatLogfmtValue(value interface{}, term bool) string { if value == nil { return "nil" } if t, ok := value.(time.Time); ok { // Performance optimization: No need for escaping since the provided // timeFormat doesn't have any escape characters, and escaping is // expensive. return t.Format(timeFormat) } if term { if s, ok := value.(TerminalStringer); ok { // Custom terminal stringer provided, use that return escapeString(s.TerminalString()) } } value = formatShared(value) switch v := value.(type) { case bool: return strconv.FormatBool(v) case float32: return strconv.FormatFloat(float64(v), floatFormat, 3, 64) case float64: return strconv.FormatFloat(v, floatFormat, 3, 64) case int, int8, int16, int32, int64, uint, uint8, uint16, uint32, uint64: return fmt.Sprintf("%d", value) case string: return escapeString(v) default: return escapeString(fmt.Sprintf("%+v", value)) } } var stringBufPool = sync.Pool{ New: func() interface{} { return new(bytes.Buffer) }, } func escapeString(s string) string { needsQuotes := false needsEscape := false for _, r := range s { if r <= ' ' || r == '=' || r == '"' { needsQuotes = true } if r == '\\' || r == '"' || r == '\n' || r == '\r' || r == '\t' { needsEscape = true } } if !needsEscape && !needsQuotes { return s } e := stringBufPool.Get().(*bytes.Buffer) e.WriteByte('"') for _, r := range s { switch r { case '\\', '"': e.WriteByte('\\') e.WriteByte(byte(r)) case '\n': e.WriteString("\\n") case '\r': e.WriteString("\\r") case '\t': e.WriteString("\\t") default: e.WriteRune(r) } } e.WriteByte('"') var ret string if needsQuotes { ret = e.String() } else { ret = string(e.Bytes()[1 : e.Len()-1]) } e.Reset() stringBufPool.Put(e) return ret }