tcp,udp,icmp: verbose logs

Author: ignoramous

intra/common.go

@@ -701,3 +701,10 @@ func logwif(cond bool) log.LogFn {
 	}
 	return log.VV
 }
+
+func pidstr(p ipn.Proxy) string {
+	if p == nil {
+		return "nil"
+	}
+	return p.ID().V()
+}

intra/tcp.go

@@ -163,7 +163,7 @@ func (h *tcpHandler) Proxy(gconn *netstack.GTCPConn, src, target netip.AddrPort)
 
 	if h.status.Load() == HDLEND {
 		err = errTcpEnd
-		log.D("tcp: proxy: end %s => %s", src, target)
+		log.D("tcp: proxy: %s end %s => %s [%v]", cid, src, target, actualTargets)
 		clos(gconn)
 		h.queueSummary(smm.done(err))
 		return deny
@@ -201,10 +201,15 @@ func (h *tcpHandler) Proxy(gconn *netstack.GTCPConn, src, target netip.AddrPort)
 		} // else not a dns request
 	} // if ipn.Exit then let it connect as-is (aka exit)
 
+	log.VV("tcp: %s proxying %s => %s [%v] for %s; pids: %s",
+		cid, src, target, actualTargets, uid, pids)
+
 	// pick all realips to connect to
 	for i, dstipp := range actualTargets {
 		var px ipn.Proxy = nil
 		if px, err = h.prox.ProxyTo(dstipp, uid, pids); err != nil || px == nil {
+			log.W("tcp: dial: #%d: %s proxy(%s) to dst(%s) for %s; err %v",
+				i, cid, pidstr(px), dstipp, uid, err)
 			continue
 		}
 
@@ -233,6 +238,9 @@ func (h *tcpHandler) handle(px ipn.Proxy, src net.Conn, boundSrc, target netip.A
 
 	start := time.Now()
 
+	log.VV("tcp: %s dial %s: attempt:  %s [%s] => %s for %s",
+		smm.ID, pidstr(px), src.LocalAddr(), boundSrc, target, smm.UID)
+
 	// github.com/google/gvisor/blob/5ba35f516b5c2/test/benchmarks/tcp/tcp_proxy.go#L359
 	// ref: stackoverflow.com/questions/63656117
 	// ref: stackoverflow.com/questions/40328025

intra/udp.go

@@ -261,12 +261,16 @@ func (h *udpHandler) Connect(gconn *netstack.GUDPConn, src, target netip.AddrPor
 			pids = []string{muxpid}
 		} // else: mxr will dial this conn with a different pid
 	}
+
+	log.VV("udp: connect: %s proxying %s => %s [%v] for %s; pids: %s, mux? %t",
+		cid, src, target, actualTargets, uid, pids, mux)
+
 	// note: fake-dns-ips shouldn't be un-nated / un-alg'd
 	for i, dstipp := range actualTargets {
 		rttstart := time.Now()
 
 		if px, err = h.prox.ProxyTo(dstipp, uid, pids); err != nil || px == nil {
-			log.W("udp: connect: %s failed to get proxy from %s: %v", cid, pids, err)
+			log.W("udp: connect: #%d: %s failed to get proxy from %s: %v", i, cid, pidstr(px), err)
 			errs = err // disconnect if loop terminates
 			continue
 		}
@@ -275,6 +279,10 @@ func (h *udpHandler) Connect(gconn *netstack.GUDPConn, src, target netip.AddrPor
 		if mux { // mux is not supported by all proxies (few like Exit, Base, WG support it)
 			pc, err = h.mux.associate(cid, pxid, uid, src, selectedTarget, px.Dialer().Announce, vendor(dmx))
 		} else {
+
+			log.VV("udp: connect: #%d: attempt: %s proxy(%s) to dst(%s) for %s; mux? %t",
+				i, cid, pxid, selectedTarget, uid, mux)
+
 			if settings.PortForward.Load() {
 				boundSrc := makeAnyAddrPort(src)
 				pc, err = px.Dialer().DialBind("udp", boundSrc.String(), selectedTarget.String())