Skip to content

Commit

Permalink
Update middleware/tripperware accordling to logger signature (#3)
Browse files Browse the repository at this point in the history
  • Loading branch information
instabledesign authored Feb 22, 2020
1 parent 218e3f2 commit 3703605
Show file tree
Hide file tree
Showing 8 changed files with 303 additions and 259 deletions.
3 changes: 2 additions & 1 deletion go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ go 1.13

require (
github.com/gol4ng/httpware/v2 v2.1.1
github.com/gol4ng/logger v0.3.0
github.com/gol4ng/logger v0.5.3
github.com/golang/mock v1.4.0
github.com/stretchr/testify v1.4.0
)
24 changes: 20 additions & 4 deletions go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -13,12 +13,12 @@ github.com/go-kit/kit v0.8.0/go.mod h1:xBxKIO96dXMWWy0MnWVtmwkA9/13aqxPnvrjFYMA2
github.com/go-logfmt/logfmt v0.3.0/go.mod h1:Qt1PoO58o5twSAckw1HlFXLmHsOX5/0LbT9GBnD5lWE=
github.com/go-stack/stack v1.8.0/go.mod h1:v0f6uXyyMGvRgIKkXu+yp6POWl0qKG85gN/melR3HDY=
github.com/gogo/protobuf v1.1.1/go.mod h1:r8qH/GZQm5c6nD/R0oafs1akxWv10x8SbQlK7atdtwQ=
github.com/gol4ng/httpware/v2 v2.1.0 h1:eKtzvaoW/dw8YIAYTfhAvPDVmj0zDw8BkQSlLhjunUI=
github.com/gol4ng/httpware/v2 v2.1.0/go.mod h1:SIOrsksHg+ydQWikEj5KUVANB4lmwB8c5/NIBtdVzFM=
github.com/gol4ng/httpware/v2 v2.1.1 h1:8xd4iN+6e/xjBSy8jjF2Vm8/PvxswJznu8GdaNu+vs8=
github.com/gol4ng/httpware/v2 v2.1.1/go.mod h1:SIOrsksHg+ydQWikEj5KUVANB4lmwB8c5/NIBtdVzFM=
github.com/gol4ng/logger v0.3.0 h1:06RSztlRiQziN2uAcjAPfGhSisbcVcoDUpwg55QFq7I=
github.com/gol4ng/logger v0.3.0/go.mod h1:br5HY3VkhGzF83IhjDNE+PHkg2rV2Zy2uGPIfVfWZWg=
github.com/gol4ng/logger v0.5.3 h1:gX9fX5Ke1c9ldyIkbHBVux3EJ73FsPsmzWnXT8LEsTo=
github.com/gol4ng/logger v0.5.3/go.mod h1:RU2axpKm//DmUGqQNIhXmUBHKeLdtWarxu8bSV+5b4Y=
github.com/golang/mock v1.4.0 h1:Rd1kQnQu0Hq3qvJppYSG0HtP+f5LPPUiDswTLiEegLg=
github.com/golang/mock v1.4.0/go.mod h1:UOMv5ysSaYNkG+OFQykRIcU/QvvxJf3p21QfJ2Bt3cw=
github.com/golang/protobuf v1.2.0/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U=
github.com/golang/protobuf v1.3.1 h1:YF8+flBXS5eO826T4nzqPrxfhQThhXl0YzfuUPu4SBg=
github.com/golang/protobuf v1.3.1/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U=
Expand All @@ -28,6 +28,11 @@ github.com/json-iterator/go v1.1.6/go.mod h1:+SdeFBvtyEkXs7REEP0seUULqWtbJapLOCV
github.com/julienschmidt/httprouter v1.2.0/go.mod h1:SYymIcj16QtmaHHD7aYtjjsJG7VTCxuUUipMqKk8s4w=
github.com/konsorten/go-windows-terminal-sequences v1.0.1/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ=
github.com/kr/logfmt v0.0.0-20140226030751-b84e30acd515/go.mod h1:+0opPa2QZZtGFBFZlji/RkVcI2GknAs/DXo4wKdlNEc=
github.com/kr/pretty v0.1.0 h1:L/CwN0zerZDmRFUapSPitk6f+Q3+0za1rQkzVuMiMFI=
github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo=
github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ=
github.com/kr/text v0.1.0 h1:45sCR5RtlFHMR4UwH9sdQ5TC8v0qDQCHnXt+kaKSTVE=
github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI=
github.com/matttproud/golang_protobuf_extensions v1.0.1 h1:4hp9jkHxhMHkqkrB3Ix0jegS5sx/RkqARlsWZ6pIwiU=
github.com/matttproud/golang_protobuf_extensions v1.0.1/go.mod h1:D8He9yQNgCq6Z5Ld7szi9bcBfOoFv/3dc6xSMkL2PC0=
github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd/go.mod h1:6dJC0mAP4ikYIbvyc7fijjWJddQyLn8Ig3JB5CqoB9Q=
Expand Down Expand Up @@ -59,17 +64,28 @@ github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UV
github.com/stretchr/testify v1.4.0 h1:2E4SXV/wtOkTonXsotYi4li6zVWxYlZuYNCXe9XRJyk=
github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4=
golang.org/x/crypto v0.0.0-20180904163835-0709b304e793/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4=
golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w=
golang.org/x/net v0.0.0-20181114220301-adae6a3d119a/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4=
golang.org/x/net v0.0.0-20190311183353-d8887717615a/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg=
golang.org/x/sync v0.0.0-20181108010431-42b317875d0f/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
golang.org/x/sync v0.0.0-20181221193216-37e7f081c4d4/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
golang.org/x/sys v0.0.0-20180905080454-ebe1bf3edb33/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
golang.org/x/sys v0.0.0-20181116152217-5ac8a444bdc5 h1:mzjBh+S5frKOsOBobWIMAbXavqjmgO17k/2puhcFR94=
golang.org/x/sys v0.0.0-20181116152217-5ac8a444bdc5/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
golang.org/x/text v0.0.0-20170915032832-14c0d48ead0c/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ=
golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ=
golang.org/x/tools v0.0.0-20190425150028-36563e24a262/go.mod h1:RgjU9mgBXZiqYHBnxXauZ1Gv1EHHAz9KjViQ78xBX0Q=
gopkg.in/alecthomas/kingpin.v2 v2.2.6/go.mod h1:FMv+mEhP44yOT+4EoQTLFTRgOQ1FBLkstjWtayDeSgw=
gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM=
gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127 h1:qIbj1fsPNlZgppZ+VLlY7N33q108Sa+fhmuc+sWQYwY=
gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
gopkg.in/yaml.v2 v2.2.1/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
gopkg.in/yaml.v2 v2.2.2 h1:ZCJp+EgiOT7lHqUV2J862kp8Qj64Jo6az82+3Td9dZw=
gopkg.in/yaml.v2 v2.2.2/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
gotest.tools v2.2.0+incompatible h1:VsBPFP1AI068pPrMxtb/S8Zkgf9xEmTLJjfM+P5UIEo=
gotest.tools v2.2.0+incompatible/go.mod h1:DsYFclhRJ6vuDpmuTbkuFWG+y2sxOXAzmJt81HFBacw=
rsc.io/quote/v3 v3.1.0/go.mod h1:yEA65RcK8LyAZtP9Kv3t0HmxON59tX3rD+tICJqUlj0=
rsc.io/sampler v1.3.0/go.mod h1:T1hPZKmBbMNahiBKFy5HrXp6adAjACjK9JXDnKaTXpA=
64 changes: 40 additions & 24 deletions middleware/correlation_id_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ import (
"github.com/gol4ng/logger"
"github.com/gol4ng/logger/formatter"
"github.com/gol4ng/logger/handler"
testing_logger "github.com/gol4ng/logger/testing"
"github.com/stretchr/testify/assert"

http_middleware "github.com/gol4ng/logger-http/middleware"
Expand All @@ -26,10 +27,7 @@ func TestCorrelationId(t *testing.T) {
rand.New(correlation_id.NewLockedSource(rand.NewSource(1))),
)

loggerOutput := &Output{}
myLogger := logger.NewLogger(
handler.Stream(loggerOutput, formatter.NewDefaultFormatter()),
)
myLogger, store := testing_logger.NewLogger()

request := httptest.NewRequest(http.MethodGet, "http://fake-addr", nil)
request = request.WithContext(logger.InjectInContext(request.Context(), myLogger))
Expand All @@ -41,35 +39,45 @@ func TestCorrelationId(t *testing.T) {
assert.NotEqual(t, request, innerRequest)
assert.Equal(t, "p1LGIehp1s", innerRequest.Header.Get(correlation_id.HeaderName))
handlerRequest = innerRequest
logger.FromContext(innerRequest.Context(), nil).Info("handler info log", nil)
logger.FromContext(innerRequest.Context(), nil).Info("handler info log")
})

myLogger.Info("info log before request", logger.NewContext().Add("ctxvalue", "before"))
myLogger.Info("info log before request", logger.String("ctxvalue", "before"))
http_middleware.CorrelationId()(h).ServeHTTP(responseWriter, request)
myLogger.Info("info log after request", logger.NewContext().Add("ctxvalue", "after"))
myLogger.Info("info log after request", logger.String("ctxvalue", "after"))

respHeaderValue := responseWriter.Header().Get(correlation_id.HeaderName)
reqContextValue := handlerRequest.Context().Value(correlation_id.HeaderName).(string)
assert.Equal(t, "p1LGIehp1s", request.Header.Get(correlation_id.HeaderName))
assert.True(t, len(respHeaderValue) == 10)
assert.True(t, len(reqContextValue) == 10)
assert.True(t, respHeaderValue == reqContextValue)
loggerOutput.Constains(t, []string{
`<info> info log before request {"ctxvalue":"before"}`,
`<info> handler info log {"Correlation-Id":"p1LGIehp1s"}`,
`<info> info log after request {"ctxvalue":"after"}`,
})

entries := store.GetEntries()
assert.Len(t, entries, 3)

entry1 := entries[0]
assert.Equal(t, logger.InfoLevel, entry1.Level)
assert.Equal(t, "info log before request", entry1.Message)
assert.Equal(t, "before", (*entry1.Context)["ctxvalue"].Value)

entry2 := entries[1]
assert.Equal(t, logger.InfoLevel, entry2.Level)
assert.Equal(t, "handler info log", entry2.Message)
assert.Equal(t, "p1LGIehp1s", (*entry2.Context)["Correlation-Id"].Value)

entry3 := entries[2]
assert.Equal(t, logger.InfoLevel, entry3.Level)
assert.Equal(t, "info log after request", entry3.Message)
assert.Equal(t, "after", (*entry3.Context)["ctxvalue"].Value)
}

