doctor, ipnlocal: add scutil check and tweak logging

This prints the slightly-parsed output of "scutil --dns" on macOS when
running a bugreport with the diagnose flag. Additionally, this reworks
how the doctor package prints logs to ensure that we don't interleave
log output between checks while still allowing checks to execute
concurrently.

Signed-off-by: Andrew Dunham <andrew@du.nham.ca>
Change-Id: If3049f8c4e1b2cf624ed8670883ad6166b15bf7f

cmd/tailscaled/depaware.txt

@@ -201,6 +201,7 @@ tailscale.com/cmd/tailscaled dependencies: (generated by github.com/tailscale/de
         tailscale.com/disco                                          from tailscale.com/derp+
         tailscale.com/doctor                                         from tailscale.com/ipn/ipnlocal
         tailscale.com/doctor/routetable                              from tailscale.com/ipn/ipnlocal
+        tailscale.com/doctor/scutil                                  from tailscale.com/ipn/ipnlocal
         tailscale.com/envknob                                        from tailscale.com/control/controlclient+
         tailscale.com/health                                         from tailscale.com/control/controlclient+
         tailscale.com/health/healthmsg                               from tailscale.com/ipn/ipnlocal

doctor/doctor.go

@@ -28,41 +28,54 @@ type Check interface {
 
 // RunChecks runs a list of checks in parallel, and logs any returned errors
 // after all checks have returned.
-func RunChecks(ctx context.Context, log logger.Logf, checks ...Check) {
+func RunChecks(ctx context.Context, logf logger.Logf, checks ...Check) {
 	if len(checks) == 0 {
 		return
 	}
 
-	type namedErr struct {
+	type logRecord struct {
-		name string
+		format string
-		err  error
+		args   []any
 	}
-	errs := make(chan namedErr, len(checks))
 
-	var wg sync.WaitGroup
+	var (
+		wg       sync.WaitGroup
+		outputMu sync.Mutex // protecting logf
+	)
 	wg.Add(len(checks))
 	for _, check := range checks {
 		go func(c Check) {
 			defer wg.Done()
 
-			plog := logger.WithPrefix(log, c.Name()+": ")
+			// Log everything in a batch at the end of the function
-			errs <- namedErr{
+			// so that we don't interleave messages.
-				name: c.Name(),
+			var (
-				err:  c.Run(ctx, plog),
+				logMu sync.Mutex // protects logs; acquire before outputMu
+				logs  []logRecord
+			)
+			checkLogf := func(format string, args ...any) {
+				logMu.Lock()
+				defer logMu.Unlock()
+				logs = append(logs, logRecord{format, args})
+			}
+			defer func() {
+				logMu.Lock()
+				defer logMu.Unlock()
+				outputMu.Lock()
+				defer outputMu.Unlock()
+
+				name := c.Name()
+				for _, log := range logs {
+					logf(name+": "+log.format, log.args...)
+				}
+			}()
+
+			if err := c.Run(ctx, checkLogf); err != nil {
+				checkLogf("error: %v", err)
 			}
 		}(check)
 	}
-
 	wg.Wait()
-	close(errs)
-
-	for n := range errs {
-		if n.err == nil {
-			continue
-		}
-
-		log("check %s: %v", n.name, n.err)
-	}
 }
 
 // CheckFunc creates a Check from a name and a function.

doctor/scutil/scutil.go

@@ -0,0 +1,13 @@
+// Copyright (c) Tailscale Inc & AUTHORS
+// SPDX-License-Identifier: BSD-3-Clause
+
+// Package scutil provides a doctor.Check that runs scutil to print debug
+// information about the system on macOS.
+package scutil
+
+// Check implements the doctor.Check interface.
+type Check struct{}
+
+func (Check) Name() string {
+	return "scutil"
+}

doctor/scutil/scutil_darwin.go

@@ -0,0 +1,156 @@
+// Copyright (c) Tailscale Inc & AUTHORS
+// SPDX-License-Identifier: BSD-3-Clause
+
+package scutil
+
+import (
+	"context"
+	"os/exec"
+	"regexp"
+	"strconv"
+	"strings"
+
+	"tailscale.com/types/logger"
+)
+
+func (Check) Run(ctx context.Context, logf logger.Logf) error {
+	cmd := exec.CommandContext(ctx, "scutil", "--dns")
+	out, err := cmd.CombinedOutput()
+	if err != nil {
+		logf("error running scutil --dns: %v", err)
+		return nil
+	}
+
+	parsed, err := parseScutilDNS(logf, string(out))
+	if err != nil {
+		logf("error parsing scutil --dns output: %v", err)
+		return nil
+	}
+
+	for _, section := range parsed.Sections {
+		logf("section: %s", section.Name)
+		for _, entry := range section.Entries {
+			logf("  entry: %s", entry.Name)
+			for key, val := range entry.Config {
+				logf("    %s=%q", key, val)
+			}
+			for key, list := range entry.ListConfig {
+				for i, val := range list {
+					logf("    %s[%d]=%q", key, i, val)
+				}
+			}
+		}
+	}
+	return nil
+}
+
+type dnsInfo struct {
+	Sections []*dnsSection
+}
+
+type dnsSection struct {
+	Name    string
+	Entries []*dnsEntry
+}
+
+type dnsEntry struct {
+	Name       string
+	Config     map[string]string
+	ListConfig map[string][]string
+}
+
+var (
+	reSpacePrefix = regexp.MustCompile(`\A\s+[^\s]`)
+	reNumSuffix   = regexp.MustCompile(`\A(.+)\[(\d+)\]\z`)
+)
+
+func parseScutilDNS(logf logger.Logf, data string) (*dnsInfo, error) {
+	lines := strings.Split(strings.TrimSpace(data), "\n")
+	ret := &dnsInfo{}
+
+	const (
+		stateEntry = iota
+		stateEntryData
+	)
+	var (
+		currState   int = stateEntry
+		currSection *dnsSection
+		currEntry   *dnsEntry
+	)
+	for _, ll := range lines {
+		switch currState {
+		case stateEntry:
+			// We're looking for a new 'resolver' section; if the
+			// current line has the 'resolver ' prefix, then we've
+			// found one.
+			if strings.HasPrefix(ll, "resolver ") {
+				currEntry = &dnsEntry{
+					Name:       ll,
+					Config:     make(map[string]string),
+					ListConfig: make(map[string][]string),
+				}
+				currSection.Entries = append(currSection.Entries, currEntry)
+				currState = stateEntryData
+				continue
+			}
+
+			// Otherwise, if we have a non-blank line treat it as a
+			// new section.
+			llTrim := strings.TrimSpace(ll)
+			if llTrim != "" {
+				currSection = &dnsSection{
+					Name: llTrim,
+				}
+				ret.Sections = append(ret.Sections, currSection)
+
+				// Still looking for a new resolver; no state change.
+			}
+
+		case stateEntryData:
+			// We're inside a 'resolver' section; if the current
+			// line doesn't have a prefix of 1 or more spaces, then
+			// we're done the current section.
+			if !reSpacePrefix.MatchString(ll) {
+				// Looking for a new 'resolver' entry.
+				currState = stateEntry
+				continue
+			}
+
+			key, val, ok := strings.Cut(ll, ":")
+			if !ok {
+				logf("unexpected: did not find ':' in: %q", ll)
+				continue
+			}
+
+			key = strings.TrimSpace(key)
+			val = strings.TrimSpace(val)
+
+			// If there's a '[##]' suffix of key, then we treat
+			// this as a list of items.
+			if sm := reNumSuffix.FindStringSubmatch(key); sm != nil {
+				index, err := strconv.Atoi(sm[2])
+				if err != nil {
+					logf("unexpected: bad index: %q", sm[2])
+					continue
+				}
+				key = sm[1]
+
+				sl := currEntry.ListConfig[key]
+				if index == len(sl) {
+					sl = append(sl, val)
+				} else {
+					logf("unexpected: out-of-order index: %d (existing len=%d)", index, len(sl))
+					continue
+				}
+				currEntry.ListConfig[key] = sl
+			} else {
+				if _, ok := currEntry.Config[key]; ok {
+					logf("unexpected: duplicate key %q", key)
+					continue
+				}
+				currEntry.Config[key] = val
+			}
+		}
+	}
+	return ret, nil
+}

doctor/scutil/scutil_darwin_test.go

@@ -0,0 +1,124 @@
+// Copyright (c) Tailscale Inc & AUTHORS
+// SPDX-License-Identifier: BSD-3-Clause
+
+package scutil
+
+import (
+	"reflect"
+	"testing"
+
+	"github.com/davecgh/go-spew/spew"
+)
+
+// Example output from a 2022 MacBook Pro with Tailscale installed, slightly
+// redacted for length/clarity.
+const scutilDnsOutput = `DNS configuration
+
+resolver #1
+  search domain[0] : example.ts.net
+  search domain[1] : tailscale.com.beta.tailscale.net
+  search domain[2] : ts-dns.test
+  nameserver[0] : 100.100.100.100
+  if_index : 30 (utun3)
+  flags    : Supplemental, Request A records, Request AAAA records
+  reach    : 0x00000003 (Reachable,Transient Connection)
+  order    : 100200
+
+resolver #2
+  nameserver[0] : 8.8.8.8
+  nameserver[1] : 8.8.4.4
+  flags    : Request A records, Request AAAA records
+  reach    : 0x00000002 (Reachable)
+  order    : 200000
+
+DNS configuration (for scoped queries)
+
+resolver #1
+  nameserver[0] : 8.8.8.8
+  nameserver[1] : 8.8.4.4
+  if_index : 15 (en0)
+  flags    : Scoped, Request A records, Request AAAA records
+  reach    : 0x00000002 (Reachable)
+
+resolver #2
+  search domain[0] : example.ts.net
+  search domain[1] : tailscale.com.beta.tailscale.net
+  search domain[2] : ts-dns.test
+  nameserver[0] : 100.100.100.100
+  if_index : 30 (utun3)
+  flags    : Scoped, Request A records, Request AAAA records
+  reach    : 0x00000003 (Reachable,Transient Connection)
+`
+
+func TestParseScutilDNS(t *testing.T) {
+	info, err := parseScutilDNS(t.Logf, scutilDnsOutput)
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	expected := &dnsInfo{Sections: []*dnsSection{
+		{
+			Name: "DNS configuration",
+			Entries: []*dnsEntry{
+				{
+					Name: "resolver #1",
+					Config: map[string]string{
+						"if_index": "30 (utun3)",
+						"flags":    "Supplemental, Request A records, Request AAAA records",
+						"reach":    "0x00000003 (Reachable,Transient Connection)",
+						"order":    "100200",
+					},
+					ListConfig: map[string][]string{
+						"search domain": []string{"example.ts.net", "tailscale.com.beta.tailscale.net", "ts-dns.test"},
+						"nameserver":    []string{"100.100.100.100"},
+					},
+				},
+				{
+					Name: "resolver #2",
+					Config: map[string]string{
+						"flags": "Request A records, Request AAAA records",
+						"reach": "0x00000002 (Reachable)",
+						"order": "200000",
+					},
+					ListConfig: map[string][]string{
+						"nameserver": []string{"8.8.8.8", "8.8.4.4"},
+					},
+				},
+			},
+		},
+		{
+			Name: "DNS configuration (for scoped queries)",
+			Entries: []*dnsEntry{
+				{
+					Name: "resolver #1",
+					Config: map[string]string{
+						"if_index": "15 (en0)",
+						"flags":    "Scoped, Request A records, Request AAAA records",
+						"reach":    "0x00000002 (Reachable)",
+					},
+					ListConfig: map[string][]string{
+						"nameserver": []string{"8.8.8.8", "8.8.4.4"},
+					},
+				},
+				{
+					Name: "resolver #2",
+					Config: map[string]string{
+						"if_index": "30 (utun3)",
+						"flags":    "Scoped, Request A records, Request AAAA records",
+						"reach":    "0x00000003 (Reachable,Transient Connection)",
+					},
+					ListConfig: map[string][]string{
+						"search domain": []string{"example.ts.net", "tailscale.com.beta.tailscale.net", "ts-dns.test"},
+						"nameserver":    []string{"100.100.100.100"},
+					},
+				},
+			},
+		},
+	}}
+	if !reflect.DeepEqual(info, expected) {
+		t.Errorf("parse mismatch:\ngot: %s\nwant: %s",
+			spew.Sdump(info),
+			spew.Sdump(expected),
+		)
+	}
+}

doctor/scutil/scutil_notdarwin.go

@@ -0,0 +1,17 @@
+// Copyright (c) Tailscale Inc & AUTHORS
+// SPDX-License-Identifier: BSD-3-Clause
+
+//go:build !darwin
+
+package scutil
+
+import (
+	"context"
+
+	"tailscale.com/types/logger"
+)
+
+func (Check) Run(ctx context.Context, logf logger.Logf) error {
+	// unimplemented
+	return nil
+}

go.mod

@@ -18,6 +18,7 @@ require (
 	github.com/coreos/go-systemd v0.0.0-20191104093116-d3cd4ed1dbcf
 	github.com/creack/pty v1.1.17
 	github.com/dave/jennifer v1.4.1
+	github.com/davecgh/go-spew v1.1.1
 	github.com/dblohm7/wingoes v0.0.0-20221124203957-6ac47ab19aa5
 	github.com/dsnet/try v0.0.3
 	github.com/evanw/esbuild v0.14.53
@@ -139,7 +140,6 @@ require (
 	github.com/cloudflare/circl v1.1.0 // indirect
 	github.com/containerd/stargz-snapshotter/estargz v0.11.4 // indirect
 	github.com/daixiang0/gci v0.2.9 // indirect
-	github.com/davecgh/go-spew v1.1.1 // indirect
 	github.com/denis-tingajkin/go-header v0.4.2 // indirect
 	github.com/docker/cli v20.10.16+incompatible // indirect
 	github.com/docker/distribution v2.8.1+incompatible // indirect

ipn/ipnlocal/local.go

@@ -35,6 +35,7 @@ import (
 	"tailscale.com/control/controlclient"
 	"tailscale.com/doctor"
 	"tailscale.com/doctor/routetable"
+	"tailscale.com/doctor/scutil"
 	"tailscale.com/envknob"
 	"tailscale.com/health"
 	"tailscale.com/health/healthmsg"
@@ -4628,6 +4629,7 @@ func (b *LocalBackend) Doctor(ctx context.Context, logf logger.Logf) {
 
 	var checks []doctor.Check
 	checks = append(checks, routetable.Check{})
+	checks = append(checks, scutil.Check{})
 
 	// Print a log message if any of the global DNS resolvers are Tailscale
 	// IPs; this can interfere with our ability to connect to the Tailscale