2017-08-11 19:19:46 +02:00
|
|
|
package hclog
|
|
|
|
|
|
|
|
import (
|
|
|
|
"bufio"
|
2018-10-02 22:03:07 +02:00
|
|
|
"bytes"
|
|
|
|
"encoding"
|
2017-08-11 19:19:46 +02:00
|
|
|
"encoding/json"
|
|
|
|
"fmt"
|
|
|
|
"log"
|
|
|
|
"os"
|
2018-10-02 22:03:07 +02:00
|
|
|
"reflect"
|
2017-08-11 19:19:46 +02:00
|
|
|
"runtime"
|
2018-10-02 22:03:07 +02:00
|
|
|
"sort"
|
2017-08-11 19:19:46 +02:00
|
|
|
"strconv"
|
|
|
|
"strings"
|
|
|
|
"sync"
|
2018-10-02 22:03:07 +02:00
|
|
|
"sync/atomic"
|
2017-08-11 19:19:46 +02:00
|
|
|
"time"
|
|
|
|
)
|
|
|
|
|
|
|
|
var (
|
|
|
|
_levelToBracket = map[Level]string{
|
|
|
|
Debug: "[DEBUG]",
|
|
|
|
Trace: "[TRACE]",
|
2018-10-02 22:03:07 +02:00
|
|
|
Info: "[INFO] ",
|
|
|
|
Warn: "[WARN] ",
|
2017-08-11 19:19:46 +02:00
|
|
|
Error: "[ERROR]",
|
|
|
|
}
|
|
|
|
)
|
|
|
|
|
|
|
|
// Given the options (nil for defaults), create a new Logger
|
|
|
|
func New(opts *LoggerOptions) Logger {
|
|
|
|
if opts == nil {
|
|
|
|
opts = &LoggerOptions{}
|
|
|
|
}
|
|
|
|
|
|
|
|
output := opts.Output
|
|
|
|
if output == nil {
|
|
|
|
output = os.Stderr
|
|
|
|
}
|
|
|
|
|
|
|
|
level := opts.Level
|
|
|
|
if level == NoLevel {
|
|
|
|
level = DefaultLevel
|
|
|
|
}
|
|
|
|
|
2018-10-02 22:03:07 +02:00
|
|
|
mtx := opts.Mutex
|
|
|
|
if mtx == nil {
|
|
|
|
mtx = new(sync.Mutex)
|
2017-08-11 19:19:46 +02:00
|
|
|
}
|
2018-10-02 22:03:07 +02:00
|
|
|
|
|
|
|
ret := &intLogger{
|
|
|
|
m: mtx,
|
|
|
|
json: opts.JSONFormat,
|
|
|
|
caller: opts.IncludeLocation,
|
|
|
|
name: opts.Name,
|
|
|
|
timeFormat: TimeFormat,
|
|
|
|
w: bufio.NewWriter(output),
|
|
|
|
level: new(int32),
|
|
|
|
}
|
|
|
|
if opts.TimeFormat != "" {
|
|
|
|
ret.timeFormat = opts.TimeFormat
|
|
|
|
}
|
|
|
|
atomic.StoreInt32(ret.level, int32(level))
|
|
|
|
return ret
|
2017-08-11 19:19:46 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
// The internal logger implementation. Internal in that it is defined entirely
|
|
|
|
// by this package.
|
|
|
|
type intLogger struct {
|
2018-10-02 22:03:07 +02:00
|
|
|
json bool
|
|
|
|
caller bool
|
|
|
|
name string
|
|
|
|
timeFormat string
|
2017-08-11 19:19:46 +02:00
|
|
|
|
|
|
|
// 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
|
2018-10-02 22:03:07 +02:00
|
|
|
level *int32
|
2017-08-11 19:19:46 +02:00
|
|
|
|
|
|
|
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{}) {
|
2018-10-02 22:03:07 +02:00
|
|
|
if level < Level(atomic.LoadInt32(z.level)) {
|
2017-08-11 19:19:46 +02:00
|
|
|
return
|
|
|
|
}
|
|
|
|
|
|
|
|
t := time.Now()
|
|
|
|
|
|
|
|
z.m.Lock()
|
|
|
|
defer z.m.Unlock()
|
|
|
|
|
|
|
|
if z.json {
|
|
|
|
z.logJson(t, level, msg, args...)
|
|
|
|
} else {
|
|
|
|
z.log(t, level, msg, args...)
|
|
|
|
}
|
|
|
|
|
|
|
|
z.w.Flush()
|
|
|
|
}
|
|
|
|
|
|
|
|
// Cleanup a path by returning the last 2 segments of the path only.
|
|
|
|
func trimCallerPath(path string) string {
|
|
|
|
// lovely borrowed from zap
|
|
|
|
// nb. To make sure we trim the path correctly on Windows too, we
|
|
|
|
// counter-intuitively need to use '/' and *not* os.PathSeparator here,
|
|
|
|
// because the path given originates from Go stdlib, specifically
|
|
|
|
// runtime.Caller() which (as of Mar/17) returns forward slashes even on
|
|
|
|
// Windows.
|
|
|
|
//
|
|
|
|
// See https://github.com/golang/go/issues/3335
|
|
|
|
// 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
|
|
|
|
}
|
|
|
|
|
|
|
|
// Find the penultimate separator.
|
|
|
|
idx = strings.LastIndexByte(path[:idx], '/')
|
|
|
|
if idx == -1 {
|
|
|
|
return path
|
|
|
|
}
|
|
|
|
|
|
|
|
return path[idx+1:]
|
|
|
|
}
|
|
|
|
|
|
|
|
// Non-JSON logging format function
|
|
|
|
func (z *intLogger) log(t time.Time, level Level, msg string, args ...interface{}) {
|
2018-10-02 22:03:07 +02:00
|
|
|
z.w.WriteString(t.Format(z.timeFormat))
|
2017-08-11 19:19:46 +02:00
|
|
|
z.w.WriteByte(' ')
|
|
|
|
|
|
|
|
s, ok := _levelToBracket[level]
|
|
|
|
if ok {
|
|
|
|
z.w.WriteString(s)
|
|
|
|
} else {
|
2018-10-02 22:03:07 +02:00
|
|
|
z.w.WriteString("[?????]")
|
2017-08-11 19:19:46 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
if z.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(':')
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
z.w.WriteByte(' ')
|
|
|
|
|
|
|
|
if z.name != "" {
|
|
|
|
z.w.WriteString(z.name)
|
|
|
|
z.w.WriteString(": ")
|
|
|
|
}
|
|
|
|
|
|
|
|
z.w.WriteString(msg)
|
|
|
|
|
|
|
|
args = append(z.implied, args...)
|
|
|
|
|
|
|
|
var stacktrace CapturedStacktrace
|
|
|
|
|
|
|
|
if args != nil && len(args) > 0 {
|
|
|
|
if len(args)%2 != 0 {
|
|
|
|
cs, ok := args[len(args)-1].(CapturedStacktrace)
|
|
|
|
if ok {
|
|
|
|
args = args[:len(args)-1]
|
|
|
|
stacktrace = cs
|
|
|
|
} else {
|
|
|
|
args = append(args, "<unknown>")
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
z.w.WriteByte(':')
|
|
|
|
|
|
|
|
FOR:
|
|
|
|
for i := 0; i < len(args); i = i + 2 {
|
2018-10-02 22:03:07 +02:00
|
|
|
var (
|
|
|
|
val string
|
|
|
|
raw bool
|
|
|
|
)
|
2017-08-11 19:19:46 +02:00
|
|
|
|
|
|
|
switch st := args[i+1].(type) {
|
|
|
|
case string:
|
|
|
|
val = st
|
|
|
|
case int:
|
|
|
|
val = strconv.FormatInt(int64(st), 10)
|
|
|
|
case int64:
|
|
|
|
val = strconv.FormatInt(int64(st), 10)
|
|
|
|
case int32:
|
|
|
|
val = strconv.FormatInt(int64(st), 10)
|
|
|
|
case int16:
|
|
|
|
val = strconv.FormatInt(int64(st), 10)
|
|
|
|
case int8:
|
|
|
|
val = strconv.FormatInt(int64(st), 10)
|
|
|
|
case uint:
|
|
|
|
val = strconv.FormatUint(uint64(st), 10)
|
|
|
|
case uint64:
|
|
|
|
val = strconv.FormatUint(uint64(st), 10)
|
|
|
|
case uint32:
|
|
|
|
val = strconv.FormatUint(uint64(st), 10)
|
|
|
|
case uint16:
|
|
|
|
val = strconv.FormatUint(uint64(st), 10)
|
|
|
|
case uint8:
|
|
|
|
val = strconv.FormatUint(uint64(st), 10)
|
|
|
|
case CapturedStacktrace:
|
|
|
|
stacktrace = st
|
|
|
|
continue FOR
|
2018-10-02 22:03:07 +02:00
|
|
|
case Format:
|
|
|
|
val = fmt.Sprintf(st[0].(string), st[1:]...)
|
2017-08-11 19:19:46 +02:00
|
|
|
default:
|
2018-10-02 22:03:07 +02:00
|
|
|
v := reflect.ValueOf(st)
|
|
|
|
if v.Kind() == reflect.Slice {
|
|
|
|
val = z.renderSlice(v)
|
|
|
|
raw = true
|
|
|
|
} else {
|
|
|
|
val = fmt.Sprintf("%v", st)
|
|
|
|
}
|
2017-08-11 19:19:46 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
z.w.WriteByte(' ')
|
|
|
|
z.w.WriteString(args[i].(string))
|
|
|
|
z.w.WriteByte('=')
|
|
|
|
|
2018-10-02 22:03:07 +02:00
|
|
|
if !raw && strings.ContainsAny(val, " \t\n\r") {
|
2017-08-11 19:19:46 +02:00
|
|
|
z.w.WriteByte('"')
|
|
|
|
z.w.WriteString(val)
|
|
|
|
z.w.WriteByte('"')
|
|
|
|
} else {
|
|
|
|
z.w.WriteString(val)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
z.w.WriteString("\n")
|
|
|
|
|
|
|
|
if stacktrace != "" {
|
|
|
|
z.w.WriteString(string(stacktrace))
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2018-10-02 22:03:07 +02:00
|
|
|
func (z *intLogger) renderSlice(v reflect.Value) string {
|
|
|
|
var buf bytes.Buffer
|
|
|
|
|
|
|
|
buf.WriteRune('[')
|
|
|
|
|
|
|
|
for i := 0; i < v.Len(); i++ {
|
|
|
|
if i > 0 {
|
|
|
|
buf.WriteString(", ")
|
|
|
|
}
|
|
|
|
|
|
|
|
sv := v.Index(i)
|
|
|
|
|
|
|
|
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)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
buf.WriteRune(']')
|
|
|
|
|
|
|
|
return buf.String()
|
|
|
|
}
|
|
|
|
|
2017-08-11 19:19:46 +02:00
|
|
|
// 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"),
|
|
|
|
}
|
|
|
|
|
|
|
|
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 z.name != "" {
|
|
|
|
vals["@module"] = z.name
|
|
|
|
}
|
|
|
|
|
|
|
|
if z.caller {
|
|
|
|
if _, file, line, ok := runtime.Caller(3); ok {
|
|
|
|
vals["@caller"] = fmt.Sprintf("%s:%d", file, line)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2018-10-02 22:03:07 +02:00
|
|
|
args = append(z.implied, args...)
|
|
|
|
|
2017-08-11 19:19:46 +02:00
|
|
|
if args != nil && len(args) > 0 {
|
|
|
|
if len(args)%2 != 0 {
|
|
|
|
cs, ok := args[len(args)-1].(CapturedStacktrace)
|
|
|
|
if ok {
|
|
|
|
args = args[:len(args)-1]
|
|
|
|
vals["stacktrace"] = cs
|
|
|
|
} else {
|
|
|
|
args = append(args, "<unknown>")
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
for i := 0; i < len(args); i = i + 2 {
|
|
|
|
if _, ok := args[i].(string); !ok {
|
|
|
|
// As this is the logging function not much we can do here
|
|
|
|
// without injecting into logs...
|
|
|
|
continue
|
|
|
|
}
|
2018-10-02 22:03:07 +02:00
|
|
|
val := args[i+1]
|
|
|
|
switch sv := val.(type) {
|
|
|
|
case error:
|
|
|
|
// Check if val is of type error. If error type doesn't
|
|
|
|
// implement json.Marshaler or encoding.TextMarshaler
|
|
|
|
// then set val to err.Error() so that it gets marshaled
|
|
|
|
switch sv.(type) {
|
|
|
|
case json.Marshaler, encoding.TextMarshaler:
|
|
|
|
default:
|
|
|
|
val = sv.Error()
|
|
|
|
}
|
|
|
|
case Format:
|
|
|
|
val = fmt.Sprintf(sv[0].(string), sv[1:]...)
|
|
|
|
}
|
|
|
|
|
|
|
|
vals[args[i].(string)] = val
|
2017-08-11 19:19:46 +02:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
err := json.NewEncoder(z.w).Encode(vals)
|
|
|
|
if err != nil {
|
|
|
|
panic(err)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
// Emit the message and args at DEBUG level
|
|
|
|
func (z *intLogger) Debug(msg string, args ...interface{}) {
|
|
|
|
z.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...)
|
|
|
|
}
|
|
|
|
|
|
|
|
// Emit the message and args at INFO level
|
|
|
|
func (z *intLogger) Info(msg string, args ...interface{}) {
|
|
|
|
z.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...)
|
|
|
|
}
|
|
|
|
|
|
|
|
// Emit the message and args at ERROR level
|
|
|
|
func (z *intLogger) Error(msg string, args ...interface{}) {
|
|
|
|
z.Log(Error, msg, args...)
|
|
|
|
}
|
|
|
|
|
|
|
|
// Indicate that the logger would emit TRACE level logs
|
|
|
|
func (z *intLogger) IsTrace() bool {
|
2018-10-02 22:03:07 +02:00
|
|
|
return Level(atomic.LoadInt32(z.level)) == Trace
|
2017-08-11 19:19:46 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
// Indicate that the logger would emit DEBUG level logs
|
|
|
|
func (z *intLogger) IsDebug() bool {
|
2018-10-02 22:03:07 +02:00
|
|
|
return Level(atomic.LoadInt32(z.level)) <= Debug
|
2017-08-11 19:19:46 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
// Indicate that the logger would emit INFO level logs
|
|
|
|
func (z *intLogger) IsInfo() bool {
|
2018-10-02 22:03:07 +02:00
|
|
|
return Level(atomic.LoadInt32(z.level)) <= Info
|
2017-08-11 19:19:46 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
// Indicate that the logger would emit WARN level logs
|
|
|
|
func (z *intLogger) IsWarn() bool {
|
2018-10-02 22:03:07 +02:00
|
|
|
return Level(atomic.LoadInt32(z.level)) <= Warn
|
2017-08-11 19:19:46 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
// Indicate that the logger would emit ERROR level logs
|
|
|
|
func (z *intLogger) IsError() bool {
|
2018-10-02 22:03:07 +02:00
|
|
|
return Level(atomic.LoadInt32(z.level)) <= Error
|
2017-08-11 19:19:46 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
// 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 {
|
2018-10-02 22:03:07 +02:00
|
|
|
if len(args)%2 != 0 {
|
|
|
|
panic("With() call requires paired arguments")
|
|
|
|
}
|
|
|
|
|
2017-08-11 19:19:46 +02:00
|
|
|
var nz intLogger = *z
|
|
|
|
|
2018-10-02 22:03:07 +02:00
|
|
|
result := make(map[string]interface{}, len(z.implied)+len(args))
|
|
|
|
keys := make([]string, 0, len(z.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)
|
|
|
|
keys = append(keys, key)
|
|
|
|
result[key] = z.implied[i+1]
|
|
|
|
}
|
|
|
|
// Read new args, store map and key for consistent sorting
|
|
|
|
for i := 0; i < len(args); i += 2 {
|
|
|
|
key := args[i].(string)
|
|
|
|
_, exists := result[key]
|
|
|
|
if !exists {
|
|
|
|
keys = append(keys, key)
|
|
|
|
}
|
|
|
|
result[key] = args[i+1]
|
|
|
|
}
|
|
|
|
|
|
|
|
// Sort keys to be consistent
|
|
|
|
sort.Strings(keys)
|
|
|
|
|
|
|
|
nz.implied = make([]interface{}, 0, len(z.implied)+len(args))
|
|
|
|
for _, k := range keys {
|
|
|
|
nz.implied = append(nz.implied, k)
|
|
|
|
nz.implied = append(nz.implied, result[k])
|
|
|
|
}
|
2017-08-11 19:19:46 +02:00
|
|
|
|
|
|
|
return &nz
|
|
|
|
}
|
|
|
|
|
|
|
|
// 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
|
|
|
|
|
|
|
|
if nz.name != "" {
|
|
|
|
nz.name = nz.name + "." + name
|
2018-10-02 22:03:07 +02:00
|
|
|
} else {
|
|
|
|
nz.name = name
|
2017-08-11 19:19:46 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
return &nz
|
|
|
|
}
|
|
|
|
|
|
|
|
// 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
|
|
|
|
|
|
|
|
nz.name = name
|
|
|
|
|
|
|
|
return &nz
|
|
|
|
}
|
|
|
|
|
2018-10-02 22:03:07 +02:00
|
|
|
// 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))
|
|
|
|
}
|
|
|
|
|
2017-08-11 19:19:46 +02:00
|
|
|
// 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 {
|
|
|
|
if opts == nil {
|
|
|
|
opts = &StandardLoggerOptions{}
|
|
|
|
}
|
|
|
|
|
|
|
|
return log.New(&stdlogAdapter{z, opts.InferLevels}, "", 0)
|
|
|
|
}
|