func TestCorrelationId_WithoutWrappableLogger(t *testing.T) {
correlation_id.DefaultIdGenerator = correlation_id.NewRandomIdGenerator(
rand.New(correlation_id.NewLockedSource(rand.NewSource(1))),
)

loggerOutput := &Output{}
myLogger := logger.NewLogger(
handler.Stream(loggerOutput, formatter.NewDefaultFormatter()),
)
myLogger, store := testing_logger.NewLogger()

request := httptest.NewRequest(http.MethodGet, "http://fake-addr", nil)
// WE DO NOT INJECT LOGGER IN REQUEST CONTEXT
Expand All @@ -85,11 +93,11 @@ func TestCorrelationId_WithoutWrappableLogger(t *testing.T) {
assert.Nil(t, logger.FromContext(innerRequest.Context(), nil))
})

myLogger.Info("info log before request", logger.NewContext().Add("ctxvalue", "before"))
myLogger.Info("info log before request", logger.String("ctxvalue", "before"))
output := getStdout(func() {
http_middleware.CorrelationId()(h).ServeHTTP(responseRecorder, request)
})
myLogger.Info("info log after request", logger.NewContext().Add("ctxvalue", "after"))
myLogger.Info("info log after request", logger.String("ctxvalue", "after"))

respHeaderValue := responseRecorder.Header().Get(correlation_id.HeaderName)
reqContextValue := handlerRequest.Context().Value(correlation_id.HeaderName).(string)
Expand All @@ -100,10 +108,18 @@ func TestCorrelationId_WithoutWrappableLogger(t *testing.T) {
assert.Contains(t, output, "correlationId need a wrappable logger /")
assert.Contains(t, output, "/src/github.com/gol4ng/logger-http/middleware/correlation_id_test.go:")

loggerOutput.Constains(t, []string{
`<info> info log before request {"ctxvalue":"before"}`,
`<info> info log after request {"ctxvalue":"after"}`,
})
entries := store.GetEntries()
assert.Len(t, entries, 2)

entry1 := entries[0]
assert.Equal(t, logger.InfoLevel, entry1.Level)
assert.Equal(t, "info log before request", entry1.Message)
assert.Equal(t, "before", (*entry1.Context)["ctxvalue"].Value)

entry2 := entries[1]
assert.Equal(t, logger.InfoLevel, entry2.Level)
assert.Equal(t, "info log after request", entry2.Message)
assert.Equal(t, "after", (*entry2.Context)["ctxvalue"].Value)
}

