diff --git a/pkg/log/doc.go b/pkg/log/doc.go new file mode 100644 index 000000000..30f94a2f5 --- /dev/null +++ b/pkg/log/doc.go @@ -0,0 +1,51 @@ +/*Package log 是kratos日志库. + +一、主要功能: + + 1. 日志打印到本地 + 2. 日志打印到标准输出 + 3. verbose日志实现,参考glog实现,可通过设置不同verbose级别,默认不开启 + +二、日志配置 + +1. 默认配置 + + 目前日志已经实现默认配置。可以直接使用以下方式: + log.Init(nil) + +2. 启动参数 or 环境变量 + + 启动参数 环境变量 说明 + log.stdout LOG_STDOUT 是否开启标准输出 + log.dir LOG_DIR 文件日志路径 + log.v LOG_V verbose日志级别 + log.module LOG_MODULE 可单独配置每个文件的verbose级别:file=1,file2=2 + log.filter LOG_FILTER 配置需要过滤的字段:field1,field2 + +3. 配置文件 +但是如果有特殊需要可以走一下格式配置: + [log] + family = "xxx-service" + dir = "/data/log/xxx-service/" + stdout = true + vLevel = 3 + filter = ["fileld1", "field2"] + [log.module] + "dao_user" = 2 + "servic*" = 1 + +三、配置说明 + +1.log + + family 项目名,默认读环境变量$APPID + studout 标准输出,prod环境不建议开启 + filter 配置需要过滤掉的字段,以“***”替换 + dir 文件日志地址,prod环境不建议开启 + v 开启verbose级别日志,可指定全局级别 + +2. log.module + + 可单独配置每个文件的verbose级别 +*/ +package log diff --git a/pkg/log/file.go b/pkg/log/file.go new file mode 100644 index 000000000..fd08caebd --- /dev/null +++ b/pkg/log/file.go @@ -0,0 +1,92 @@ +package log + +import ( + "context" + "io" + "path/filepath" + "time" + + "github.com/bilibili/Kratos/pkg/log/internal/filewriter" +) + +// level idx +const ( + _infoIdx = iota + _warnIdx + _errorIdx + _totalIdx +) + +var _fileNames = map[int]string{ + _infoIdx: "info.log", + _warnIdx: "warning.log", + _errorIdx: "error.log", +} + +// FileHandler . +type FileHandler struct { + render Render + fws [_totalIdx]*filewriter.FileWriter +} + +// NewFile crete a file logger. +func NewFile(dir string, bufferSize, rotateSize int64, maxLogFile int) *FileHandler { + // new info writer + newWriter := func(name string) *filewriter.FileWriter { + var options []filewriter.Option + if rotateSize > 0 { + options = append(options, filewriter.MaxSize(rotateSize)) + } + if maxLogFile > 0 { + options = append(options, filewriter.MaxFile(maxLogFile)) + } + w, err := filewriter.New(filepath.Join(dir, name), options...) + if err != nil { + panic(err) + } + return w + } + handler := &FileHandler{ + render: newPatternRender("[%D %T] [%L] [%S] %M"), + } + for idx, name := range _fileNames { + handler.fws[idx] = newWriter(name) + } + return handler +} + +// Log loggint to file . +func (h *FileHandler) Log(ctx context.Context, lv Level, args ...D) { + d := make(map[string]interface{}, 10+len(args)) + for _, arg := range args { + d[arg.Key] = arg.Value + } + // add extra fields + addExtraField(ctx, d) + d[_time] = time.Now().Format(_timeFormat) + var w io.Writer + switch lv { + case _warnLevel: + w = h.fws[_warnIdx] + case _errorLevel: + w = h.fws[_errorIdx] + default: + w = h.fws[_infoIdx] + } + h.render.Render(w, d) + w.Write([]byte("\n")) +} + +// Close log handler +func (h *FileHandler) Close() error { + for _, fw := range h.fws { + // ignored error + fw.Close() + } + return nil +} + +// SetFormat set log format +func (h *FileHandler) SetFormat(format string) { + h.render = newPatternRender(format) +} diff --git a/pkg/log/handler.go b/pkg/log/handler.go index 68e762896..1dffd74d7 100644 --- a/pkg/log/handler.go +++ b/pkg/log/handler.go @@ -2,12 +2,44 @@ package log import ( "context" + "time" pkgerr "github.com/pkg/errors" ) const ( + _timeFormat = "2006-01-02T15:04:05.999999" + + // log level defined in level.go. + _levelValue = "level_value" + // log level name: INFO, WARN... + _level = "level" + // log time. + _time = "time" + // log file. + _source = "source" + // common log filed. _log = "log" + // app name. + _appID = "app_id" + // container ID. + _instanceID = "instance_id" + // uniq ID from trace. + _tid = "traceid" + // request time. + _ts = "ts" + // requester. + _caller = "caller" + // container environment: prod, pre, uat, fat. + _deplyEnv = "env" + // container area. + _zone = "zone" + // mirror flag + _mirror = "mirror" + // color. + _color = "color" + // cluster. + _cluster = "cluster" ) // Handler is used to handle log events, outputting them to @@ -28,19 +60,43 @@ type Handler interface { Close() error } -// Handlers . -type Handlers []Handler +func newHandlers(filters []string, handlers ...Handler) *Handlers { + set := make(map[string]struct{}) + for _, k := range filters { + set[k] = struct{}{} + } + return &Handlers{filters: set, handlers: handlers} +} + +// Handlers a bundle for hander with filter function. +type Handlers struct { + filters map[string]struct{} + handlers []Handler +} // Log handlers logging. func (hs Handlers) Log(c context.Context, lv Level, d ...D) { - for _, h := range hs { + var fn string + for i := range d { + if _, ok := hs.filters[d[i].Key]; ok { + d[i].Value = "***" + } + if d[i].Key == _source { + fn = d[i].Value.(string) + } + } + if fn == "" { + fn = funcName(4) + } + d = append(d, KV(_source, fn), KV(_time, time.Now()), KV(_levelValue, int(lv)), KV(_level, lv.String())) + for _, h := range hs.handlers { h.Log(c, lv, d...) } } // Close close resource. func (hs Handlers) Close() (err error) { - for _, h := range hs { + for _, h := range hs.handlers { if e := h.Close(); e != nil { err = pkgerr.WithStack(e) } @@ -50,7 +106,7 @@ func (hs Handlers) Close() (err error) { // SetFormat . func (hs Handlers) SetFormat(format string) { - for _, h := range hs { + for _, h := range hs.handlers { h.SetFormat(format) } } diff --git a/pkg/log/internal/LICENSE.txt b/pkg/log/internal/LICENSE.txt new file mode 100644 index 000000000..1b5d6ae6c --- /dev/null +++ b/pkg/log/internal/LICENSE.txt @@ -0,0 +1,21 @@ +COPY FROM: https://github.com/uber-go/zap + +Copyright (c) 2016-2017 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. diff --git a/pkg/log/internal/buffer.go b/pkg/log/internal/buffer.go new file mode 100644 index 000000000..a2efea492 --- /dev/null +++ b/pkg/log/internal/buffer.go @@ -0,0 +1,97 @@ +package core + +import "strconv" + +const _size = 1024 // by default, create 1 KiB buffers + +// NewBuffer is new buffer +func NewBuffer(_size int) *Buffer { + return &Buffer{bs: make([]byte, 0, _size)} +} + +// Buffer is a thin wrapper around a byte slice. It's intended to be pooled, so +// the only way to construct one is via a Pool. +type Buffer struct { + bs []byte + pool Pool +} + +// AppendByte writes a single byte to the Buffer. +func (b *Buffer) AppendByte(v byte) { + b.bs = append(b.bs, v) +} + +// AppendString writes a string to the Buffer. +func (b *Buffer) AppendString(s string) { + b.bs = append(b.bs, s...) +} + +// AppendInt appends an integer to the underlying buffer (assuming base 10). +func (b *Buffer) AppendInt(i int64) { + b.bs = strconv.AppendInt(b.bs, i, 10) +} + +// AppendUint appends an unsigned integer to the underlying buffer (assuming +// base 10). +func (b *Buffer) AppendUint(i uint64) { + b.bs = strconv.AppendUint(b.bs, i, 10) +} + +// AppendBool appends a bool to the underlying buffer. +func (b *Buffer) AppendBool(v bool) { + b.bs = strconv.AppendBool(b.bs, v) +} + +// AppendFloat appends a float to the underlying buffer. It doesn't quote NaN +// or +/- Inf. +func (b *Buffer) AppendFloat(f float64, bitSize int) { + b.bs = strconv.AppendFloat(b.bs, f, 'f', -1, bitSize) +} + +// Len returns the length of the underlying byte slice. +func (b *Buffer) Len() int { + return len(b.bs) +} + +// Cap returns the capacity of the underlying byte slice. +func (b *Buffer) Cap() int { + return cap(b.bs) +} + +// Bytes returns a mutable reference to the underlying byte slice. +func (b *Buffer) Bytes() []byte { + return b.bs +} + +// String returns a string copy of the underlying byte slice. +func (b *Buffer) String() string { + return string(b.bs) +} + +// Reset resets the underlying byte slice. Subsequent writes re-use the slice's +// backing array. +func (b *Buffer) Reset() { + b.bs = b.bs[:0] +} + +// Write implements io.Writer. +func (b *Buffer) Write(bs []byte) (int, error) { + b.bs = append(b.bs, bs...) + return len(bs), nil +} + +// TrimNewline trims any final "\n" byte from the end of the buffer. +func (b *Buffer) TrimNewline() { + if i := len(b.bs) - 1; i >= 0 { + if b.bs[i] == '\n' { + b.bs = b.bs[:i] + } + } +} + +// Free returns the Buffer to its Pool. +// +// Callers must not retain references to the Buffer after calling Free. +func (b *Buffer) Free() { + b.pool.put(b) +} diff --git a/pkg/log/internal/buffer_test.go b/pkg/log/internal/buffer_test.go new file mode 100644 index 000000000..8decbfbb7 --- /dev/null +++ b/pkg/log/internal/buffer_test.go @@ -0,0 +1,71 @@ +package core + +import ( + "bytes" + "strings" + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestBufferWrites(t *testing.T) { + buf := NewPool(0).Get() + + tests := []struct { + desc string + f func() + want string + }{ + {"AppendByte", func() { buf.AppendByte('v') }, "v"}, + {"AppendString", func() { buf.AppendString("foo") }, "foo"}, + {"AppendIntPositive", func() { buf.AppendInt(42) }, "42"}, + {"AppendIntNegative", func() { buf.AppendInt(-42) }, "-42"}, + {"AppendUint", func() { buf.AppendUint(42) }, "42"}, + {"AppendBool", func() { buf.AppendBool(true) }, "true"}, + {"AppendFloat64", func() { buf.AppendFloat(3.14, 64) }, "3.14"}, + // Intenationally introduce some floating-point error. + {"AppendFloat32", func() { buf.AppendFloat(float64(float32(3.14)), 32) }, "3.14"}, + {"AppendWrite", func() { buf.Write([]byte("foo")) }, "foo"}, + } + + for _, tt := range tests { + t.Run(tt.desc, func(t *testing.T) { + buf.Reset() + tt.f() + assert.Equal(t, tt.want, buf.String(), "Unexpected buffer.String().") + assert.Equal(t, tt.want, string(buf.Bytes()), "Unexpected string(buffer.Bytes()).") + assert.Equal(t, len(tt.want), buf.Len(), "Unexpected buffer length.") + // We're not writing more than a kibibyte in tests. + assert.Equal(t, _size, buf.Cap(), "Expected buffer capacity to remain constant.") + }) + } +} + +func BenchmarkBuffers(b *testing.B) { + // Because we use the strconv.AppendFoo functions so liberally, we can't + // use the standard library's bytes.Buffer anyways (without incurring a + // bunch of extra allocations). Nevertheless, let's make sure that we're + // not losing any precious nanoseconds. + str := strings.Repeat("a", 1024) + slice := make([]byte, 1024) + buf := bytes.NewBuffer(slice) + custom := NewPool(0).Get() + b.Run("ByteSlice", func(b *testing.B) { + for i := 0; i < b.N; i++ { + slice = append(slice, str...) + slice = slice[:0] + } + }) + b.Run("BytesBuffer", func(b *testing.B) { + for i := 0; i < b.N; i++ { + buf.WriteString(str) + buf.Reset() + } + }) + b.Run("CustomBuffer", func(b *testing.B) { + for i := 0; i < b.N; i++ { + custom.AppendString(str) + custom.Reset() + } + }) +} diff --git a/pkg/log/internal/bufferpool.go b/pkg/log/internal/bufferpool.go new file mode 100644 index 000000000..bb9f1f7fa --- /dev/null +++ b/pkg/log/internal/bufferpool.go @@ -0,0 +1,7 @@ +package core + +var ( + _pool = NewPool(_size) + // GetPool retrieves a buffer from the pool, creating one if necessary. + GetPool = _pool.Get +) diff --git a/pkg/log/internal/encoder.go b/pkg/log/internal/encoder.go new file mode 100644 index 000000000..912245244 --- /dev/null +++ b/pkg/log/internal/encoder.go @@ -0,0 +1,187 @@ +package core + +import ( + "time" +) + +// DefaultLineEnding defines the default line ending when writing logs. +// Alternate line endings specified in EncoderConfig can override this +// behavior. +const DefaultLineEnding = "\n" + +// ObjectEncoder is a strongly-typed, encoding-agnostic interface for adding a +// map- or struct-like object to the logging context. Like maps, ObjectEncoders +// aren't safe for concurrent use (though typical use shouldn't require locks). +type ObjectEncoder interface { + // Logging-specific marshalers. + AddArray(key string, marshaler ArrayMarshaler) error + AddObject(key string, marshaler ObjectMarshaler) error + + // Built-in types. + AddBinary(key string, value []byte) // for arbitrary bytes + AddByteString(key string, value []byte) // for UTF-8 encoded bytes + AddBool(key string, value bool) + AddComplex128(key string, value complex128) + AddComplex64(key string, value complex64) + AddDuration(key string, value time.Duration) + AddFloat64(key string, value float64) + AddFloat32(key string, value float32) + AddInt(key string, value int) + AddInt64(key string, value int64) + AddInt32(key string, value int32) + AddInt16(key string, value int16) + AddInt8(key string, value int8) + AddString(key, value string) + AddTime(key string, value time.Time) + AddUint(key string, value uint) + AddUint64(key string, value uint64) + AddUint32(key string, value uint32) + AddUint16(key string, value uint16) + AddUint8(key string, value uint8) + AddUintptr(key string, value uintptr) + + // AddReflected uses reflection to serialize arbitrary objects, so it's slow + // and allocation-heavy. + AddReflected(key string, value interface{}) error + // OpenNamespace opens an isolated namespace where all subsequent fields will + // be added. Applications can use namespaces to prevent key collisions when + // injecting loggers into sub-components or third-party libraries. + OpenNamespace(key string) +} + +// ObjectMarshaler allows user-defined types to efficiently add themselves to the +// logging context, and to selectively omit information which shouldn't be +// included in logs (e.g., passwords). +type ObjectMarshaler interface { + MarshalLogObject(ObjectEncoder) error +} + +// ObjectMarshalerFunc is a type adapter that turns a function into an +// ObjectMarshaler. +type ObjectMarshalerFunc func(ObjectEncoder) error + +// MarshalLogObject calls the underlying function. +func (f ObjectMarshalerFunc) MarshalLogObject(enc ObjectEncoder) error { + return f(enc) +} + +// ArrayMarshaler allows user-defined types to efficiently add themselves to the +// logging context, and to selectively omit information which shouldn't be +// included in logs (e.g., passwords). +type ArrayMarshaler interface { + MarshalLogArray(ArrayEncoder) error +} + +// ArrayMarshalerFunc is a type adapter that turns a function into an +// ArrayMarshaler. +type ArrayMarshalerFunc func(ArrayEncoder) error + +// MarshalLogArray calls the underlying function. +func (f ArrayMarshalerFunc) MarshalLogArray(enc ArrayEncoder) error { + return f(enc) +} + +// ArrayEncoder is a strongly-typed, encoding-agnostic interface for adding +// array-like objects to the logging context. Of note, it supports mixed-type +// arrays even though they aren't typical in Go. Like slices, ArrayEncoders +// aren't safe for concurrent use (though typical use shouldn't require locks). +type ArrayEncoder interface { + // Built-in types. + PrimitiveArrayEncoder + + // Time-related types. + AppendDuration(time.Duration) + AppendTime(time.Time) + + // Logging-specific marshalers. + AppendArray(ArrayMarshaler) error + AppendObject(ObjectMarshaler) error + + // AppendReflected uses reflection to serialize arbitrary objects, so it's + // slow and allocation-heavy. + AppendReflected(value interface{}) error +} + +// PrimitiveArrayEncoder is the subset of the ArrayEncoder interface that deals +// only in Go's built-in types. It's included only so that Duration- and +// TimeEncoders cannot trigger infinite recursion. +type PrimitiveArrayEncoder interface { + // Built-in types. + AppendBool(bool) + AppendByteString([]byte) // for UTF-8 encoded bytes + AppendComplex128(complex128) + AppendComplex64(complex64) + AppendFloat64(float64) + AppendFloat32(float32) + AppendInt(int) + AppendInt64(int64) + AppendInt32(int32) + AppendInt16(int16) + AppendInt8(int8) + AppendString(string) + AppendUint(uint) + AppendUint64(uint64) + AppendUint32(uint32) + AppendUint16(uint16) + AppendUint8(uint8) + AppendUintptr(uintptr) +} + +// An EncoderConfig allows users to configure the concrete encoders supplied by +// zapcore. +type EncoderConfig struct { + EncodeTime TimeEncoder `json:"timeEncoder" yaml:"timeEncoder"` + EncodeDuration DurationEncoder `json:"durationEncoder" yaml:"durationEncoder"` + // Configure the primitive representations of common complex types. For + // example, some users may want all time.Times serialized as floating-point + // seconds since epoch, while others may prefer ISO8601 strings. + /*EncodeLevel LevelEncoder `json:"levelEncoder" yaml:"levelEncoder"` + EncodeTime TimeEncoder `json:"timeEncoder" yaml:"timeEncoder"` + EncodeDuration DurationEncoder `json:"durationEncoder" yaml:"durationEncoder"` + EncodeCaller CallerEncoder `json:"callerEncoder" yaml:"callerEncoder"` + // Unlike the other primitive type encoders, EncodeName is optional. The + // zero value falls back to FullNameEncoder. + EncodeName NameEncoder `json:"nameEncoder" yaml:"nameEncoder"`*/ +} + +// Encoder is a format-agnostic interface for all log entry marshalers. Since +// log encoders don't need to support the same wide range of use cases as +// general-purpose marshalers, it's possible to make them faster and +// lower-allocation. +// +// Implementations of the ObjectEncoder interface's methods can, of course, +// freely modify the receiver. However, the Clone and EncodeEntry methods will +// be called concurrently and shouldn't modify the receiver. +type Encoder interface { + ObjectEncoder + + // Clone copies the encoder, ensuring that adding fields to the copy doesn't + // affect the original. + Clone() Encoder + + // EncodeEntry encodes an entry and fields, along with any accumulated + // context, into a byte buffer and returns it. + Encode(*Buffer, ...Field) error +} + +// A TimeEncoder serializes a time.Time to a primitive type. +type TimeEncoder func(time.Time, PrimitiveArrayEncoder) + +// A DurationEncoder serializes a time.Duration to a primitive type. +type DurationEncoder func(time.Duration, PrimitiveArrayEncoder) + +// EpochTimeEncoder serializes a time.Time to a floating-point number of seconds +// since the Unix epoch. +func EpochTimeEncoder(t time.Time, enc PrimitiveArrayEncoder) { + //var d []byte + enc.AppendString(t.Format("2006-01-02T15:04:05.999999")) + //enc.AppendByteString(t.AppendFormat(d, "2006-01-02T15:04:05.999999")) + /*nanos := t.UnixNano() + sec := float64(nanos) / float64(time.Second) + enc.AppendFloat64(sec)*/ +} + +// SecondsDurationEncoder serializes a time.Duration to a floating-point number of seconds elapsed. +func SecondsDurationEncoder(d time.Duration, enc PrimitiveArrayEncoder) { + enc.AppendFloat64(float64(d) / float64(time.Second)) +} diff --git a/pkg/log/internal/field.go b/pkg/log/internal/field.go new file mode 100644 index 000000000..3116973e3 --- /dev/null +++ b/pkg/log/internal/field.go @@ -0,0 +1,6 @@ +package core + +// Field is for encoder +type Field interface { + AddTo(enc ObjectEncoder) +} diff --git a/pkg/log/internal/filewriter/filewriter.go b/pkg/log/internal/filewriter/filewriter.go new file mode 100644 index 000000000..f981cc9fe --- /dev/null +++ b/pkg/log/internal/filewriter/filewriter.go @@ -0,0 +1,344 @@ +package filewriter + +import ( + "bytes" + "container/list" + "fmt" + "io/ioutil" + "log" + "os" + "path/filepath" + "sort" + "strconv" + "strings" + "sync" + "sync/atomic" + "time" +) + +// FileWriter create file log writer +type FileWriter struct { + opt option + dir string + fname string + ch chan *bytes.Buffer + stdlog *log.Logger + pool *sync.Pool + + lastRotateFormat string + lastSplitNum int + + current *wrapFile + files *list.List + + closed int32 + wg sync.WaitGroup +} + +type rotateItem struct { + rotateTime int64 + rotateNum int + fname string +} + +func parseRotateItem(dir, fname, rotateFormat string) (*list.List, error) { + fis, err := ioutil.ReadDir(dir) + if err != nil { + return nil, err + } + + // parse exists log file filename + parse := func(s string) (rt rotateItem, err error) { + // remove filename and left "." error.log.2018-09-12.001 -> 2018-09-12.001 + rt.fname = s + s = strings.TrimLeft(s[len(fname):], ".") + seqs := strings.Split(s, ".") + var t time.Time + switch len(seqs) { + case 2: + if rt.rotateNum, err = strconv.Atoi(seqs[1]); err != nil { + return + } + fallthrough + case 1: + if t, err = time.Parse(rotateFormat, seqs[0]); err != nil { + return + } + rt.rotateTime = t.Unix() + } + return + } + + var items []rotateItem + for _, fi := range fis { + if strings.HasPrefix(fi.Name(), fname) && fi.Name() != fname { + rt, err := parse(fi.Name()) + if err != nil { + // TODO deal with error + continue + } + items = append(items, rt) + } + } + sort.Slice(items, func(i, j int) bool { + if items[i].rotateTime == items[j].rotateTime { + return items[i].rotateNum > items[j].rotateNum + } + return items[i].rotateTime > items[j].rotateTime + }) + l := list.New() + + for _, item := range items { + l.PushBack(item) + } + return l, nil +} + +type wrapFile struct { + fsize int64 + fp *os.File +} + +func (w *wrapFile) size() int64 { + return w.fsize +} + +func (w *wrapFile) write(p []byte) (n int, err error) { + n, err = w.fp.Write(p) + w.fsize += int64(n) + return +} + +func newWrapFile(fpath string) (*wrapFile, error) { + fp, err := os.OpenFile(fpath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644) + if err != nil { + return nil, err + } + fi, err := fp.Stat() + if err != nil { + return nil, err + } + return &wrapFile{fp: fp, fsize: fi.Size()}, nil +} + +// New FileWriter A FileWriter is safe for use by multiple goroutines simultaneously. +func New(fpath string, fns ...Option) (*FileWriter, error) { + opt := defaultOption + for _, fn := range fns { + fn(&opt) + } + + fname := filepath.Base(fpath) + if fname == "" { + return nil, fmt.Errorf("filename can't empty") + } + dir := filepath.Dir(fpath) + fi, err := os.Stat(dir) + if err == nil && !fi.IsDir() { + return nil, fmt.Errorf("%s already exists and not a directory", dir) + } + if os.IsNotExist(err) { + if err = os.MkdirAll(dir, 0755); err != nil { + return nil, fmt.Errorf("create dir %s error: %s", dir, err.Error()) + } + } + + current, err := newWrapFile(fpath) + if err != nil { + return nil, err + } + + stdlog := log.New(os.Stderr, "flog ", log.LstdFlags) + ch := make(chan *bytes.Buffer, opt.ChanSize) + + files, err := parseRotateItem(dir, fname, opt.RotateFormat) + if err != nil { + // set files a empty list + files = list.New() + stdlog.Printf("parseRotateItem error: %s", err) + } + + lastRotateFormat := time.Now().Format(opt.RotateFormat) + var lastSplitNum int + if files.Len() > 0 { + rt := files.Front().Value.(rotateItem) + // check contains is mush esay than compared with timestamp + if strings.Contains(rt.fname, lastRotateFormat) { + lastSplitNum = rt.rotateNum + } + } + + fw := &FileWriter{ + opt: opt, + dir: dir, + fname: fname, + stdlog: stdlog, + ch: ch, + pool: &sync.Pool{New: func() interface{} { return new(bytes.Buffer) }}, + + lastSplitNum: lastSplitNum, + lastRotateFormat: lastRotateFormat, + + files: files, + current: current, + } + + fw.wg.Add(1) + go fw.daemon() + + return fw, nil +} + +// Write write data to log file, return write bytes is pseudo just for implement io.Writer. +func (f *FileWriter) Write(p []byte) (int, error) { + // atomic is not necessary + if atomic.LoadInt32(&f.closed) == 1 { + f.stdlog.Printf("%s", p) + return 0, fmt.Errorf("filewriter already closed") + } + // because write to file is asynchronousc, + // copy p to internal buf prevent p be change on outside + buf := f.getBuf() + buf.Write(p) + + if f.opt.WriteTimeout == 0 { + select { + case f.ch <- buf: + return len(p), nil + default: + // TODO: write discard log to to stdout? + return 0, fmt.Errorf("log channel is full, discard log") + } + } + + // write log with timeout + timeout := time.NewTimer(f.opt.WriteTimeout) + select { + case f.ch <- buf: + return len(p), nil + case <-timeout.C: + // TODO: write discard log to to stdout? + return 0, fmt.Errorf("log channel is full, discard log") + } +} + +func (f *FileWriter) daemon() { + // TODO: check aggsbuf size prevent it too big + aggsbuf := &bytes.Buffer{} + tk := time.NewTicker(f.opt.RotateInterval) + // TODO: make it configrable + aggstk := time.NewTicker(10 * time.Millisecond) + var err error + for { + select { + case t := <-tk.C: + f.checkRotate(t) + case buf, ok := <-f.ch: + if ok { + aggsbuf.Write(buf.Bytes()) + f.putBuf(buf) + } + case <-aggstk.C: + if aggsbuf.Len() > 0 { + if err = f.write(aggsbuf.Bytes()); err != nil { + f.stdlog.Printf("write log error: %s", err) + } + aggsbuf.Reset() + } + } + if atomic.LoadInt32(&f.closed) != 1 { + continue + } + // read all buf from channel and break loop + if err = f.write(aggsbuf.Bytes()); err != nil { + f.stdlog.Printf("write log error: %s", err) + } + for buf := range f.ch { + if err = f.write(buf.Bytes()); err != nil { + f.stdlog.Printf("write log error: %s", err) + } + f.putBuf(buf) + } + break + } + f.wg.Done() +} + +// Close close file writer +func (f *FileWriter) Close() error { + atomic.StoreInt32(&f.closed, 1) + close(f.ch) + f.wg.Wait() + return nil +} + +func (f *FileWriter) checkRotate(t time.Time) { + formatFname := func(format string, num int) string { + if num == 0 { + return fmt.Sprintf("%s.%s", f.fname, format) + } + return fmt.Sprintf("%s.%s.%03d", f.fname, format, num) + } + format := t.Format(f.opt.RotateFormat) + + if f.opt.MaxFile != 0 { + for f.files.Len() > f.opt.MaxFile { + rt := f.files.Remove(f.files.Front()).(rotateItem) + fpath := filepath.Join(f.dir, rt.fname) + if err := os.Remove(fpath); err != nil { + f.stdlog.Printf("remove file %s error: %s", fpath, err) + } + } + } + + if format != f.lastRotateFormat || (f.opt.MaxSize != 0 && f.current.size() > f.opt.MaxSize) { + var err error + // close current file first + if err = f.current.fp.Close(); err != nil { + f.stdlog.Printf("close current file error: %s", err) + } + + // rename file + fname := formatFname(f.lastRotateFormat, f.lastSplitNum) + oldpath := filepath.Join(f.dir, f.fname) + newpath := filepath.Join(f.dir, fname) + if err = os.Rename(oldpath, newpath); err != nil { + f.stdlog.Printf("rename file %s to %s error: %s", oldpath, newpath, err) + return + } + + f.files.PushBack(rotateItem{fname: fname /*rotateNum: f.lastSplitNum, rotateTime: t.Unix() unnecessary*/}) + + if format != f.lastRotateFormat { + f.lastRotateFormat = format + f.lastSplitNum = 0 + } else { + f.lastSplitNum++ + } + + // recreate current file + f.current, err = newWrapFile(filepath.Join(f.dir, f.fname)) + if err != nil { + f.stdlog.Printf("create log file error: %s", err) + } + } +} + +func (f *FileWriter) write(p []byte) error { + // f.current may be nil, if newWrapFile return err in checkRotate, redirect log to stderr + if f.current == nil { + f.stdlog.Printf("can't write log to file, please check stderr log for detail") + f.stdlog.Printf("%s", p) + } + _, err := f.current.write(p) + return err +} + +func (f *FileWriter) putBuf(buf *bytes.Buffer) { + buf.Reset() + f.pool.Put(buf) +} + +func (f *FileWriter) getBuf() *bytes.Buffer { + return f.pool.Get().(*bytes.Buffer) +} diff --git a/pkg/log/internal/filewriter/filewriter_test.go b/pkg/log/internal/filewriter/filewriter_test.go new file mode 100644 index 000000000..2b3612ff7 --- /dev/null +++ b/pkg/log/internal/filewriter/filewriter_test.go @@ -0,0 +1,221 @@ +package filewriter + +import ( + "fmt" + "io/ioutil" + "os" + "path/filepath" + "testing" + "time" + + "github.com/stretchr/testify/assert" +) + +const logdir = "testlog" + +func touch(dir, name string) { + os.MkdirAll(dir, 0755) + fp, err := os.OpenFile(filepath.Join(dir, name), os.O_CREATE, 0644) + if err != nil { + panic(err) + } + fp.Close() +} + +func TestMain(m *testing.M) { + ret := m.Run() + // os.RemoveAll(logdir) + os.Exit(ret) +} + +func TestParseRotate(t *testing.T) { + touch := func(dir, name string) { + os.MkdirAll(dir, 0755) + fp, err := os.OpenFile(filepath.Join(dir, name), os.O_CREATE, 0644) + if err != nil { + t.Fatal(err) + } + fp.Close() + } + dir := filepath.Join(logdir, "test-parse-rotate") + names := []string{"info.log.2018-11-11", "info.log.2018-11-11.001", "info.log.2018-11-11.002", "info.log." + time.Now().Format("2006-01-02") + ".005"} + for _, name := range names { + touch(dir, name) + } + l, err := parseRotateItem(dir, "info.log", "2006-01-02") + if err != nil { + t.Fatal(err) + } + + assert.Equal(t, len(names), l.Len()) + + rt := l.Front().Value.(rotateItem) + + assert.Equal(t, 5, rt.rotateNum) +} + +func TestRotateExists(t *testing.T) { + dir := filepath.Join(logdir, "test-rotate-exists") + names := []string{"info.log." + time.Now().Format("2006-01-02") + ".005"} + for _, name := range names { + touch(dir, name) + } + fw, err := New(logdir+"/test-rotate-exists/info.log", + MaxSize(1024*1024), + func(opt *option) { opt.RotateInterval = time.Millisecond }, + ) + if err != nil { + t.Fatal(err) + } + data := make([]byte, 1024) + for i := range data { + data[i] = byte(i) + } + for i := 0; i < 10; i++ { + for i := 0; i < 1024; i++ { + _, err = fw.Write(data) + if err != nil { + t.Error(err) + } + } + time.Sleep(10 * time.Millisecond) + } + fw.Close() + fis, err := ioutil.ReadDir(logdir + "/test-rotate-exists") + if err != nil { + t.Fatal(err) + } + var fnams []string + for _, fi := range fis { + fnams = append(fnams, fi.Name()) + } + assert.Contains(t, fnams, "info.log."+time.Now().Format("2006-01-02")+".006") +} + +func TestSizeRotate(t *testing.T) { + fw, err := New(logdir+"/test-rotate/info.log", + MaxSize(1024*1024), + func(opt *option) { opt.RotateInterval = 1 * time.Millisecond }, + ) + if err != nil { + t.Fatal(err) + } + data := make([]byte, 1024) + for i := range data { + data[i] = byte(i) + } + for i := 0; i < 10; i++ { + for i := 0; i < 1024; i++ { + _, err = fw.Write(data) + if err != nil { + t.Error(err) + } + } + time.Sleep(10 * time.Millisecond) + } + fw.Close() + fis, err := ioutil.ReadDir(logdir + "/test-rotate") + if err != nil { + t.Fatal(err) + } + assert.True(t, len(fis) > 5, "expect more than 5 file get %d", len(fis)) +} + +func TestMaxFile(t *testing.T) { + fw, err := New(logdir+"/test-maxfile/info.log", + MaxSize(1024*1024), + MaxFile(1), + func(opt *option) { opt.RotateInterval = 1 * time.Millisecond }, + ) + if err != nil { + t.Fatal(err) + } + data := make([]byte, 1024) + for i := range data { + data[i] = byte(i) + } + for i := 0; i < 10; i++ { + for i := 0; i < 1024; i++ { + _, err = fw.Write(data) + if err != nil { + t.Error(err) + } + } + time.Sleep(10 * time.Millisecond) + } + fw.Close() + fis, err := ioutil.ReadDir(logdir + "/test-maxfile") + if err != nil { + t.Fatal(err) + } + assert.True(t, len(fis) <= 2, fmt.Sprintf("expect 2 file get %d", len(fis))) +} + +func TestMaxFile2(t *testing.T) { + files := []string{ + "info.log.2018-12-01", + "info.log.2018-12-02", + "info.log.2018-12-03", + "info.log.2018-12-04", + "info.log.2018-12-05", + "info.log.2018-12-05.001", + } + for _, file := range files { + touch(logdir+"/test-maxfile2", file) + } + fw, err := New(logdir+"/test-maxfile2/info.log", + MaxSize(1024*1024), + MaxFile(3), + func(opt *option) { opt.RotateInterval = 1 * time.Millisecond }, + ) + if err != nil { + t.Fatal(err) + } + data := make([]byte, 1024) + for i := range data { + data[i] = byte(i) + } + for i := 0; i < 10; i++ { + for i := 0; i < 1024; i++ { + _, err = fw.Write(data) + if err != nil { + t.Error(err) + } + } + time.Sleep(10 * time.Millisecond) + } + fw.Close() + fis, err := ioutil.ReadDir(logdir + "/test-maxfile2") + if err != nil { + t.Fatal(err) + } + assert.True(t, len(fis) == 4, fmt.Sprintf("expect 4 file get %d", len(fis))) +} + +func TestFileWriter(t *testing.T) { + fw, err := New("testlog/info.log") + if err != nil { + t.Fatal(err) + } + defer fw.Close() + _, err = fw.Write([]byte("Hello World!\n")) + if err != nil { + t.Error(err) + } +} + +func BenchmarkFileWriter(b *testing.B) { + fw, err := New("testlog/bench/info.log", + func(opt *option) { opt.WriteTimeout = time.Second }, MaxSize(1024*1024*8), /*32MB*/ + func(opt *option) { opt.RotateInterval = 10 * time.Millisecond }, + ) + if err != nil { + b.Fatal(err) + } + for i := 0; i < b.N; i++ { + _, err = fw.Write([]byte("Hello World!\n")) + if err != nil { + b.Error(err) + } + } +} diff --git a/pkg/log/internal/filewriter/option.go b/pkg/log/internal/filewriter/option.go new file mode 100644 index 000000000..aecdb3691 --- /dev/null +++ b/pkg/log/internal/filewriter/option.go @@ -0,0 +1,69 @@ +package filewriter + +import ( + "fmt" + "strings" + "time" +) + +// RotateFormat +const ( + RotateDaily = "2006-01-02" +) + +var defaultOption = option{ + RotateFormat: RotateDaily, + MaxSize: 1 << 30, + ChanSize: 1024 * 8, + RotateInterval: 10 * time.Second, +} + +type option struct { + RotateFormat string + MaxFile int + MaxSize int64 + ChanSize int + + // TODO export Option + RotateInterval time.Duration + WriteTimeout time.Duration +} + +// Option filewriter option +type Option func(opt *option) + +// RotateFormat e.g 2006-01-02 meaning rotate log file every day. +// NOTE: format can't contain ".", "." will cause panic ヽ(*。>Д<)o゜. +func RotateFormat(format string) Option { + if strings.Contains(format, ".") { + panic(fmt.Sprintf("rotate format can't contain '.' format: %s", format)) + } + return func(opt *option) { + opt.RotateFormat = format + } +} + +// MaxFile default 999, 0 meaning unlimit. +// TODO: don't create file list if MaxSize is unlimt. +func MaxFile(n int) Option { + return func(opt *option) { + opt.MaxFile = n + } +} + +// MaxSize set max size for single log file, +// defult 1GB, 0 meaning unlimit. +func MaxSize(n int64) Option { + return func(opt *option) { + opt.MaxSize = n + } +} + +// ChanSize set internal chan size default 8192 use about 64k memory on x64 platfrom static, +// because filewriter has internal object pool, change chan size bigger may cause filewriter use +// a lot of memory, because sync.Pool can't set expire time memory won't free until program exit. +func ChanSize(n int) Option { + return func(opt *option) { + opt.ChanSize = n + } +} diff --git a/pkg/log/internal/json_encoder.go b/pkg/log/internal/json_encoder.go new file mode 100644 index 000000000..1f9dadc20 --- /dev/null +++ b/pkg/log/internal/json_encoder.go @@ -0,0 +1,424 @@ +package core + +import ( + "encoding/base64" + "encoding/json" + "math" + "sync" + "time" + "unicode/utf8" +) + +// For JSON-escaping; see jsonEncoder.safeAddString below. +const _hex = "0123456789abcdef" + +var _ ObjectEncoder = &jsonEncoder{} +var _jsonPool = sync.Pool{New: func() interface{} { + return &jsonEncoder{} +}} + +func getJSONEncoder() *jsonEncoder { + return _jsonPool.Get().(*jsonEncoder) +} + +func putJSONEncoder(enc *jsonEncoder) { + if enc.reflectBuf != nil { + enc.reflectBuf.Free() + } + enc.EncoderConfig = nil + enc.buf = nil + enc.spaced = false + enc.openNamespaces = 0 + enc.reflectBuf = nil + enc.reflectEnc = nil + _jsonPool.Put(enc) +} + +type jsonEncoder struct { + *EncoderConfig + buf *Buffer + spaced bool // include spaces after colons and commas + openNamespaces int + + // for encoding generic values by reflection + reflectBuf *Buffer + reflectEnc *json.Encoder +} + +// NewJSONEncoder creates a fast, low-allocation JSON encoder. The encoder +// appropriately escapes all field keys and values. +// +// Note that the encoder doesn't deduplicate keys, so it's possible to produce +// a message like +// {"foo":"bar","foo":"baz"} +// This is permitted by the JSON specification, but not encouraged. Many +// libraries will ignore duplicate key-value pairs (typically keeping the last +// pair) when unmarshaling, but users should attempt to avoid adding duplicate +// keys. +func NewJSONEncoder(cfg EncoderConfig, buf *Buffer) Encoder { + return newJSONEncoder(cfg, false, buf) +} + +func newJSONEncoder(cfg EncoderConfig, spaced bool, buf *Buffer) *jsonEncoder { + return &jsonEncoder{ + EncoderConfig: &cfg, + buf: buf, + spaced: spaced, + } +} + +func (enc *jsonEncoder) AddArray(key string, arr ArrayMarshaler) error { + enc.addKey(key) + return enc.AppendArray(arr) +} + +func (enc *jsonEncoder) AddObject(key string, obj ObjectMarshaler) error { + enc.addKey(key) + return enc.AppendObject(obj) +} + +func (enc *jsonEncoder) AddBinary(key string, val []byte) { + enc.AddString(key, base64.StdEncoding.EncodeToString(val)) +} + +func (enc *jsonEncoder) AddByteString(key string, val []byte) { + enc.addKey(key) + enc.AppendByteString(val) +} + +func (enc *jsonEncoder) AddBool(key string, val bool) { + enc.addKey(key) + enc.AppendBool(val) +} + +func (enc *jsonEncoder) AddComplex128(key string, val complex128) { + enc.addKey(key) + enc.AppendComplex128(val) +} + +func (enc *jsonEncoder) AddDuration(key string, val time.Duration) { + enc.addKey(key) + enc.AppendDuration(val) +} + +func (enc *jsonEncoder) AddFloat64(key string, val float64) { + enc.addKey(key) + enc.AppendFloat64(val) +} + +func (enc *jsonEncoder) AddInt64(key string, val int64) { + enc.addKey(key) + enc.AppendInt64(val) +} + +func (enc *jsonEncoder) resetReflectBuf() { + if enc.reflectBuf == nil { + enc.reflectBuf = GetPool() + enc.reflectEnc = json.NewEncoder(enc.reflectBuf) + } else { + enc.reflectBuf.Reset() + } +} + +func (enc *jsonEncoder) AddReflected(key string, obj interface{}) error { + enc.resetReflectBuf() + err := enc.reflectEnc.Encode(obj) + if err != nil { + return err + } + enc.reflectBuf.TrimNewline() + enc.addKey(key) + _, err = enc.buf.Write(enc.reflectBuf.Bytes()) + return err +} + +func (enc *jsonEncoder) OpenNamespace(key string) { + enc.addKey(key) + enc.buf.AppendByte('{') + enc.openNamespaces++ +} + +func (enc *jsonEncoder) AddString(key, val string) { + enc.addKey(key) + enc.AppendString(val) +} + +func (enc *jsonEncoder) AddTime(key string, val time.Time) { + enc.addKey(key) + enc.AppendTime(val) +} + +func (enc *jsonEncoder) AddUint64(key string, val uint64) { + enc.addKey(key) + enc.AppendUint64(val) +} + +func (enc *jsonEncoder) AppendArray(arr ArrayMarshaler) error { + enc.addElementSeparator() + enc.buf.AppendByte('[') + err := arr.MarshalLogArray(enc) + enc.buf.AppendByte(']') + return err +} + +func (enc *jsonEncoder) AppendObject(obj ObjectMarshaler) error { + enc.addElementSeparator() + enc.buf.AppendByte('{') + err := obj.MarshalLogObject(enc) + enc.buf.AppendByte('}') + return err +} + +func (enc *jsonEncoder) AppendBool(val bool) { + enc.addElementSeparator() + enc.buf.AppendBool(val) +} + +func (enc *jsonEncoder) AppendByteString(val []byte) { + enc.addElementSeparator() + enc.buf.AppendByte('"') + enc.safeAddByteString(val) + enc.buf.AppendByte('"') +} + +func (enc *jsonEncoder) AppendComplex128(val complex128) { + enc.addElementSeparator() + // Cast to a platform-independent, fixed-size type. + r, i := float64(real(val)), float64(imag(val)) + enc.buf.AppendByte('"') + // Because we're always in a quoted string, we can use strconv without + // special-casing NaN and +/-Inf. + enc.buf.AppendFloat(r, 64) + enc.buf.AppendByte('+') + enc.buf.AppendFloat(i, 64) + enc.buf.AppendByte('i') + enc.buf.AppendByte('"') +} + +func (enc *jsonEncoder) AppendDuration(val time.Duration) { + cur := enc.buf.Len() + enc.EncodeDuration(val, enc) + if cur == enc.buf.Len() { + // User-supplied EncodeDuration is a no-op. Fall back to nanoseconds to keep + // JSON valid. + enc.AppendInt64(int64(val)) + } +} + +func (enc *jsonEncoder) AppendInt64(val int64) { + enc.addElementSeparator() + enc.buf.AppendInt(val) +} + +func (enc *jsonEncoder) AppendReflected(val interface{}) error { + enc.resetReflectBuf() + err := enc.reflectEnc.Encode(val) + if err != nil { + return err + } + enc.reflectBuf.TrimNewline() + enc.addElementSeparator() + _, err = enc.buf.Write(enc.reflectBuf.Bytes()) + return err +} + +func (enc *jsonEncoder) AppendString(val string) { + enc.addElementSeparator() + enc.buf.AppendByte('"') + enc.safeAddString(val) + enc.buf.AppendByte('"') +} + +func (enc *jsonEncoder) AppendTime(val time.Time) { + cur := enc.buf.Len() + enc.EncodeTime(val, enc) + if cur == enc.buf.Len() { + // User-supplied EncodeTime is a no-op. Fall back to nanos since epoch to keep + // output JSON valid. + enc.AppendInt64(val.UnixNano()) + } +} + +func (enc *jsonEncoder) AppendUint64(val uint64) { + enc.addElementSeparator() + enc.buf.AppendUint(val) +} + +func (enc *jsonEncoder) AddComplex64(k string, v complex64) { enc.AddComplex128(k, complex128(v)) } +func (enc *jsonEncoder) AddFloat32(k string, v float32) { enc.AddFloat64(k, float64(v)) } +func (enc *jsonEncoder) AddInt(k string, v int) { enc.AddInt64(k, int64(v)) } +func (enc *jsonEncoder) AddInt32(k string, v int32) { enc.AddInt64(k, int64(v)) } +func (enc *jsonEncoder) AddInt16(k string, v int16) { enc.AddInt64(k, int64(v)) } +func (enc *jsonEncoder) AddInt8(k string, v int8) { enc.AddInt64(k, int64(v)) } +func (enc *jsonEncoder) AddUint(k string, v uint) { enc.AddUint64(k, uint64(v)) } +func (enc *jsonEncoder) AddUint32(k string, v uint32) { enc.AddUint64(k, uint64(v)) } +func (enc *jsonEncoder) AddUint16(k string, v uint16) { enc.AddUint64(k, uint64(v)) } +func (enc *jsonEncoder) AddUint8(k string, v uint8) { enc.AddUint64(k, uint64(v)) } +func (enc *jsonEncoder) AddUintptr(k string, v uintptr) { enc.AddUint64(k, uint64(v)) } +func (enc *jsonEncoder) AppendComplex64(v complex64) { enc.AppendComplex128(complex128(v)) } +func (enc *jsonEncoder) AppendFloat64(v float64) { enc.appendFloat(v, 64) } +func (enc *jsonEncoder) AppendFloat32(v float32) { enc.appendFloat(float64(v), 32) } +func (enc *jsonEncoder) AppendInt(v int) { enc.AppendInt64(int64(v)) } +func (enc *jsonEncoder) AppendInt32(v int32) { enc.AppendInt64(int64(v)) } +func (enc *jsonEncoder) AppendInt16(v int16) { enc.AppendInt64(int64(v)) } +func (enc *jsonEncoder) AppendInt8(v int8) { enc.AppendInt64(int64(v)) } +func (enc *jsonEncoder) AppendUint(v uint) { enc.AppendUint64(uint64(v)) } +func (enc *jsonEncoder) AppendUint32(v uint32) { enc.AppendUint64(uint64(v)) } +func (enc *jsonEncoder) AppendUint16(v uint16) { enc.AppendUint64(uint64(v)) } +func (enc *jsonEncoder) AppendUint8(v uint8) { enc.AppendUint64(uint64(v)) } +func (enc *jsonEncoder) AppendUintptr(v uintptr) { enc.AppendUint64(uint64(v)) } + +func (enc *jsonEncoder) Clone() Encoder { + clone := enc.clone() + return clone +} + +func (enc *jsonEncoder) clone() *jsonEncoder { + clone := getJSONEncoder() + clone.EncoderConfig = enc.EncoderConfig + clone.spaced = enc.spaced + clone.openNamespaces = enc.openNamespaces + clone.buf = GetPool() + return clone +} + +func (enc *jsonEncoder) Encode(buf *Buffer, fields ...Field) error { + final := enc.clone() + final.buf = buf + final.buf.AppendByte('{') + if enc.buf.Len() > 0 { + final.addElementSeparator() + final.buf.Write(enc.buf.Bytes()) + } + + for i := range fields { + fields[i].AddTo(final) + } + + final.closeOpenNamespaces() + final.buf.AppendString("}\n") + putJSONEncoder(final) + return nil +} + +func (enc *jsonEncoder) closeOpenNamespaces() { + for i := 0; i < enc.openNamespaces; i++ { + enc.buf.AppendByte('}') + } +} + +func (enc *jsonEncoder) addKey(key string) { + enc.addElementSeparator() + enc.buf.AppendByte('"') + enc.safeAddString(key) + enc.buf.AppendByte('"') + enc.buf.AppendByte(':') + if enc.spaced { + enc.buf.AppendByte(' ') + } +} + +func (enc *jsonEncoder) addElementSeparator() { + last := enc.buf.Len() - 1 + if last < 0 { + return + } + switch enc.buf.Bytes()[last] { + case '{', '[', ':', ',', ' ': + return + default: + enc.buf.AppendByte(',') + if enc.spaced { + enc.buf.AppendByte(' ') + } + } +} + +func (enc *jsonEncoder) appendFloat(val float64, bitSize int) { + enc.addElementSeparator() + switch { + case math.IsNaN(val): + enc.buf.AppendString(`"NaN"`) + case math.IsInf(val, 1): + enc.buf.AppendString(`"+Inf"`) + case math.IsInf(val, -1): + enc.buf.AppendString(`"-Inf"`) + default: + enc.buf.AppendFloat(val, bitSize) + } +} + +// safeAddString JSON-escapes a string and appends it to the internal buffer. +// Unlike the standard library's encoder, it doesn't attempt to protect the +// user from browser vulnerabilities or JSONP-related problems. +func (enc *jsonEncoder) safeAddString(s string) { + for i := 0; i < len(s); { + if enc.tryAddRuneSelf(s[i]) { + i++ + continue + } + r, size := utf8.DecodeRuneInString(s[i:]) + if enc.tryAddRuneError(r, size) { + i++ + continue + } + enc.buf.AppendString(s[i : i+size]) + i += size + } +} + +// safeAddByteString is no-alloc equivalent of safeAddString(string(s)) for s []byte. +func (enc *jsonEncoder) safeAddByteString(s []byte) { + for i := 0; i < len(s); { + if enc.tryAddRuneSelf(s[i]) { + i++ + continue + } + r, size := utf8.DecodeRune(s[i:]) + if enc.tryAddRuneError(r, size) { + i++ + continue + } + enc.buf.Write(s[i : i+size]) + i += size + } +} + +// tryAddRuneSelf appends b if it is valid UTF-8 character represented in a single byte. +func (enc *jsonEncoder) tryAddRuneSelf(b byte) bool { + if b >= utf8.RuneSelf { + return false + } + if 0x20 <= b && b != '\\' && b != '"' { + enc.buf.AppendByte(b) + return true + } + switch b { + case '\\', '"': + enc.buf.AppendByte('\\') + enc.buf.AppendByte(b) + case '\n': + enc.buf.AppendByte('\\') + enc.buf.AppendByte('n') + case '\r': + enc.buf.AppendByte('\\') + enc.buf.AppendByte('r') + case '\t': + enc.buf.AppendByte('\\') + enc.buf.AppendByte('t') + default: + // Encode bytes < 0x20, except for the escape sequences above. + enc.buf.AppendString(`\u00`) + enc.buf.AppendByte(_hex[b>>4]) + enc.buf.AppendByte(_hex[b&0xF]) + } + return true +} + +func (enc *jsonEncoder) tryAddRuneError(r rune, size int) bool { + if r == utf8.RuneError && size == 1 { + enc.buf.AppendString(`\ufffd`) + return true + } + return false +} diff --git a/pkg/log/internal/pool.go b/pkg/log/internal/pool.go new file mode 100644 index 000000000..27f87a7d4 --- /dev/null +++ b/pkg/log/internal/pool.go @@ -0,0 +1,32 @@ +package core + +import "sync" + +// A Pool is a type-safe wrapper around a sync.Pool. +type Pool struct { + p *sync.Pool +} + +// NewPool constructs a new Pool. +func NewPool(size int) Pool { + if size == 0 { + size = _size + } + return Pool{p: &sync.Pool{ + New: func() interface{} { + return &Buffer{bs: make([]byte, 0, size)} + }, + }} +} + +// Get retrieves a Buffer from the pool, creating one if necessary. +func (p Pool) Get() *Buffer { + buf := p.p.Get().(*Buffer) + buf.Reset() + buf.pool = p + return buf +} + +func (p Pool) put(buf *Buffer) { + p.p.Put(buf) +} diff --git a/pkg/log/internal/pool_test.go b/pkg/log/internal/pool_test.go new file mode 100644 index 000000000..276866497 --- /dev/null +++ b/pkg/log/internal/pool_test.go @@ -0,0 +1,32 @@ +package core + +import ( + "sync" + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestBuffers(t *testing.T) { + const dummyData = "dummy data" + p := NewPool(0) + + var wg sync.WaitGroup + for g := 0; g < 10; g++ { + wg.Add(1) + go func() { + for i := 0; i < 100; i++ { + buf := p.Get() + assert.Zero(t, buf.Len(), "Expected truncated buffer") + assert.NotZero(t, buf.Cap(), "Expected non-zero capacity") + + buf.AppendString(dummyData) + assert.Equal(t, buf.Len(), len(dummyData), "Expected buffer to contain dummy data") + + buf.Free() + } + wg.Done() + }() + } + wg.Wait() +} diff --git a/pkg/log/log.go b/pkg/log/log.go index 7f5a37d48..436abc3c3 100644 --- a/pkg/log/log.go +++ b/pkg/log/log.go @@ -2,7 +2,14 @@ package log import ( "context" + "flag" "fmt" + "os" + "strconv" + "strings" + "time" + + "github.com/bilibili/Kratos/pkg/conf/env" ) // Config log config. @@ -42,6 +49,72 @@ var ( c *Config ) +func init() { + addFlag(flag.CommandLine) +} + +var ( + _v int + _stdout bool + _dir string + _filter logFilter + _module = verboseModule{} +) + +// addFlag init log from dsn. +func addFlag(fs *flag.FlagSet) { + if lv, err := strconv.ParseInt(os.Getenv("LOG_V"), 10, 64); err == nil { + _v = int(lv) + } + _stdout, _ = strconv.ParseBool(os.Getenv("LOG_STDOUT")) + _dir = os.Getenv("LOG_DIR") + if tm := os.Getenv("LOG_MODULE"); len(tm) > 0 { + _module.Set(tm) + } + if tf := os.Getenv("LOG_FILTER"); len(tf) > 0 { + _filter.Set(tf) + } + // 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.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.") +} + +// Init create logger with context. +func Init(conf *Config) { + var isNil bool + if conf == nil { + isNil = true + conf = &Config{ + Stdout: _stdout, + Dir: _dir, + V: int32(_v), + Module: _module, + Filter: _filter, + } + } + if len(env.AppID) != 0 { + conf.Family = env.AppID // for caster + } + conf.Host = env.Hostname + if len(conf.Host) == 0 { + host, _ := os.Hostname() + conf.Host = host + } + var hs []Handler + // when env is dev + if isNil || conf.Stdout { + hs = append(hs, NewStdout()) + } + if conf.Dir != "" { + hs = append(hs, NewFile(conf.Dir, conf.FileBufferSize, conf.RotateSize, conf.MaxLogFile)) + } + h = newHandlers(conf.Filter, hs...) + c = conf +} + // D represents a map of entry level data used for structured logging. // type D map[string]interface{} type D struct { @@ -49,6 +122,68 @@ type D struct { Value interface{} } +// AddTo exports a field through the ObjectEncoder interface. It's primarily +// useful to library authors, and shouldn't be necessary in most applications. +func (d D) AddTo(enc core.ObjectEncoder) { + var err error + switch val := d.Value.(type) { + case bool: + enc.AddBool(d.Key, val) + case complex128: + enc.AddComplex128(d.Key, val) + case complex64: + enc.AddComplex64(d.Key, val) + case float64: + enc.AddFloat64(d.Key, val) + case float32: + enc.AddFloat32(d.Key, val) + case int: + enc.AddInt(d.Key, val) + case int64: + enc.AddInt64(d.Key, val) + case int32: + enc.AddInt32(d.Key, val) + case int16: + enc.AddInt16(d.Key, val) + case int8: + enc.AddInt8(d.Key, val) + case string: + enc.AddString(d.Key, val) + case uint: + enc.AddUint(d.Key, val) + case uint64: + enc.AddUint64(d.Key, val) + case uint32: + enc.AddUint32(d.Key, val) + case uint16: + enc.AddUint16(d.Key, val) + case uint8: + enc.AddUint8(d.Key, val) + case []byte: + enc.AddByteString(d.Key, val) + case uintptr: + enc.AddUintptr(d.Key, val) + case time.Time: + enc.AddTime(d.Key, val) + case xtime.Time: + enc.AddTime(d.Key, val.Time()) + case time.Duration: + enc.AddDuration(d.Key, val) + case xtime.Duration: + enc.AddDuration(d.Key, time.Duration(val)) + case error: + enc.AddString(d.Key, val.Error()) + case fmt.Stringer: + enc.AddString(d.Key, val.String()) + default: + err = enc.AddReflected(d.Key, val) + } + + if err != nil { + enc.AddString(fmt.Sprintf("%sError", d.Key), err.Error()) + } +} + // KV return a log kv for logging field. func KV(key string, value interface{}) D { return D{ @@ -57,6 +192,21 @@ func KV(key string, value interface{}) D { } } +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, KV(_log, fmt.Sprintf(format, args...))) @@ -72,6 +222,69 @@ func Error(format string, args ...interface{}) { h.Log(context.Background(), _errorLevel, KV(_log, fmt.Sprintf(format, args...))) } +// Infoc logs a message at the info log level. +func Infoc(ctx context.Context, format string, args ...interface{}) { + h.Log(ctx, _infoLevel, KV(_log, fmt.Sprintf(format, args...))) +} + +// Errorc logs a message at the error log level. +func Errorc(ctx context.Context, format string, args ...interface{}) { + h.Log(ctx, _errorLevel, KV(_log, fmt.Sprintf(format, args...))) +} + +// Warnc logs a message at the warning log level. +func Warnc(ctx context.Context, format string, args ...interface{}) { + h.Log(ctx, _warnLevel, KV(_log, fmt.Sprintf(format, args...))) +} + +// Infov logs a message at the info log level. +func Infov(ctx context.Context, args ...D) { + h.Log(ctx, _infoLevel, args...) +} + +// Warnv logs a message at the warning log level. +func Warnv(ctx context.Context, args ...D) { + h.Log(ctx, _warnLevel, args...) +} + +// Errorv logs a message at the error log level. +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) +} + +// Infow logs a message with some additional context. The variadic key-value pairs are treated as they are in With. +func Infow(ctx context.Context, args ...interface{}) { + h.Log(ctx, _infoLevel, logw(args)...) +} + +// Warnw logs a message with some additional context. The variadic key-value pairs are treated as they are in With. +func Warnw(ctx context.Context, args ...interface{}) { + h.Log(ctx, _warnLevel, logw(args)...) +} + +// Errorw logs a message with some additional context. The variadic key-value pairs are treated as they are in With. +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") @@ -86,3 +299,10 @@ func logw(args []interface{}) []D { } return ds } + +// Close close resource. +func Close() (err error) { + err = h.Close() + h = _defaultStdout + return +} diff --git a/pkg/log/log_test.go b/pkg/log/log_test.go new file mode 100644 index 000000000..4b15c1b7e --- /dev/null +++ b/pkg/log/log_test.go @@ -0,0 +1,89 @@ +package log + +import ( + "context" + "testing" + + "github.com/bilibili/Kratos/pkg/net/metadata" + + "github.com/stretchr/testify/assert" +) + +func initStdout() { + conf := &Config{ + Stdout: true, + } + Init(conf) +} + +func initFile() { + conf := &Config{ + Dir: "/tmp", + // VLevel: 2, + Module: map[string]int32{"log_test": 1}, + } + Init(conf) +} + +type TestLog struct { + A string + B int + C string + D string +} + +func testLog(t *testing.T) { + t.Run("Error", func(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") + }) +} + +func TestFile(t *testing.T) { + initFile() + testLog(t) + assert.Equal(t, nil, Close()) +} + +func TestStdout(t *testing.T) { + initStdout() + testLog(t) + assert.Equal(t, nil, Close()) +} + +func TestLogW(t *testing.T) { + D := logw([]interface{}{"i", "like", "a", "dog"}) + if len(D) != 2 || D[0].Key != "i" || D[0].Value != "like" || D[1].Key != "a" || D[1].Value != "dog" { + t.Fatalf("logw out put should be ' {i like} {a dog}'") + } + D = logw([]interface{}{"i", "like", "dog"}) + if len(D) != 1 || D[0].Key != "i" || D[0].Value != "like" { + t.Fatalf("logw out put should be ' {i like}'") + } +} + +func TestLogWithMirror(t *testing.T) { + Info("test log") + mdcontext := metadata.NewContext(context.Background(), metadata.MD{metadata.Mirror: "true"}) + Infov(mdcontext, KV("key1", "val1"), KV("key2", ""), KV("log", "log content"), KV("msg", "msg content")) + + mdcontext = metadata.NewContext(context.Background(), metadata.MD{metadata.Mirror: "***"}) + Infov(mdcontext, KV("key1", "val1"), KV("key2", ""), KV("log", "log content"), KV("msg", "msg content")) + + Infov(context.Background(), KV("key1", "val1"), KV("key2", ""), KV("log", "log content"), KV("msg", "msg content")) + +} diff --git a/pkg/log/pattern.go b/pkg/log/pattern.go new file mode 100644 index 000000000..14a9853b5 --- /dev/null +++ b/pkg/log/pattern.go @@ -0,0 +1,173 @@ +package log + +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, + "D": longDate, + "d": shortDate, + "L": keyFactory(_level), + "f": keyFactory(_source), + "i": keyFactory(_instanceID), + "e": keyFactory(_deplyEnv), + "z": keyFactory(_zone), + "S": longSource, + "s": shortSource, + "M": message, +} + +// newPatternRender new pattern render +func newPatternRender(format string) Render { + p := &pattern{ + bufPool: sync.Pool{New: func() interface{} { return &bytes.Buffer{} }}, + } + b := make([]byte, 0, len(format)) + for i := 0; i < len(format); i++ { + if format[i] != '%' { + b = append(b, format[i]) + continue + } + if i+1 >= len(format) { + b = append(b, format[i]) + continue + } + f, ok := patternMap[string(format[i+1])] + if !ok { + b = append(b, format[i]) + continue + } + if len(b) != 0 { + p.funcs = append(p.funcs, textFactory(string(b))) + b = b[:0] + } + p.funcs = append(p.funcs, f) + i++ + } + if len(b) != 0 { + p.funcs = append(p.funcs, textFactory(string(b))) + } + return p +} + +type pattern struct { + funcs []func(map[string]interface{}) string + bufPool sync.Pool +} + +// Render implemet Formater +func (p *pattern) Render(w io.Writer, d map[string]interface{}) error { + buf := p.bufPool.Get().(*bytes.Buffer) + defer func() { + buf.Reset() + p.bufPool.Put(buf) + }() + for _, f := range p.funcs { + buf.WriteString(f(d)) + } + + _, err := buf.WriteTo(w) + return err +} + +// Render implemet Formater as string +func (p *pattern) RenderString(d map[string]interface{}) string { + // TODO strings.Builder + buf := p.bufPool.Get().(*bytes.Buffer) + defer func() { + buf.Reset() + p.bufPool.Put(buf) + }() + for _, f := range p.funcs { + buf.WriteString(f(d)) + } + + return buf.String() +} + +func textFactory(text string) func(map[string]interface{}) string { + return func(map[string]interface{}) string { + return text + } +} +func keyFactory(key string) func(map[string]interface{}) string { + return func(d map[string]interface{}) string { + if v, ok := d[key]; ok { + if s, ok := v.(string); ok { + return s + } + return fmt.Sprint(v) + } + return "" + } +} + +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") +} + +func shortTime(map[string]interface{}) string { + return time.Now().Format("15:04") +} + +func longDate(map[string]interface{}) string { + return time.Now().Format("2006/01/02") +} + +func shortDate(map[string]interface{}) string { + return time.Now().Format("01/02") +} + +func isInternalKey(k string) bool { + switch k { + case _level, _levelValue, _time, _source, _instanceID, _appID, _deplyEnv, _zone: + return true + } + return false +} + +func message(d map[string]interface{}) string { + var m string + var s []string + for k, v := range d { + if k == _log { + m = fmt.Sprint(v) + continue + } + if isInternalKey(k) { + continue + } + s = append(s, fmt.Sprintf("%s=%v", k, v)) + } + s = append(s, m) + return strings.Join(s, " ") +} diff --git a/pkg/log/pattern_test.go b/pkg/log/pattern_test.go new file mode 100644 index 000000000..a6aa6be00 --- /dev/null +++ b/pkg/log/pattern_test.go @@ -0,0 +1,35 @@ +package log + +import ( + "bytes" + "strings" + "testing" + "time" + + "github.com/stretchr/testify/assert" +) + +func TestPatternDefault(t *testing.T) { + buf := &bytes.Buffer{} + p := newPatternRender("%L %T %f %M") + p.Render(buf, map[string]interface{}{_level: _infoLevel.String(), _log: "hello", _time: time.Now().Format(_timeFormat), _source: "xxx:123"}) + + fields := strings.Fields(buf.String()) + assert.Equal(t, 4, len(fields)) + assert.Equal(t, "INFO", fields[0]) + assert.Equal(t, "hello", fields[3]) +} + +func TestKV(t *testing.T) { + buf := &bytes.Buffer{} + p := newPatternRender("%M") + p.Render(buf, map[string]interface{}{_level: _infoLevel.String(), _log: "2233", "hello": "test"}) + assert.Equal(t, "hello=test 2233", buf.String()) +} + +func TestBadSymbol(t *testing.T) { + buf := &bytes.Buffer{} + p := newPatternRender("%12 %% %xd %M") + p.Render(buf, map[string]interface{}{_level: _infoLevel.String(), _log: "2233"}) + assert.Equal(t, "%12 %% %xd 2233", buf.String()) +} diff --git a/pkg/log/stdout.go b/pkg/log/stdout.go new file mode 100644 index 000000000..ef4cb037d --- /dev/null +++ b/pkg/log/stdout.go @@ -0,0 +1,61 @@ +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 + render Render +} + +// NewStdout create a stdout log handler +func NewStdout() *StdoutHandler { + return &StdoutHandler{ + out: os.Stderr, + render: newPatternRender(defaultPattern), + } +} + +// Log stdout loging, only for developing env. +func (h *StdoutHandler) Log(ctx context.Context, lv Level, args ...D) { + d := make(map[string]interface{}, 10+len(args)) + for _, arg := range args { + d[arg.Key] = arg.Value + } + // add extra fields + addExtraField(ctx, d) + d[_time] = time.Now().Format(_timeFormat) + h.render.Render(h.out, d) + h.out.Write([]byte("\n")) +} + +// Close stdout loging +func (h *StdoutHandler) Close() error { + return nil +} + +// SetFormat set stdout log output format +// %T time format at "15:04:05.999" +// %t time format at "15:04:05" +// %D data format at "2006/01/02" +// %d data format at "01/02" +// %L log level e.g. INFO WARN ERROR +// %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 +// %M log message and additional fields: key=value this is log message +func (h *StdoutHandler) SetFormat(format string) { + h.render = newPatternRender(format) +} diff --git a/pkg/log/util.go b/pkg/log/util.go new file mode 100644 index 000000000..de0454377 --- /dev/null +++ b/pkg/log/util.go @@ -0,0 +1,54 @@ +package log + +import ( + "context" + "fmt" + "runtime" + "strconv" + "sync" + + "github.com/bilibili/Kratos/pkg/conf/env" + "github.com/bilibili/Kratos/pkg/net/metadata" + "github.com/bilibili/Kratos/pkg/net/trace" +) + +var fm sync.Map + +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) + } + } + if caller := metadata.String(ctx, metadata.Caller); caller != "" { + fields[_caller] = caller + } + if color := metadata.String(ctx, metadata.Color); color != "" { + fields[_color] = color + } + if cluster := metadata.String(ctx, metadata.Cluster); cluster != "" { + fields[_cluster] = cluster + } + fields[_deplyEnv] = env.DeployEnv + fields[_zone] = env.Zone + fields[_appID] = c.Family + fields[_instanceID] = c.Host + if metadata.Bool(ctx, metadata.Mirror) { + fields[_mirror] = true + } +} + +// funcName get func name. +func funcName(skip int) (name string) { + if pc, _, lineNo, ok := runtime.Caller(skip); ok { + if v, ok := fm.Load(pc); ok { + name = v.(string) + } else { + name = runtime.FuncForPC(pc).Name() + ":" + strconv.FormatInt(int64(lineNo), 10) + fm.Store(pc, name) + } + } + return +} diff --git a/pkg/log/verbose.go b/pkg/log/verbose.go index 230b92b9a..c45af4824 100644 --- a/pkg/log/verbose.go +++ b/pkg/log/verbose.go @@ -1,13 +1,42 @@ 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. diff --git a/pkg/net/http/blademaster/client.go b/pkg/net/http/blademaster/client.go index 9ed117407..45678bb31 100644 --- a/pkg/net/http/blademaster/client.go +++ b/pkg/net/http/blademaster/client.go @@ -29,8 +29,6 @@ import ( const ( _minRead = 16 * 1024 // 16kb - - _ts = "ts" ) var (