💡 feat: add NAT monitoring and hole punching logging for improved connection diagnostics

Author: smolgroot

docs/NAT-Monitoring-Logs.md

@@ -0,0 +1,206 @@
+# NAT Traversal and Hole Punching Monitoring
+
+## Overview
+
+Skypier VPN now includes comprehensive logging for NAT traversal, AutoNAT detection, and hole punching events. This helps diagnose connection issues and understand how peers are connecting to your node.
+
+## New Log Components
+
+Two new log components have been added:
+
+- `[NAT]` - AutoNAT status and reachability monitoring
+- `[HOLEPUNCH]` - Connection establishment methods and hole punching monitoring
+
+## Log Examples
+
+### Node Startup
+
+When your node starts, you'll see:
+
+```
+[INF] [NAT      ] AutoNAT monitoring started
+[INF] [HOLEPUNCH] Connection monitoring started
+```
+
+### If Your Node is Publicly Reachable
+
+After ~5 seconds, you'll see one of these:
+
+```
+[INF] [NAT      ] ✓ Node appears PUBLICLY reachable (has public addresses)
+[DBG] [NAT      ] Public address detected: /ip4/203.0.113.45/udp/4002/quic-v1
+```
+
+### If Your Node is Behind NAT
+
+```
+[WRN] [NAT      ] ⚠ Node appears behind NAT/firewall (only private addresses)
+[INF] [NAT      ] Hole punching or relay will be used for incoming connections
+```
+
+### Connection Methods
+
+When peers connect, you'll see different messages based on the connection method:
+
+#### Direct QUIC Connection (Outbound)
+
+```
+[INF] [HOLEPUNCH] ✓ DIRECT outbound QUIC connection to peer 16Uiu2HAm...
+[DBG] [HOLEPUNCH]   └─ Local: /ip4/192.168.1.100/udp/4002/quic-v1
+[DBG] [HOLEPUNCH]   └─ Remote: /ip4/203.0.113.45/udp/4002/quic-v1
+```
+
+#### Direct QUIC Connection (Inbound - Hole Punch Success!)
+
+```
+[INF] [HOLEPUNCH] ✓ DIRECT inbound QUIC connection from peer 16Uiu2HAm...
+[DBG] [HOLEPUNCH]   └─ Peer successfully connected to us (hole punch or public)
+[DBG] [HOLEPUNCH]   └─ Local: /ip4/192.168.1.100/udp/4002/quic-v1
+[DBG] [HOLEPUNCH]   └─ Remote: /ip4/198.51.100.23/udp/54321/quic-v1
+```
+
+This indicates successful hole punching or that your node is publicly reachable!
+
+#### Relayed Connection (Hole Punch Failed)
+
+```
+[INF] [HOLEPUNCH] 🔄 RELAYED connection established with peer 16Uiu2HAm...
+[DBG] [HOLEPUNCH]   └─ via circuit relay: /ip4/147.75.77.187/tcp/4001/p2p/QmNnoo.../p2p-circuit
+```
+
+This means direct connection failed and traffic is going through a relay server.
+
+#### TCP Connection
+
+```
+[INF] [HOLEPUNCH] ✓ DIRECT outbound TCP connection to peer 16Uiu2HAm...
+[DBG] [HOLEPUNCH]   └─ Local: /ip4/192.168.1.100/tcp/4001
+[DBG] [HOLEPUNCH]   └─ Remote: /ip4/203.0.113.45/tcp/4001
+```
+
+#### Resource-Limited Connection
+
+```
+[INF] [HOLEPUNCH] ✓ DIRECT outbound QUIC connection to peer 16Uiu2HAm...
+[WRN] [HOLEPUNCH]   └─ ⚠ Connection is RATE LIMITED by resource manager
+```
+
+This means the connection is being throttled due to resource constraints.
+
+### Peer Disconnection
+
+```
+[DBG] [HOLEPUNCH] Peer disconnected: 16Uiu2HAm...
+```
+
+## Interpreting the Logs
+
+### What Success Looks Like
+
+**Best Case: Public Node**
+```
+[INF] [NAT      ] ✓ Node appears PUBLICLY reachable
+[INF] [HOLEPUNCH] ✓ DIRECT inbound QUIC connection from peer 16Uiu2H...
+```
+
+**Good Case: NAT with Working Hole Punching**
+```
+[WRN] [NAT      ] ⚠ Node appears behind NAT/firewall
+[INF] [HOLEPUNCH] ✓ DIRECT inbound QUIC connection from peer 16Uiu2H...
+[DBG] [HOLEPUNCH]   └─ Peer successfully connected to us (hole punch or public)
+```
+
+### What Problems Look Like
+
+**All Connections are Relayed**
+```
+[WRN] [NAT      ] ⚠ Node appears behind NAT/firewall
+[INF] [HOLEPUNCH] 🔄 RELAYED connection established with peer 16Uiu2H...
+[INF] [HOLEPUNCH] 🔄 RELAYED connection established with peer 16Uiu2H...
+```
+
+This indicates:
+- Hole punching is not working
+- You're behind a strict/symmetric NAT
+- All traffic is routed through relay servers (slower)
+
+**Solutions:**
+1. Enable UPnP on your router
+2. Set up port forwarding (UDP port 4002)
+3. Check firewall settings
+
+## Log Levels
+
+Use different log levels to control verbosity:
+
+- `LogLevel: "error"` - Only errors
+- `LogLevel: "warn"` - Errors and warnings (NAT warnings, relay usage)
+- `LogLevel: "info"` - Normal operation (connection established messages) **[Recommended]**
+- `LogLevel: "debug"` - Detailed information (addresses, periodic checks)
+
+Set in `/etc/skypier/config.json`:
+
+```json
+{
+  "LogLevel": "info"
+}
+```
+
+## Monitoring in Real-Time
+
+To see only NAT and connection logs:
+
+```bash
+sudo /usr/local/bin/skypier-vpn | grep -E '\[NAT|HOLEPUNCH\]'
+```
+
+Or to see all connection-related logs:
+
+```bash
+sudo /usr/local/bin/skypier-vpn | grep -E '\[NAT|HOLEPUNCH|WATCHER\]'
+```
+
+## Troubleshooting NAT Issues
+
+### Check Current Status
+
+1. Start your node
+2. Wait 5-10 seconds
+3. Look for the NAT status message
+
+### If You See "Behind NAT" but Want Direct Connections
+
+1. **Enable UPnP on your router** (easiest)
+2. **Set up port forwarding:**
+   - Forward UDP port 4002 to your node's internal IP
+   - Some nodes may also use TCP port 4001
+3. **Check your node's addresses:**
+   ```bash
+   # Look for public IP addresses in the node startup logs
+   grep "Listening on addresses" /var/log/skypier.log
+   ```
+
+### If All Connections are Relayed
+
+This means hole punching isn't working. Check:
+
+1. Your NAT type (use online NAT type detection tools)
+2. Whether UPnP is enabled on your router
+3. Firewall rules blocking UDP traffic
+4. If you're behind multiple layers of NAT (e.g., ISP + home router)
+
+Symmetric NAT is the most restrictive and often requires relay connections.
+
+## Performance Impact
+
+**Direct Connections (Best):**
+- Lowest latency
+- Highest throughput
+- No relay overhead
+
+**Relayed Connections (Fallback):**
+- Higher latency (+50-200ms)
+- Lower throughput (bandwidth shared with relay)
+- Depends on relay server performance
+
+The logs will help you identify which peers are using relays so you can optimize your network setup.

