diff --git a/cmd/tta/tta.go b/cmd/tta/tta.go index 5ed184c09..11bfd9ead 100644 --- a/cmd/tta/tta.go +++ b/cmd/tta/tta.go @@ -141,7 +141,6 @@ func main() { for { <-needConnCh c, err := connect() - log.Printf("Connect: %v", err) if err != nil { s := err.Error() if s != lastErr { diff --git a/tstest/integration/nat/nat_test.go b/tstest/integration/nat/nat_test.go index 8dbaad111..990d7c081 100644 --- a/tstest/integration/nat/nat_test.go +++ b/tstest/integration/nat/nat_test.go @@ -7,6 +7,7 @@ import ( "context" "encoding/json" "errors" + "flag" "fmt" "io" "log" @@ -27,9 +28,10 @@ import ( "tailscale.com/ipn/ipnstate" "tailscale.com/tailcfg" "tailscale.com/tstest/natlab/vnet" - "tailscale.com/types/logger" ) +var logTailscaled = flag.Bool("log-tailscaled", false, "log tailscaled output") + type natTest struct { tb testing.TB base string // base image @@ -94,6 +96,13 @@ func easy(c *vnet.Config) *vnet.Node { fmt.Sprintf("192.168.%d.1/24", n), vnet.EasyNAT)) } +func one2one(c *vnet.Config) *vnet.Node { + n := c.NumNodes() + 1 + return c.AddNode(c.AddNetwork( + fmt.Sprintf("2.%d.%d.%d", n, n, n), // public IP + fmt.Sprintf("172.16.%d.1/24", n), vnet.One2OneNAT)) +} + func easyPMP(c *vnet.Config) *vnet.Node { n := c.NumNodes() + 1 return c.AddNode(c.AddNetwork( @@ -205,11 +214,13 @@ func (nt *natTest) runTest(node1, node2 addNodeFunc) { for i, c := range clients { i, c := i, c eg.Go(func() error { - wg.Add(1) - go func() { - defer wg.Done() - streamDaemonLogs(ctx, t, c, fmt.Sprintf("node%d:", i)) - }() + if *logTailscaled { + wg.Add(1) + go func() { + defer wg.Done() + streamDaemonLogs(ctx, t, c, fmt.Sprintf("node%d:", i)) + }() + } st, err := c.Status(ctx) if err != nil { return fmt.Errorf("node%d status: %w", i, err) @@ -236,10 +247,41 @@ func (nt *natTest) runTest(node1, node2 addNodeFunc) { t.Fatalf("initial setup: %v", err) } - route, err := ping(ctx, lc1, sts[1].Self.TailscaleIPs[0]) - t.Logf("ping route: %v, %v", logger.AsJSON(route), err) + defer nt.vnet.Close() + + pingRes, err := ping(ctx, lc1, sts[1].Self.TailscaleIPs[0]) + if err != nil { + t.Fatalf("ping failure: %v", err) + } + route := classifyPing(pingRes) + t.Logf("ping route: %v", route) +} + +func classifyPing(pr *ipnstate.PingResult) pingRoute { + if pr == nil { + return routeNil + } + if pr.Endpoint != "" { + ap, err := netip.ParseAddrPort(pr.Endpoint) + if err == nil { + if ap.Addr().IsPrivate() { + return routeLocal + } + return routeDirect + } + } + return routeDERP // presumably } +type pingRoute string + +const ( + routeDERP pingRoute = "derp" + routeLocal pingRoute = "local" + routeDirect pingRoute = "direct" + routeNil pingRoute = "nil" // *ipnstate.PingResult is nil +) + func streamDaemonLogs(ctx context.Context, t testing.TB, c *vnet.NodeAgentClient, nodeID string) { ctx, cancel := context.WithCancel(ctx) defer cancel() @@ -336,3 +378,23 @@ func TestEasyPMPHard(t *testing.T) { nt := newNatTest(t) nt.runTest(easyPMP, hard) } + +func TestHardHardPMP(t *testing.T) { + nt := newNatTest(t) + nt.runTest(hard, hardPMP) +} + +func TestHardHard(t *testing.T) { + nt := newNatTest(t) + nt.runTest(hard, hard) +} + +func TestEasyOne2One(t *testing.T) { + nt := newNatTest(t) + nt.runTest(easy, one2one) +} + +func TestHardOne2One(t *testing.T) { + nt := newNatTest(t) + nt.runTest(hard, one2one) +} diff --git a/tstest/natlab/vnet/vnet.go b/tstest/natlab/vnet/vnet.go index f920f20a9..0baec5e9b 100644 --- a/tstest/natlab/vnet/vnet.go +++ b/tstest/natlab/vnet/vnet.go @@ -247,7 +247,6 @@ func stringifyTEI(tei stack.TransportEndpointID) string { func (n *network) acceptTCP(r *tcp.ForwarderRequest) { reqDetails := r.ID() - log.Printf("AcceptTCP: %v", stringifyTEI(reqDetails)) clientRemoteIP := netaddrIPFromNetstackIP(reqDetails.RemoteAddress) destIP := netaddrIPFromNetstackIP(reqDetails.LocalAddress) destPort := reqDetails.LocalPort @@ -325,6 +324,8 @@ func (n *network) acceptTCP(r *tcp.ForwarderRequest) { return } + log.Printf("vnet-AcceptTCP: %v", stringifyTEI(reqDetails)) + var targetDial string if n.s.derpIPs.Contains(destIP) { targetDial = destIP.String() + ":" + strconv.Itoa(int(destPort)) @@ -641,12 +642,20 @@ func (s *Server) ServeUnixConn(uc *net.UnixConn, proto Protocol) { packetRaw = buf[:n] } else if proto == ProtocolQEMU { if _, err := io.ReadFull(uc, buf[:4]); err != nil { + if s.shutdownCtx.Err() != nil { + // Return without logging. + return + } log.Printf("ReadFull header: %v", err) return } n := binary.BigEndian.Uint32(buf[:4]) if _, err := io.ReadFull(uc, buf[4:4+n]); err != nil { + if s.shutdownCtx.Err() != nil { + // Return without logging. + return + } log.Printf("ReadFull pkt: %v", err) return } @@ -1234,16 +1243,13 @@ func (n *network) doNATIn(src, dst netip.AddrPort) (newDst netip.AddrPort) { peerWAN: src, lanAP: lanAP.dst, }, dst) - n.logf("XXX NAT: doNatIn: port mapping %v=>%v", dst, lanAP.dst) + //n.logf("NAT: doNatIn: port mapping %v=>%v", dst, lanAP.dst) return lanAP.dst } - n.logf("XXX NAT: doNatIn: port mapping EXPIRED for %v=>%v", dst, lanAP.dst) + n.logf("NAT: doNatIn: port mapping EXPIRED for %v=>%v", dst, lanAP.dst) delete(n.portMap, dst) return netip.AddrPort{} } - if len(n.portMap) > 0 { - n.logf("XXX NAT: doNatIn: no port mapping for %v; have %v", dst, n.portMap) - } return n.natTable.PickIncomingDst(src, dst, now) } @@ -1293,7 +1299,7 @@ func (n *network) doPortMap(src netip.Addr, dstLANPort, wantExtPort uint16, sec dst: dst, expiry: time.Now().Add(time.Duration(sec) * time.Second), }) - n.logf("XXX allocated NAT mapping from %v to %v", wanAP, dst) + n.logf("vnet: allocated NAT mapping from %v to %v", wanAP, dst) return wanAP.Port(), true } wantExtPort = rand.N(uint16(32<<10)) + 32<<10