From e42a7bc45c8302ea45e961acf2622f1b9edfa965 Mon Sep 17 00:00:00 2001
From: Will McCutchen <will@mccutch.org>
Date: Tue, 15 Jan 2019 17:00:10 -0800
Subject: [PATCH] Support pluggable request observer (#11)
Add support for an observer that will be called with the result of each
request handled, which can be used to log or otherwise instrument
the service.
---
cmd/go-httpbin/main.go | 12 ++++++----
httpbin/handlers_test.go | 6 ++++-
httpbin/httpbin.go | 14 ++++++++++-
httpbin/httpbin_test.go | 36 +++++++++++++++++++++++++++-
httpbin/middleware.go | 51 ++++++++++++++++++++++++++++++++++------
5 files changed, 104 insertions(+), 15 deletions(-)
diff --git a/cmd/go-httpbin/main.go b/cmd/go-httpbin/main.go
index d4fbf2e..fecdcaf 100644
--- a/cmd/go-httpbin/main.go
+++ b/cmd/go-httpbin/main.go
@@ -27,8 +27,6 @@ func main() {
flag.DurationVar(&maxDuration, "max-duration", httpbin.DefaultMaxDuration, "Maximum duration a response may take")
flag.Parse()
- log.SetFlags(log.Ldate | log.Lmicroseconds | log.LUTC)
-
// Command line flags take precedence over environment vars, so we only
// check for environment vars if we have default values for our command
// line flags.
@@ -58,11 +56,15 @@ func main() {
}
}
+ logger := log.New(os.Stderr, "", 0)
+
h := httpbin.New(
httpbin.WithMaxBodySize(maxBodySize),
- httpbin.WithMaxDuration(maxDuration))
+ httpbin.WithMaxDuration(maxDuration),
+ httpbin.WithObserver(httpbin.StdLogObserver(logger)),
+ )
listenAddr := net.JoinHostPort("0.0.0.0", strconv.Itoa(port))
- log.Printf("addr=%s", listenAddr)
- log.Fatal(http.ListenAndServe(listenAddr, h.Handler()))
+ logger.Printf("go-httpbin listening on %s", listenAddr)
+ http.ListenAndServe(listenAddr, h.Handler())
}
diff --git a/httpbin/handlers_test.go b/httpbin/handlers_test.go
index 00c094c..901c7bb 100644
--- a/httpbin/handlers_test.go
+++ b/httpbin/handlers_test.go
@@ -8,10 +8,12 @@ import (
"encoding/json"
"fmt"
"io/ioutil"
+ "log"
"mime/multipart"
"net/http"
"net/http/httptest"
"net/url"
+ "os"
"reflect"
"strconv"
"strings"
@@ -24,7 +26,9 @@ const maxDuration time.Duration = 1 * time.Second
var app = New(
WithMaxBodySize(maxBodySize),
- WithMaxDuration(maxDuration))
+ WithMaxDuration(maxDuration),
+ WithObserver(StdLogObserver(log.New(os.Stderr, "", 0))),
+)
var handler = app.Handler()
diff --git a/httpbin/httpbin.go b/httpbin/httpbin.go
index 37f0601..e42ee2b 100644
--- a/httpbin/httpbin.go
+++ b/httpbin/httpbin.go
@@ -84,6 +84,9 @@ type HTTPBin struct {
// Max duration of a request, for those requests that allow user control
// over timing (e.g. /delay)
MaxDuration time.Duration
+
+ // Observer called with the result of each handled request
+ Observer Observer
}
// Handler returns an http.Handler that exposes all HTTPBin endpoints
@@ -169,7 +172,9 @@ func (h *HTTPBin) Handler() http.Handler {
handler = mux
handler = limitRequestSize(h.MaxBodySize, handler)
handler = metaRequests(handler)
- handler = logger(handler)
+ if h.Observer != nil {
+ handler = observe(h.Observer, handler)
+ }
return handler
}
@@ -202,3 +207,10 @@ func WithMaxDuration(d time.Duration) OptionFunc {
h.MaxDuration = d
}
}
+
+// WithObserver sets the request observer callback
+func WithObserver(o Observer) OptionFunc {
+ return func(h *HTTPBin) {
+ h.Observer = o
+ }
+}
diff --git a/httpbin/httpbin_test.go b/httpbin/httpbin_test.go
index 1d0d4fc..a3f500c 100644
--- a/httpbin/httpbin_test.go
+++ b/httpbin/httpbin_test.go
@@ -1,6 +1,9 @@
package httpbin
import (
+ "fmt"
+ "net/http"
+ "net/http/httptest"
"testing"
"time"
)
@@ -13,15 +16,21 @@ func TestNew(t *testing.T) {
if h.MaxDuration != DefaultMaxDuration {
t.Fatalf("expected default MaxDuration == %s, got %#v", DefaultMaxDuration, h.MaxDuration)
}
+ if h.Observer != nil {
+ t.Fatalf("expected default Observer == nil, got %#v", h.Observer)
+ }
}
func TestNewOptions(t *testing.T) {
maxDuration := 1 * time.Second
maxBodySize := int64(1024)
+ observer := func(_ Result) {}
h := New(
WithMaxBodySize(maxBodySize),
- WithMaxDuration(maxDuration))
+ WithMaxDuration(maxDuration),
+ WithObserver(observer),
+ )
if h.MaxBodySize != maxBodySize {
t.Fatalf("expected MaxBodySize == %d, got %#v", maxBodySize, h.MaxBodySize)
@@ -29,4 +38,29 @@ func TestNewOptions(t *testing.T) {
if h.MaxDuration != maxDuration {
t.Fatalf("expected MaxDuration == %s, got %#v", maxDuration, h.MaxDuration)
}
+ if h.Observer == nil {
+ t.Fatalf("expected non-nil Observer")
+ }
+}
+
+func TestNewObserver(t *testing.T) {
+ expectedStatus := http.StatusTeapot
+
+ observed := false
+ observer := func(r Result) {
+ observed = true
+ if r.Status != expectedStatus {
+ t.Fatalf("expected result status = %d, got %d", expectedStatus, r.Status)
+ }
+ }
+
+ h := New(WithObserver(observer))
+
+ r, _ := http.NewRequest("GET", fmt.Sprintf("/status/%d", expectedStatus), nil)
+ w := httptest.NewRecorder()
+ h.Handler().ServeHTTP(w, r)
+
+ if observed == false {
+ t.Fatalf("observer never called")
+ }
}
diff --git a/httpbin/middleware.go b/httpbin/middleware.go
index 60033fa..c604130 100644
--- a/httpbin/middleware.go
+++ b/httpbin/middleware.go
@@ -67,12 +67,12 @@ func limitRequestSize(maxSize int64, h http.Handler) http.Handler {
type metaResponseWriter struct {
w http.ResponseWriter
status int
- size int
+ size int64
}
func (mw *metaResponseWriter) Write(b []byte) (int, error) {
size, err := mw.w.Write(b)
- mw.size += size
+ mw.size += int64(size)
return size, err
}
@@ -97,17 +97,54 @@ func (mw *metaResponseWriter) Status() int {
return mw.status
}
-func (mw *metaResponseWriter) Size() int {
+func (mw *metaResponseWriter) Size() int64 {
return mw.size
}
-func logger(h http.Handler) http.Handler {
+func observe(o Observer, h http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
- reqMethod, reqURI := r.Method, r.URL.RequestURI()
mw := &metaResponseWriter{w: w}
t := time.Now()
h.ServeHTTP(mw, r)
- duration := time.Now().Sub(t)
- log.Printf("status=%d method=%s uri=%q size=%d duration=%s", mw.Status(), reqMethod, reqURI, mw.Size(), duration)
+ o(Result{
+ Status: mw.Status(),
+ Method: r.Method,
+ URI: r.URL.RequestURI(),
+ Size: mw.Size(),
+ Duration: time.Now().Sub(t),
+ })
})
}
+
+// Result is the result of handling a request, used for instrumentation
+type Result struct {
+ Status int
+ Method string
+ URI string
+ Size int64
+ Duration time.Duration
+}
+
+// Observer is a function that will be called with the details of a handled
+// request, which can be used for logging, instrumentation, etc
+type Observer func(result Result)
+
+// StdLogObserver creates an Observer that will log each request in structured
+// format using the given stdlib logger
+func StdLogObserver(l *log.Logger) Observer {
+ const (
+ logFmt = "time=%q status=%d method=%q uri=%q size_bytes=%d duration_ms=%0.02f"
+ dateFmt = "2006-01-02T15:04:05.9999"
+ )
+ return func(result Result) {
+ l.Printf(
+ logFmt,
+ time.Now().Format(dateFmt),
+ result.Status,
+ result.Method,
+ result.URI,
+ result.Size,
+ result.Duration.Seconds()*1e3, // https://github.com/golang/go/issues/5491#issuecomment-66079585
+ )
+ }
+}
--
GitLab