pkg/ui/web

@@ -61,6 +61,8 @@ const (
 	ComponentNegotiate Component = "NEGOTIATE"
 	ComponentCrypto    Component = "CRYPTO"
 	ComponentWatcher   Component = "WATCHER"
+	ComponentNAT       Component = "NAT"
+	ComponentHolePunch Component = "HOLEPUNCH"
 )
 
 // componentColors maps components to their display colors
@@ -77,6 +79,8 @@ var componentColors = map[Component]string{
 	ComponentNegotiate: ColorBlue,
 	ComponentCrypto:    ColorGray,
 	ComponentWatcher:   ColorBoldYellow,
+	ComponentNAT:       ColorBoldMagenta,
+	ComponentHolePunch: ColorBoldGreen,
 }
 
 // levelColors maps log levels to their display colors
@@ -329,4 +333,6 @@ var (
 	NegotiateLog = NewLogger(ComponentNegotiate)
 	CryptoLog    = NewLogger(ComponentCrypto)
 	WatcherLog   = NewLogger(ComponentWatcher)
+	NATLog       = NewLogger(ComponentNAT)
+	HolePunchLog = NewLogger(ComponentHolePunch)
 )

pkg/utils/logger.go

@@ -11,6 +11,7 @@ import (
 	"github.com/libp2p/go-libp2p"
 	dht "github.com/libp2p/go-libp2p-kad-dht"
 	"github.com/libp2p/go-libp2p/core/crypto"
+	"github.com/libp2p/go-libp2p/core/event"
 	"github.com/libp2p/go-libp2p/core/host"
 	"github.com/libp2p/go-libp2p/core/network"
 	peerstore "github.com/libp2p/go-libp2p/core/peer"
@@ -109,6 +110,8 @@ func StartNode(innerConfig utils.InnerConfig, pk crypto.PrivKey, tcpPort string,
 		libp2p.Transport(quic.NewTransport),
 		libp2p.Transport(tcp.NewTCPTransport),
 		libp2p.NATPortMap(),
+		libp2p.EnableAutoNATv2(),
+		libp2p.EnableHolePunching(),
 		libp2p.Routing(func(h host.Host) (routing.PeerRouting, error) {
 			// Configure DHT with options to limit connection usage
 			idht, err = dht.New(ctx, h,
@@ -167,9 +170,52 @@ func StartNode(innerConfig utils.InnerConfig, pk crypto.PrivKey, tcpPort string,
 	// Refresh the routing table to help discover peers
 	// idht.RefreshRoutingTable()
 
+	// Start monitoring NAT status and hole punching events
+	go monitorNATStatus(ctx, node)
+
 	return node, idht, err
 }
 
+// logVPNConnectionType logs the connection method when a VPN stream is established
+func logVPNConnectionType(node host.Host, conn network.Conn) {
+	remoteAddr := conn.RemoteMultiaddr().String()
+	localAddr := conn.LocalMultiaddr().String()
+	peerID := conn.RemotePeer().ShortString()
+	direction := conn.Stat().Direction
+
+	// Determine connection type
+	if strings.Contains(remoteAddr, "/p2p-circuit/") {
+		utils.HolePunchLog.Info("🔄 VPN over RELAYED connection with peer %s", peerID)
+		utils.HolePunchLog.Debug("  └─ via circuit relay: %s", remoteAddr)
+		utils.HolePunchLog.Warn("  └─ ⚠ Performance may be degraded (using relay)")
+	} else if strings.Contains(remoteAddr, "/quic") {
+		if direction == network.DirInbound {
+			utils.HolePunchLog.Success("✓ VPN over DIRECT inbound QUIC from peer %s", peerID)
+			utils.HolePunchLog.Debug("  └─ Peer connected to us (hole punch success or we're public)")
+		} else {
+			utils.HolePunchLog.Success("✓ VPN over DIRECT outbound QUIC to peer %s", peerID)
+		}
+		utils.HolePunchLog.Debug("  └─ Local: %s", localAddr)
+		utils.HolePunchLog.Debug("  └─ Remote: %s", remoteAddr)
+	} else if strings.Contains(remoteAddr, "/tcp") {
+		if direction == network.DirInbound {
+			utils.HolePunchLog.Success("✓ VPN over DIRECT inbound TCP from peer %s", peerID)
+		} else {
+			utils.HolePunchLog.Success("✓ VPN over DIRECT outbound TCP to peer %s", peerID)
+		}
+		utils.HolePunchLog.Debug("  └─ Local: %s", localAddr)
+		utils.HolePunchLog.Debug("  └─ Remote: %s", remoteAddr)
+	} else {
+		utils.HolePunchLog.Info("VPN connection established with peer %s", peerID)
+		utils.HolePunchLog.Debug("  └─ Type: %s", remoteAddr)
+	}
+
+	// Check if connection is limited by resource manager
+	if conn.Stat().Limited {
+		utils.HolePunchLog.Warn("  └─ ⚠ VPN connection is RATE LIMITED by resource manager")
+	}
+}
+
 func shouldCloseStream(err error) bool {
 	if err == nil {
 		return false
@@ -224,6 +270,9 @@ func makeStreamHandler(node host.Host) network.StreamHandler {
 		streamLog.Info("Starting stream handler for peer: %s", peerID)
 		streamLog.Debug("Node status: %v (true=server, false=client)", utils.IS_NODE_HOST)
 
+		// Log VPN connection type (NAT/hole punching info)
+		logVPNConnectionType(node, s.Conn())
+
 		// CRITICAL: Protect this VPN connection from being pruned by the connection manager
 		// This prevents the connection manager from closing VPN streams when trimming connections
 		streamLog.Info("🛡️ Protecting VPN connection for peer %s", peerID)
@@ -379,3 +428,71 @@ func makeStreamHandler(node host.Host) network.StreamHandler {
 		}()
 	} // end of stream handler function
 } // end of makeStreamHandler
+
+// monitorNATStatus monitors and logs AutoNAT reachability status
+func monitorNATStatus(ctx context.Context, node host.Host) {
+	// Subscribe to AutoNAT reachability events
+	sub, err := node.EventBus().Subscribe(new(event.EvtPeerIdentificationCompleted))
+	if err != nil {
+		utils.NATLog.Error("Failed to subscribe to AutoNAT events: %v", err)
+		return
+	}
+	defer sub.Close()
+
+	utils.NATLog.Info("AutoNAT monitoring started")
+
+	// Check initial reachability status periodically
+	ticker := time.NewTicker(30 * time.Second)
+	defer ticker.Stop()
+
+	checkReachability := func() {
+		conns := node.Network().Conns()
+		if len(conns) == 0 {
+			utils.NATLog.Debug("No connections yet, reachability unknown")
+			return
+		}
+
+		// Check if we have any public addresses
+		hasPublicAddr := false
+		for _, addr := range node.Addrs() {
+			addrStr := addr.String()
+			// Check if address is not a private IP
+			if !strings.Contains(addrStr, "127.0.0.1") &&
+				!strings.Contains(addrStr, "192.168.") &&
+				!strings.Contains(addrStr, "10.") &&
+				!strings.Contains(addrStr, "172.16.") &&
+				!strings.Contains(addrStr, "172.17.") &&
+				!strings.Contains(addrStr, "172.18.") &&
+				!strings.Contains(addrStr, "172.19.") &&
+				!strings.Contains(addrStr, "172.2") &&
+				!strings.Contains(addrStr, "172.30.") &&
+				!strings.Contains(addrStr, "172.31.") {
+				hasPublicAddr = true
+				utils.NATLog.Debug("Public address detected: %s", addrStr)
+			}
+		}
+
+		if hasPublicAddr {
+			utils.NATLog.Success("✓ Node appears PUBLICLY reachable (has public addresses)")
+		} else {
+			utils.NATLog.Warn("⚠ Node appears behind NAT/firewall (only private addresses)")
+			utils.NATLog.Info("Hole punching or relay will be used for incoming connections")
+		}
+	}
+
+	// Initial check after 5 seconds
+	time.Sleep(5 * time.Second)
+	checkReachability()
+
+	for {
+		select {
+		case <-ctx.Done():
+			return
+		case <-ticker.C:
+			// Periodic reachability check
+			checkReachability()
+		case evt := <-sub.Out():
+			_ = evt // Event received, will trigger reachability check on next ticker
+		}
+	}
+}