Skip to content

Commit 311bef8

Browse files
codefionncodefionn
committed
feat: More Logging with UUID
1 parent da0c6fe commit 311bef8

2 files changed

Lines changed: 102 additions & 28 deletions

File tree

‎msgtausch-srv/logger/logger.go‎

Lines changed: 78 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
package logger
22

33
import (
4+
"context"
45
"fmt"
56
"log"
67
"os"
@@ -142,3 +143,80 @@ func Fatal(format string, v ...any) {
142143
func WithRequestID(requestID, format string, v ...any) string {
143144
return fmt.Sprintf("[%s] %s", requestID, fmt.Sprintf(format, v...))
144145
}
146+
147+
// ConnectionUUIDFromContext extracts the connection UUID from context.
148+
// This function should be implemented to match the proxy's context key structure.
149+
// We'll create a simple interface that allows the proxy to provide UUID extraction.
150+
var ConnectionUUIDExtractor func(context.Context) (string, bool)
151+
152+
// getUUIDFromContext extracts UUID from context if available
153+
func getUUIDFromContext(ctx context.Context) string {
154+
if ctx == nil {
155+
return ""
156+
}
157+
158+
// Use the extractor function if available (set by proxy initialization)
159+
if ConnectionUUIDExtractor != nil {
160+
if uuid, ok := ConnectionUUIDExtractor(ctx); ok {
161+
return uuid
162+
}
163+
}
164+
165+
return ""
166+
}
167+
168+
// formatWithUUID formats a message with UUID prefix if available
169+
func formatWithUUID(ctx context.Context, format string, v ...any) string {
170+
msg := fmt.Sprintf(format, v...)
171+
if uuid := getUUIDFromContext(ctx); uuid != "" {
172+
return fmt.Sprintf("[%s] %s", uuid, msg)
173+
}
174+
return msg
175+
}
176+
177+
// Context-aware logging functions that include UUID when available
178+
179+
// TraceCtx logs a trace message with UUID context if available
180+
func TraceCtx(ctx context.Context, format string, v ...any) {
181+
if TRACE < LogLevel(currentLevel.Load()) {
182+
return
183+
}
184+
msg := formatWithUUID(ctx, format, v...)
185+
stdLogger.Printf("[%s] %s", levelToString(TRACE), msg)
186+
}
187+
188+
// DebugCtx logs a debug message with UUID context if available
189+
func DebugCtx(ctx context.Context, format string, v ...any) {
190+
if DEBUG < LogLevel(currentLevel.Load()) {
191+
return
192+
}
193+
msg := formatWithUUID(ctx, format, v...)
194+
stdLogger.Printf("[%s] %s", levelToString(DEBUG), msg)
195+
}
196+
197+
// InfoCtx logs an info message with UUID context if available
198+
func InfoCtx(ctx context.Context, format string, v ...any) {
199+
if INFO < LogLevel(currentLevel.Load()) {
200+
return
201+
}
202+
msg := formatWithUUID(ctx, format, v...)
203+
stdLogger.Printf("[%s] %s", levelToString(INFO), msg)
204+
}
205+
206+
// WarnCtx logs a warning message with UUID context if available
207+
func WarnCtx(ctx context.Context, format string, v ...any) {
208+
if WARN < LogLevel(currentLevel.Load()) {
209+
return
210+
}
211+
msg := formatWithUUID(ctx, format, v...)
212+
stdLogger.Printf("[%s] %s", levelToString(WARN), msg)
213+
}
214+
215+
// ErrorCtx logs an error message with UUID context if available
216+
func ErrorCtx(ctx context.Context, format string, v ...any) {
217+
if ERROR < LogLevel(currentLevel.Load()) {
218+
return
219+
}
220+
msg := formatWithUUID(ctx, format, v...)
221+
stdLogger.Printf("[%s] %s", levelToString(ERROR), msg)
222+
}

‎msgtausch-srv/proxy/proxy.go‎

Lines changed: 24 additions & 28 deletions
Original file line numberDiff line numberDiff line change
@@ -257,6 +257,9 @@ func NewProxy(cfg *config.Config) *Proxy {
257257
servers: make([]*Server, 0, len(cfg.Servers)),
258258
}
259259

260+
// Set up logger to extract connection UUIDs from context
261+
logger.ConnectionUUIDExtractor = ConnectionUUIDFromContext
262+
260263
p.CompileClassifiers()
261264

262265
if cfg.Statistics.Enabled {
@@ -822,7 +825,7 @@ func (p *Server) handleRequest(w http.ResponseWriter, r *http.Request) {
822825
r = r.WithContext(ctx)
823826

824827
targetAddr := r.Host
825-
logger.Debug("[%s] %s request for %s", connUUID, r.Method, targetAddr)
828+
logger.DebugCtx(ctx, "%s request for %s", r.Method, targetAddr)
826829

827830
if p.proxy.portal.IsPortalRequest(r) {
828831
p.proxy.portal.ServeHTTP(w, r)
@@ -838,19 +841,19 @@ func (p *Server) handleRequest(w http.ResponseWriter, r *http.Request) {
838841
strings.Contains(strings.ToLower(r.Header.Get("Connection")), "upgrade")
839842

840843
if isWebSocketUpgrade {
841-
logger.Debug("WebSocket upgrade detected for %s", host)
844+
logger.DebugCtx(ctx, "WebSocket upgrade detected for %s", host)
842845
}
843846

844847
var remotePort uint16
845848
hostname, portStr, err := net.SplitHostPort(host)
846849
if err != nil {
847850
// If parsing fails, use the original host as hostname (it might not have a port)
848851
hostname = host
849-
logger.Debug("No port found in host, using default: %s", host)
852+
logger.DebugCtx(ctx, "No port found in host, using default: %s", host)
850853
} else {
851854
port, err := strconv.ParseUint(portStr, 10, 16)
852855
if err != nil {
853-
logger.Error("Error parsing port: %v", err)
856+
logger.ErrorCtx(ctx, "Error parsing port: %v", err)
854857
} else {
855858
remotePort = uint16(port)
856859
}
@@ -899,10 +902,10 @@ func (p *Server) handleRequest(w http.ResponseWriter, r *http.Request) {
899902
}
900903

901904
if !p.isHostAllowed(hostname, clientIP, remotePort) {
902-
logger.Warn("Host not allowed: %s", host)
905+
logger.WarnCtx(ctx, "Host not allowed: %s", host)
903906
if p.proxy.Collector != nil {
904907
if err := p.proxy.Collector.RecordBlockedRequest(ctx, clientIP, hostname, "host_not_allowed"); err != nil {
905-
logger.Error("Failed to record blocked request: %v", err)
908+
logger.ErrorCtx(ctx, "Failed to record blocked request: %v", err)
906909
}
907910
}
908911
http.Error(w, "Host not allowed", http.StatusForbidden)
@@ -914,7 +917,7 @@ func (p *Server) handleRequest(w http.ResponseWriter, r *http.Request) {
914917

915918
if p.proxy.Collector != nil {
916919
if err := p.proxy.Collector.RecordAllowedRequest(ctx, clientIP, hostname); err != nil {
917-
logger.Error("Failed to record allowed request: %v", err)
920+
logger.ErrorCtx(ctx, "Failed to record allowed request: %v", err)
918921
}
919922
}
920923

@@ -925,7 +928,7 @@ func (p *Server) handleRequest(w http.ResponseWriter, r *http.Request) {
925928

926929
client, ok := ClientFromContext(r.Context())
927930
if !ok || client == nil {
928-
logger.Error("No http.Client found in request context")
931+
logger.ErrorCtx(ctx, "No http.Client found in request context")
929932
http.Error(w, "Internal server error", http.StatusInternalServerError)
930933
return
931934
}
@@ -959,13 +962,13 @@ func (p *Server) forwardRequest(w http.ResponseWriter, r *http.Request, client *
959962
if strings.ToLower(r.Header.Get("Upgrade")) == "websocket" &&
960963
strings.Contains(strings.ToLower(r.Header.Get("Connection")), "upgrade") {
961964
isWebSocketRequest = true
962-
logger.Debug("Detected WebSocket upgrade request to %s", targetURL)
965+
logger.DebugCtx(ctx, "Detected WebSocket upgrade request to %s", targetURL)
963966
}
964967

965968
isProxiedWebSocket := false
966969
if r.Header.Get("Sec-WebSocket-Key") != "" && r.Header.Get("Sec-WebSocket-Version") != "" {
967970
isProxiedWebSocket = true
968-
logger.Debug("Detected proxied WebSocket request to %s", targetURL)
971+
logger.DebugCtx(ctx, "Detected proxied WebSocket request to %s", targetURL)
969972
}
970973

971974
skip := map[string]struct{}{
@@ -1037,15 +1040,15 @@ func (p *Server) forwardRequest(w http.ResponseWriter, r *http.Request, client *
10371040
if p.isHTTPInterceptionEnabled() && p.httpInterceptor != nil {
10381041
err := p.httpInterceptor.applyRequestHooks(req)
10391042
if err != nil {
1040-
logger.Error("Failed to apply HTTP request hooks: %v", err)
1043+
logger.ErrorCtx(ctx, "Failed to apply HTTP request hooks: %v", err)
10411044
http.Error(w, "Internal server error", http.StatusInternalServerError)
10421045
return
10431046
}
10441047
}
10451048

10461049
resp, err := client.Do(req)
10471050
if err != nil {
1048-
logger.Error("Failed to forward request to %s: %v", targetHost, err)
1051+
logger.ErrorCtx(ctx, "Failed to forward request to %s: %v", targetHost, err)
10491052
if netErr, ok := err.(net.Error); ok && netErr.Timeout() {
10501053
http.Error(w, "Request timeout", http.StatusGatewayTimeout)
10511054
} else {
@@ -1058,14 +1061,14 @@ func (p *Server) forwardRequest(w http.ResponseWriter, r *http.Request, client *
10581061
}
10591062
defer func() {
10601063
if closeErr := resp.Body.Close(); closeErr != nil {
1061-
logger.Error("Error closing response body: %v", closeErr)
1064+
logger.ErrorCtx(ctx, "Error closing response body: %v", closeErr)
10621065
}
10631066
}()
10641067

10651068
if p.isHTTPInterceptionEnabled() && p.httpInterceptor != nil {
10661069
err := p.httpInterceptor.applyResponseHooks(resp)
10671070
if err != nil {
1068-
logger.Error("Failed to apply HTTP response hooks: %v", err)
1071+
logger.ErrorCtx(ctx, "Failed to apply HTTP response hooks: %v", err)
10691072
http.Error(w, "Internal server error", http.StatusInternalServerError)
10701073
return
10711074
}
@@ -1297,19 +1300,12 @@ func (p *Server) handleWebSocketTunnel(w http.ResponseWriter, r *http.Request, r
12971300

12981301
func (p *Server) handleConnect(w http.ResponseWriter, r *http.Request, connectionID int64, _, _ string, remotePort int) {
12991302
targetAddr := r.Host
1303+
ctx := r.Context()
13001304

1301-
if connUUID, ok := ConnectionUUIDFromContext(r.Context()); ok {
1302-
logger.Debug("[%s] CONNECT request for %s", connUUID, targetAddr)
1303-
} else {
1304-
logger.Debug("CONNECT request for %s", targetAddr)
1305-
}
1305+
logger.DebugCtx(ctx, "CONNECT request for %s", targetAddr)
13061306

13071307
if p.shouldInterceptTunnel(r) {
1308-
if connUUID, ok := ConnectionUUIDFromContext(r.Context()); ok {
1309-
logger.Debug("[%s] Intercepting CONNECT request for %s", connUUID, targetAddr)
1310-
} else {
1311-
logger.Debug("Intercepting CONNECT request for %s", targetAddr)
1312-
}
1308+
logger.DebugCtx(ctx, "Intercepting CONNECT request for %s", targetAddr)
13131309

13141310
// First use the default port-based detection
13151311
isHTTPS := strings.HasSuffix(targetAddr, ":443") ||
@@ -1331,17 +1327,17 @@ func (p *Server) handleConnect(w http.ResponseWriter, r *http.Request, connectio
13311327

13321328
classifierResult, err := p.httpsClassifier.Classify(classifierInput)
13331329
if err != nil {
1334-
logger.Warn("Error evaluating HTTPS classifier for %s: %v, falling back to default detection", targetAddr, err)
1330+
logger.WarnCtx(ctx, "Error evaluating HTTPS classifier for %s: %v, falling back to default detection", targetAddr, err)
13351331
} else {
1336-
logger.Debug("HTTPS classifier result for %s: %v (default detection: %v)", targetAddr, classifierResult, isHTTPS)
1332+
logger.DebugCtx(ctx, "HTTPS classifier result for %s: %v (default detection: %v)", targetAddr, classifierResult, isHTTPS)
13371333
isHTTPS = classifierResult
13381334
}
13391335
}
13401336

1341-
logger.Debug("Protocol detection: isHTTPS=%v, targetAddr=%s, URL=%s, Scheme=%s",
1337+
logger.DebugCtx(ctx, "Protocol detection: isHTTPS=%v, targetAddr=%s, URL=%s, Scheme=%s",
13421338
isHTTPS, targetAddr, r.URL.String(), r.URL.Scheme)
13431339

1344-
logger.Debug("HTTPS interception enabled: %v, interceptor: %v",
1340+
logger.DebugCtx(ctx, "HTTPS interception enabled: %v, interceptor: %v",
13451341
p.isHTTPSInterceptionEnabled(), p.httpsInterceptor != nil)
13461342

13471343
// If the target is HTTPS but HTTPS interception is disabled/not available,

0 commit comments

Comments
 (0)