From 1a1123d461f725d91e543f112d893593c0771477 Mon Sep 17 00:00:00 2001
From: Brad Fitzpatrick <bradfitz@tailscale.com>
Date: Wed, 5 May 2021 13:59:40 -0700
Subject: [PATCH] wgengine: fix pendopen debug to not track SYN+ACKs, show
 Node.Online state

Signed-off-by: Brad Fitzpatrick <bradfitz@tailscale.com>
---
 wgengine/pendopen.go | 27 +++++++++++++++++++++++----
 1 file changed, 23 insertions(+), 4 deletions(-)

diff --git a/wgengine/pendopen.go b/wgengine/pendopen.go
index 0903a2d10..df98d670a 100644
--- a/wgengine/pendopen.go
+++ b/wgengine/pendopen.go
@@ -104,6 +104,7 @@ func (e *userspaceEngine) trackOpenPostFilterOut(pp *packet.Parsed, t *tstun.Wra
 
 	if pp.IPVersion == 0 ||
 		pp.IPProto != ipproto.TCP ||
+		pp.TCPFlags&packet.TCPAck != 0 ||
 		pp.TCPFlags&packet.TCPSyn == 0 {
 		return
 	}
@@ -219,14 +220,32 @@ func (e *userspaceEngine) onOpenTimeout(flow flowtrack.Tuple) {
 	// handshake completed, which is what I want.
 	_ = ps.LastHandshake
 
-	e.logf("open-conn-track: timeout opening %v to node %v; lastSeen=%v, lastRecv=%v",
+	online := "?"
+	if n.Online != nil {
+		if *n.Online {
+			online = "yes"
+		} else {
+			online = "no"
+		}
+	}
+	e.logf("open-conn-track: timeout opening %v to node %v; lastSeen=%v, online=%v, lastRecv=%v",
 		flow, n.Key.ShortString(),
-		agoOrNever(lastSeen), agoOrNever(e.magicConn.LastRecvActivityOfDisco(n.DiscoKey)))
+		durFmt(lastSeen),
+		online,
+		durFmt(e.magicConn.LastRecvActivityOfDisco(n.DiscoKey)))
 }
 
-func agoOrNever(t time.Time) string {
+func durFmt(t time.Time) string {
 	if t.IsZero() {
 		return "never"
 	}
-	return time.Since(t).Round(time.Second).String()
+	d := time.Since(t).Round(time.Second)
+	if d < 10*time.Minute {
+		// node.LastSeen times are rounded very coarsely, and
+		// we compare times from different clocks (server vs
+		// local), so negative is common when close. Format as
+		// "recent" if negative or actually recent.
+		return "recent"
+	}
+	return d.String()
 }