diff --git a/.gitignore b/.gitignore new file mode 100644 index 0000000..f3b5c5f --- /dev/null +++ b/.gitignore @@ -0,0 +1,16 @@ +# IntelliJ +.idea + +# Binaries for programs and plugins +/build + +# Test binary, build with `go test -c` +*.test + +# Output of the go coverage tool, specifically when used with LiteIDE +*.out + +# Project-local glide cache, RE: https://github.com/Masterminds/glide/issues/736 +.glide/ +/vendor + diff --git a/.travis.yml b/.travis.yml deleted file mode 100644 index 96da367..0000000 --- a/.travis.yml +++ /dev/null @@ -1,10 +0,0 @@ -language: go -go: -- 1.7 -- 1.8 -- tip -matrix: - allow_failures: - - go: tip -script: - go test -v -race -cpu=1,2,4 ./... diff --git a/README.md b/README.md index 8df8f57..f46cb6f 100644 --- a/README.md +++ b/README.md @@ -1,15 +1,11 @@ -:warning: **Check [zerolog](https://github.com/rs/zerolog), the successor of xlog.** - - # HTTP Handler Logger -[![godoc](http://img.shields.io/badge/godoc-reference-blue.svg?style=flat)](https://godoc.org/github.com/rs/xlog) [![license](http://img.shields.io/badge/license-MIT-red.svg?style=flat)](https://raw.githubusercontent.com/rs/xlog/master/LICENSE) [![Build Status](https://travis-ci.org/rs/xlog.svg?branch=master)](https://travis-ci.org/rs/xlog) [![Coverage](http://gocover.io/_badge/github.com/rs/xlog)](http://gocover.io/github.com/rs/xlog) +[![godoc](http://img.shields.io/badge/godoc-reference-blue.svg?style=flat)](https://godoc.org/github.com/Ak-Army/xlog) [![license](http://img.shields.io/badge/license-MIT-red.svg?style=flat)](https://raw.githubusercontent.com/Ak-Army/xlog/master/LICENSE) [![Build Status](https://travis-ci.org/Ak-Army/xlog.svg?branch=master)](https://travis-ci.org/Ak-Army/xlog) [![Coverage](http://gocover.io/_badge/github.com/Ak-Army/xlog)](http://gocover.io/github.com/Ak-Army/xlog) `xlog` is a logger for [net/context](https://godoc.org/golang.org/x/net/context) aware HTTP applications. Unlike most loggers, `xlog` will never block your application because one its outputs is lagging. The log commands are connected to their outputs through a buffered channel and will prefer to discard messages if the buffer get full. All message formatting, serialization and transport happen in a dedicated go routine. -Read more about `xlog` on [Dailymotion engineering blog](http://engineering.dailymotion.com/our-way-to-go/). ![](screenshot.png) @@ -17,18 +13,16 @@ Read more about `xlog` on [Dailymotion engineering blog](http://engineering.dail - Per request log context - Per request and/or per message key/value fields -- Log levels (Debug, Info, Warn, Error) +- Log levels (Debug, Info, Warn, Error, Fatal) - Color output when terminal is detected - Custom output (JSON, [logfmt](https://github.com/kr/logfmt), …) - Automatic gathering of request context like User-Agent, IP etc. - Drops message rather than blocking execution - Easy access logging thru [github.com/rs/xaccess](https://github.com/rs/xaccess) -Works with both Go 1.7+ (with `net/context` support) and Go 1.6 if used with [github.com/rs/xhandler](https://github.com/rs/xhandler). - ## Install - go get github.com/rs/xlog + go get github.com/Ak-Army/xlog ## Usage @@ -158,7 +152,7 @@ xlog.SetLogger(xlog.New(xlog.Config{ By default, output is setup to output debug and info message on `STDOUT` and warning and errors to `STDERR`. You can easily change this setup. -XLog output can be customized using composable output handlers. Thanks to the [LevelOutput](https://godoc.org/github.com/rs/xlog#LevelOutput), [MultiOutput](https://godoc.org/github.com/rs/xlog#MultiOutput) and [FilterOutput](https://godoc.org/github.com/rs/xlog#FilterOutput), it is easy to route messages precisely. +XLog output can be customized using composable output handlers. Thanks to the [LevelOutput](https://godoc.org/github.com/Ak-Army/xlog#LevelOutput), [MultiOutput](https://godoc.org/github.com/Ak-Army/xlog#MultiOutput) and [FilterOutput](https://godoc.org/github.com/Ak-Army/xlog#FilterOutput), it is easy to route messages precisely. ```go conf := xlog.Config{ @@ -187,25 +181,25 @@ h = xlog.NewHandler(conf) | Name | Description | |------|-------------| -| [OutputChannel](https://godoc.org/github.com/rs/xlog#OutputChannel) | Buffers messages before sending. This output should always be the output directly set to xlog's configuration. -| [MultiOutput](https://godoc.org/github.com/rs/xlog#MultiOutput) | Routes the same message to several outputs. If one or more outputs return error, the last error is returned. -| [FilterOutput](https://godoc.org/github.com/rs/xlog#FilterOutput) | Tests a condition on the message and forward it to the child output if true. -| [LevelOutput](https://godoc.org/github.com/rs/xlog#LevelOutput) | Routes messages per level outputs. -| [ConsoleOutput](https://godoc.org/github.com/rs/xlog#NewConsoleOutput) | Prints messages in a human readable form on the stdout with color when supported. Fallback to logfmt output if the stdout isn't a terminal. -| [JSONOutput](https://godoc.org/github.com/rs/xlog#NewJSONOutput) | Serialize messages in JSON. -| [LogfmtOutput](https://godoc.org/github.com/rs/xlog#NewLogfmtOutput) | Serialize messages using Heroku like [logfmt](https://github.com/kr/logfmt). -| [LogstashOutput](https://godoc.org/github.com/rs/xlog#NewLogstashOutput) | Serialize JSON message using Logstash 2.0 (schema v1) structured format. -| [SyslogOutput](https://godoc.org/github.com/rs/xlog#NewSyslogOutput) | Send messages to syslog. -| [UIDOutput](https://godoc.org/github.com/rs/xlog#NewUIDOutput) | Append a globally unique id to every message and forward it to the next output. +| [OutputChannel](https://godoc.org/github.com/Ak-Army/xlog#OutputChannel) | Buffers messages before sending. This output should always be the output directly set to xlog's configuration. +| [MultiOutput](https://godoc.org/github.com/Ak-Army/xlog#MultiOutput) | Routes the same message to several outputs. If one or more outputs return error, the last error is returned. +| [FilterOutput](https://godoc.org/github.com/Ak-Army/xlog#FilterOutput) | Tests a condition on the message and forward it to the child output if true. +| [LevelOutput](https://godoc.org/github.com/Ak-Army/xlog#LevelOutput) | Routes messages per level outputs. +| [ConsoleOutput](https://godoc.org/github.com/Ak-Army/xlog#NewConsoleOutput) | Prints messages in a human readable form on the stdout with color when supported. Fallback to logfmt output if the stdout isn't a terminal. +| [JSONOutput](https://godoc.org/github.com/Ak-Army/xlog#NewJSONOutput) | Serialize messages in JSON. +| [LogfmtOutput](https://godoc.org/github.com/Ak-Army/xlog#NewLogfmtOutput) | Serialize messages using Heroku like [logfmt](https://github.com/kr/logfmt). +| [LogstashOutput](https://godoc.org/github.com/Ak-Army/xlog#NewLogstashOutput) | Serialize JSON message using Logstash 2.0 (schema v1) structured format. +| [SyslogOutput](https://godoc.org/github.com/Ak-Army/xlog#NewSyslogOutput) | Send messages to syslog. +| [UIDOutput](https://godoc.org/github.com/Ak-Army/xlog#NewUIDOutput) | Append a globally unique id to every message and forward it to the next output. ## Third Party Extensions | Project | Author | Description | |---------|--------|-------------| | [gRPClog](https://github.com/clawio/grpcxlog) | [Hugo González Labrador](https://github.com/labkode) | An adapter to use xlog as the logger for grpclog. -| [xlog-nsq](https://github.com/rs/xlog-nsq) | [Olivier Poitrey](https://github.com/rs) | An xlog to [NSQ](http://nsq.io) output. +| [xlog-nsq](https://github.com/Ak-Army/xlog-nsq) | [Olivier Poitrey](https://github.com/rs) | An xlog to [NSQ](http://nsq.io) output. | [xlog-sentry](https://github.com/trong/xlog-sentry) | [trong](https://github.com/trong) | An xlog to [Sentry](https://getsentry.com/) output. ## Licenses -All source code is licensed under the [MIT License](https://raw.github.com/rs/xlog/master/LICENSE). +All source code is licensed under the [MIT License](https://raw.github.com/Ak-Army/xlog/master/LICENSE). diff --git a/go.mod b/go.mod new file mode 100644 index 0000000..178d014 --- /dev/null +++ b/go.mod @@ -0,0 +1,16 @@ +module github.com/Ak-Army/xlog + +go 1.21 + +require ( + github.com/rs/xid v1.6.0 + github.com/stretchr/testify v1.10.0 +) + +require ( + github.com/davecgh/go-spew v1.1.1 // indirect + github.com/kr/text v0.2.0 // indirect + github.com/pmezard/go-difflib v1.0.0 // indirect + gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c // indirect + gopkg.in/yaml.v3 v3.0.1 // indirect +) diff --git a/go.sum b/go.sum new file mode 100644 index 0000000..0de9c9f --- /dev/null +++ b/go.sum @@ -0,0 +1,20 @@ +github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E= +github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= +github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/kr/pretty v0.2.1 h1:Fmg33tUaq4/8ym9TJN1x7sLJnHVwhP33CNkpYV/7rwI= +github.com/kr/pretty v0.2.1/go.mod h1:ipq/a2n7PKx3OHsz4KJII5eveXtPO4qwEXGdVfWzfnI= +github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ= +github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI= +github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= +github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE= +github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= +github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= +github.com/rs/xid v1.6.0 h1:fV591PaemRlL6JfRxGDEPl69wICngIQ3shQtzfy2gxU= +github.com/rs/xid v1.6.0/go.mod h1:7XoLgs4eV+QndskICGsho+ADou8ySMSjJKDIan90Nz0= +github.com/stretchr/testify v1.10.0 h1:Xv5erBjTwe/5IxqUQTdXv5kgmIvbHo3QQyRwhJsOfJA= +github.com/stretchr/testify v1.10.0/go.mod h1:r2ic/lqez/lEtzL7wO/rwa5dbSLXVDPFyf8C91i36aY= +gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c h1:Hei/4ADfdWqJk1ZMxUNpqntNwaWcugrBjAiHlqqRiVk= +gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c/go.mod h1:JHkPIbrfpd72SG/EVd6muEfDQjcINNoR0C8j2r3qZ4Q= +gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= +gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/handler.go b/handler.go index 311b613..3ad9628 100644 --- a/handler.go +++ b/handler.go @@ -1,3 +1,4 @@ +//go:build go1.7 // +build go1.7 package xlog @@ -44,6 +45,29 @@ func FromContext(ctx context.Context) Logger { return l } +// FromContextWithStd gets the logger out of the context. +// If not logger is stored in the context, a GetLogger is returned. +func FromContextWithStd(ctx context.Context) Logger { + if ctx == nil { + return GetLogger() + } + l, ok := ctx.Value(logKey).(Logger) + if !ok { + return GetLogger() + } + return l +} + +// FromContextWithFields gets the logger out of the context. +// If not logger is stored in the context, a GetLogger is returned. +func FromContextWithFields(ctx context.Context, fields F) Logger { + l := FromContextWithStd(ctx) + l = Copy(l) + l.SetFields(fields) + + return l +} + // FromRequest gets the logger in the request's context. // This is a shortcut for xlog.FromContext(r.Context()) func FromRequest(r *http.Request) Logger { diff --git a/handler_examples_test.go b/handler_examples_test.go deleted file mode 100644 index 2b02cff..0000000 --- a/handler_examples_test.go +++ /dev/null @@ -1,65 +0,0 @@ -// +build go1.7 - -package xlog_test - -import ( - "errors" - "log" - "net/http" - "os" - - "github.com/justinas/alice" - "github.com/rs/xlog" -) - -func Example_handler() { - c := alice.New() - - host, _ := os.Hostname() - conf := xlog.Config{ - // Set some global env fields - Fields: xlog.F{ - "role": "my-service", - "host": host, - }, - } - - // Install the logger handler with default output on the console - c = c.Append(xlog.NewHandler(conf)) - - // Plug the xlog handler's input to Go's default logger - log.SetFlags(0) - log.SetOutput(xlog.New(conf)) - - // Install some provided extra handler to set some request's context fields. - // Thanks to those handler, all our logs will come with some pre-populated fields. - c = c.Append(xlog.RemoteAddrHandler("ip")) - c = c.Append(xlog.UserAgentHandler("user_agent")) - c = c.Append(xlog.RefererHandler("referer")) - c = c.Append(xlog.RequestIDHandler("req_id", "Request-Id")) - - // Here is your final handler - h := c.Then(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - // Get the logger from the request's context. You can safely assume it - // will be always there: if the handler is removed, xlog.FromContext - // will return a NopLogger - l := xlog.FromRequest(r) - - // Then log some errors - if err := errors.New("some error from elsewhere"); err != nil { - l.Errorf("Here is an error: %v", err) - } - - // Or some info with fields - l.Info("Something happend", xlog.F{ - "user": "current user id", - "status": "ok", - }) - })) - http.Handle("/", h) - - if err := http.ListenAndServe(":8080", nil); err != nil { - log.SetOutput(os.Stderr) // make sure we print to console - log.Fatal(err) - } -} diff --git a/handler_pre17.go b/handler_pre17.go deleted file mode 100644 index 4dbc880..0000000 --- a/handler_pre17.go +++ /dev/null @@ -1,162 +0,0 @@ -// +build !go1.7 - -package xlog - -import ( - "net" - "net/http" - - "github.com/rs/xhandler" - "github.com/rs/xid" - "golang.org/x/net/context" -) - -type key int - -const ( - logKey key = iota - idKey -) - -// IDFromContext returns the unique id associated to the request if any. -func IDFromContext(ctx context.Context) (xid.ID, bool) { - id, ok := ctx.Value(idKey).(xid.ID) - return id, ok -} - -// FromContext gets the logger out of the context. -// If not logger is stored in the context, a NopLogger is returned. -func FromContext(ctx context.Context) Logger { - if ctx == nil { - return NopLogger - } - l, ok := ctx.Value(logKey).(Logger) - if !ok { - return NopLogger - } - return l -} - -// NewContext returns a copy of the parent context and associates it with the provided logger. -func NewContext(ctx context.Context, l Logger) context.Context { - return context.WithValue(ctx, logKey, l) -} - -// NewHandler instanciates a new xlog HTTP handler. -// -// If not configured, the output is set to NewConsoleOutput() by default. -func NewHandler(c Config) func(xhandler.HandlerC) xhandler.HandlerC { - if c.Output == nil { - c.Output = NewOutputChannel(NewConsoleOutput()) - } - return func(next xhandler.HandlerC) xhandler.HandlerC { - return xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - l := New(c) - ctx = NewContext(ctx, l) - next.ServeHTTPC(ctx, w, r) - if l, ok := l.(*logger); ok { - l.close() - } - }) - } -} - -// URLHandler returns a handler setting the request's URL as a field -// to the current context's logger using the passed name as field name. -func URLHandler(name string) func(next xhandler.HandlerC) xhandler.HandlerC { - return func(next xhandler.HandlerC) xhandler.HandlerC { - return xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - FromContext(ctx).SetField(name, r.URL.String()) - next.ServeHTTPC(ctx, w, r) - }) - } -} - -// MethodHandler returns a handler setting the request's method as a field -// to the current context's logger using the passed name as field name. -func MethodHandler(name string) func(next xhandler.HandlerC) xhandler.HandlerC { - return func(next xhandler.HandlerC) xhandler.HandlerC { - return xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - FromContext(ctx).SetField(name, r.Method) - next.ServeHTTPC(ctx, w, r) - }) - } -} - -// RequestHandler returns a handler setting the request's method and URL as a field -// to the current context's logger using the passed name as field name. -func RequestHandler(name string) func(next xhandler.HandlerC) xhandler.HandlerC { - return func(next xhandler.HandlerC) xhandler.HandlerC { - return xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - FromContext(ctx).SetField(name, r.Method+" "+r.URL.String()) - next.ServeHTTPC(ctx, w, r) - }) - } -} - -// RemoteAddrHandler returns a handler setting the request's remote address as a field -// to the current context's logger using the passed name as field name. -func RemoteAddrHandler(name string) func(next xhandler.HandlerC) xhandler.HandlerC { - return func(next xhandler.HandlerC) xhandler.HandlerC { - return xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - if host, _, err := net.SplitHostPort(r.RemoteAddr); err == nil { - FromContext(ctx).SetField(name, host) - } - next.ServeHTTPC(ctx, w, r) - }) - } -} - -// UserAgentHandler returns a handler setting the request's client's user-agent as -// a field to the current context's logger using the passed name as field name. -func UserAgentHandler(name string) func(next xhandler.HandlerC) xhandler.HandlerC { - return func(next xhandler.HandlerC) xhandler.HandlerC { - return xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - if ua := r.Header.Get("User-Agent"); ua != "" { - FromContext(ctx).SetField(name, ua) - } - next.ServeHTTPC(ctx, w, r) - }) - } -} - -// RefererHandler returns a handler setting the request's referer header as -// a field to the current context's logger using the passed name as field name. -func RefererHandler(name string) func(next xhandler.HandlerC) xhandler.HandlerC { - return func(next xhandler.HandlerC) xhandler.HandlerC { - return xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - if ref := r.Header.Get("Referer"); ref != "" { - FromContext(ctx).SetField(name, ref) - } - next.ServeHTTPC(ctx, w, r) - }) - } -} - -// RequestIDHandler returns a handler setting a unique id to the request which can -// be gathered using IDFromContext(ctx). This generated id is added as a field to the -// logger using the passed name as field name. The id is also added as a response -// header if the headerName is not empty. -// -// The generated id is a URL safe base64 encoded mongo object-id-like unique id. -// Mongo unique id generation algorithm has been selected as a trade-off between -// size and ease of use: UUID is less space efficient and snowflake requires machine -// configuration. -func RequestIDHandler(name, headerName string) func(next xhandler.HandlerC) xhandler.HandlerC { - return func(next xhandler.HandlerC) xhandler.HandlerC { - return xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - id, ok := IDFromContext(ctx) - if !ok { - id = xid.New() - ctx = context.WithValue(ctx, idKey, id) - } - if name != "" { - FromContext(ctx).SetField(name, id) - } - if headerName != "" { - w.Header().Set(headerName, id.String()) - } - next.ServeHTTPC(ctx, w, r) - }) - } -} diff --git a/handler_pre17_test.go b/handler_pre17_test.go deleted file mode 100644 index ee8c737..0000000 --- a/handler_pre17_test.go +++ /dev/null @@ -1,147 +0,0 @@ -// +build !go1.7 - -package xlog - -import ( - "net/http" - "net/http/httptest" - "net/url" - "testing" - - "github.com/rs/xhandler" - "github.com/stretchr/testify/assert" - "golang.org/x/net/context" -) - -func TestFromContext(t *testing.T) { - assert.Equal(t, NopLogger, FromContext(nil)) - assert.Equal(t, NopLogger, FromContext(context.Background())) - l := &logger{} - ctx := NewContext(context.Background(), l) - assert.Equal(t, l, FromContext(ctx)) -} - -func TestNewHandler(t *testing.T) { - c := Config{ - Level: LevelInfo, - Fields: F{"foo": "bar"}, - Output: NewOutputChannel(&testOutput{}), - } - lh := NewHandler(c) - h := lh(xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - l := FromContext(ctx) - assert.NotNil(t, l) - assert.NotEqual(t, NopLogger, l) - if l, ok := l.(*logger); assert.True(t, ok) { - assert.Equal(t, LevelInfo, l.level) - assert.Equal(t, c.Output, l.output) - assert.Equal(t, F{"foo": "bar"}, F(l.fields)) - } - })) - h.ServeHTTPC(context.Background(), nil, nil) -} - -func TestURLHandler(t *testing.T) { - r := &http.Request{ - URL: &url.URL{Path: "/path", RawQuery: "foo=bar"}, - } - h := URLHandler("url")(xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - l := FromContext(ctx).(*logger) - assert.Equal(t, F{"url": "/path?foo=bar"}, F(l.fields)) - })) - h = NewHandler(Config{})(h) - h.ServeHTTPC(context.Background(), nil, r) -} - -func TestMethodHandler(t *testing.T) { - r := &http.Request{ - Method: "POST", - } - h := MethodHandler("method")(xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - l := FromContext(ctx).(*logger) - assert.Equal(t, F{"method": "POST"}, F(l.fields)) - })) - h = NewHandler(Config{})(h) - h.ServeHTTPC(context.Background(), nil, r) -} - -func TestRequestHandler(t *testing.T) { - r := &http.Request{ - Method: "POST", - URL: &url.URL{Path: "/path", RawQuery: "foo=bar"}, - } - h := RequestHandler("request")(xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - l := FromContext(ctx).(*logger) - assert.Equal(t, F{"request": "POST /path?foo=bar"}, F(l.fields)) - })) - h = NewHandler(Config{})(h) - h.ServeHTTPC(context.Background(), nil, r) -} - -func TestRemoteAddrHandler(t *testing.T) { - r := &http.Request{ - RemoteAddr: "1.2.3.4:1234", - } - h := RemoteAddrHandler("ip")(xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - l := FromContext(ctx).(*logger) - assert.Equal(t, F{"ip": "1.2.3.4"}, F(l.fields)) - })) - h = NewHandler(Config{})(h) - h.ServeHTTPC(context.Background(), nil, r) -} - -func TestRemoteAddrHandlerIPv6(t *testing.T) { - r := &http.Request{ - RemoteAddr: "[2001:db8:a0b:12f0::1]:1234", - } - h := RemoteAddrHandler("ip")(xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - l := FromContext(ctx).(*logger) - assert.Equal(t, F{"ip": "2001:db8:a0b:12f0::1"}, F(l.fields)) - })) - h = NewHandler(Config{})(h) - h.ServeHTTPC(context.Background(), nil, r) -} - -func TestUserAgentHandler(t *testing.T) { - r := &http.Request{ - Header: http.Header{ - "User-Agent": []string{"some user agent string"}, - }, - } - h := UserAgentHandler("ua")(xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - l := FromContext(ctx).(*logger) - assert.Equal(t, F{"ua": "some user agent string"}, F(l.fields)) - })) - h = NewHandler(Config{})(h) - h.ServeHTTPC(context.Background(), nil, r) -} - -func TestRefererHandler(t *testing.T) { - r := &http.Request{ - Header: http.Header{ - "Referer": []string{"http://foo.com/bar"}, - }, - } - h := RefererHandler("ua")(xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - l := FromContext(ctx).(*logger) - assert.Equal(t, F{"ua": "http://foo.com/bar"}, F(l.fields)) - })) - h = NewHandler(Config{})(h) - h.ServeHTTPC(context.Background(), nil, r) -} - -func TestRequestIDHandler(t *testing.T) { - r := &http.Request{} - h := RequestIDHandler("id", "Request-Id")(xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) { - l := FromContext(ctx).(*logger) - if id, ok := IDFromContext(ctx); assert.True(t, ok) { - assert.Equal(t, l.fields["id"], id) - assert.Len(t, id.String(), 20) - assert.Equal(t, id.String(), w.Header().Get("Request-Id")) - } - assert.Len(t, l.fields["id"], 12) - })) - h = NewHandler(Config{})(h) - w := httptest.NewRecorder() - h.ServeHTTPC(context.Background(), w, r) -} diff --git a/handler_test.go b/handler_test.go index 69d3438..291ba06 100644 --- a/handler_test.go +++ b/handler_test.go @@ -1,3 +1,4 @@ +//go:build go1.7 // +build go1.7 package xlog @@ -20,6 +21,27 @@ func TestFromContext(t *testing.T) { assert.Equal(t, l, FromContext(ctx)) } +func TestFromContextWithStd(t *testing.T) { + assert.Equal(t, GetLogger(), FromContextWithStd(nil)) + assert.Equal(t, GetLogger(), FromContextWithStd(context.Background())) + l := &logger{} + ctx := NewContext(context.Background(), l) + assert.Equal(t, l, FromContext(ctx)) +} + +func TestFromContextWithFields(t *testing.T) { + fields := F{"a": "a"} + l := GetLogger() + expected := Copy(l) + expected.SetFields(fields) + assert.Equal(t, expected, FromContextWithFields(nil, fields)) + assert.Equal(t, expected, FromContextWithFields(context.Background(), fields)) + nl := &logger{} + ctx := NewContext(context.Background(), nl) + + assert.Equal(t, &logger{fields: fields}, FromContextWithFields(ctx, fields)) +} + func TestNewHandler(t *testing.T) { c := Config{ Level: LevelInfo, diff --git a/internal/term/term_openbsd.go b/internal/term/term_openbsd.go index ff01f99..f993166 100755 --- a/internal/term/term_openbsd.go +++ b/internal/term/term_openbsd.go @@ -1,5 +1,5 @@ -package term - -import "syscall" - -const ioctlReadTermios = syscall.TIOCGETA +package term + +import "syscall" + +const ioctlReadTermios = syscall.TIOCGETA diff --git a/internal/term/term_windows.go b/internal/term/term_windows.go index 1f218cc..9c063d3 100644 --- a/internal/term/term_windows.go +++ b/internal/term/term_windows.go @@ -3,31 +3,16 @@ // Use of this source code is governed by a BSD-style // license that can be found in the LICENSE file. +//go:build windows // +build windows package term import ( "io" - "syscall" - "unsafe" -) - -var kernel32 = syscall.NewLazyDLL("kernel32.dll") - -var ( - procGetConsoleMode = kernel32.NewProc("GetConsoleMode") ) // IsTerminal returns true if w writes to a terminal. func IsTerminal(w io.Writer) bool { - fw, ok := w.(interface { - Fd() uintptr - }) - if !ok { - return false - } - var st uint32 - r, _, e := syscall.Syscall(procGetConsoleMode.Addr(), 2, fw.Fd(), uintptr(unsafe.Pointer(&st)), 0) - return r != 0 && e == 0 + return false } diff --git a/nop.go b/nop.go index 1575a61..abefbfa 100644 --- a/nop.go +++ b/nop.go @@ -1,5 +1,7 @@ package xlog +import "context" + type nop struct{} // NopLogger is an no-op implementation of xlog.Logger @@ -7,9 +9,12 @@ var NopLogger = &nop{} func (n nop) SetField(name string, value interface{}) {} +func (n nop) SetFields(fields F) {} + func (n nop) GetFields() F { return map[string]interface{}{} } -func (n nop) OutputF(level Level, calldepth int, msg string, fields map[string]interface{}) {} +func (n nop) OutputF(level Level, calldepth int, msg string, fields map[string]interface{}, err error) { +} func (n nop) Debug(v ...interface{}) {} @@ -40,3 +45,5 @@ func (n nop) Write(p []byte) (int, error) { return len(p), nil } func (n nop) Output(calldepth int, s string) error { return nil } + +func (n nop) SetContext(ctx context.Context) {} diff --git a/nop_test.go b/nop_test.go index 25a12b7..17a3766 100644 --- a/nop_test.go +++ b/nop_test.go @@ -5,7 +5,7 @@ import "testing" func TestNopLogger(t *testing.T) { // cheap cover score upper NopLogger.SetField("name", "value") - NopLogger.OutputF(LevelInfo, 0, "", nil) + NopLogger.OutputF(LevelInfo, 0, "", nil, nil) NopLogger.Debug() NopLogger.Debugf("format") NopLogger.Info() diff --git a/output.go b/output.go index 86106c1..800a842 100644 --- a/output.go +++ b/output.go @@ -12,7 +12,8 @@ import ( "time" "github.com/rs/xid" - "github.com/rs/xlog/internal/term" + + "github.com/Ak-Army/xlog/internal/term" ) // Output sends a log message fields to a destination. @@ -110,9 +111,11 @@ func (oc *OutputChannel) Close() { } // Discard is an Output that discards all log message going thru it. -var Discard = OutputFunc(func(fields map[string]interface{}) error { - return nil -}) +var Discard = OutputFunc( + func(fields map[string]interface{}) error { + return nil + }, +) var bufPool = &sync.Pool{ New: func() interface{} { @@ -200,7 +203,8 @@ func (l *RecorderOutput) Reset() { } type consoleOutput struct { - w io.Writer + w io.Writer + isTerminal bool } var isTerminal = term.IsTerminal @@ -211,16 +215,91 @@ func NewConsoleOutput() Output { return NewConsoleOutputW(os.Stderr, NewLogfmtOutput(os.Stderr)) } +// NewForceConsoleOutput returns a Output printing message in a colored human readable form on the +// stderr. If the stderr is not on a terminal, a color is returned stripped. +func NewForceConsoleOutput() Output { + return consoleOutput{ + w: os.Stderr, + isTerminal: isTerminal(os.Stderr), + } +} + // NewConsoleOutputW returns a Output printing message in a colored human readable form with // the provided writer. If the writer is not on a terminal, the noTerm output is returned. func NewConsoleOutputW(w io.Writer, noTerm Output) Output { if isTerminal(w) { - return consoleOutput{w: w} + return consoleOutput{w: w, isTerminal: true} } return noTerm } +// NewForceConsoleOutputW returns a Output printing message in a colored human readable form with +// the provided writer. If the writer is not on a terminal, a color is returned stripped. +func NewForceConsoleOutputW(w io.Writer) Output { + return consoleOutput{ + w: w, + isTerminal: isTerminal(w), + } +} + func (o consoleOutput) Write(fields map[string]interface{}) error { + if o.isTerminal { + return o.writeWithColor(fields) + } + return o.write(fields) +} + +func (o consoleOutput) write(fields map[string]interface{}) error { + buf := bufPool.Get().(*bytes.Buffer) + defer func() { + buf.Reset() + bufPool.Put(buf) + }() + if ts, ok := fields[KeyTime].(time.Time); ok { + buf.Write([]byte(ts.Format("2006/01/02 15:04:05 "))) + } + if lvl, ok := fields[KeyLevel].(string); ok { + buf.Write([]byte(strings.ToUpper(lvl[0:4]))) + buf.WriteByte(' ') + } + if msg, ok := fields[KeyMessage].(string); ok { + msg = strings.Replace(msg, "\n", "\\n", -1) + buf.Write([]byte(msg)) + } + if msg, ok := fields[KeyError]; ok { + buf.WriteByte(' ') + buf.Write([]byte(KeyError)) + buf.WriteByte('=') + if err := writeValue(buf, msg); err != nil { + return err + } + } + // Gather field keys + keys := []string{} + for k := range fields { + switch k { + case KeyLevel, KeyMessage, KeyTime, KeyError, KeyContext: + continue + } + keys = append(keys, k) + } + // Sort fields by key names + sort.Strings(keys) + // Print fields using logfmt format + for _, k := range keys { + buf.WriteByte(' ') + buf.Write([]byte(k)) + buf.WriteByte('=') + if err := writeValue(buf, fields[k]); err != nil { + return err + } + } + buf.WriteByte('\n') + _, err := o.w.Write(buf.Bytes()) + return err +} + +func (o consoleOutput) writeWithColor(fields map[string]interface{}) error { buf := bufPool.Get().(*bytes.Buffer) defer func() { buf.Reset() @@ -246,11 +325,19 @@ func (o consoleOutput) Write(fields map[string]interface{}) error { msg = strings.Replace(msg, "\n", "\\n", -1) buf.Write([]byte(msg)) } + if msg, ok := fields[KeyError]; ok { + buf.WriteByte(' ') + colorPrint(buf, KeyError, red) + buf.WriteByte('=') + if err := writeValue(buf, msg); err != nil { + return err + } + } // Gather field keys keys := []string{} for k := range fields { switch k { - case KeyLevel, KeyMessage, KeyTime: + case KeyLevel, KeyMessage, KeyTime, KeyError, KeyContext: continue } keys = append(keys, k) @@ -290,7 +377,7 @@ func (o logfmtOutput) Write(fields map[string]interface{}) error { keys := []string{} for k := range fields { switch k { - case KeyLevel, KeyMessage, KeyTime: + case KeyLevel, KeyMessage, KeyTime, KeyError, KeyContext: continue } keys = append(keys, k) @@ -298,7 +385,11 @@ func (o logfmtOutput) Write(fields map[string]interface{}) error { // Sort fields by key names sort.Strings(keys) // Prepend default fields in a specific order - keys = append([]string{KeyLevel, KeyMessage, KeyTime}, keys...) + if _, ok := fields[KeyError]; ok { + keys = append([]string{KeyLevel, KeyMessage, KeyError, KeyTime}, keys...) + } else { + keys = append([]string{KeyLevel, KeyMessage, KeyTime}, keys...) + } l := len(keys) for i, k := range keys { buf.Write([]byte(k)) @@ -319,73 +410,83 @@ func (o logfmtOutput) Write(fields map[string]interface{}) error { // NewJSONOutput returns a new JSON output with the given writer. func NewJSONOutput(w io.Writer) Output { enc := json.NewEncoder(w) - return OutputFunc(func(fields map[string]interface{}) error { - return enc.Encode(fields) - }) + return OutputFunc( + func(fields map[string]interface{}) error { + return enc.Encode(fields) + }, + ) } // NewLogstashOutput returns an output to generate logstash friendly JSON format. func NewLogstashOutput(w io.Writer) Output { - return OutputFunc(func(fields map[string]interface{}) error { - lsf := map[string]interface{}{ - "@version": 1, - } - for k, v := range fields { - switch k { - case KeyTime: - k = "@timestamp" - case KeyLevel: - if s, ok := v.(string); ok { - v = strings.ToUpper(s) + return OutputFunc( + func(fields map[string]interface{}) error { + lsf := map[string]interface{}{ + "@version": 1, + } + for k, v := range fields { + switch k { + case KeyTime: + k = "@timestamp" + case KeyLevel: + if s, ok := v.(string); ok { + v = strings.ToUpper(s) + } + } + if t, ok := v.(time.Time); ok { + lsf[k] = t.Format(time.RFC3339) + } else { + lsf[k] = v } } - if t, ok := v.(time.Time); ok { - lsf[k] = t.Format(time.RFC3339) - } else { - lsf[k] = v + b, err := json.Marshal(lsf) + if err != nil { + return err } - } - b, err := json.Marshal(lsf) - if err != nil { + _, err = w.Write(b) return err - } - _, err = w.Write(b) - return err - }) + }, + ) } // NewUIDOutput returns an output filter adding a globally unique id (using github.com/rs/xid) // to all message going thru this output. The o parameter defines the next output to pass data // to. func NewUIDOutput(field string, o Output) Output { - return OutputFunc(func(fields map[string]interface{}) error { - fields[field] = xid.New().String() - return o.Write(fields) - }) + return OutputFunc( + func(fields map[string]interface{}) error { + fields[field] = xid.New().String() + return o.Write(fields) + }, + ) } // NewTrimOutput trims any field of type string with a value length greater than maxLen // to maxLen. func NewTrimOutput(maxLen int, o Output) Output { - return OutputFunc(func(fields map[string]interface{}) error { - for k, v := range fields { - if s, ok := v.(string); ok && len(s) > maxLen { - fields[k] = s[:maxLen] + return OutputFunc( + func(fields map[string]interface{}) error { + for k, v := range fields { + if s, ok := v.(string); ok && len(s) > maxLen { + fields[k] = s[:maxLen] + } } - } - return o.Write(fields) - }) + return o.Write(fields) + }, + ) } // NewTrimFieldsOutput trims listed field fields of type string with a value length greater than maxLen // to maxLen. func NewTrimFieldsOutput(trimFields []string, maxLen int, o Output) Output { - return OutputFunc(func(fields map[string]interface{}) error { - for _, f := range trimFields { - if s, ok := fields[f].(string); ok && len(s) > maxLen { - fields[f] = s[:maxLen] + return OutputFunc( + func(fields map[string]interface{}) error { + for _, f := range trimFields { + if s, ok := fields[f].(string); ok && len(s) > maxLen { + fields[f] = s[:maxLen] + } } - } - return o.Write(fields) - }) + return o.Write(fields) + }, + ) } diff --git a/output_examples_test.go b/output_examples_test.go index e26ec22..ead5dec 100644 --- a/output_examples_test.go +++ b/output_examples_test.go @@ -3,7 +3,7 @@ package xlog_test import ( "log/syslog" - "github.com/rs/xlog" + "github.com/Ak-Army/xlog" ) func Example_combinedOutputs() { diff --git a/output_test.go b/output_test.go index 6982763..0cf21fe 100644 --- a/output_test.go +++ b/output_test.go @@ -4,7 +4,6 @@ import ( "bytes" "errors" "io" - "io/ioutil" "log" "os" "testing" @@ -27,6 +26,7 @@ func newTestOutputErr(err error) *testOutput { } func (o *testOutput) Write(fields map[string]interface{}) (err error) { + delete(fields, KeyContext) o.w <- fields return o.err } @@ -77,7 +77,7 @@ func TestOutputChannelError(t *testing.T) { critialLogger = oldCritialLogger w.Close() }() - b, err := ioutil.ReadAll(r) + b, err := io.ReadAll(r) assert.NoError(t, err) assert.Contains(t, string(b), "cannot write log message: some error") } @@ -215,9 +215,11 @@ func TestSyslogOutput(t *testing.T) { }() m := NewSyslogOutput("udp", "127.0.0.1:1234", "mytag") assert.IsType(t, LevelOutput{}, m) - assert.Panics(t, func() { - NewSyslogOutput("tcp", "an invalid host name", "mytag") - }) + assert.Panics( + t, func() { + NewSyslogOutput("tcp", "an invalid host name", "mytag") + }, + ) assert.Regexp(t, "syslog dial error: dial tcp:.*missing port in address.*", buf.String()) } @@ -260,8 +262,13 @@ func TestNewConsoleOutputW(t *testing.T) { func TestConsoleOutput(t *testing.T) { buf := &bytes.Buffer{} - c := consoleOutput{w: buf} - err := c.Write(F{"message": "some message", "level": "info", "time": time.Date(2000, 1, 2, 3, 4, 5, 0, time.UTC), "foo": "bar"}) + c := consoleOutput{w: buf, isTerminal: true} + err := c.Write( + F{ + "message": "some message", "level": "info", "time": time.Date(2000, 1, 2, 3, 4, 5, 0, time.UTC), + "foo": "bar", + }, + ) assert.NoError(t, err) assert.Equal(t, "2000/01/02 03:04:05 \x1b[34mINFO\x1b[0m some message \x1b[32mfoo\x1b[0m=bar\n", buf.String()) buf.Reset() @@ -281,18 +288,24 @@ func TestConsoleOutput(t *testing.T) { func TestLogfmtOutput(t *testing.T) { buf := &bytes.Buffer{} c := NewLogfmtOutput(buf) - err := c.Write(F{ - "time": time.Date(2000, 1, 2, 3, 4, 5, 0, time.UTC), - "message": "some message", - "level": "info", - "string": "foo", - "null": nil, - "quoted": "needs \" quotes", - "err": errors.New("error"), - "errq": errors.New("error with \" quote"), - }) + err := c.Write( + F{ + "time": time.Date(2000, 1, 2, 3, 4, 5, 0, time.UTC), + "message": "some message", + "level": "info", + "string": "foo", + "null": nil, + "quoted": "needs \" quotes", + "err": errors.New("error"), + "errq": errors.New("error with \" quote"), + }, + ) assert.NoError(t, err) - assert.Equal(t, "level=info message=\"some message\" time=\"2000-01-02 03:04:05 +0000 UTC\" err=error errq=\"error with \\\" quote\" null=null quoted=\"needs \\\" quotes\" string=foo\n", buf.String()) + assert.Equal( + t, + "level=info message=\"some message\" time=\"2000-01-02 03:04:05 +0000 UTC\" err=error errq=\"error with \\\" quote\" null=null quoted=\"needs \\\" quotes\" string=foo\n", + buf.String(), + ) } func TestJSONOutput(t *testing.T) { @@ -306,15 +319,21 @@ func TestJSONOutput(t *testing.T) { func TestLogstashOutput(t *testing.T) { buf := &bytes.Buffer{} o := NewLogstashOutput(buf) - err := o.Write(F{ - "message": "some message", - "level": "info", - "time": time.Date(2000, 1, 2, 3, 4, 5, 0, time.UTC), - "file": "test.go:234", - "foo": "bar", - }) + err := o.Write( + F{ + "message": "some message", + "level": "info", + "time": time.Date(2000, 1, 2, 3, 4, 5, 0, time.UTC), + "file": "test.go:234", + "foo": "bar", + }, + ) assert.NoError(t, err) - assert.Equal(t, "{\"@timestamp\":\"2000-01-02T03:04:05Z\",\"@version\":1,\"file\":\"test.go:234\",\"foo\":\"bar\",\"level\":\"INFO\",\"message\":\"some message\"}", buf.String()) + assert.Equal( + t, + "{\"@timestamp\":\"2000-01-02T03:04:05Z\",\"@version\":1,\"file\":\"test.go:234\",\"foo\":\"bar\",\"level\":\"INFO\",\"message\":\"some message\"}", + buf.String(), + ) } func TestUIDOutput(t *testing.T) { diff --git a/std.go b/std.go index 623177e..d2be3ff 100644 --- a/std.go +++ b/std.go @@ -11,46 +11,51 @@ func SetLogger(logger Logger) { std = logger } +// GetLogger get the global logger instance +func GetLogger() Logger { + return std +} + // Debug calls the Debug() method on the default logger func Debug(v ...interface{}) { - f := extractFields(&v) - std.OutputF(LevelDebug, 2, fmt.Sprint(v...), f) + f, e := extractFields(&v) + std.OutputF(LevelDebug, 2, fmt.Sprint(v...), f, e) } // Debugf calls the Debugf() method on the default logger func Debugf(format string, v ...interface{}) { - f := extractFields(&v) - std.OutputF(LevelDebug, 2, fmt.Sprintf(format, v...), f) + f, e := extractFields(&v) + std.OutputF(LevelDebug, 2, fmt.Sprintf(format, v...), f, e) } // Info calls the Info() method on the default logger func Info(v ...interface{}) { - f := extractFields(&v) - std.OutputF(LevelInfo, 2, fmt.Sprint(v...), f) + f, e := extractFields(&v) + std.OutputF(LevelInfo, 2, fmt.Sprint(v...), f, e) } // Infof calls the Infof() method on the default logger func Infof(format string, v ...interface{}) { - f := extractFields(&v) - std.OutputF(LevelInfo, 2, fmt.Sprintf(format, v...), f) + f, e := extractFields(&v) + std.OutputF(LevelInfo, 2, fmt.Sprintf(format, v...), f, e) } // Warn calls the Warn() method on the default logger func Warn(v ...interface{}) { - f := extractFields(&v) - std.OutputF(LevelWarn, 2, fmt.Sprint(v...), f) + f, e := extractFields(&v) + std.OutputF(LevelWarn, 2, fmt.Sprint(v...), f, e) } // Warnf calls the Warnf() method on the default logger func Warnf(format string, v ...interface{}) { - f := extractFields(&v) - std.OutputF(LevelWarn, 2, fmt.Sprintf(format, v...), f) + f, e := extractFields(&v) + std.OutputF(LevelWarn, 2, fmt.Sprintf(format, v...), f, e) } // Error calls the Error() method on the default logger func Error(v ...interface{}) { - f := extractFields(&v) - std.OutputF(LevelError, 2, fmt.Sprint(v...), f) + f, e := extractFields(&v) + std.OutputF(LevelError, 2, fmt.Sprint(v...), f, e) } // Errorf calls the Errorf() method on the default logger @@ -58,7 +63,7 @@ func Error(v ...interface{}) { // Go vet users: you may append %v at the end of you format when using xlog.F{} as a last // argument to workaround go vet false alarm. func Errorf(format string, v ...interface{}) { - f := extractFields(&v) + f, e := extractFields(&v) if f != nil { // Let user add a %v at the end of the message when fields are passed to satisfy go vet l := len(format) @@ -66,13 +71,13 @@ func Errorf(format string, v ...interface{}) { format = format[0 : l-2] } } - std.OutputF(LevelError, 2, fmt.Sprintf(format, v...), f) + std.OutputF(LevelError, 2, fmt.Sprintf(format, v...), f, e) } // Fatal calls the Fatal() method on the default logger func Fatal(v ...interface{}) { - f := extractFields(&v) - std.OutputF(LevelFatal, 2, fmt.Sprint(v...), f) + f, e := extractFields(&v) + std.OutputF(LevelFatal, 2, fmt.Sprint(v...), f, e) if l, ok := std.(*logger); ok { if o, ok := l.output.(*OutputChannel); ok { o.Close() @@ -86,7 +91,7 @@ func Fatal(v ...interface{}) { // Go vet users: you may append %v at the end of you format when using xlog.F{} as a last // argument to workaround go vet false alarm. func Fatalf(format string, v ...interface{}) { - f := extractFields(&v) + f, e := extractFields(&v) if f != nil { // Let user add a %v at the end of the message when fields are passed to satisfy go vet l := len(format) @@ -94,7 +99,7 @@ func Fatalf(format string, v ...interface{}) { format = format[0 : l-2] } } - std.OutputF(LevelFatal, 2, fmt.Sprintf(format, v...), f) + std.OutputF(LevelFatal, 2, fmt.Sprintf(format, v...), f, e) if l, ok := std.(*logger); ok { if o, ok := l.output.(*OutputChannel); ok { o.Close() diff --git a/std_example_test.go b/std_example_test.go index 784aebc..75bbf21 100644 --- a/std_example_test.go +++ b/std_example_test.go @@ -1,6 +1,6 @@ package xlog_test -import "github.com/rs/xlog" +import "github.com/Ak-Army/xlog" func ExampleSetLogger() { xlog.SetLogger(xlog.New(xlog.Config{ diff --git a/util.go b/util.go index 4382be1..12e03a5 100644 --- a/util.go +++ b/util.go @@ -1,7 +1,6 @@ package xlog import ( - "encoding/json" "fmt" "io" "strings" @@ -34,11 +33,8 @@ func writeValue(w io.Writer, v interface{}) (err error) { _, err = w.Write([]byte("null")) case string: if strings.IndexFunc(v, needsQuotedValueRune) != -1 { - var b []byte - b, err = json.Marshal(v) - if err == nil { - w.Write(b) - } + s := fmt.Sprintf("%q", v) + _, err = w.Write([]byte(s)) } else { _, err = w.Write([]byte(v)) } diff --git a/xlog.go b/xlog.go index 106faf2..e35c597 100644 --- a/xlog.go +++ b/xlog.go @@ -8,25 +8,27 @@ // // Features: // -// - Per request log context -// - Per request and/or per message key/value fields -// - Log levels (Debug, Info, Warn, Error) -// - Color output when terminal is detected -// - Custom output (JSON, logfmt, …) -// - Automatic gathering of request context like User-Agent, IP etc. -// - Drops message rather than blocking execution -// - Easy access logging thru github.com/rs/xaccess +// - Per request log context +// - Per request and/or per message key/value fields +// - Log levels (Debug, Info, Warn, Error) +// - Color output when terminal is detected +// - Custom output (JSON, logfmt, …) +// - Automatic gathering of request context like User-Agent, IP etc. +// - Drops message rather than blocking execution +// - Easy access logging thru github.com/rs/xaccess // // It works best in combination with github.com/rs/xhandler. -package xlog // import "github.com/rs/xlog" +package xlog // import "github.com/Ak-Army/xlog" import ( + "context" "fmt" "io" "log" "os" "path" "runtime" + "runtime/debug" "strconv" "strings" "sync" @@ -38,9 +40,15 @@ type Logger interface { // Implements io.Writer so it can be set a output of log.Logger io.Writer + // SetContext set the context for logging. All future messages on this logger + // will have this context set. + SetContext(ctx context.Context) // SetField sets a field on the logger's context. All future messages on this logger // will have this field set. SetField(name string, value interface{}) + // SetFields sets a fielsd on the logger's context. All future messages on this logger + // will have this fields set. + SetFields(fields F) // GetFields returns all the fields set on the logger GetFields() F // Debug logs a debug message. If last parameter is a map[string]string, it's content @@ -76,7 +84,7 @@ type Logger interface { // Output mimics std logger interface Output(calldepth int, s string) error // OutputF outputs message with fields. - OutputF(level Level, calldepth int, msg string, fields map[string]interface{}) + OutputF(level Level, calldepth int, msg string, fields map[string]interface{}, err error) } // LoggerCopier defines a logger with copy support @@ -101,16 +109,20 @@ type Config struct { // puts a greater pressure on GC and increases the amount of memory allocated // and freed. Use only if persistent loggers are a requirement. DisablePooling bool + // DisableCallerInfo removes the caller file info from the log line + DisableCallerInfo bool } // F represents a set of log message fields type F map[string]interface{} type logger struct { - level Level - output Output - fields F - disablePooling bool + level Level + output Output + fields F + ctx context.Context + disablePooling bool + disableCallerInfo bool } // Common field names for log messages. @@ -119,6 +131,8 @@ var ( KeyMessage = "message" KeyLevel = "level" KeyFile = "file" + KeyError = "error" + KeyContext = "context" ) var now = time.Now @@ -145,13 +159,13 @@ func New(c Config) Logger { } l.level = c.Level l.output = c.Output + l.ctx = context.Background() if l.output == nil { l.output = NewOutputChannel(NewConsoleOutput()) } - for k, v := range c.Fields { - l.SetField(k, v) - } + l.SetFields(c.Fields) l.disablePooling = c.DisablePooling + l.disableCallerInfo = c.DisableCallerInfo return l } @@ -171,6 +185,7 @@ func (l *logger) Copy() Logger { output: l.output, fields: map[string]interface{}{}, disablePooling: l.disablePooling, + ctx: l.ctx, } for k, v := range l.fields { l2.fields[k] = v @@ -188,16 +203,27 @@ func (l *logger) close() { } } -func (l *logger) send(level Level, calldepth int, msg string, fields map[string]interface{}) { +func (l *logger) send(level Level, calldepth int, msg string, fields map[string]interface{}, err error) { if level < l.level || l.output == nil { return } + defer func() { + if r := recover(); r != nil { + l.Errorf("Unable to send message, panic recovered: %s; stack: %s", r, string(debug.Stack())) + } + }() data := make(map[string]interface{}, 4+len(fields)+len(l.fields)) data[KeyTime] = now() data[KeyLevel] = level.String() data[KeyMessage] = msg - if _, file, line, ok := runtime.Caller(calldepth); ok { - data[KeyFile] = path.Base(file) + ":" + strconv.FormatInt(int64(line), 10) + data[KeyContext] = l.ctx + if err != nil { + data[KeyError] = err + } + if !l.disableCallerInfo { + if _, file, line, ok := runtime.Caller(calldepth); ok { + data[KeyFile] = path.Base(file) + ":" + strconv.FormatInt(int64(line), 10) + } } for k, v := range fields { data[k] = v @@ -212,18 +238,33 @@ func (l *logger) send(level Level, calldepth int, msg string, fields map[string] } } -func extractFields(v *[]interface{}) map[string]interface{} { +func extractFields(v *[]interface{}) (map[string]interface{}, error) { + var f map[string]interface{} + var ok bool + var e error + if l := len(*v); l > 1 { + if e, ok = (*v)[l-1].(error); ok { + *v = (*v)[:l-1] + } + } if l := len(*v); l > 0 { - if f, ok := (*v)[l-1].(map[string]interface{}); ok { + if f, ok = (*v)[l-1].(map[string]interface{}); ok { + *v = (*v)[:l-1] + } else if f, ok = (*v)[l-1].(F); ok { *v = (*v)[:l-1] - return f } - if f, ok := (*v)[l-1].(F); ok { + } + if l := len(*v); l > 1 && e == nil { + if e, ok = (*v)[l-1].(error); ok { *v = (*v)[:l-1] - return f } } - return nil + return f, e +} + +// SetContext implements Logger interface +func (l *logger) SetContext(ctx context.Context) { + l.ctx = ctx } // SetField implements Logger interface @@ -234,56 +275,66 @@ func (l *logger) SetField(name string, value interface{}) { l.fields[name] = value } +// SetFields implements Logger interface +func (l *logger) SetFields(fields F) { + if l.fields == nil { + l.fields = map[string]interface{}{} + } + for name, value := range fields { + l.fields[name] = value + } +} + // GetFields implements Logger interface func (l *logger) GetFields() F { return l.fields } -// Output implements Logger interface -func (l *logger) OutputF(level Level, calldepth int, msg string, fields map[string]interface{}) { - l.send(level, calldepth+1, msg, fields) +// OutputF implements Logger interface +func (l *logger) OutputF(level Level, calldepth int, msg string, fields map[string]interface{}, err error) { + l.send(level, calldepth+1, msg, fields, err) } // Debug implements Logger interface func (l *logger) Debug(v ...interface{}) { - f := extractFields(&v) - l.send(LevelDebug, 2, fmt.Sprint(v...), f) + f, e := extractFields(&v) + l.send(LevelDebug, 2, fmt.Sprint(v...), f, e) } // Debugf implements Logger interface func (l *logger) Debugf(format string, v ...interface{}) { - f := extractFields(&v) - l.send(LevelDebug, 2, fmt.Sprintf(format, v...), f) + f, e := extractFields(&v) + l.send(LevelDebug, 2, fmt.Sprintf(format, v...), f, e) } // Info implements Logger interface func (l *logger) Info(v ...interface{}) { - f := extractFields(&v) - l.send(LevelInfo, 2, fmt.Sprint(v...), f) + f, e := extractFields(&v) + l.send(LevelInfo, 2, fmt.Sprint(v...), f, e) } // Infof implements Logger interface func (l *logger) Infof(format string, v ...interface{}) { - f := extractFields(&v) - l.send(LevelInfo, 2, fmt.Sprintf(format, v...), f) + f, e := extractFields(&v) + l.send(LevelInfo, 2, fmt.Sprintf(format, v...), f, e) } // Warn implements Logger interface func (l *logger) Warn(v ...interface{}) { - f := extractFields(&v) - l.send(LevelWarn, 2, fmt.Sprint(v...), f) + f, e := extractFields(&v) + l.send(LevelWarn, 2, fmt.Sprint(v...), f, e) } // Warnf implements Logger interface func (l *logger) Warnf(format string, v ...interface{}) { - f := extractFields(&v) - l.send(LevelWarn, 2, fmt.Sprintf(format, v...), f) + f, e := extractFields(&v) + l.send(LevelWarn, 2, fmt.Sprintf(format, v...), f, e) } // Error implements Logger interface func (l *logger) Error(v ...interface{}) { - f := extractFields(&v) - l.send(LevelError, 2, fmt.Sprint(v...), f) + f, e := extractFields(&v) + l.send(LevelError, 2, fmt.Sprint(v...), f, e) } // Errorf implements Logger interface @@ -291,21 +342,14 @@ func (l *logger) Error(v ...interface{}) { // Go vet users: you may append %v at the end of you format when using xlog.F{} as a last // argument to workaround go vet false alarm. func (l *logger) Errorf(format string, v ...interface{}) { - f := extractFields(&v) - if f != nil { - // Let user add a %v at the end of the message when fields are passed to satisfy go vet - l := len(format) - if l > 2 && format[l-2] == '%' && format[l-1] == 'v' { - format = format[0 : l-2] - } - } - l.send(LevelError, 2, fmt.Sprintf(format, v...), f) + f, e := extractFields(&v) + l.send(LevelError, 2, fmt.Sprintf(format, v...), f, e) } // Fatal implements Logger interface func (l *logger) Fatal(v ...interface{}) { - f := extractFields(&v) - l.send(LevelFatal, 2, fmt.Sprint(v...), f) + f, e := extractFields(&v) + l.send(LevelFatal, 2, fmt.Sprint(v...), f, e) if o, ok := l.output.(*OutputChannel); ok { o.Close() } @@ -317,15 +361,8 @@ func (l *logger) Fatal(v ...interface{}) { // Go vet users: you may append %v at the end of you format when using xlog.F{} as a last // argument to workaround go vet false alarm. func (l *logger) Fatalf(format string, v ...interface{}) { - f := extractFields(&v) - if f != nil { - // Let user add a %v at the end of the message when fields are passed to satisfy go vet - l := len(format) - if l > 2 && format[l-2] == '%' && format[l-1] == 'v' { - format = format[0 : l-2] - } - } - l.send(LevelFatal, 2, fmt.Sprintf(format, v...), f) + f, e := extractFields(&v) + l.send(LevelFatal, 2, fmt.Sprintf(format, v...), f, e) if o, ok := l.output.(*OutputChannel); ok { o.Close() } @@ -335,7 +372,7 @@ func (l *logger) Fatalf(format string, v ...interface{}) { // Write implements io.Writer interface func (l *logger) Write(p []byte) (int, error) { msg := strings.TrimRight(string(p), "\n") - l.send(LevelInfo, 4, msg, nil) + l.send(LevelInfo, 4, msg, nil, nil) if o, ok := l.output.(*OutputChannel); ok { o.Flush() } @@ -343,7 +380,7 @@ func (l *logger) Write(p []byte) (int, error) { } // Output implements common logger interface -func (l *logger) Output(calldepth int, s string) error { - l.send(LevelInfo, 2, s, nil) +func (l *logger) Output(callDepth int, s string) error { + l.send(LevelInfo, callDepth, s, nil, nil) return nil } diff --git a/xlog_bench_test.go b/xlog_bench_test.go index cbc13d4..3d5d83a 100644 --- a/xlog_bench_test.go +++ b/xlog_bench_test.go @@ -3,10 +3,10 @@ package xlog import "testing" func BenchmarkSend(b *testing.B) { - l := New(Config{Output: Discard, Fields: F{"a": "b"}}).(*logger) + l := New(Config{Output: Discard, Fields: F{"a": "b"}, DisableCallerInfo: true}).(*logger) b.ResetTimer() b.ReportAllocs() for i := 0; i < b.N; i++ { - l.send(0, 0, "test", F{"foo": "bar", "bar": "baz"}) + l.send(0, 0, "test", F{"foo": "bar", "bar": "baz"}, nil) } } diff --git a/xlog_examples_test.go b/xlog_examples_test.go index 3f59445..a80c0e1 100644 --- a/xlog_examples_test.go +++ b/xlog_examples_test.go @@ -7,7 +7,7 @@ import ( "errors" "log" - "github.com/rs/xlog" + "github.com/Ak-Army/xlog" ) func Example_log() { diff --git a/xlog_test.go b/xlog_test.go index a42357b..3e9fd3c 100644 --- a/xlog_test.go +++ b/xlog_test.go @@ -1,8 +1,9 @@ package xlog import ( + "context" + "errors" "io" - "io/ioutil" "log" "sync" "testing" @@ -116,27 +117,30 @@ func TestNewDefautOutput(t *testing.T) { func TestSend(t *testing.T) { o := newTestOutput() l := New(Config{Output: o}).(*logger) - l.send(LevelDebug, 1, "test", F{"foo": "bar"}) + l.send(LevelDebug, 1, "test", F{"foo": "bar"}, nil) last := <-o.w assert.Contains(t, last["file"], "log_test.go:") delete(last, "file") assert.Equal(t, map[string]interface{}{"time": fakeNow, "level": "debug", "message": "test", "foo": "bar"}, last) l.SetField("bar", "baz") - l.send(LevelInfo, 1, "test", F{"foo": "bar"}) + l.send(LevelInfo, 1, "test", F{"foo": "bar"}, nil) last = <-o.w assert.Contains(t, last["file"], "log_test.go:") delete(last, "file") - assert.Equal(t, map[string]interface{}{"time": fakeNow, "level": "info", "message": "test", "foo": "bar", "bar": "baz"}, last) + assert.Equal( + t, + map[string]interface{}{"time": fakeNow, "level": "info", "message": "test", "foo": "bar", "bar": "baz"}, + last, + ) l = New(Config{Output: o, Level: 1}).(*logger) o.reset() - l.send(0, 2, "test", F{"foo": "bar"}) + l.send(0, 2, "test", F{"foo": "bar"}, nil) assert.True(t, o.empty()) } func TestSendDrop(t *testing.T) { - t.Skip() r, w := io.Pipe() go func() { critialLoggerMux.Lock() @@ -146,9 +150,9 @@ func TestSendDrop(t *testing.T) { o := newTestOutput() oc := NewOutputChannelBuffer(Discard, 1) l := New(Config{Output: oc}).(*logger) - l.send(LevelDebug, 2, "test", F{"foo": "bar"}) - l.send(LevelDebug, 2, "test", F{"foo": "bar"}) - l.send(LevelDebug, 2, "test", F{"foo": "bar"}) + l.send(LevelDebug, 2, "test", F{"foo": "bar"}, nil) + l.send(LevelDebug, 2, "test", F{"foo": "bar"}, nil) + l.send(LevelDebug, 2, "test", F{"foo": "bar"}, nil) o.get() o.get() o.get() @@ -156,30 +160,41 @@ func TestSendDrop(t *testing.T) { critialLogger = oldCritialLogger w.Close() }() - b, err := ioutil.ReadAll(r) + + b, err := io.ReadAll(r) assert.NoError(t, err) assert.Contains(t, string(b), "send error: buffer full") } func TestExtractFields(t *testing.T) { - v := []interface{}{"a", 1, map[string]interface{}{"foo": "bar"}} - f := extractFields(&v) + err := errors.New("err") + v := []interface{}{"a", 1, err, map[string]interface{}{"foo": "bar"}} + f, e := extractFields(&v) assert.Equal(t, map[string]interface{}{"foo": "bar"}, f) assert.Equal(t, []interface{}{"a", 1}, v) + assert.Equal(t, err, e) v = []interface{}{map[string]interface{}{"foo": "bar"}, "a", 1} - f = extractFields(&v) + f, e = extractFields(&v) assert.Nil(t, f) + assert.Nil(t, e) + assert.Equal(t, []interface{}{map[string]interface{}{"foo": "bar"}, "a", 1}, v) + + v = []interface{}{map[string]interface{}{"foo": "bar"}, "a", 1} + f, e = extractFields(&v) + assert.Nil(t, f) + assert.Nil(t, e) assert.Equal(t, []interface{}{map[string]interface{}{"foo": "bar"}, "a", 1}, v) v = []interface{}{"a", 1, F{"foo": "bar"}} - f = extractFields(&v) + f, e = extractFields(&v) assert.Equal(t, map[string]interface{}{"foo": "bar"}, f) assert.Equal(t, []interface{}{"a", 1}, v) v = []interface{}{} - f = extractFields(&v) + f, e = extractFields(&v) assert.Nil(t, f) + assert.Nil(t, e) assert.Equal(t, []interface{}{}, v) } @@ -267,7 +282,11 @@ func TestErrorf(t *testing.T) { last := <-o.w assert.Contains(t, last["file"], "log_test.go:") delete(last, "file") - assert.Equal(t, map[string]interface{}{"time": fakeNow, "level": "error", "message": "test 1", "foo": "bar"}, last) + assert.Equal( + t, + map[string]interface{}{"time": fakeNow, "level": "error", "message": "test 1%!v(MISSING)", "foo": "bar"}, + last, + ) } func TestFatal(t *testing.T) { @@ -296,7 +315,11 @@ func TestFatalf(t *testing.T) { last := <-o.w assert.Contains(t, last["file"], "log_test.go:") delete(last, "file") - assert.Equal(t, map[string]interface{}{"time": fakeNow, "level": "fatal", "message": "test 1", "foo": "bar"}, last) + assert.Equal( + t, + map[string]interface{}{"time": fakeNow, "level": "fatal", "message": "test 1%!v(MISSING)", "foo": "bar"}, + last, + ) assert.Equal(t, 1, exited) } @@ -320,3 +343,39 @@ func TestOutput(t *testing.T) { delete(last, "file") assert.Equal(t, map[string]interface{}{"time": fakeNow, "level": "info", "message": "test"}, last) } + +func TestOutput2(t *testing.T) { + o := newTestOutput() + l := New(Config{Output: o}).(*logger) + done := make(chan struct{}) + end := make(chan struct{}) + go func() { + defer close(end) + for { + select { + case <-done: + return + default: + l.Output(2, "test") + last := <-o.w + assert.Contains(t, last["file"], "log_test.go:") + delete(last, "file") + assert.Equal(t, map[string]interface{}{"time": fakeNow, "level": "info", "message": "test"}, last) + } + } + }() + go func() { + for { + select { + case <-done: + return + default: + ll := l.Copy() + ll.SetContext(context.Background()) + } + } + }() + time.Sleep(time.Second) + close(done) + <-end +}