fix: disable t.Parallel on TestPortForward (#10449)

I've said it before, I'll say it again: you can't create a timed context before calling `t.Parallel()` and then use it after.

Fixes flakes like https://github.com/coder/coder/actions/runs/6716682414/job/18253279157

I've chosen just to drop `t.Parallel()` entirely rather than create a second context after the parallel call, since the vast majority of the test time happens before where the parallel call was.  It does all the tailnet setup before `t.Parallel()`.
Leaving a call to `t.Parallel()` is a bug risk for future maintainers to come in and use the wrong context in the latter part of the test by accident.

cli/portforward.go

@@ -98,7 +98,7 @@ func (r *RootCmd) portForward() *clibase.Cmd {
 				return xerrors.Errorf("await agent: %w", err)
 			}
 
-			var logger slog.Logger
+			logger := slog.Make()
 			if r.verbose {
 				logger = slog.Make(sloghuman.Sink(inv.Stdout)).Leveled(slog.LevelDebug)
 			}
@@ -131,7 +131,7 @@ func (r *RootCmd) portForward() *clibase.Cmd {
 			defer closeAllListeners()
 
 			for i, spec := range specs {
-				l, err := listenAndPortForward(ctx, inv, conn, wg, spec)
+				l, err := listenAndPortForward(ctx, inv, conn, wg, spec, logger)
 				if err != nil {
 					return err
 				}
@@ -185,7 +185,15 @@ func (r *RootCmd) portForward() *clibase.Cmd {
 	return cmd
 }
 
-func listenAndPortForward(ctx context.Context, inv *clibase.Invocation, conn *codersdk.WorkspaceAgentConn, wg *sync.WaitGroup, spec portForwardSpec) (net.Listener, error) {
+func listenAndPortForward(
+	ctx context.Context,
+	inv *clibase.Invocation,
+	conn *codersdk.WorkspaceAgentConn,
+	wg *sync.WaitGroup,
+	spec portForwardSpec,
+	logger slog.Logger,
+) (net.Listener, error) {
+	logger = logger.With(slog.F("network", spec.listenNetwork), slog.F("address", spec.listenAddress))
 	_, _ = fmt.Fprintf(inv.Stderr, "Forwarding '%v://%v' locally to '%v://%v' in the workspace\n", spec.listenNetwork, spec.listenAddress, spec.dialNetwork, spec.dialAddress)
 
 	var (
@@ -218,6 +226,7 @@ func listenAndPortForward(ctx context.Context, inv *clibase.Invocation, conn *co
 	if err != nil {
 		return nil, xerrors.Errorf("listen '%v://%v': %w", spec.listenNetwork, spec.listenAddress, err)
 	}
+	logger.Debug(ctx, "listening")
 
 	wg.Add(1)
 	go func(spec portForwardSpec) {
@@ -227,12 +236,14 @@ func listenAndPortForward(ctx context.Context, inv *clibase.Invocation, conn *co
 			if err != nil {
 				// Silently ignore net.ErrClosed errors.
 				if xerrors.Is(err, net.ErrClosed) {
+					logger.Debug(ctx, "listener closed")
 					return
 				}
 				_, _ = fmt.Fprintf(inv.Stderr, "Error accepting connection from '%v://%v': %v\n", spec.listenNetwork, spec.listenAddress, err)
 				_, _ = fmt.Fprintln(inv.Stderr, "Killing listener")
 				return
 			}
+			logger.Debug(ctx, "accepted connection", slog.F("remote_addr", netConn.RemoteAddr()))
 
 			go func(netConn net.Conn) {
 				defer netConn.Close()
@@ -242,8 +253,10 @@ func listenAndPortForward(ctx context.Context, inv *clibase.Invocation, conn *co
 					return
 				}
 				defer remoteConn.Close()
+				logger.Debug(ctx, "dialed remote", slog.F("remote_addr", netConn.RemoteAddr()))
 
 				agentssh.Bicopy(ctx, netConn, remoteConn)
+				logger.Debug(ctx, "connection closing", slog.F("remote_addr", netConn.RemoteAddr()))
 			}(netConn)
 		}
 	}(spec)

cli/portforward_test.go

@@ -140,9 +140,10 @@ func TestPortForward(t *testing.T) {
 
 	for _, c := range cases {
 		c := c
-		// Delay parallel tests here because setupLocal reserves
+		// No parallel tests here because setupLocal reserves
 		// a free open port which is not guaranteed to be free
 		// between the listener closing and port-forward ready.
+		//nolint:tparallel,paralleltest
 		t.Run(c.name+"_OnePort", func(t *testing.T) {
 			p1 := setupTestListener(t, c.setupRemote(t))
 
@@ -166,8 +167,6 @@ func TestPortForward(t *testing.T) {
 			}()
 			pty.ExpectMatchContext(ctx, "Ready!")
 
-			t.Parallel() // Port is reserved, enable parallel execution.
-
 			// Open two connections simultaneously and test them out of
 			// sync.
 			d := net.Dialer{Timeout: testutil.WaitShort}
@@ -185,6 +184,10 @@ func TestPortForward(t *testing.T) {
 			require.ErrorIs(t, err, context.Canceled)
 		})
 
+		// No parallel tests here because setupLocal reserves
+		// a free open port which is not guaranteed to be free
+		// between the listener closing and port-forward ready.
+		//nolint:tparallel,paralleltest
 		t.Run(c.name+"_TwoPorts", func(t *testing.T) {
 			var (
 				p1 = setupTestListener(t, c.setupRemote(t))
@@ -213,8 +216,6 @@ func TestPortForward(t *testing.T) {
 			}()
 			pty.ExpectMatchContext(ctx, "Ready!")
 
-			t.Parallel() // Port is reserved, enable parallel execution.
-
 			// Open a connection to both listener 1 and 2 simultaneously and
 			// then test them out of order.
 			d := net.Dialer{Timeout: testutil.WaitShort}
@@ -234,6 +235,10 @@ func TestPortForward(t *testing.T) {
 	}
 
 	// Test doing TCP and UDP at the same time.
+	// No parallel tests here because setupLocal reserves
+	// a free open port which is not guaranteed to be free
+	// between the listener closing and port-forward ready.
+	//nolint:tparallel,paralleltest
 	t.Run("All", func(t *testing.T) {
 		var (
 			dials = []addr{}
@@ -266,8 +271,6 @@ func TestPortForward(t *testing.T) {
 		}()
 		pty.ExpectMatchContext(ctx, "Ready!")
 
-		t.Parallel() // Port is reserved, enable parallel execution.
-
 		// Open connections to all items in the "dial" array.
 		var (
 			d     = net.Dialer{Timeout: testutil.WaitShort}

tailnet/conn.go

@@ -936,10 +936,12 @@ func (c *Conn) Listen(network, addr string) (net.Listener, error) {
 }
 
 func (c *Conn) DialContextTCP(ctx context.Context, ipp netip.AddrPort) (*gonet.TCPConn, error) {
+	c.logger.Debug(ctx, "dial tcp", slog.F("addr_port", ipp))
 	return c.netStack.DialContextTCP(ctx, ipp)
 }
 
 func (c *Conn) DialContextUDP(ctx context.Context, ipp netip.AddrPort) (*gonet.UDPConn, error) {
+	c.logger.Debug(ctx, "dial udp", slog.F("addr_port", ipp))
 	return c.netStack.DialContextUDP(ctx, ipp)
 }