From 9bc7a1bf082d76d0d68771806190bfa8aca47257 Mon Sep 17 00:00:00 2001 From: Andrew Dunham Date: Fri, 10 Feb 2023 16:05:03 -0500 Subject: [PATCH] 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 Change-Id: If3049f8c4e1b2cf624ed8670883ad6166b15bf7f --- cmd/tailscaled/depaware.txt | 1 + doctor/doctor.go | 53 ++++++---- doctor/scutil/scutil.go | 13 +++ doctor/scutil/scutil_darwin.go | 156 ++++++++++++++++++++++++++++ doctor/scutil/scutil_darwin_test.go | 124 ++++++++++++++++++++++ doctor/scutil/scutil_notdarwin.go | 17 +++ go.mod | 2 +- ipn/ipnlocal/local.go | 2 + 8 files changed, 347 insertions(+), 21 deletions(-) create mode 100644 doctor/scutil/scutil.go create mode 100644 doctor/scutil/scutil_darwin.go create mode 100644 doctor/scutil/scutil_darwin_test.go create mode 100644 doctor/scutil/scutil_notdarwin.go diff --git a/cmd/tailscaled/depaware.txt b/cmd/tailscaled/depaware.txt index 8f21502f0..d217e4320 100644 --- a/cmd/tailscaled/depaware.txt +++ b/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 diff --git a/doctor/doctor.go b/doctor/doctor.go index 7c3047e12..fe5d5aaee 100644 --- a/doctor/doctor.go +++ b/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 { - name string - err error + type logRecord struct { + format string + 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()+": ") - errs <- namedErr{ - name: c.Name(), - err: c.Run(ctx, plog), + // Log everything in a batch at the end of the function + // so that we don't interleave messages. + var ( + 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. diff --git a/doctor/scutil/scutil.go b/doctor/scutil/scutil.go new file mode 100644 index 000000000..eeed6cf7c --- /dev/null +++ b/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" +} diff --git a/doctor/scutil/scutil_darwin.go b/doctor/scutil/scutil_darwin.go new file mode 100644 index 000000000..3a5efa733 --- /dev/null +++ b/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 +} diff --git a/doctor/scutil/scutil_darwin_test.go b/doctor/scutil/scutil_darwin_test.go new file mode 100644 index 000000000..07905d151 --- /dev/null +++ b/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), + ) + } +} diff --git a/doctor/scutil/scutil_notdarwin.go b/doctor/scutil/scutil_notdarwin.go new file mode 100644 index 000000000..4fd9f9f4a --- /dev/null +++ b/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 +} diff --git a/go.mod b/go.mod index c0cd84264..bca20267e 100644 --- a/go.mod +++ b/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 diff --git a/ipn/ipnlocal/local.go b/ipn/ipnlocal/local.go index cc56040ba..a05ecb018 100644 --- a/ipn/ipnlocal/local.go +++ b/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