cmd/tailscale, logtail: add 'tailscale debug daemon-logs' logtail mechanism

Fixes #6836

Change-Id: Ia6eb39ff8972e1aa149aeeb63844a97497c2cf04
Signed-off-by: Brad Fitzpatrick <bradfitz@tailscale.com>

client/tailscale/localclient.go

@@ -257,6 +257,23 @@ func (lc *LocalClient) DaemonMetrics(ctx context.Context) ([]byte, error) {
 	return lc.get200(ctx, "/localapi/v0/metrics")
 }
 
+// TailDaemonLogs returns a stream the Tailscale daemon's logs as they arrive.
+// Close the context to stop the stream.
+func (lc *LocalClient) TailDaemonLogs(ctx context.Context) (io.Reader, error) {
+	req, err := http.NewRequestWithContext(ctx, "GET", "http://"+apitype.LocalAPIHost+"/localapi/v0/logtap", nil)
+	if err != nil {
+		return nil, err
+	}
+	res, err := lc.doLocalRequestNiceError(req)
+	if err != nil {
+		return nil, err
+	}
+	if res.StatusCode != 200 {
+		return nil, errors.New(res.Status)
+	}
+	return res.Body, nil
+}
+
 // Pprof returns a pprof profile of the Tailscale daemon.
 func (lc *LocalClient) Pprof(ctx context.Context, pprofType string, sec int) ([]byte, error) {
 	var secArg string

cmd/tailscale/cli/debug.go

@@ -76,6 +76,17 @@
 			Exec:      runDaemonGoroutines,
 			ShortHelp: "print tailscaled's goroutines",
 		},