// Use to get os.Stdout
Expand Down Expand Up @@ -147,7 +163,7 @@ func ExampleCorrelationId() {
port := ":5001"

myLogger := logger.NewLogger(
handler.Stream(os.Stdout, formatter.NewDefaultFormatter()),
handler.Stream(os.Stdout, formatter.NewDefaultFormatter(formatter.WithContext(true))),
)

// we recommend to use MiddlewareStack to simplify managing all wanted middlewares
Expand All @@ -164,7 +180,7 @@ func ExampleCorrelationId() {

h := http.HandlerFunc(func(writer http.ResponseWriter, innerRequest *http.Request) {
l := logger.FromContext(innerRequest.Context(), myLogger)
l.Info("handler log info", nil)
l.Info("handler log info")
})

go func() {
Expand Down
8 changes: 4 additions & 4 deletions middleware/logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -30,25 +30,25 @@ func Logger(log logger.LoggerInterface, opts ...logger_http.Option) httpware.Mid

if err := recover(); err != nil {
currentLoggerContext.Add("http_panic", err)
_ = currentLogger.Critical(fmt.Sprintf("http server panic %s %s [duration:%s]", req.Method, req.URL, duration), currentLoggerContext)
currentLogger.Critical(fmt.Sprintf("http server panic %s %s [duration:%s]", req.Method, req.URL, duration), *currentLoggerContext.Slice()...)
panic(err)
}

currentLoggerContext.Add("http_status", http.StatusText(writerInterceptor.StatusCode)).
Add("http_status_code", writerInterceptor.StatusCode).
Add("http_response_length", len(writerInterceptor.Body))

_ = currentLogger.Log(
currentLogger.Log(
fmt.Sprintf(
"http server %s %s [status_code:%d, duration:%s, content_length:%d]",
req.Method, req.URL, writerInterceptor.StatusCode, duration, len(writerInterceptor.Body),
),
o.LevelFunc(writerInterceptor.StatusCode),
currentLoggerContext,
*currentLoggerContext.Slice()...,
)
}()

_ = currentLogger.Debug(fmt.Sprintf("http server received %s %s", req.Method, req.URL), currentLoggerContext)
currentLogger.Debug(fmt.Sprintf("http server received %s %s", req.Method, req.URL), *currentLoggerContext.Slice()...)
next.ServeHTTP(writerInterceptor, req)
})
}
Expand Down
Loading

0 comments on commit 3703605

Please sign in to comment.