pomerium/internal/log/handler_log_test.go
Bobby DeSimone 426e003b03
proxy: add JWT request signing support (#19)
- Refactored middleware and request hander logging.
- Request refactored to use context.Context.
- Add helper (based on Alice) to allow middleware chaining.
- Add helper scripts to generate elliptic curve self-signed certificate that can be used to sign JWT.
- Changed LetsEncrypt scripts to use acme instead of certbot.
- Add script to have LetsEncrypt sign an RSA based certificate.
- Add documentation to explain how to verify headers.
- Refactored internal/cryptutil signer's code to expect a valid EC priv key.
- Changed JWT expiries to use default leeway period.
- Update docs and add screenshots.
- Replaced logging handler logic to use context.Context.
- Removed specific XML error handling.
- Refactored handler function signatures to prefer standard go idioms.
2019-01-22 21:44:22 -08:00

260 lines
7.2 KiB
Go

// Package log provides a set of http.Handler helpers for zerolog.
package log // import "github.com/pomerium/pomerium/internal/log"
import (
"bytes"
"fmt"
"io/ioutil"
"net/http"
"net/http/httptest"
"net/url"
"reflect"
"regexp"
"testing"
"github.com/rs/zerolog"
)
func TestGenerateUUID(t *testing.T) {
prev := uuid()
for i := 0; i < 100; i++ {
id := uuid()
if id == "" {
t.Fatal("random pool failure")
}
if prev == id {
t.Fatalf("Should get a new ID!")
}
matched, err := regexp.MatchString("[a-fA-F0-9]{8}-[a-fA-F0-9]{4}-[a-fA-F0-9]{4}-[a-fA-F0-9]{4}-[a-fA-F0-9]{12}", id)
if !matched || err != nil {
t.Fatalf("expected match %s %v %s", id, matched, err)
}
}
}
func decodeIfBinary(out *bytes.Buffer) string {
// p := out.Bytes()
// if len(p) == 0 || p[0] < 0x7F {
// return out.String()
// }
return out.String() //cbor.DecodeObjectToStr(p) + "\n"
}
func TestNewHandler(t *testing.T) {
log := zerolog.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("")
}))
h = NewHandler(zerolog.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("")
}))
h = NewHandler(zerolog.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("")
}))
h = NewHandler(zerolog.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("")
}))
h = NewHandler(zerolog.New(out))(h)
h.ServeHTTP(nil, r)
if want, got := `{"ip":"1.2.3.4"}`+"\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("")
}))
h = NewHandler(zerolog.New(out))(h)
h.ServeHTTP(nil, r)
if want, got := `{"ip":"2001:db8:a0b:12f0::1"}`+"\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("")
}))
h = NewHandler(zerolog.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("")
}))
h = NewHandler(zerolog.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)
}
}))
h = NewHandler(zerolog.New(out))(h)
h.ServeHTTP(httptest.NewRecorder(), r)
}
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("")
}))))
h = NewHandler(zerolog.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{
"Single": NewHandler(zerolog.New(ioutil.Discard))(h1),
"Combined": NewHandler(zerolog.New(ioutil.Discard))(h2),
"SingleDisabled": NewHandler(zerolog.New(ioutil.Discard).Level(zerolog.Disabled))(h1),
"CombinedDisabled": NewHandler(zerolog.New(ioutil.Discard).Level(zerolog.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) {
log := zerolog.New(nil).With().
Str("foo", "bar").
Logger()
lh := NewHandler(log)
h := lh(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
l := FromRequest(r)
l.UpdateContext(func(c zerolog.Context) zerolog.Context {
return c.Str("bar", "baz")
})
l.Log().Msg("")
}))
b.RunParallel(func(pb *testing.PB) {
for pb.Next() {
h.ServeHTTP(nil, &http.Request{})
}
})
}