From 12776d65c172d09fc4ec19e70c8c12efb94584eb Mon Sep 17 00:00:00 2001 From: Owen Date: Sat, 11 Apr 2026 21:56:28 -0700 Subject: [PATCH] Add logging --- clients/clients.go | 7 ++ netstack2/http_handler.go | 45 ++++++++- netstack2/http_request_log.go | 175 ++++++++++++++++++++++++++++++++++ netstack2/proxy.go | 27 ++++++ netstack2/tun.go | 10 ++ 5 files changed, 261 insertions(+), 3 deletions(-) create mode 100644 netstack2/http_request_log.go diff --git a/clients/clients.go b/clients/clients.go index e646053..3862160 100644 --- a/clients/clients.go +++ b/clients/clients.go @@ -850,6 +850,13 @@ func (s *WireGuardService) ensureWireguardInterface(wgconfig WgConfig) error { }) }) + // Configure the HTTP request log sender to ship compressed request logs via websocket + s.tnet.SetHTTPRequestLogSender(func(data string) error { + return s.client.SendMessageNoLog("newt/request-log", map[string]interface{}{ + "compressed": data, + }) + }) + // Create WireGuard device using the shared bind s.device = device.NewDevice(s.tun, s.sharedBind, device.NewLogger( device.LogLevelSilent, // Use silent logging by default - could be made configurable diff --git a/netstack2/http_handler.go b/netstack2/http_handler.go index c31a791..8e04413 100644 --- a/netstack2/http_handler.go +++ b/netstack2/http_handler.go @@ -14,6 +14,7 @@ import ( "net/http/httputil" "net/url" "sync" + "time" "github.com/fosrl/newt/logger" "gvisor.dev/gvisor/pkg/tcpip/stack" @@ -50,8 +51,9 @@ type HTTPTarget struct { // Outbound connections to downstream targets honour HTTPTarget.UseHTTPS // independently of the incoming protocol. type HTTPHandler struct { - stack *stack.Stack - proxyHandler *ProxyHandler + stack *stack.Stack + proxyHandler *ProxyHandler + requestLogger *HTTPRequestLogger listener *chanListener server *http.Server @@ -152,6 +154,12 @@ func NewHTTPHandler(s *stack.Stack, ph *ProxyHandler) *HTTPHandler { } } +// SetRequestLogger attaches an HTTPRequestLogger so that every proxied request +// is recorded and periodically shipped to the server. +func (h *HTTPHandler) SetRequestLogger(rl *HTTPRequestLogger) { + h.requestLogger = rl +} + // Start launches the internal http.Server that services connections delivered // via HandleConn. The server runs for the lifetime of the HTTPHandler; call // Close to stop it. @@ -289,6 +297,19 @@ func (h *HTTPHandler) getProxy(target HTTPTarget) *httputil.ReverseProxy { return actual.(*httputil.ReverseProxy) } +// statusCapture wraps an http.ResponseWriter and records the HTTP status code +// written by the upstream handler. If WriteHeader is never called the status +// defaults to 200 (http.StatusOK), matching net/http semantics. +type statusCapture struct { + http.ResponseWriter + status int +} + +func (sc *statusCapture) WriteHeader(code int) { + sc.status = code + sc.ResponseWriter.WriteHeader(code) +} + // handleRequest is the http.Handler entry point. It retrieves the SubnetRule // attached to the connection by ConnContext, selects the first configured // downstream target, and forwards the request via the cached ReverseProxy. @@ -308,5 +329,23 @@ func (h *HTTPHandler) handleRequest(w http.ResponseWriter, r *http.Request) { logger.Info("HTTP handler: %s %s -> %s://%s:%d", r.Method, r.URL.RequestURI(), scheme, target.DestAddr, target.DestPort) - h.getProxy(target).ServeHTTP(w, r) + timestamp := time.Now() + sc := &statusCapture{ResponseWriter: w, status: http.StatusOK} + + h.getProxy(target).ServeHTTP(sc, r) + + if h.requestLogger != nil && rule.ResourceId != 0 { + h.requestLogger.LogRequest(HTTPRequestLog{ + ResourceID: rule.ResourceId, + Timestamp: timestamp, + Method: r.Method, + Scheme: rule.Protocol, + Host: r.Host, + Path: r.URL.Path, + RawQuery: r.URL.RawQuery, + UserAgent: r.UserAgent(), + SourceAddr: r.RemoteAddr, + TLS: rule.Protocol == "https", + }) + } } diff --git a/netstack2/http_request_log.go b/netstack2/http_request_log.go new file mode 100644 index 0000000..85ab5db --- /dev/null +++ b/netstack2/http_request_log.go @@ -0,0 +1,175 @@ +package netstack2 + +import ( + "bytes" + "compress/zlib" + "encoding/base64" + "encoding/json" + "sync" + "time" + + "github.com/fosrl/newt/logger" +) + +// HTTPRequestLog represents a single HTTP/HTTPS request proxied through the handler. +type HTTPRequestLog struct { + RequestID string `json:"requestId"` + ResourceID int `json:"resourceId"` + Timestamp time.Time `json:"timestamp"` + Method string `json:"method"` + Scheme string `json:"scheme"` + Host string `json:"host"` + Path string `json:"path"` + RawQuery string `json:"rawQuery,omitempty"` + UserAgent string `json:"userAgent,omitempty"` + SourceAddr string `json:"sourceAddr"` + TLS bool `json:"tls"` +} + +// HTTPRequestLogger buffers HTTP request logs and periodically flushes them +// to the server via a configurable SendFunc. +type HTTPRequestLogger struct { + mu sync.Mutex + pending []HTTPRequestLog + sendFn SendFunc + stopCh chan struct{} + flushDone chan struct{} +} + +// NewHTTPRequestLogger creates a new HTTPRequestLogger and starts its background flush loop. +func NewHTTPRequestLogger() *HTTPRequestLogger { + rl := &HTTPRequestLogger{ + pending: make([]HTTPRequestLog, 0), + stopCh: make(chan struct{}), + flushDone: make(chan struct{}), + } + go rl.backgroundLoop() + return rl +} + +// SetSendFunc sets the callback used to send compressed HTTP request log batches +// to the server. This can be called after construction once the websocket +// client is available. +func (rl *HTTPRequestLogger) SetSendFunc(fn SendFunc) { + rl.mu.Lock() + defer rl.mu.Unlock() + rl.sendFn = fn +} + +// LogRequest adds an HTTP request log entry to the buffer. If the buffer +// reaches maxBufferedSessions entries a flush is triggered immediately. +func (rl *HTTPRequestLogger) LogRequest(log HTTPRequestLog) { + if log.RequestID == "" { + log.RequestID = generateSessionID() + } + + rl.mu.Lock() + rl.pending = append(rl.pending, log) + shouldFlush := len(rl.pending) >= maxBufferedSessions + rl.mu.Unlock() + + if shouldFlush { + rl.flush() + } +} + +// backgroundLoop handles periodic flushing of buffered request logs. +func (rl *HTTPRequestLogger) backgroundLoop() { + defer close(rl.flushDone) + + ticker := time.NewTicker(flushInterval) + defer ticker.Stop() + + for { + select { + case <-rl.stopCh: + return + case <-ticker.C: + rl.flush() + } + } +} + +// flush drains the pending buffer, compresses with zlib, and sends via the SendFunc. +// On send failure the batch is re-queued, capped at maxBufferedSessions*5 entries +// to prevent unbounded memory growth when the server is unreachable. +func (rl *HTTPRequestLogger) flush() { + rl.mu.Lock() + if len(rl.pending) == 0 { + rl.mu.Unlock() + return + } + batch := rl.pending + rl.pending = make([]HTTPRequestLog, 0) + sendFn := rl.sendFn + rl.mu.Unlock() + + if sendFn == nil { + logger.Debug("HTTP request logger: no send function configured, discarding %d requests", len(batch)) + return + } + + compressed, err := compressRequestLogs(batch) + if err != nil { + logger.Error("HTTP request logger: failed to compress %d requests: %v", len(batch), err) + return + } + + if err := sendFn(compressed); err != nil { + logger.Error("HTTP request logger: failed to send %d requests: %v", len(batch), err) + // Re-queue the batch so we don't lose data + rl.mu.Lock() + rl.pending = append(batch, rl.pending...) + // Cap re-queued data to prevent unbounded growth if server is unreachable + if len(rl.pending) > maxBufferedSessions*5 { + dropped := len(rl.pending) - maxBufferedSessions*5 + rl.pending = rl.pending[:maxBufferedSessions*5] + logger.Warn("HTTP request logger: buffer overflow, dropped %d oldest requests", dropped) + } + rl.mu.Unlock() + return + } + + logger.Info("HTTP request logger: sent %d requests to server", len(batch)) +} + +// compressRequestLogs JSON-encodes the request logs, compresses with zlib, and +// returns a base64-encoded string suitable for embedding in a JSON message. +func compressRequestLogs(logs []HTTPRequestLog) (string, error) { + jsonData, err := json.Marshal(logs) + if err != nil { + return "", err + } + + var buf bytes.Buffer + w, err := zlib.NewWriterLevel(&buf, zlib.BestCompression) + if err != nil { + return "", err + } + if _, err := w.Write(jsonData); err != nil { + w.Close() + return "", err + } + if err := w.Close(); err != nil { + return "", err + } + + return base64.StdEncoding.EncodeToString(buf.Bytes()), nil +} + +// Close shuts down the background loop and performs one final flush to send +// any remaining buffered requests to the server. +func (rl *HTTPRequestLogger) Close() { + select { + case <-rl.stopCh: + // Already closed + return + default: + close(rl.stopCh) + } + + // Wait for the background loop to exit so we don't race on flush + <-rl.flushDone + + rl.flush() +} \ No newline at end of file diff --git a/netstack2/proxy.go b/netstack2/proxy.go index f4c2352..b08eea3 100644 --- a/netstack2/proxy.go +++ b/netstack2/proxy.go @@ -133,6 +133,7 @@ type ProxyHandler struct { icmpReplies chan []byte // Channel for ICMP reply packets to be sent back through the tunnel notifiable channel.Notification // Notification handler for triggering reads accessLogger *AccessLogger // Access logger for tracking sessions + httpRequestLogger *HTTPRequestLogger // HTTP request logger for proxied HTTP/HTTPS requests } // ProxyHandlerOptions configures the proxy handler @@ -187,6 +188,9 @@ func NewProxyHandler(options ProxyHandlerOptions) (*ProxyHandler, error) { if err := handler.httpHandler.Start(); err != nil { return nil, fmt.Errorf("failed to start HTTP handler: %v", err) } + + handler.httpRequestLogger = NewHTTPRequestLogger() + handler.httpHandler.SetRequestLogger(handler.httpRequestLogger) logger.Debug("ProxyHandler: HTTP handler enabled") } @@ -289,6 +293,24 @@ func (p *ProxyHandler) SetAccessLogSender(fn SendFunc) { p.accessLogger.SetSendFunc(fn) } +// GetHTTPRequestLogger returns the HTTP request logger. +func (p *ProxyHandler) GetHTTPRequestLogger() *HTTPRequestLogger { + if p == nil { + return nil + } + return p.httpRequestLogger +} + +// SetHTTPRequestLogSender configures the function used to send compressed HTTP +// request log batches to the server. This should be called once the websocket +// client is available. +func (p *ProxyHandler) SetHTTPRequestLogSender(fn SendFunc) { + if p == nil || !p.enabled || p.httpRequestLogger == nil { + return + } + p.httpRequestLogger.SetSendFunc(fn) +} + // LookupDestinationRewrite looks up the rewritten destination for a connection // This is used by TCP/UDP handlers to find the actual target address func (p *ProxyHandler) LookupDestinationRewrite(srcIP, dstIP string, dstPort uint16, proto uint8) (netip.Addr, bool) { @@ -810,6 +832,11 @@ func (p *ProxyHandler) Close() error { p.accessLogger.Close() } + // Shut down HTTP request logger + if p.httpRequestLogger != nil { + p.httpRequestLogger.Close() + } + // Shut down HTTP handler if p.httpHandler != nil { p.httpHandler.Close() diff --git a/netstack2/tun.go b/netstack2/tun.go index 5d2d6e1..fae90dd 100644 --- a/netstack2/tun.go +++ b/netstack2/tun.go @@ -394,6 +394,16 @@ func (net *Net) SetAccessLogSender(fn SendFunc) { } } +// SetHTTPRequestLogSender configures the function used to send compressed HTTP +// request log batches to the server. This should be called once the websocket +// client is available. +func (net *Net) SetHTTPRequestLogSender(fn SendFunc) { + tun := (*netTun)(net) + if tun.proxyHandler != nil { + tun.proxyHandler.SetHTTPRequestLogSender(fn) + } +} + type PingConn struct { laddr PingAddr raddr PingAddr