2017-02-20 18:39:36 +03:00
|
|
|
package log
|
|
|
|
|
|
|
|
import (
|
|
|
|
"bytes"
|
|
|
|
"encoding/json"
|
|
|
|
"fmt"
|
|
|
|
"reflect"
|
|
|
|
"strconv"
|
|
|
|
"strings"
|
|
|
|
"sync"
|
2017-02-23 12:44:16 +03:00
|
|
|
"sync/atomic"
|
2017-02-20 18:39:36 +03:00
|
|
|
"time"
|
2017-02-28 16:36:51 +03:00
|
|
|
"unicode/utf8"
|
2017-02-20 18:39:36 +03:00
|
|
|
)
|
|
|
|
|
|
|
|
const (
|
|
|
|
timeFormat = "2006-01-02T15:04:05-0700"
|
|
|
|
termTimeFormat = "01-02|15:04:05"
|
|
|
|
floatFormat = 'f'
|
|
|
|
termMsgJust = 40
|
|
|
|
)
|
|
|
|
|
2017-02-23 12:44:16 +03:00
|
|
|
// locationTrims are trimmed for display to avoid unwieldy log lines.
|
|
|
|
var locationTrims = []string{
|
|
|
|
"github.com/ethereum/go-ethereum/",
|
|
|
|
"github.com/ethereum/ethash/",
|
|
|
|
}
|
|
|
|
|
|
|
|
// 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
|
|
|
|
|
2017-02-28 16:36:51 +03:00
|
|
|
// 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
|
|
|
|
|
2017-02-20 18:39:36 +03:00
|
|
|
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)
|
|
|
|
}
|
|
|
|
|
2017-02-27 18:06:40 +03:00
|
|
|
// 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
|
|
|
|
}
|
|
|
|
|
2017-02-20 18:39:36 +03:00
|
|
|
// 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.
|
|
|
|
//
|
|
|
|
// [TIME] [LEVEL] MESAGE key=value key=value ...
|
|
|
|
//
|
|
|
|
// Example:
|
|
|
|
//
|
|
|
|
// [May 16 20:58:45] [DBUG] remove route ns=haproxy addr=127.0.0.1:50002
|
|
|
|
//
|
2017-02-23 21:31:13 +03:00
|
|
|
func TerminalFormat(usecolor bool) Format {
|
2017-02-20 18:39:36 +03:00
|
|
|
return FormatFunc(func(r *Record) []byte {
|
|
|
|
var color = 0
|
2017-02-23 21:31:13 +03:00
|
|
|
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
|
|
|
|
}
|
2017-02-20 18:39:36 +03:00
|
|
|
}
|
|
|
|
|
|
|
|
b := &bytes.Buffer{}
|
2017-02-23 20:30:32 +03:00
|
|
|
lvl := r.Lvl.AlignedString()
|
2017-02-23 12:44:16 +03:00
|
|
|
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 {
|
2017-02-23 20:30:32 +03:00
|
|
|
fmt.Fprintf(b, "%s[%s|%s]%s %s ", lvl, r.Time.Format(termTimeFormat), location, padding, r.Msg)
|
2017-02-23 12:44:16 +03:00
|
|
|
}
|
2017-02-20 18:39:36 +03:00
|
|
|
} else {
|
2017-02-23 12:44:16 +03:00
|
|
|
if color > 0 {
|
|
|
|
fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%s] %s ", color, lvl, r.Time.Format(termTimeFormat), r.Msg)
|
|
|
|
} else {
|
2017-02-23 20:30:32 +03:00
|
|
|
fmt.Fprintf(b, "%s[%s] %s ", lvl, r.Time.Format(termTimeFormat), r.Msg)
|
2017-02-23 12:44:16 +03:00
|
|
|
}
|
2017-02-20 18:39:36 +03:00
|
|
|
}
|
|
|
|
// try to justify the log output for short messages
|
|
|
|
if len(r.Ctx) > 0 && len(r.Msg) < termMsgJust {
|
|
|
|
b.Write(bytes.Repeat([]byte{' '}, termMsgJust-len(r.Msg)))
|
|
|
|
}
|
|
|
|
|
|
|
|
// print the keys logfmt style
|
2017-02-27 18:06:40 +03:00
|
|
|
logfmt(b, r.Ctx, color, true)
|
2017-02-20 18:39:36 +03:00
|
|
|
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{}
|
2017-02-27 18:06:40 +03:00
|
|
|
logfmt(buf, append(common, r.Ctx...), 0, false)
|
2017-02-20 18:39:36 +03:00
|
|
|
return buf.Bytes()
|
|
|
|
})
|
|
|
|
}
|
|
|
|
|
2017-02-27 18:06:40 +03:00
|
|
|
func logfmt(buf *bytes.Buffer, ctx []interface{}, color int, term bool) {
|
2017-02-20 18:39:36 +03:00
|
|
|
for i := 0; i < len(ctx); i += 2 {
|
|
|
|
if i != 0 {
|
|
|
|
buf.WriteByte(' ')
|
|
|
|
}
|
|
|
|
|
|
|
|
k, ok := ctx[i].(string)
|
2017-02-27 18:06:40 +03:00
|
|
|
v := formatLogfmtValue(ctx[i+1], term)
|
2017-02-20 18:39:36 +03:00
|
|
|
if !ok {
|
2017-02-27 18:06:40 +03:00
|
|
|
k, v = errorKey, formatLogfmtValue(k, term)
|
2017-02-20 18:39:36 +03:00
|
|
|
}
|
|
|
|
|
|
|
|
// XXX: we should probably check that all of your key bytes aren't invalid
|
2017-02-28 16:36:51 +03:00
|
|
|
fieldPaddingLock.RLock()
|
|
|
|
padding := fieldPadding[k]
|
|
|
|
fieldPaddingLock.RUnlock()
|
|
|
|
|
|
|
|
length := utf8.RuneCountInString(v)
|
|
|
|
if padding < length {
|
|
|
|
padding = length
|
|
|
|
|
|
|
|
fieldPaddingLock.Lock()
|
|
|
|
fieldPadding[k] = padding
|
|
|
|
fieldPaddingLock.Unlock()
|
|
|
|
}
|
2017-02-20 18:39:36 +03:00
|
|
|
if color > 0 {
|
2017-02-28 16:36:51 +03:00
|
|
|
fmt.Fprintf(buf, "\x1b[%dm%s\x1b[0m=", color, k)
|
2017-02-20 18:39:36 +03:00
|
|
|
} else {
|
|
|
|
buf.WriteString(k)
|
|
|
|
buf.WriteByte('=')
|
2017-02-28 16:36:51 +03:00
|
|
|
}
|
|
|
|
buf.WriteString(v)
|
|
|
|
if i < len(ctx)-2 {
|
|
|
|
buf.Write(bytes.Repeat([]byte{' '}, padding-length))
|
2017-02-20 18:39:36 +03:00
|
|
|
}
|
|
|
|
}
|
|
|
|
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)
|
|
|
|
}
|
|
|
|
|
|
|
|
// 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
|
2017-02-27 18:06:40 +03:00
|
|
|
func formatLogfmtValue(value interface{}, term bool) string {
|
2017-02-20 18:39:36 +03:00
|
|
|
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)
|
|
|
|
}
|
2017-02-27 18:06:40 +03:00
|
|
|
if term {
|
|
|
|
if s, ok := value.(TerminalStringer); ok {
|
|
|
|
// Custom terminal stringer provided, use that
|
|
|
|
return escapeString(s.TerminalString())
|
|
|
|
}
|
|
|
|
}
|
2017-02-20 18:39:36 +03:00
|
|
|
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 == false && needsQuotes == false {
|
|
|
|
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
|
|
|
|
}
|