refactor layout and structure

proxy/internal/accesslog/logger.go

@@ -0,0 +1,89 @@
+package accesslog
+
+import (
+	"context"
+	"log/slog"
+
+	"github.com/netbirdio/netbird/shared/management/proto"
+	"google.golang.org/grpc"
+	"google.golang.org/protobuf/types/known/timestamppb"
+)
+
+type gRPCClient interface {
+	SendAccessLog(ctx context.Context, in *proto.SendAccessLogRequest, opts ...grpc.CallOption) (*proto.SendAccessLogResponse, error)
+}
+
+type errorLogger interface {
+	ErrorContext(ctx context.Context, msg string, args ...any)
+}
+
+type Logger struct {
+	client   gRPCClient
+	errorLog errorLogger
+}
+
+func NewLogger(client gRPCClient, errorLog errorLogger) *Logger {
+	if errorLog == nil {
+		errorLog = slog.New(slog.DiscardHandler)
+	}
+	return &Logger{
+		client:   client,
+		errorLog: errorLog,
+	}
+}
+
+type logEntry struct {
+	ServiceId     string
+	Host          string
+	Path          string
+	DurationMs    int64
+	Method        string
+	ResponseCode  int32
+	SourceIp      string
+	AuthMechanism string
+	UserId        string
+	AuthSuccess   bool
+}
+
+func (l *Logger) log(ctx context.Context, log logEntry) {
+	// Fire off the log request in a separate routine.
+	// This increases the possibility of losing a log message
+	// (although it should still get logged in the event of an error),
+	// but it will reduce latency returning the request in the
+	// middleware.
+	// There is also a chance that log messages will arrive at
+	// the server out of order; however, the timestamp should
+	// allow for resolving that on the server.
+	now := timestamppb.Now() // Grab the timestamp before launching the goroutine to try to prevent weird timing issues. This is probably unnecessary.
+	go func() {
+		if _, err := l.client.SendAccessLog(ctx, &proto.SendAccessLogRequest{
+			Log: &proto.AccessLog{
+				Timestamp:     now,
+				ServiceId:     log.ServiceId,
+				Host:          log.Host,
+				Path:          log.Path,
+				DurationMs:    log.DurationMs,
+				Method:        log.Method,
+				ResponseCode:  log.ResponseCode,
+				SourceIp:      log.SourceIp,
+				AuthMechanism: log.AuthMechanism,
+				UserId:        log.UserId,
+				AuthSuccess:   log.AuthSuccess,
+			},
+		}); err != nil {
+			// If it fails to send on the gRPC connection, then at least log it to the error log.
+			l.errorLog.ErrorContext(ctx, "Error sending access log on gRPC connection",
+				"service_id", log.ServiceId,
+				"host", log.Host,
+				"path", log.Path,
+				"duration", log.DurationMs,
+				"method", log.Method,
+				"response_code", log.ResponseCode,
+				"source_ip", log.SourceIp,
+				"auth_mechanism", log.AuthMechanism,
+				"user_id", log.UserId,
+				"auth_success", log.AuthSuccess,
+				"error", err)
+		}
+	}()
+}

proxy/internal/accesslog/middleware.go

@@ -0,0 +1,47 @@
+package accesslog
+
+import (
+	"net"
+	"net/http"
+	"time"
+
+	"github.com/netbirdio/netbird/proxy/internal/auth"
+	"github.com/netbirdio/netbird/proxy/internal/proxy"
+)
+
+func (l *Logger) Middleware(next http.Handler) http.Handler {
+	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		// Use a response writer wrapper so we can access the status code later.
+		sw := &statusWriter{
+			w:      w,
+			status: http.StatusOK, // Default status is OK unless otherwise modified.
+		}
+
+		// Get the source IP before passing the request on as the proxy will modify
+		// headers that we wish to use to gather that information on the request.
+		sourceIp := extractSourceIP(r)
+
+		start := time.Now()
+		next.ServeHTTP(sw, r)
+		duration := time.Since(start)
+
+		host, _, err := net.SplitHostPort(r.Host)
+		if err != nil {
+			// Fallback to just using the full host value.
+			host = r.Host
+		}
+
+		l.log(r.Context(), logEntry{
+			ServiceId:     proxy.ServiceIdFromContext(r.Context()),
+			Host:          host,
+			Path:          r.URL.Path,
+			DurationMs:    duration.Milliseconds(),
+			Method:        r.Method,
+			ResponseCode:  int32(sw.status),
+			SourceIp:      sourceIp,
+			AuthMechanism: auth.MethodFromContext(r.Context()).String(),
+			UserId:        auth.UserFromContext(r.Context()),
+			AuthSuccess:   sw.status != http.StatusUnauthorized && sw.status != http.StatusForbidden,
+		})
+	})
+}

proxy/internal/accesslog/requestip.go

@@ -0,0 +1,43 @@
+package accesslog
+
+import (
+	"net"
+	"net/http"
+	"slices"
+	"strings"
+)
+
+// requestIP attempts to extract the source IP from a request.
+// Adapted from https://husobee.github.io/golang/ip-address/2015/12/17/remote-ip-go.html
+// with the addition of some newer stdlib functions that are now
+// available.
+// The concept here is to look backwards through IP headers until
+// the first public IP address is found. The hypothesis is that
+// even if there are multiple IP addresses specified in these headers,
+// the last public IP should be the hop immediately before reaching
+// the server and therefore represents the "true" source IP regardless
+// of the number of intermediate proxies or network hops.
+func extractSourceIP(r *http.Request) string {
+	for _, h := range []string{"X-Forwarded-For", "X-Real-IP"} {
+		addresses := strings.Split(r.Header.Get(h), ",")
+		// Iterate from right to left until we get a public address
+		// that should be the address right before our proxy.
+		for _, address := range slices.Backward(addresses) {
+			// Trim the address because sometimes clients put whitespace in there.
+			ip := strings.TrimSpace(address)
+			// Parse the IP so that we can easily check whether it is a valid public address.
+			realIP := net.ParseIP(ip)
+			if !realIP.IsGlobalUnicast() || realIP.IsPrivate() || realIP.IsLoopback() {
+				continue
+			}
+			return ip
+		}
+	}
+	// Fallback to the requests RemoteAddr, this is least likely to be correct but
+	// should at least yield something in the event that the above has failed.
+	ip, _, err := net.SplitHostPort(r.RemoteAddr)
+	if err != nil {
+		ip = r.RemoteAddr
+	}
+	return ip
+}

proxy/internal/accesslog/statuswriter.go

@@ -0,0 +1,26 @@
+package accesslog
+
+import (
+	"net/http"
+)
+
+// statusWriter is a simple wrapper around an http.ResponseWriter
+// that captures the setting of the status code via the WriteHeader
+// function and stores it so that it can be retrieved later.
+type statusWriter struct {
+	w      http.ResponseWriter
+	status int
+}
+
+func (w *statusWriter) Header() http.Header {
+	return w.w.Header()
+}
+
+func (w *statusWriter) Write(data []byte) (int, error) {
+	return w.w.Write(data)
+}
+
+func (w *statusWriter) WriteHeader(status int) {
+	w.status = status
+	w.w.WriteHeader(status)
+}