zlog/hlog/hlog_test.go

278 lines
7.5 KiB
Go
Raw Permalink Normal View History

// +build go1.7
package hlog
import (
"bytes"
"context"
"fmt"
"io/ioutil"
"net/http"
"net/http/httptest"
"net/url"
"reflect"
"testing"
"github.com/rs/xid"
2022-03-20 19:19:42 +00:00
"git.tuxpa.in/a/zlog"
"git.tuxpa.in/a/zlog/internal/cbor"
)
func decodeIfBinary(out *bytes.Buffer) string {
p := out.Bytes()
if len(p) == 0 || p[0] < 0x7F {
return out.String()
}
return cbor.DecodeObjectToStr(p) + "\n"
}
func TestNewHandler(t *testing.T) {
2022-03-20 19:19:42 +00:00
log := zlog.New(nil).With().
Str("foo", "bar").
Logger()
lh := NewHandler(log)
h := lh(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
l := FromRequest(r)
if !reflect.DeepEqual(*l, log) {
t.Fail()
}
}))
h.ServeHTTP(nil, &http.Request{})
}
func TestURLHandler(t *testing.T) {
out := &bytes.Buffer{}
r := &http.Request{
URL: &url.URL{Path: "/path", RawQuery: "foo=bar"},
}
h := URLHandler("url")(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
l := FromRequest(r)
l.Log().Msg("")
}))
2022-03-20 19:19:42 +00:00
h = NewHandler(zlog.New(out))(h)
h.ServeHTTP(nil, r)
if want, got := `{"url":"/path?foo=bar"}`+"\n", decodeIfBinary(out); want != got {
t.Errorf("Invalid log output, got: %s, want: %s", got, want)
}
}
func TestMethodHandler(t *testing.T) {
out := &bytes.Buffer{}
r := &http.Request{
Method: "POST",
}
h := MethodHandler("method")(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
l := FromRequest(r)
l.Log().Msg("")
}))
2022-03-20 19:19:42 +00:00
h = NewHandler(zlog.New(out))(h)
h.ServeHTTP(nil, r)
if want, got := `{"method":"POST"}`+"\n", decodeIfBinary(out); want != got {
t.Errorf("Invalid log output, got: %s, want: %s", got, want)
}
}
func TestRequestHandler(t *testing.T) {
out := &bytes.Buffer{}
r := &http.Request{
Method: "POST",
URL: &url.URL{Path: "/path", RawQuery: "foo=bar"},
}
h := RequestHandler("request")(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
l := FromRequest(r)
l.Log().Msg("")
}))
2022-03-20 19:19:42 +00:00
h = NewHandler(zlog.New(out))(h)
h.ServeHTTP(nil, r)
if want, got := `{"request":"POST /path?foo=bar"}`+"\n", decodeIfBinary(out); want != got {
t.Errorf("Invalid log output, got: %s, want: %s", got, want)
}
}
func TestRemoteAddrHandler(t *testing.T) {
out := &bytes.Buffer{}
r := &http.Request{
RemoteAddr: "1.2.3.4:1234",
}
h := RemoteAddrHandler("ip")(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
l := FromRequest(r)
l.Log().Msg("")
}))
2022-03-20 19:19:42 +00:00
h = NewHandler(zlog.New(out))(h)
h.ServeHTTP(nil, r)
if want, got := `{"ip":"1.2.3.4:1234"}`+"\n", decodeIfBinary(out); want != got {
t.Errorf("Invalid log output, got: %s, want: %s", got, want)
}
}
func TestRemoteAddrHandlerIPv6(t *testing.T) {
out := &bytes.Buffer{}
r := &http.Request{
RemoteAddr: "[2001:db8:a0b:12f0::1]:1234",
}
h := RemoteAddrHandler("ip")(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
l := FromRequest(r)
l.Log().Msg("")
}))
2022-03-20 19:19:42 +00:00
h = NewHandler(zlog.New(out))(h)
h.ServeHTTP(nil, r)
if want, got := `{"ip":"[2001:db8:a0b:12f0::1]:1234"}`+"\n", decodeIfBinary(out); want != got {
t.Errorf("Invalid log output, got: %s, want: %s", got, want)
}
}
func TestUserAgentHandler(t *testing.T) {
out := &bytes.Buffer{}
r := &http.Request{
Header: http.Header{
"User-Agent": []string{"some user agent string"},
},
}
h := UserAgentHandler("ua")(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
l := FromRequest(r)
l.Log().Msg("")
}))
2022-03-20 19:19:42 +00:00
h = NewHandler(zlog.New(out))(h)
h.ServeHTTP(nil, r)
if want, got := `{"ua":"some user agent string"}`+"\n", decodeIfBinary(out); want != got {
t.Errorf("Invalid log output, got: %s, want: %s", got, want)
}
}
func TestRefererHandler(t *testing.T) {
out := &bytes.Buffer{}
r := &http.Request{
Header: http.Header{
"Referer": []string{"http://foo.com/bar"},
},
}
h := RefererHandler("referer")(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
l := FromRequest(r)
l.Log().Msg("")
}))
2022-03-20 19:19:42 +00:00
h = NewHandler(zlog.New(out))(h)
h.ServeHTTP(nil, r)
if want, got := `{"referer":"http://foo.com/bar"}`+"\n", decodeIfBinary(out); want != got {
t.Errorf("Invalid log output, got: %s, want: %s", got, want)
}
}
func TestRequestIDHandler(t *testing.T) {
out := &bytes.Buffer{}
r := &http.Request{
Header: http.Header{
"Referer": []string{"http://foo.com/bar"},
},
}
h := RequestIDHandler("id", "Request-Id")(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
id, ok := IDFromRequest(r)
if !ok {
t.Fatal("Missing id in request")
}
if want, got := id.String(), w.Header().Get("Request-Id"); got != want {
t.Errorf("Invalid Request-Id header, got: %s, want: %s", got, want)
}
l := FromRequest(r)
l.Log().Msg("")
if want, got := fmt.Sprintf(`{"id":"%s"}`+"\n", id), decodeIfBinary(out); want != got {
t.Errorf("Invalid log output, got: %s, want: %s", got, want)
}
}))
2022-03-20 19:19:42 +00:00
h = NewHandler(zlog.New(out))(h)
h.ServeHTTP(httptest.NewRecorder(), r)
}
2019-11-04 18:14:00 +00:00
func TestCustomHeaderHandler(t *testing.T) {
out := &bytes.Buffer{}
r := &http.Request{
Header: http.Header{
"X-Request-Id": []string{"514bbe5bb5251c92bd07a9846f4a1ab6"},
},
}
h := CustomHeaderHandler("reqID", "X-Request-Id")(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
l := FromRequest(r)
l.Log().Msg("")
}))
2022-03-20 19:19:42 +00:00
h = NewHandler(zlog.New(out))(h)
2019-11-04 18:14:00 +00:00
h.ServeHTTP(nil, r)
if want, got := `{"reqID":"514bbe5bb5251c92bd07a9846f4a1ab6"}`+"\n", decodeIfBinary(out); want != got {
t.Errorf("Invalid log output, got: %s, want: %s", got, want)
}
}
func TestCombinedHandlers(t *testing.T) {
out := &bytes.Buffer{}
r := &http.Request{
Method: "POST",
URL: &url.URL{Path: "/path", RawQuery: "foo=bar"},
}
h := MethodHandler("method")(RequestHandler("request")(URLHandler("url")(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
l := FromRequest(r)
l.Log().Msg("")
}))))
2022-03-20 19:19:42 +00:00
h = NewHandler(zlog.New(out))(h)
h.ServeHTTP(nil, r)
if want, got := `{"method":"POST","request":"POST /path?foo=bar","url":"/path?foo=bar"}`+"\n", decodeIfBinary(out); want != got {
t.Errorf("Invalid log output, got: %s, want: %s", got, want)
}
}
func BenchmarkHandlers(b *testing.B) {
r := &http.Request{
Method: "POST",
URL: &url.URL{Path: "/path", RawQuery: "foo=bar"},
}
h1 := URLHandler("url")(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
l := FromRequest(r)
l.Log().Msg("")
}))
h2 := MethodHandler("method")(RequestHandler("request")(h1))
handlers := map[string]http.Handler{
2022-03-20 19:19:42 +00:00
"Single": NewHandler(zlog.New(ioutil.Discard))(h1),
"Combined": NewHandler(zlog.New(ioutil.Discard))(h2),
"SingleDisabled": NewHandler(zlog.New(ioutil.Discard).Level(zlog.Disabled))(h1),
"CombinedDisabled": NewHandler(zlog.New(ioutil.Discard).Level(zlog.Disabled))(h2),
}
for name := range handlers {
h := handlers[name]
b.Run(name, func(b *testing.B) {
for i := 0; i < b.N; i++ {
h.ServeHTTP(nil, r)
}
})
}
}
func BenchmarkDataRace(b *testing.B) {
2022-03-20 19:19:42 +00:00
log := zlog.New(nil).With().
Str("foo", "bar").
Logger()
lh := NewHandler(log)
h := lh(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
l := FromRequest(r)
2022-03-20 19:19:42 +00:00
l.UpdateContext(func(c zlog.Context) zlog.Context {
return c.Str("bar", "baz")
})
l.Log().Msg("")
}))
b.RunParallel(func(pb *testing.PB) {
for pb.Next() {
h.ServeHTTP(nil, &http.Request{})
}
})
}
func TestCtxWithID(t *testing.T) {
ctx := context.Background()
id, _ := xid.FromString(`c0umremcie6smuu506pg`)
want := context.Background()
want = context.WithValue(want, idKey{}, id)
if got := CtxWithID(ctx, id); !reflect.DeepEqual(got, want) {
t.Errorf("CtxWithID() = %v, want %v", got, want)
}
}