Log remote host names if available

log/log.go

@@ -2,6 +2,7 @@ package log
 
 import (
 	"context"
+	"net"
 	"net/http"
 	"time"
 
@@ -21,10 +22,18 @@ func Request(next http.Handler, logger log.Logger) http.Handler {
 			remote = r.RemoteAddr
 		}
 
+		// Try to figure out a name for the remote. If there are multiple, we select the first.
+		names, err := net.LookupAddr(remote)
+		if err != nil {
+			// Can't resolve name, but that's ok. There might not be a PTR record for the remote.
+			names = []string{"n/a"}
+		}
+
 		l := log.With(logger,
 			"method", r.Method,
 			"url", r.URL,
 			"remote", remote,
+			"host", names[0],
 			"request_id", betterguid.New())
 
 		start := time.Now()
@@ -32,8 +41,7 @@ func Request(next http.Handler, logger log.Logger) http.Handler {
 			d := time.Since(start)
 
 			level.Info(l).
-				Log("duration", d,
-					"msg", "request handled")
+				Log("duration", d, "msg", "request handled")
 		}()
 
 		key := contextKey("logger")

log/log_test.go

+package log
+
+import (
+	"fmt"
+	"net/http"
+	"net/http/httptest"
+	"testing"
+)
+
+type testLogger struct {
+	m map[string]string
+}
+
+func (tl *testLogger) Log(vals ...interface{}) error {
+	tl.m = make(map[string]string)
+
+	if len(vals)%2 != 0 {
+		// Append dummy MISSING! value
+		vals = append(vals, "MISSING!")
+	}
+
+	for i := 0; i < len(vals); i += 2 {
+		key := fmt.Sprintf("%v", vals[i])
+		val := fmt.Sprintf("%v", vals[i+1])
+
+		tl.m[key] = val
+	}
+
+	return nil
+}
+
+func TestLogRequest(t *testing.T) {
+	next := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		t.Log("next called!")
+	})
+
+	testCases := []struct {
+		forwardedFor string
+		remoteAddr   string
+		expectRemote string
+		expectHost   string
+	}{
+		{
+			forwardedFor: "8.8.4.4",
+			remoteAddr:   "foobar",
+			expectRemote: "8.8.4.4",
+			expectHost:   "dns.google.",
+		},
+		{
+			forwardedFor: "2001:4860:4860::8888",
+			remoteAddr:   "foobar",
+			expectRemote: "2001:4860:4860::8888",
+			expectHost:   "dns.google.",
+		},
+		{expectHost: "n/a"},
+		{remoteAddr: "1.2.3.4", expectRemote: "1.2.3.4", expectHost: "n/a"},
+		{remoteAddr: "2001:db8::1", expectRemote: "2001:db8::1", expectHost: "n/a"},
+	}
+
+	for _, tc := range testCases {
+		t.Run(tc.forwardedFor+"-"+tc.remoteAddr, func(t *testing.T) {
+			var log testLogger
+			hdlr := Request(next, &log)
+
+			t.Log(tc)
+
+			w := httptest.NewRecorder()
+
+			r := httptest.NewRequest("GET", "/", nil)
+			r.RemoteAddr = tc.remoteAddr
+
+			if tc.forwardedFor != "" {
+				r.Header.Set("X-Forwarded-For", tc.forwardedFor)
+			}
+
+			hdlr.ServeHTTP(w, r)
+
+			t.Log("logged fields:", log.m)
+
+			if log.m["host"] != tc.expectHost {
+				t.Errorf("unexpected host name in log. want %q, have %q", tc.expectHost, log.m["host"])
+			}
+
+			if log.m["remote"] != tc.expectRemote {
+				t.Errorf("unexpected remote address in log. want %q, have %q", tc.expectRemote, log.m["remote"])
+			}
+		})
+	}
+}