net/netcheck: use logger.ArgWriter in logConciseReport, fix comma bug, add tests

net/netcheck/netcheck.go

@@ -6,7 +6,7 @@
 package netcheck
 
 import (
-	"bytes"
+	"bufio"
 	"context"
 	"crypto/tls"
 	"errors"
@@ -841,42 +841,43 @@ func (c *Client) measureHTTPSLatency(ctx context.Context, reg *tailcfg.DERPRegio
 }
 
 func (c *Client) logConciseReport(r *Report, dm *tailcfg.DERPMap) {
-	buf := bytes.NewBuffer(make([]byte, 0, 256)) // empirically: 5 DERPs + IPv6 == ~233 bytes
-	fmt.Fprintf(buf, "udp=%v", r.UDP)
-	if !r.IPv4 {
-		fmt.Fprintf(buf, " v4=%v", r.IPv4)
-	}
-	fmt.Fprintf(buf, " v6=%v", r.IPv6)
-	fmt.Fprintf(buf, " mapvarydest=%v", r.MappingVariesByDestIP)
-	fmt.Fprintf(buf, " hair=%v", r.HairPinning)
-	if r.GlobalV4 != "" {
-		fmt.Fprintf(buf, " v4a=%v", r.GlobalV4)
-	}
-	if r.GlobalV6 != "" {
-		fmt.Fprintf(buf, " v6a=%v", r.GlobalV6)
-	}
-	fmt.Fprintf(buf, " derp=%v", r.PreferredDERP)
-	if r.PreferredDERP != 0 {
-		fmt.Fprintf(buf, " derpdist=")
-		for i, rid := range dm.RegionIDs() {
-			if i != 0 {
-				buf.WriteByte(',')
-			}
+	c.logf("%v", logger.ArgWriter(func(w *bufio.Writer) {
+		fmt.Fprintf(w, "udp=%v", r.UDP)
+		if !r.IPv4 {
+			fmt.Fprintf(w, " v4=%v", r.IPv4)
+		}
+
+		fmt.Fprintf(w, " v6=%v", r.IPv6)
+		fmt.Fprintf(w, " mapvarydest=%v", r.MappingVariesByDestIP)
+		fmt.Fprintf(w, " hair=%v", r.HairPinning)
+		if r.GlobalV4 != "" {
+			fmt.Fprintf(w, " v4a=%v", r.GlobalV4)
+		}
+		if r.GlobalV6 != "" {
+			fmt.Fprintf(w, " v6a=%v", r.GlobalV6)
+		}
+		fmt.Fprintf(w, " derp=%v", r.PreferredDERP)
+		if r.PreferredDERP != 0 {
+			fmt.Fprintf(w, " derpdist=")
 			needComma := false
-			if d := r.RegionV4Latency[rid]; d != 0 {
-				fmt.Fprintf(buf, "%dv4:%v", rid, d.Round(time.Millisecond))
-				needComma = true
-			}
-			if d := r.RegionV6Latency[rid]; d != 0 {
-				if needComma {
-					buf.WriteByte(',')
+			for _, rid := range dm.RegionIDs() {
+				if d := r.RegionV4Latency[rid]; d != 0 {
+					if needComma {
+						w.WriteByte(',')
+					}
+					fmt.Fprintf(w, "%dv4:%v", rid, d.Round(time.Millisecond))
+					needComma = true
+				}
+				if d := r.RegionV6Latency[rid]; d != 0 {
+					if needComma {
+						w.WriteByte(',')
+					}
+					fmt.Fprintf(w, "%dv6:%v", rid, d.Round(time.Millisecond))
+					needComma = true
 				}
-				fmt.Fprintf(buf, "%dv6:%v", rid, d.Round(time.Millisecond))
 			}
 		}
-	}
-
-	c.logf("%s", buf.Bytes())
+	}))
 }
 
 func (c *Client) timeNow() time.Time {

net/netcheck/netcheck_test.go

@@ -5,6 +5,7 @@
 package netcheck
 
 import (
+	"bytes"
 	"context"
 	"fmt"
 	"net"
@@ -443,3 +444,94 @@ func (p probeProto) String() string {
 	}
 	return "?"
 }
+
+func TestLogConciseReport(t *testing.T) {
+	dm := &tailcfg.DERPMap{
+		Regions: map[int]*tailcfg.DERPRegion{
+			1: nil,
+			2: nil,
+			3: nil,
+		},
+	}
+	const ms = time.Millisecond
+	tests := []struct {
+		name string
+		r    *Report
+		want string
+	}{
+		{
+			name: "no_udp",
+			r:    &Report{},
+			want: "udp=false v4=false v6=false mapvarydest= hair= derp=0",
+		},
+		{
+			name: "ipv4_one_region",
+			r: &Report{
+				UDP:           true,
+				IPv4:          true,
+				PreferredDERP: 1,
+				RegionLatency: map[int]time.Duration{
+					1: 10 * ms,
+				},
+				RegionV4Latency: map[int]time.Duration{
+					1: 10 * ms,
+				},
+			},
+			want: "udp=true v6=false mapvarydest= hair= derp=1 derpdist=1v4:10ms",
+		},
+		{
+			name: "ipv4_all_region",
+			r: &Report{
+				UDP:           true,
+				IPv4:          true,
+				PreferredDERP: 1,
+				RegionLatency: map[int]time.Duration{
+					1: 10 * ms,
+					2: 20 * ms,
+					3: 30 * ms,
+				},
+				RegionV4Latency: map[int]time.Duration{
+					1: 10 * ms,
+					2: 20 * ms,
+					3: 30 * ms,
+				},
+			},
+			want: "udp=true v6=false mapvarydest= hair= derp=1 derpdist=1v4:10ms,2v4:20ms,3v4:30ms",
+		},
+		{
+			name: "ipboth_all_region",
+			r: &Report{
+				UDP:           true,
+				IPv4:          true,
+				IPv6:          true,
+				PreferredDERP: 1,
+				RegionLatency: map[int]time.Duration{
+					1: 10 * ms,
+					2: 20 * ms,
+					3: 30 * ms,
+				},
+				RegionV4Latency: map[int]time.Duration{
+					1: 10 * ms,
+					2: 20 * ms,
+					3: 30 * ms,
+				},
+				RegionV6Latency: map[int]time.Duration{
+					1: 10 * ms,
+					2: 20 * ms,
+					3: 30 * ms,
+				},
+			},
+			want: "udp=true v6=true mapvarydest= hair= derp=1 derpdist=1v4:10ms,1v6:10ms,2v4:20ms,2v6:20ms,3v4:30ms,3v6:30ms",
+		},
+	}
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			var buf bytes.Buffer
+			c := &Client{Logf: func(f string, a ...interface{}) { fmt.Fprintf(&buf, f, a...) }}
+			c.logConciseReport(tt.r, dm)
+			if got := buf.String(); got != tt.want {
+				t.Errorf("unexpected result.\n got: %#q\nwant: %#q\n", got, tt.want)
+			}
+		})
+	}
+}