From 1ef9de6aedc4584be97cc818c0a4d9654a4db39e Mon Sep 17 00:00:00 2001
From: Nathaniel Cook <nvcook42@gmail.com>
Date: Mon, 30 Jul 2018 16:16:37 -0600
Subject: [PATCH] feat: Add optional http logging to handler

---
 cmd/fluxd/main.go |  1 +
 http/handler.go   | 26 ++++++++++++++++++++------
 http/status.go    | 14 +++++++++++---
 3 files changed, 32 insertions(+), 9 deletions(-)

diff --git a/cmd/fluxd/main.go b/cmd/fluxd/main.go
index f184650631..3a760ce0cb 100644
--- a/cmd/fluxd/main.go
+++ b/cmd/fluxd/main.go
@@ -117,6 +117,7 @@ func fluxF(cmd *cobra.Command, args []string) {
 
 	handler := http.NewHandlerFromRegistry("query", reg)
 	handler.Handler = queryHandler
+	handler.Logger = logger
 
 	logger.Info("listening", zap.String("transport", "http"), zap.String("addr", bindAddr))
 	if err := nethttp.ListenAndServe(bindAddr, handler); err != nil {
diff --git a/http/handler.go b/http/handler.go
index 8127acfcbd..74b85680dd 100644
--- a/http/handler.go
+++ b/http/handler.go
@@ -11,6 +11,7 @@ import (
 	"github.com/influxdata/platform/kit/prom"
 	"github.com/prometheus/client_golang/prometheus"
 	"github.com/prometheus/client_golang/prometheus/promhttp"
+	"go.uber.org/zap"
 )
 
 const (
@@ -34,6 +35,9 @@ type Handler struct {
 
 	requests   *prometheus.CounterVec
 	requestDur *prometheus.HistogramVec
+
+	// Logger if set will log all HTTP requests as they are served
+	Logger *zap.Logger
 }
 
 // NewHandler creates a new handler with the given name.
@@ -73,21 +77,31 @@ func (h *Handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	w = statusW
 
 	// TODO: This could be problematic eventually. But for now it should be fine.
-	defer func() {
+	defer func(start time.Time) {
+		duration := time.Since(start)
+		statusClass := statusW.statusCodeClass()
+		statusCode := statusW.code()
 		h.requests.With(prometheus.Labels{
 			"handler": h.name,
 			"method":  r.Method,
 			"path":    r.URL.Path,
-			"status":  statusW.statusCodeClass(),
+			"status":  statusClass,
 		}).Inc()
-	}()
-	defer func(start time.Time) {
 		h.requestDur.With(prometheus.Labels{
 			"handler": h.name,
 			"method":  r.Method,
 			"path":    r.URL.Path,
-			"status":  statusW.statusCodeClass(),
-		}).Observe(time.Since(start).Seconds())
+			"status":  statusClass,
+		}).Observe(duration.Seconds())
+		if h.Logger != nil {
+			h.Logger.Info("served http request",
+				zap.String("handler", h.name),
+				zap.String("method", r.Method),
+				zap.String("path", r.URL.Path),
+				zap.Int("status", statusCode),
+				zap.Int("duration_ns", int(duration)),
+			)
+		}
 	}(time.Now())
 
 	switch {
diff --git a/http/status.go b/http/status.go
index fb2215de6a..cf734834ab 100644
--- a/http/status.go
+++ b/http/status.go
@@ -19,13 +19,21 @@ func (w *statusResponseWriter) WriteHeader(statusCode int) {
 	w.ResponseWriter.WriteHeader(statusCode)
 }
 
+func (w *statusResponseWriter) code() int {
+	code := w.statusCode
+	if code == 0 {
+		// When statusCode is 0 then WriteHeader was never called and we can assume that
+		// the ResponseWriter wrote an http.StatusOK.
+		code = http.StatusOK
+	}
+	return code
+}
 func (w *statusResponseWriter) statusCodeClass() string {
 	class := "XXX"
-	switch w.statusCode / 100 {
+	switch w.code() / 100 {
 	case 1:
 		class = "1XX"
-	case 0, 2:
-		// When statusCode is 0 then WriteHeader was never called and we can assume that the ResponseWriter wrote an http.StatusOK.
+	case 2:
 		class = "2XX"
 	case 3:
 		class = "3XX"