diff --git a/go.mod b/go.mod index 9d5257a8d..915ce23d0 100644 --- a/go.mod +++ b/go.mod @@ -25,7 +25,7 @@ require ( github.com/remyoudompheng/bigfft v0.0.0-20190321074620-2f0d2b0e0001 // indirect github.com/samuel/go-zookeeper v0.0.0-20180130194729-c4fab1ac1bec // indirect github.com/siddontang/go v0.0.0-20180604090527-bdc77568d726 - github.com/sirupsen/logrus v1.4.1 // indirect + github.com/sirupsen/logrus v1.4.1 github.com/stretchr/testify v1.3.0 github.com/tsuna/gohbase v0.0.0-20190201102810-d3184c1526df github.com/urfave/cli v1.20.0 diff --git a/pkg/log/doc.go b/pkg/log/doc.go index 30f94a2f5..8c85fe52e 100644 --- a/pkg/log/doc.go +++ b/pkg/log/doc.go @@ -2,21 +2,23 @@ 一、主要功能： - 1. 日志打印到本地 - 2. 日志打印到标准输出 - 3. verbose日志实现，参考glog实现，可通过设置不同verbose级别，默认不开启 + 1. 日志打印到elk + 2. 日志打印到本地，内部使用log4go + 3. 日志打印到标准输出 + 4. verbose日志实现，参考glog实现，可通过设置不同verbose级别，默认不开启 二、日志配置 -1. 默认配置 +1. 默认agent配置 - 目前日志已经实现默认配置。可以直接使用以下方式： + 目前日志已经实现默认配置，可以根据env自动切换远程日志。可以直接使用以下方式： log.Init(nil) 2. 启动参数 or 环境变量 启动参数 环境变量 说明 log.stdout LOG_STDOUT 是否开启标准输出 + log.agent LOG_AGENT 远端日志地址：unixpacket:///var/run/lancer/collector_tcp.sock?timeout=100ms&chan=1024 log.dir LOG_DIR 文件日志路径 log.v LOG_V verbose日志级别 log.module LOG_MODULE 可单独配置每个文件的verbose级别：file=1,file2=2 @@ -30,9 +32,14 @@ stdout = true vLevel = 3 filter = ["fileld1", "field2"] - [log.module] - "dao_user" = 2 - "servic*" = 1 + [log.module] + "dao_user" = 2 + "servic*" = 1 + [log.agent] + taskID = "00000x" + proto = "unixpacket" + addr = "/var/run/lancer/collector_tcp.sock" + chanSize = 10240 三、配置说明 @@ -47,5 +54,16 @@ 2. log.module 可单独配置每个文件的verbose级别 + +3. log.agent +远端日志配置项 + taskID lancer分配的taskID + proto 网络协议，常见：tcp, udp, unixgram + addr 网络地址，常见：ip:prot, sock + chanSize 日志队列长度 + +四、最佳实践 + +1. KVString 使用 KVString 代替 KV 可以减少对象分配, 避免给 golang GC 造成压力. */ package log diff --git a/pkg/log/dsn.go b/pkg/log/dsn.go new file mode 100644 index 000000000..0f541ac60 --- /dev/null +++ b/pkg/log/dsn.go @@ -0,0 +1,50 @@ +package log + +import ( + "bytes" + "fmt" + "strconv" + "strings" +) + +type verboseModule map[string]int32 + +type logFilter []string + +func (f *logFilter) String() string { + return fmt.Sprint(*f) +} + +// Set sets the value of the named command-line flag. +// format: -log.filter key1,key2 +func (f *logFilter) Set(value string) error { + for _, i := range strings.Split(value, ",") { + *f = append(*f, strings.TrimSpace(i)) + } + return nil +} + +func (m verboseModule) String() string { + // FIXME strings.Builder + var buf bytes.Buffer + for k, v := range m { + buf.WriteString(k) + buf.WriteString(strconv.FormatInt(int64(v), 10)) + buf.WriteString(",") + } + return buf.String() +} + +// Set sets the value of the named command-line flag. +// format: -log.module file=1,file2=2 +func (m verboseModule) Set(value string) error { + for _, i := range strings.Split(value, ",") { + kv := strings.Split(i, "=") + if len(kv) == 2 { + if v, err := strconv.ParseInt(kv[1], 10, 64); err == nil { + m[strings.TrimSpace(kv[0])] = int32(v) + } + } + } + return nil +} diff --git a/pkg/log/field.go b/pkg/log/field.go index d235cea76..144af2fd3 100644 --- a/pkg/log/field.go +++ b/pkg/log/field.go @@ -18,7 +18,7 @@ func KVString(key string, value string) D { // KVInt construct Field with int value. func KVInt(key string, value int) D { - return D{Key: key, Type: core.IntType, Int64Val: int64(value)} + return D{Key: key, Type: core.IntTpye, Int64Val: int64(value)} } // KVInt64 construct D with int64 value. diff --git a/pkg/log/handler.go b/pkg/log/handler.go index 44c2397e3..71b846bf1 100644 --- a/pkg/log/handler.go +++ b/pkg/log/handler.go @@ -16,6 +16,8 @@ const ( _level = "level" // log time. _time = "time" + // request path. + // _title = "title" // log file. _source = "source" // common log filed. @@ -27,7 +29,7 @@ const ( // uniq ID from trace. _tid = "traceid" // request time. - _ts = "ts" + // _ts = "ts" // requester. _caller = "caller" // container environment: prod, pre, uat, fat. @@ -38,6 +40,8 @@ const ( _mirror = "mirror" // color. _color = "color" + // env_color + _envColor = "env_color" // cluster. _cluster = "cluster" ) @@ -75,8 +79,8 @@ type Handlers struct { } // Log handlers logging. -func (hs Handlers) Log(c context.Context, lv Level, d ...D) { - var hasSource bool +func (hs Handlers) Log(ctx context.Context, lv Level, d ...D) { + hasSource := false for i := range d { if _, ok := hs.filters[d[i].Key]; ok { d[i].Value = "***" @@ -87,11 +91,12 @@ func (hs Handlers) Log(c context.Context, lv Level, d ...D) { } if !hasSource { fn := funcName(3) + errIncr(lv, fn) d = append(d, KVString(_source, fn)) } d = append(d, KV(_time, time.Now()), KVInt64(_levelValue, int64(lv)), KVString(_level, lv.String())) for _, h := range hs.handlers { - h.Log(c, lv, d...) + h.Log(ctx, lv, d...) } } diff --git a/pkg/log/internal/core/buffer_test.go b/pkg/log/internal/core/buffer_test.go index 8decbfbb7..67e723c0a 100644 --- a/pkg/log/internal/core/buffer_test.go +++ b/pkg/log/internal/core/buffer_test.go @@ -1,3 +1,23 @@ +// Copyright (c) 2016 Uber Technologies, Inc. +// +// 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. + package core import ( diff --git a/pkg/log/internal/core/bufferpool.go b/pkg/log/internal/core/bufferpool.go index bb9f1f7fa..d1ee3caaf 100644 --- a/pkg/log/internal/core/bufferpool.go +++ b/pkg/log/internal/core/bufferpool.go @@ -1,3 +1,25 @@ +// Copyright (c) 2016 Uber Technologies, Inc. +// +// 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. + +// Package core houses zap's shared internal buffer pool. Third-party +// packages can recreate the same functionality with buffers.NewPool. package core var ( diff --git a/pkg/log/internal/core/field.go b/pkg/log/internal/core/field.go index ea91bd784..99c78325b 100644 --- a/pkg/log/internal/core/field.go +++ b/pkg/log/internal/core/field.go @@ -15,7 +15,7 @@ type FieldType int32 const ( UnknownType FieldType = iota StringType - IntType + IntTpye Int64Type UintType Uint64Type @@ -43,7 +43,7 @@ func (f Field) AddTo(enc ObjectEncoder) { switch f.Type { case StringType: enc.AddString(f.Key, f.StringVal) - case IntType: + case IntTpye: enc.AddInt(f.Key, int(f.Int64Val)) case Int64Type: enc.AddInt64(f.Key, f.Int64Val) diff --git a/pkg/log/internal/core/pool.go b/pkg/log/internal/core/pool.go index 27f87a7d4..6644d5067 100644 --- a/pkg/log/internal/core/pool.go +++ b/pkg/log/internal/core/pool.go @@ -1,3 +1,23 @@ +// Copyright (c) 2016 Uber Technologies, Inc. +// +// 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. + package core import "sync" diff --git a/pkg/log/internal/core/pool_test.go b/pkg/log/internal/core/pool_test.go index 276866497..33bb4ff52 100644 --- a/pkg/log/internal/core/pool_test.go +++ b/pkg/log/internal/core/pool_test.go @@ -1,3 +1,23 @@ +// Copyright (c) 2016 Uber Technologies, Inc. +// +// 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. + package core import ( diff --git a/pkg/log/log.go b/pkg/log/log.go index 1fe7ed56a..ccd2536c2 100644 --- a/pkg/log/log.go +++ b/pkg/log/log.go @@ -4,17 +4,18 @@ import ( "context" "flag" "fmt" + "io" "os" "strconv" - "strings" "github.com/bilibili/kratos/pkg/conf/env" + "github.com/bilibili/kratos/pkg/stat/prom" ) // Config log config. type Config struct { - AppID string - Host string + Family string + Host string // stdout Stdout bool @@ -43,23 +44,39 @@ type Config struct { Filter []string } +// errProm prometheus error counter. +var errProm = prom.BusinessErrCount + +// Render render log output +type Render interface { + Render(io.Writer, map[string]interface{}) error + RenderString(map[string]interface{}) string +} + var ( h Handler c *Config ) func init() { + host, _ := os.Hostname() + c = &Config{ + Family: env.AppID, + Host: host, + } + h = newHandlers([]string{}, NewStdout()) + addFlag(flag.CommandLine) - h = newHandlers(nil) - c = new(Config) } var ( - _v int - _stdout bool - _dir string - _filter logFilter - _module = verboseModule{} + _v int + _stdout bool + _dir string + _agentDSN string + _filter logFilter + _module = verboseModule{} + _noagent bool ) // addFlag init log from dsn. @@ -75,12 +92,15 @@ func addFlag(fs *flag.FlagSet) { if tf := os.Getenv("LOG_FILTER"); len(tf) > 0 { _filter.Set(tf) } + _noagent, _ = strconv.ParseBool(os.Getenv("LOG_NO_AGENT")) // get val from flag fs.IntVar(&_v, "log.v", _v, "log verbose level, or use LOG_V env variable.") fs.BoolVar(&_stdout, "log.stdout", _stdout, "log enable stdout or not, or use LOG_STDOUT env variable.") fs.StringVar(&_dir, "log.dir", _dir, "log file `path, or use LOG_DIR env variable.") + fs.StringVar(&_agentDSN, "log.agent", _agentDSN, "log agent dsn, or use LOG_AGENT env variable.") fs.Var(&_module, "log.module", "log verbose for specified module, or use LOG_MODULE env variable, format: file=1,file2=2.") fs.Var(&_filter, "log.filter", "log field for sensitive message, or use LOG_FILTER env variable, format: field1,field2.") + fs.BoolVar(&_noagent, "log.noagent", _noagent, "force disable log agent print log to stderr, or use LOG_NO_AGENT") } // Init create logger with context. @@ -96,8 +116,8 @@ func Init(conf *Config) { Filter: _filter, } } - if conf.AppID == "" && len(env.AppID) != 0 { - conf.AppID = env.AppID + if len(env.AppID) != 0 { + conf.Family = env.AppID // for caster } conf.Host = env.Hostname if len(conf.Host) == 0 { @@ -106,7 +126,7 @@ func Init(conf *Config) { } var hs []Handler // when env is dev - if isNil || conf.Stdout { + if conf.Stdout || (isNil && (env.DeployEnv == "" || env.DeployEnv == env.DeployEnvDev)) || _noagent { hs = append(hs, NewStdout()) } if conf.Dir != "" { @@ -116,21 +136,6 @@ func Init(conf *Config) { c = conf } -type logFilter []string - -func (f *logFilter) String() string { - return fmt.Sprint(*f) -} - -// Set sets the value of the named command-line flag. -// format: -log.filter key1,key2 -func (f *logFilter) Set(value string) error { - for _, i := range strings.Split(value, ",") { - *f = append(*f, strings.TrimSpace(i)) - } - return nil -} - // Info logs a message at the info log level. func Info(format string, args ...interface{}) { h.Log(context.Background(), _infoLevel, KVString(_log, fmt.Sprintf(format, args...))) @@ -176,22 +181,19 @@ func Errorv(ctx context.Context, args ...D) { h.Log(ctx, _errorLevel, args...) } -// SetFormat only effective on stdout and file handler -// %T time format at "15:04:05.999" on stdout handler, "15:04:05 MST" on file handler -// %t time format at "15:04:05" on stdout handler, "15:04" on file on file handler -// %D data format at "2006/01/02" -// %d data format at "01/02" -// %L log level e.g. INFO WARN ERROR -// %M log message and additional fields: key=value this is log message -// NOTE below pattern not support on file handler -// %f function name and line number e.g. model.Get:121 -// %i instance id -// %e deploy env e.g. dev uat fat prod -// %z zone -// %S full file name and line number: /a/b/c/d.go:23 -// %s final file name element and line number: d.go:23 -func SetFormat(format string) { - h.SetFormat(format) +func logw(args []interface{}) []D { + if len(args)%2 != 0 { + Warn("log: the variadic must be plural, the last one will ignored") + } + ds := make([]D, 0, len(args)/2) + for i := 0; i < len(args)-1; i = i + 2 { + if key, ok := args[i].(string); ok { + ds = append(ds, KV(key, args[i+1])) + } else { + Warn("log: key must be string, get %T, ignored", args[i]) + } + } + return ds } // Infow logs a message with some additional context. The variadic key-value pairs are treated as they are in With. @@ -209,19 +211,22 @@ func Errorw(ctx context.Context, args ...interface{}) { h.Log(ctx, _errorLevel, logw(args)...) } -func logw(args []interface{}) []D { - if len(args)%2 != 0 { - Warn("log: the variadic must be plural, the last one will ignored") - } - ds := make([]D, 0, len(args)/2) - for i := 0; i < len(args)-1; i = i + 2 { - if key, ok := args[i].(string); ok { - ds = append(ds, KV(key, args[i+1])) - } else { - Warn("log: key must be string, get %T, ignored", args[i]) - } - } - return ds +// SetFormat only effective on stdout and file handler +// %T time format at "15:04:05.999" on stdout handler, "15:04:05 MST" on file handler +// %t time format at "15:04:05" on stdout handler, "15:04" on file on file handler +// %D data format at "2006/01/02" +// %d data format at "01/02" +// %L log level e.g. INFO WARN ERROR +// %M log message and additional fields: key=value this is log message +// NOTE below pattern not support on file handler +// %f function name and line number e.g. model.Get:121 +// %i instance id +// %e deploy env e.g. dev uat fat prod +// %z zone +// %S full file name and line number: /a/b/c/d.go:23 +// %s final file name element and line number: d.go:23 +func SetFormat(format string) { + h.SetFormat(format) } // Close close resource. @@ -230,3 +235,9 @@ func Close() (err error) { h = _defaultStdout return } + +func errIncr(lv Level, source string) { + if lv == _errorLevel { + errProm.Incr(source) + } +} diff --git a/pkg/log/log_test.go b/pkg/log/log_test.go index 2933d42f2..87c720699 100644 --- a/pkg/log/log_test.go +++ b/pkg/log/log_test.go @@ -37,19 +37,16 @@ func testLog(t *testing.T) { Error("hello %s", "world") Errorv(context.Background(), KV("key", 2222222), KV("test2", "test")) Errorc(context.Background(), "keys: %s %s...", "key1", "key2") - Errorw(context.Background(), "key1", "value1", "key2", "value2") }) t.Run("Warn", func(t *testing.T) { Warn("hello %s", "world") Warnv(context.Background(), KV("key", 2222222), KV("test2", "test")) Warnc(context.Background(), "keys: %s %s...", "key1", "key2") - Warnw(context.Background(), "key1", "value1", "key2", "value2") }) t.Run("Info", func(t *testing.T) { Info("hello %s", "world") Infov(context.Background(), KV("key", 2222222), KV("test2", "test")) Infoc(context.Background(), "keys: %s %s...", "key1", "key2") - Infow(context.Background(), "key1", "value1", "key2", "value2") }) } @@ -87,3 +84,22 @@ func TestLogWithMirror(t *testing.T) { Infov(context.Background(), KV("key1", "val1"), KV("key2", ""), KV("log", "log content"), KV("msg", "msg content")) } + +func TestOverwriteSouce(t *testing.T) { + ctx := context.Background() + t.Run("test source kv string", func(t *testing.T) { + Infov(ctx, KVString("source", "test")) + }) + t.Run("test source kv string", func(t *testing.T) { + Infov(ctx, KV("source", "test")) + }) +} + +func BenchmarkLog(b *testing.B) { + ctx := context.Background() + b.RunParallel(func(pb *testing.PB) { + for pb.Next() { + Infov(ctx, KVString("test", "hello"), KV("int", 34), KV("hhh", "hhhh")) + } + }) +} diff --git a/pkg/log/logrus.go b/pkg/log/logrus.go new file mode 100644 index 000000000..96523077f --- /dev/null +++ b/pkg/log/logrus.go @@ -0,0 +1,61 @@ +package log + +import ( + "context" + "io/ioutil" + "os" + + "github.com/sirupsen/logrus" +) + +func init() { + redirectLogrus() +} + +func redirectLogrus() { + // FIXME: because of different stack depth call runtime.Caller will get error function name. + logrus.AddHook(redirectHook{}) + if os.Getenv("LOGRUS_STDOUT") == "" { + logrus.SetOutput(ioutil.Discard) + } +} + +type redirectHook struct{} + +func (redirectHook) Levels() []logrus.Level { + return logrus.AllLevels +} + +func (redirectHook) Fire(entry *logrus.Entry) error { + lv := _infoLevel + var logrusLv string + var verbose int32 + switch entry.Level { + case logrus.FatalLevel, logrus.PanicLevel: + logrusLv = entry.Level.String() + fallthrough + case logrus.ErrorLevel: + lv = _errorLevel + case logrus.WarnLevel: + lv = _warnLevel + case logrus.InfoLevel: + lv = _infoLevel + case logrus.DebugLevel: + // use verbose log replace of debuglevel + verbose = 10 + } + args := make([]D, 0, len(entry.Data)+1) + args = append(args, D{Key: _log, Value: entry.Message}) + for k, v := range entry.Data { + args = append(args, D{Key: k, Value: v}) + } + if logrusLv != "" { + args = append(args, D{Key: "logrus_lv", Value: logrusLv}) + } + if verbose != 0 { + V(verbose).Infov(context.Background(), args...) + } else { + h.Log(context.Background(), lv, args...) + } + return nil +} diff --git a/pkg/log/pattern.go b/pkg/log/pattern.go index 13c6450f2..804151d39 100644 --- a/pkg/log/pattern.go +++ b/pkg/log/pattern.go @@ -4,17 +4,13 @@ import ( "bytes" "fmt" "io" + "path" + "runtime" "strings" "sync" "time" ) -// Render render log output -type Render interface { - Render(io.Writer, map[string]interface{}) error - RenderString(map[string]interface{}) string -} - var patternMap = map[string]func(map[string]interface{}) string{ "T": longTime, "t": shortTime, @@ -25,8 +21,8 @@ var patternMap = map[string]func(map[string]interface{}) string{ "i": keyFactory(_instanceID), "e": keyFactory(_deplyEnv), "z": keyFactory(_zone), - "S": keyFactory(_source), - "s": keyFactory(_source), + "S": longSource, + "s": shortSource, "M": message, } @@ -78,6 +74,7 @@ func (p *pattern) Render(w io.Writer, d map[string]interface{}) error { for _, f := range p.funcs { buf.WriteString(f(d)) } + _, err := buf.WriteTo(w) return err } @@ -114,6 +111,20 @@ func keyFactory(key string) func(map[string]interface{}) string { } } +func longSource(map[string]interface{}) string { + if _, file, lineNo, ok := runtime.Caller(6); ok { + return fmt.Sprintf("%s:%d", file, lineNo) + } + return "unknown:0" +} + +func shortSource(map[string]interface{}) string { + if _, file, lineNo, ok := runtime.Caller(6); ok { + return fmt.Sprintf("%s:%d", path.Base(file), lineNo) + } + return "unknown:0" +} + func longTime(map[string]interface{}) string { return time.Now().Format("15:04:05.000") } diff --git a/pkg/log/stdout.go b/pkg/log/stdout.go index 9d7746cd6..ff9630426 100644 --- a/pkg/log/stdout.go +++ b/pkg/log/stdout.go @@ -2,27 +2,22 @@ package log import ( "context" - "io" "os" "time" ) +const defaultPattern = "%L %d-%T %f %M" + var _defaultStdout = NewStdout() // StdoutHandler stdout log handler type StdoutHandler struct { - out io.Writer - err io.Writer render Render } // NewStdout create a stdout log handler func NewStdout() *StdoutHandler { - return &StdoutHandler{ - out: os.Stdout, - err: os.Stderr, - render: newPatternRender("[%D %T] [%s] %M"), - } + return &StdoutHandler{render: newPatternRender(defaultPattern)} } // Log stdout loging, only for developing env. @@ -31,12 +26,8 @@ func (h *StdoutHandler) Log(ctx context.Context, lv Level, args ...D) { // add extra fields addExtraField(ctx, d) d[_time] = time.Now().Format(_timeFormat) - if lv <= _infoLevel { - h.render.Render(h.out, d) - } else { - h.render.Render(h.err, d) - } - h.out.Write([]byte("\n")) + h.render.Render(os.Stderr, d) + os.Stderr.Write([]byte("\n")) } // Close stdout loging diff --git a/pkg/log/util.go b/pkg/log/util.go index 9e9f74893..b44f8cac8 100644 --- a/pkg/log/util.go +++ b/pkg/log/util.go @@ -2,7 +2,6 @@ package log import ( "context" - "fmt" "math" "runtime" "strconv" @@ -16,11 +15,7 @@ import ( func addExtraField(ctx context.Context, fields map[string]interface{}) { if t, ok := trace.FromContext(ctx); ok { - if s, ok := t.(fmt.Stringer); ok { - fields[_tid] = s.String() - } else { - fields[_tid] = fmt.Sprintf("%s", t) - } + fields[_tid] = t.TraceID() } if caller := metadata.String(ctx, metadata.Caller); caller != "" { fields[_caller] = caller @@ -28,24 +23,35 @@ func addExtraField(ctx context.Context, fields map[string]interface{}) { if color := metadata.String(ctx, metadata.Color); color != "" { fields[_color] = color } + if env.Color != "" { + fields[_envColor] = env.Color + } if cluster := metadata.String(ctx, metadata.Cluster); cluster != "" { fields[_cluster] = cluster } fields[_deplyEnv] = env.DeployEnv fields[_zone] = env.Zone - fields[_appID] = c.AppID + fields[_appID] = c.Family fields[_instanceID] = c.Host - if metadata.Bool(ctx, metadata.Mirror) { + if metadata.String(ctx, metadata.Mirror) != "" { fields[_mirror] = true } } +// funcName get func name. +func funcName(skip int) (name string) { + if _, file, lineNo, ok := runtime.Caller(skip); ok { + return file + ":" + strconv.Itoa(lineNo) + } + return "unknown:0" +} + // toMap convert D slice to map[string]interface{} for legacy file and stdout. func toMap(args ...D) map[string]interface{} { d := make(map[string]interface{}, 10+len(args)) for _, arg := range args { switch arg.Type { - case core.UintType, core.Uint64Type, core.IntType, core.Int64Type: + case core.UintType, core.Uint64Type, core.IntTpye, core.Int64Type: d[arg.Key] = arg.Int64Val case core.StringType: d[arg.Key] = arg.StringVal @@ -61,11 +67,3 @@ func toMap(args ...D) map[string]interface{} { } return d } - -// funcName get func name. -func funcName(skip int) (name string) { - if _, file, lineNo, ok := runtime.Caller(skip); ok { - return file + ":" + strconv.Itoa(lineNo) - } - return "unknown:0" -} diff --git a/pkg/log/util_test.go b/pkg/log/util_test.go new file mode 100644 index 000000000..546fd6b1c --- /dev/null +++ b/pkg/log/util_test.go @@ -0,0 +1,54 @@ +package log + +import ( + "reflect" + "strings" + "testing" + "time" +) + +func TestFuncName(t *testing.T) { + name := funcName(1) + if !strings.Contains(name, "util_test.go:11") { + t.Errorf("expect contains util_test.go:11 got %s", name) + } +} + +func Test_toMap(t *testing.T) { + type args struct { + args []D + } + tests := []struct { + name string + args args + want map[string]interface{} + }{ + { + args: args{[]D{KVString("test", "hello")}}, + want: map[string]interface{}{"test": "hello"}, + }, + { + args: args{[]D{KVInt64("test", 123)}}, + want: map[string]interface{}{"test": int64(123)}, + }, + { + args: args{[]D{KVFloat32("test", float32(1.01))}}, + want: map[string]interface{}{"test": float32(1.01)}, + }, + { + args: args{[]D{KVFloat32("test", float32(1.01))}}, + want: map[string]interface{}{"test": float32(1.01)}, + }, + { + args: args{[]D{KVDuration("test", time.Second)}}, + want: map[string]interface{}{"test": time.Second}, + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + if got := toMap(tt.args.args...); !reflect.DeepEqual(got, tt.want) { + t.Errorf("toMap() = %v, want %v", got, tt.want) + } + }) + } +} diff --git a/pkg/log/verbose.go b/pkg/log/verbose.go index 8c23effee..44124c6c6 100644 --- a/pkg/log/verbose.go +++ b/pkg/log/verbose.go @@ -1,42 +1,13 @@ package log import ( - "bytes" "context" "fmt" "path/filepath" "runtime" - "strconv" "strings" ) -type verboseModule map[string]int32 - -func (m verboseModule) String() string { - // FIXME strings.Builder - var buf bytes.Buffer - for k, v := range m { - buf.WriteString(k) - buf.WriteString(strconv.FormatInt(int64(v), 10)) - buf.WriteString(",") - } - return buf.String() -} - -// Set sets the value of the named command-line flag. -// format: -log.module file=1,file2=2 -func (m verboseModule) Set(value string) error { - for _, i := range strings.Split(value, ",") { - kv := strings.Split(i, "=") - if len(kv) == 2 { - if v, err := strconv.ParseInt(kv[1], 10, 64); err == nil { - m[strings.TrimSpace(kv[0])] = int32(v) - } - } - } - return nil -} - // V reports whether verbosity at the call site is at least the requested level. // The returned value is a boolean of type Verbose, which implements Info, Infov etc. // These methods will write to the Info log if called.