From edfa256311e7c47ed28bb5be9d36f06ddde9b589 Mon Sep 17 00:00:00 2001 From: Johnny Steenbergen Date: Sat, 13 Jan 2024 22:34:04 -0600 Subject: [PATCH] chore(allsrv): add http server observability The HTTP server now has quantification for different metrics important to an HTTP server. The basis of our observability is now in place. We can now create dashboards/insights to understand the deployed service. One thing to note here is we have not touched on logging just yet. Good logging is inherently coupled to good error handling. We'll wait until we have a better handle of our error handling before proceeding. --- allsrv/observer_http_handler.go | 110 ++++++++++++++++++++++++++++++++ allsrv/server.go | 4 +- allsrv/server_test.go | 24 ++++--- 3 files changed, 128 insertions(+), 10 deletions(-) create mode 100644 allsrv/observer_http_handler.go diff --git a/allsrv/observer_http_handler.go b/allsrv/observer_http_handler.go new file mode 100644 index 0000000..da951da --- /dev/null +++ b/allsrv/observer_http_handler.go @@ -0,0 +1,110 @@ +package allsrv + +import ( + "io" + "net/http" + "strconv" + "time" + + "github.com/hashicorp/go-metrics" + "github.com/opentracing/opentracing-go" + "github.com/opentracing/opentracing-go/log" +) + +// ObserveHandler provides observability to an http handler. +func ObserveHandler(name string, met *metrics.Metrics) func(http.Handler) http.Handler { + return func(next http.Handler) http.Handler { + return &handlerMW{ + name: name, + next: next, + met: met, + } + } +} + +type handlerMW struct { + name string + next http.Handler + met *metrics.Metrics +} + +func (h *handlerMW) ServeHTTP(w http.ResponseWriter, r *http.Request) { + span, ctx := opentracing.StartSpanFromContext(r.Context(), "http_request_"+h.name) + defer span.Finish() + span.LogFields(log.String("url_path", r.URL.Path)) + + start := time.Now() + name := []string{metricsPrefix, h.name, r.URL.Path} + + labels := []metrics.Label{ + { + Name: "method", + Value: r.Method, + }, + { + Name: "url_path", + Value: r.URL.Path, + }, + } + + h.met.IncrCounterWithLabels(append(name, "reqs"), 1, labels) + + reqBody := &readRec{ReadCloser: r.Body} + r.Body = reqBody + + rec := &responseWriterRec{ResponseWriter: w} + + h.next.ServeHTTP(rec, r.WithContext(ctx)) + + if rec.code == 0 { + rec.code = http.StatusOK + } + + labels = append(labels, + metrics.Label{ + Name: "status", + Value: strconv.Itoa(rec.code), + }, + metrics.Label{ + Name: "request_body_size", + Value: strconv.Itoa(reqBody.size), + }, + metrics.Label{ + Name: "response_body_size", + Value: strconv.Itoa(rec.size), + }, + ) + if rec.code > 299 { + h.met.IncrCounterWithLabels(append(name, "errs"), 1, labels) + } + + h.met.MeasureSinceWithLabels(append(name, "dur"), start, labels) +} + +type readRec struct { + size int + io.ReadCloser +} + +func (r *readRec) Read(p []byte) (int, error) { + n, err := r.ReadCloser.Read(p) + r.size += n + return n, err +} + +type responseWriterRec struct { + size int + code int + http.ResponseWriter +} + +func (r *responseWriterRec) Write(b []byte) (int, error) { + n, err := r.ResponseWriter.Write(b) + r.size += n + return n, err +} + +func (r *responseWriterRec) WriteHeader(statusCode int) { + r.code = statusCode + r.ResponseWriter.WriteHeader(statusCode) +} diff --git a/allsrv/server.go b/allsrv/server.go index 49f5dd3..63bedc8 100644 --- a/allsrv/server.go +++ b/allsrv/server.go @@ -34,9 +34,9 @@ import ( a) there is nothing actionable, so how does the consumer know to handle the error? b) if the APIs evolve, how does the consumer distinguish between old and new? 10) Observability.... - a) metrics + ✅a) metrics b) logging - c) tracing + ✅c) tracing ✅11) hard coding UUID generation into db 12) possible race conditions in inmem store ✅13) there is a bug in the delete foo inmem db implementation diff --git a/allsrv/server_test.go b/allsrv/server_test.go index ca99f21..97724c5 100644 --- a/allsrv/server_test.go +++ b/allsrv/server_test.go @@ -19,13 +19,15 @@ import ( func TestServer(t *testing.T) { t.Run("foo create", func(t *testing.T) { t.Run("when provided a valid foo should pass", func(t *testing.T) { - db := allsrv.ObserveDB("inmem", newTestMetrics(t))(new(allsrv.InmemDB)) - svr := allsrv.NewServer(db, + met := newTestMetrics(t) + db := allsrv.ObserveDB("inmem", met)(new(allsrv.InmemDB)) + var svr http.Handler = allsrv.NewServer(db, allsrv.WithBasicAuth("dodgers@stink.com", "PaSsWoRd"), allsrv.WithIDFn(func() string { return "id1" }), ) + svr = allsrv.ObserveHandler("allsrv", met)(svr) req := httptest.NewRequest("POST", "/foo", newJSONBody(t, allsrv.Foo{ Name: "first-foo", @@ -65,7 +67,8 @@ func TestServer(t *testing.T) { t.Run("foo read", func(t *testing.T) { t.Run("when querying for existing foo id should pass", func(t *testing.T) { - db := allsrv.ObserveDB("inmem", newTestMetrics(t))(new(allsrv.InmemDB)) + met := newTestMetrics(t) + db := allsrv.ObserveDB("inmem", met)(new(allsrv.InmemDB)) err := db.CreateFoo(context.TODO(), allsrv.Foo{ ID: "reader1", Name: "read", @@ -73,7 +76,8 @@ func TestServer(t *testing.T) { }) require.NoError(t, err) - svr := allsrv.NewServer(db, allsrv.WithBasicAuth("dodgers@stink.com", "PaSsWoRd")) + var svr http.Handler = allsrv.NewServer(db, allsrv.WithBasicAuth("dodgers@stink.com", "PaSsWoRd")) + svr = allsrv.ObserveHandler("allsrv", met)(svr) req := httptest.NewRequest("GET", "/foo?id=reader1", nil) req.SetBasicAuth("dodgers@stink.com", "PaSsWoRd") @@ -107,7 +111,8 @@ func TestServer(t *testing.T) { t.Run("foo update", func(t *testing.T) { t.Run("when updating an existing foo with valid changes should pass", func(t *testing.T) { - db := allsrv.ObserveDB("inmem", newTestMetrics(t))(new(allsrv.InmemDB)) + met := newTestMetrics(t) + db := allsrv.ObserveDB("inmem", met)(new(allsrv.InmemDB)) err := db.CreateFoo(context.TODO(), allsrv.Foo{ ID: "id1", Name: "first_name", @@ -115,7 +120,8 @@ func TestServer(t *testing.T) { }) require.NoError(t, err) - svr := allsrv.NewServer(db, allsrv.WithBasicAuth("dodgers@stink.com", "PaSsWoRd")) + var svr http.Handler = allsrv.NewServer(db, allsrv.WithBasicAuth("dodgers@stink.com", "PaSsWoRd")) + svr = allsrv.ObserveHandler("allsrv", met)(svr) req := httptest.NewRequest("PUT", "/foo", newJSONBody(t, allsrv.Foo{ ID: "id1", @@ -158,7 +164,8 @@ func TestServer(t *testing.T) { t.Run("foo delete", func(t *testing.T) { t.Run("when deleting an existing foo should pass", func(t *testing.T) { - db := allsrv.ObserveDB("inmem", newTestMetrics(t))(new(allsrv.InmemDB)) + met := newTestMetrics(t) + db := allsrv.ObserveDB("inmem", met)(new(allsrv.InmemDB)) err := db.CreateFoo(context.TODO(), allsrv.Foo{ ID: "id1", Name: "first_name", @@ -166,7 +173,8 @@ func TestServer(t *testing.T) { }) require.NoError(t, err) - svr := allsrv.NewServer(db, allsrv.WithBasicAuth("dodgers@stink.com", "PaSsWoRd")) + var svr http.Handler = allsrv.NewServer(db, allsrv.WithBasicAuth("dodgers@stink.com", "PaSsWoRd")) + svr = allsrv.ObserveHandler("allsrv", met)(svr) req := httptest.NewRequest("DELETE", "/foo?id=id1", nil) req.SetBasicAuth("dodgers@stink.com", "PaSsWoRd")