Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Merged
merged 1 commit into from
Sep 24, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
48 changes: 45 additions & 3 deletions logging/handler.go
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,14 @@
"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
Expand All @@ -28,16 +36,23 @@
// 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,
}
Expand Down Expand Up @@ -67,9 +82,12 @@
}

// 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
Expand Down Expand Up @@ -110,14 +128,14 @@
switch {
case status < http.StatusBadRequest:
if l.options.onlyTraceHealthEndpoint && uri == "/health" {
l.logger.WithFields(fields).Trace()

Check failure

Code scanning / CodeQL

Clear-text logging of sensitive information High

Sensitive data returned by HTTP request headers
flows to a logging call.
Sensitive data returned by HTTP request headers
flows to a logging call.
Sensitive data returned by HTTP request headers
flows to a logging call.
} else {
l.logger.WithFields(fields).Info()

Check failure

Code scanning / CodeQL

Clear-text logging of sensitive information High

Sensitive data returned by HTTP request headers
flows to a logging call.
Sensitive data returned by HTTP request headers
flows to a logging call.
Sensitive data returned by HTTP request headers
flows to a logging call.
}
case status < http.StatusInternalServerError:
l.logger.WithFields(fields).Warn()

Check failure

Code scanning / CodeQL

Clear-text logging of sensitive information High

Sensitive data returned by HTTP request headers
flows to a logging call.
Sensitive data returned by HTTP request headers
flows to a logging call.
Sensitive data returned by HTTP request headers
flows to a logging call.
default:
l.logger.WithFields(fields).Error()

Check failure

Code scanning / CodeQL

Clear-text logging of sensitive information High

Sensitive data returned by HTTP request headers
flows to a logging call.
Sensitive data returned by HTTP request headers
flows to a logging call.
Sensitive data returned by HTTP request headers
flows to a logging call.
}
}

Expand All @@ -125,3 +143,27 @@
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
}
117 changes: 117 additions & 0 deletions logging/handler_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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"])
}
})
}
}