Add option for the logging middleware to log real IP (#2002)

This commit adds the option (enabled via environment variable) to the
logging middleware to log real/originating IP address of a client based
on specific headers.

Three headers are supported: True-Client-IP, X-Real-IP, X-Forwarded-For.

This is particularly useful when there is proxy server(s) sitting
between step-ca and client.

Implements #1995

logging/handler.go

@@ -14,6 +14,14 @@ import (
  "github.com/smallstep/certificates/middleware/requestid"
 )
 
+// Common headers used for identifying the originating IP address of a client
+// connecting to a web server through a proxy server
+var (
+ trueClientIP = http.CanonicalHeaderKey("True-Client-IP")
+ xRealIP = http.CanonicalHeaderKey("X-Real-IP")
+ xForwardedFor = http.CanonicalHeaderKey("X-Forwarded-For")
+)
+
 // LoggerHandler creates a logger handler
 type LoggerHandler struct {
  name string
@@ -28,16 +36,23 @@ type options struct {
  // endpoint should only be logged at the TRACE level in the (expected) HTTP
  // 200 case
  onlyTraceHealthEndpoint bool
+
+ // logRealIP determines if the real IP address of the client should be logged
+ // instead of the IP address of the proxy
+ logRealIP bool
 }
 
 // NewLoggerHandler returns the given http.Handler with the logger integrated.
 func NewLoggerHandler(name string, logger *Logger, next http.Handler) http.Handler {
  onlyTraceHealthEndpoint, _ := strconv.ParseBool(os.Getenv("STEP_LOGGER_ONLY_TRACE_HEALTH_ENDPOINT"))
+ logRealIP, _ := strconv.ParseBool(os.Getenv("STEP_LOGGER_LOG_REAL_IP"))
+
  return &LoggerHandler{
  name: name,
  logger: logger.GetImpl(),
  options: options{
  onlyTraceHealthEndpoint: onlyTraceHealthEndpoint,
+ logRealIP: logRealIP,
  },
  next: next,
  }
@@ -67,9 +82,12 @@ func (l *LoggerHandler) writeEntry(w ResponseLogger, r *http.Request, t time.Tim
  }
 
  // Remote hostname
- addr, _, err := net.SplitHostPort(r.RemoteAddr)
- if err != nil {
- addr = r.RemoteAddr
+ addr := r.RemoteAddr
+ if l.options.logRealIP {
+ addr = realIP(r)
+ }
+ if host, _, err := net.SplitHostPort(addr); err == nil {
+ addr = host
  }
 
  // From https://github.com/gorilla/handlers
@@ -125,3 +143,27 @@ func sanitizeLogEntry(s string) string {
  escaped := strings.ReplaceAll(s, "\n", "")
  return strings.ReplaceAll(escaped, "\r", "")
 }
+
+// realIP returns the real IP address of the client connecting to the server by
+// parsing either the True-Client-IP, X-Real-IP or the X-Forwarded-For headers
+// (in that order). If the headers are not set or set to an invalid IP, it
+// returns the RemoteAddr of the request.
+func realIP(r *http.Request) string {
+ var ip string
+
+ if tcip := r.Header.Get(trueClientIP); tcip != "" {
+ ip = tcip
+ } else if xrip := r.Header.Get(xRealIP); xrip != "" {
+ ip = xrip
+ } else if xff := r.Header.Get(xForwardedFor); xff != "" {
+ i := strings.Index(xff, ",")
+ if i == -1 {
+ i = len(xff)
+ }
+ ip = xff[:i]
+ }
+ if ip == "" || net.ParseIP(ip) == nil {
+ return r.RemoteAddr
+ }
+ return ip
+}

logging/handler_test.go

@@ -143,3 +143,120 @@ func TestHandlingRegardlessOfOptions(t *testing.T) {
  })
  }
 }
+
+// TestLogRealIP ensures that the real originating IP is logged instead of the
+// proxy IP when STEP_LOGGER_LOG_REAL_IP is set to true and specific headers are
+// present.
+func TestLogRealIP(t *testing.T) {
+ statusHandler := func(statusCode int) http.HandlerFunc {
+ return func(w http.ResponseWriter, _ *http.Request) {
+ w.WriteHeader(statusCode)
+ w.Write([]byte("{}"))
+ }
+ }
+
+ proxyIP := "1.1.1.1"
+
+ tests := []struct {
+ name string
+ logRealIP string
+ headers map[string]string
+ expected string
+ }{
+ {
+ name: "setting is turned on, no header is set",
+ logRealIP: "true",
+ expected: "1.1.1.1",
+ headers: map[string]string{},
+ },
+ {
+ name: "setting is turned on, True-Client-IP header is set",
+ logRealIP: "true",
+ headers: map[string]string{
+ "True-Client-IP": "2.2.2.2",
+ },
+ expected: "2.2.2.2",
+ },
+ {
+ name: "setting is turned on, True-Client-IP header is set with invalid value",
+ logRealIP: "true",
+ headers: map[string]string{
+ "True-Client-IP": "a.b.c.d",
+ },
+ expected: "1.1.1.1",
+ },
+ {
+ name: "setting is turned on, X-Real-IP header is set",
+ logRealIP: "true",
+ headers: map[string]string{
+ "X-Real-IP": "3.3.3.3",
+ },
+ expected: "3.3.3.3",
+ },
+ {
+ name: "setting is turned on, X-Forwarded-For header is set",
+ logRealIP: "true",
+ headers: map[string]string{
+ "X-Forwarded-For": "4.4.4.4",
+ },
+ expected: "4.4.4.4",
+ },
+ {
+ name: "setting is turned on, X-Forwarded-For header is set with multiple IPs",
+ logRealIP: "true",
+ headers: map[string]string{
+ "X-Forwarded-For": "4.4.4.4, 5.5.5.5, 6.6.6.6",
+ },
+ expected: "4.4.4.4",
+ },
+ {
+ name: "setting is turned on, all headers are set",
+ logRealIP: "true",
+ headers: map[string]string{
+ "True-Client-IP": "2.2.2.2",
+ "X-Real-IP": "3.3.3.3",
+ "X-Forwarded-For": "4.4.4.4",
+ },
+ expected: "2.2.2.2",
+ },
+ {
+ name: "setting is turned off, True-Client-IP header is set",
+ logRealIP: "false",
+ expected: "1.1.1.1",
+ headers: map[string]string{
+ "True-Client-IP": "2.2.2.2",
+ },
+ },
+ {
+ name: "setting is turned off, no header is set",
+ logRealIP: "false",
+ expected: "1.1.1.1",
+ headers: map[string]string{},
+ },
+ }
+
+ for _, tt := range tests {
+ t.Run(tt.name, func(t *testing.T) {
+ t.Setenv("STEP_LOGGER_LOG_REAL_IP", tt.logRealIP)
+
+ baseLogger, hook := test.NewNullLogger()
+ logger := &Logger{
+ Logger: baseLogger,
+ }
+ l := NewLoggerHandler("test", logger, statusHandler(http.StatusOK))
+
+ r := httptest.NewRequest("GET", "/test", http.NoBody)
+ r.RemoteAddr = proxyIP
+ for k, v := range tt.headers {
+ r.Header.Set(k, v)
+ }
+ w := httptest.NewRecorder()
+ l.ServeHTTP(w, r)
+
+ if assert.Equals(t, 1, len(hook.AllEntries())) {
+ entry := hook.LastEntry()
+ assert.Equals(t, tt.expected, entry.Data["remote-address"])
+ }
+ })
+ }
+}