Add more logging for failed tests

spikecurtis · spikecurtis · commit af83870b43e4 · 2023-07-14T11:21:30.000Z
Signed-off-by: Spike Curtis &lt;spike@coder.com&gt;
diff --git a/agent/agent_test.go b/agent/agent_test.go
@@ -1797,6 +1797,7 @@ func TestAgent_WriteVSCodeConfigs(t *testing.T) {
 }
 
 func setupSSHCommand(t *testing.T, beforeArgs []string, afterArgs []string) (*ptytest.PTYCmd, pty.Process) {
+	logger := slogtest.Make(t, nil).Named("testsetup").Leveled(slog.LevelDebug)
 	//nolint:dogsled
 	agentConn, _, _, _, _ := setupAgent(t, agentsdk.Manifest{}, 0)
 	listener, err := net.Listen("tcp", "127.0.0.1:0")
@@ -1807,16 +1808,20 @@ func setupSSHCommand(t *testing.T, beforeArgs []string, afterArgs []string) (*pt
 		for {
 			conn, err := listener.Accept()
 			if err != nil {
+				logger.Debug(context.Background(), "error listening", slog.Error(err))
 				return
 			}
+			logger.Debug(context.Background(), "got local TCP connection")
 
 			ctx, cancel := context.WithTimeout(context.Background(), testutil.WaitLong)
 			ssh, err := agentConn.SSH(ctx)
 			cancel()
 			if err != nil {
+				logger.Debug(context.Background(), "failed to connect to agent SSH")
 				_ = conn.Close()
 				return
 			}
+			logger.Debug(context.Background(), "got SSH connection to agent")
 			waitGroup.Add(1)
 			go func() {
 				agentssh.Bicopy(context.Background(), conn, ssh)
diff --git a/tailnet/conn.go b/tailnet/conn.go
@@ -588,6 +588,7 @@ var unixEpoch = time.Unix(0, 0)
 // the Wireguard layer. It's the callers responsibility to provide  a timeout, otherwise this function will block
 // forever.
 func (c *Conn) AwaitReachable(ctx context.Context, ip netip.Addr) bool {
+	logger := c.logger.With(slog.F("ip", ip))
 	rightAway := make(chan struct{}, 1)
 	rightAway <- struct{}{}
 	tkr := time.NewTicker(50 * time.Millisecond)
@@ -603,7 +604,7 @@ func (c *Conn) AwaitReachable(ctx context.Context, ip netip.Addr) bool {
 
 		nKeys := c.getNodeKeysForIP(ip)
 		if len(nKeys) == 0 {
-			c.logger.Debug(ctx, "missing node(s) for IP", slog.F("ip", ip.String()))
+			logger.Debug(ctx, "missing node(s) for IP", slog.F("ip", ip.String()))
 			continue
 		}
 		s := c.Status()
@@ -613,9 +614,13 @@ func (c *Conn) AwaitReachable(ctx context.Context, ip netip.Addr) bool {
 				c.logger.Debug(ctx, "missing status for node", slog.F("node", nKey.ShortString()))
 				continue
 			}
+			logger.Debug(ctx, "checking peer for handshake",
+				slog.F("peer", ps.PublicKey.ShortString()), slog.F("last_handshake", ps.LastHandshake))
 			// Note that wireguard initializes the last handshake to the Unix Epoch until there is at least one
 			// handshake
 			if ps.LastHandshake.After(unixEpoch) {
+				//nolint: gocritic
+				logger.Debug(ctx, "IP is now reachable", slog.F("peer", ps.PublicKey.ShortString()))
 				return true
 			}
 		}