+		{
+			Name:      "daemon-logs",
+			Exec:      runDaemonLogs,
+			ShortHelp: "watch tailscaled's server logs",
+			FlagSet: (func() *flag.FlagSet {
+				fs := newFlagSet("daemon-logs")
+				fs.IntVar(&daemonLogsArgs.verbose, "verbose", 0, "verbosity level")
+				fs.BoolVar(&daemonLogsArgs.time, "time", false, "include client time")
+				return fs
+			})(),
+		},
 		{
 			Name:      "metrics",
 			Exec:      runDaemonMetrics,
@@ -419,6 +430,39 @@ func runDaemonGoroutines(ctx context.Context, args []string) error {
 	return nil
 }
 
+var daemonLogsArgs struct {
+	verbose int
+	time    bool
+}
+
+func runDaemonLogs(ctx context.Context, args []string) error {
+	logs, err := localClient.TailDaemonLogs(ctx)
+	if err != nil {
+		return err
+	}
+	d := json.NewDecoder(logs)
+	for {
+		var line struct {
+			Text    string `json:"text"`
+			Verbose int    `json:"v"`
+			Time    string `json:"client_time"`
+		}
+		err := d.Decode(&line)
+		if err != nil {
+			return err
+		}
+		line.Text = strings.TrimSpace(line.Text)
+		if line.Text == "" || line.Verbose > daemonLogsArgs.verbose {
+			continue
+		}
+		if daemonLogsArgs.time {
+			fmt.Printf("%s %s\n", line.Time, line.Text)
+		} else {
+			fmt.Println(line.Text)
+		}
+	}
+}
+
 var metricsArgs struct {
 	watch bool
 }

ipn/localapi/localapi.go

@@ -34,6 +34,7 @@
 	"tailscale.com/ipn"
 	"tailscale.com/ipn/ipnlocal"
 	"tailscale.com/ipn/ipnstate"
+	"tailscale.com/logtail"
 	"tailscale.com/net/netutil"
 	"tailscale.com/safesocket"
 	"tailscale.com/tailcfg"
@@ -77,6 +78,7 @@
 	"id-token":                    (*Handler).serveIDToken,
 	"login-interactive":           (*Handler).serveLoginInteractive,
 	"logout":                      (*Handler).serveLogout,
+	"logtap":                      (*Handler).serveLogTap,
 	"metrics":                     (*Handler).serveMetrics,
 	"ping":                        (*Handler).servePing,
 	"prefs":                       (*Handler).servePrefs,
@@ -421,6 +423,45 @@ func (h *Handler) serveGoroutines(w http.ResponseWriter, r *http.Request) {
 	w.Write(buf)
 }
 
+// serveLogTap taps into the tailscaled/logtail server output and streams
+// it to the client.
+func (h *Handler) serveLogTap(w http.ResponseWriter, r *http.Request) {
+	ctx := r.Context()
+
+	// Require write access (~root) as the logs could contain something
+	// sensitive.
+	if !h.PermitWrite {
+		http.Error(w, "logtap access denied", http.StatusForbidden)
+		return
+	}
+	if r.Method != "GET" {
+		http.Error(w, "GET required", http.StatusMethodNotAllowed)
+		return
+	}
+	f, ok := w.(http.Flusher)
+	if !ok {
+		http.Error(w, "streaming unsupported", http.StatusInternalServerError)
+		return
+	}
+
+	io.WriteString(w, `{"text":"[logtap connected]\n"}`+"\n")
+	f.Flush()
+
+	msgc := make(chan string, 16)
+	unreg := logtail.RegisterLogTap(msgc)
+	defer unreg()
+
+	for {
+		select {
+		case <-ctx.Done():
+			return
+		case msg := <-msgc:
+			io.WriteString(w, msg)
+			f.Flush()
+		}
+	}
+}
+
 func (h *Handler) serveMetrics(w http.ResponseWriter, r *http.Request) {
 	// Require write access out of paranoia that the metrics
 	// might contain something sensitive.

logtail/logtail.go

@@ -26,6 +26,7 @@
 	"tailscale.com/logtail/backoff"
 	"tailscale.com/net/interfaces"
 	tslogger "tailscale.com/types/logger"
+	"tailscale.com/util/set"
 	"tailscale.com/wgengine/monitor"
 )
 
@@ -505,6 +506,7 @@ func (l *Logger) tryDrainWake() {
 }
 
 func (l *Logger) sendLocked(jsonBlob []byte) (int, error) {
+	tapSend(jsonBlob)
 	if logtailDisabled.Load() {
 		return len(jsonBlob), nil
 	}
@@ -758,3 +760,48 @@ func parseAndRemoveLogLevel(buf []byte) (level int, cleanBuf []byte) {
 	}
 	return 0, buf
 }
+
+var (
+	tapSetSize atomic.Int32
+	tapMu      sync.Mutex
+	tapSet     set.HandleSet[chan<- string]
+)
+
+// RegisterLogTap registers dst to get a copy of every log write. The caller
+// must call unregister when done watching.
+//
+// This would ideally be a method on Logger, but Logger isn't really available
+// in most places; many writes go via stderr which filch redirects to the
+// singleton Logger set up early. For better or worse, there's basically only
+// one Logger within the program. This mechanism at least works well for
+// tailscaled. It works less well for a binary with multiple tsnet.Servers. Oh
+// well. This then subscribes to all of them.
+func RegisterLogTap(dst chan<- string) (unregister func()) {
+	tapMu.Lock()
+	defer tapMu.Unlock()
+	h := tapSet.Add(dst)
+	tapSetSize.Store(int32(len(tapSet)))
+	return func() {
+		tapMu.Lock()
+		defer tapMu.Unlock()
+		delete(tapSet, h)
+		tapSetSize.Store(int32(len(tapSet)))
+	}
+}
+
+// tapSend relays the JSON blob to any/all registered local debug log watchers
+// (somebody running "tailscale debug daemon-logs").
+func tapSend(jsonBlob []byte) {
+	if tapSetSize.Load() == 0 {
+		return
+	}
+	s := string(jsonBlob)
+	tapMu.Lock()
+	defer tapMu.Unlock()
+	for _, dst := range tapSet {
+		select {
+		case dst <- s:
+		default:
+		}
+	}
+}