From 823d970d60eb177d7e11d87ed256de91a576d55a Mon Sep 17 00:00:00 2001
From: Josh Bleecher Snyder <josh@tailscale.com>
Date: Fri, 18 Feb 2022 13:00:08 -0800
Subject: [PATCH] control/controlclient: use structured logging for
 MapResponse.ControlTime

Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
---
 control/controlclient/direct.go        |  2 +-
 tstest/integration/integration.go      | 12 ++++++++++++
 tstest/integration/integration_test.go |  3 ++-
 3 files changed, 15 insertions(+), 2 deletions(-)

diff --git a/control/controlclient/direct.go b/control/controlclient/direct.go
index e5acbbaf0..320f688bb 100644
--- a/control/controlclient/direct.go
+++ b/control/controlclient/direct.go
@@ -773,7 +773,7 @@ func (c *Direct) sendMapRequest(ctx context.Context, maxPolls int, cb func(*netm
 		}
 
 		if resp.ControlTime != nil && !resp.ControlTime.IsZero() {
-			c.logf("netmap: control time is %v", resp.ControlTime.UTC().Format(time.RFC3339Nano))
+			c.logf.JSON(1, "controltime", resp.ControlTime.UTC())
 		}
 		if resp.KeepAlive {
 			vlogf("netmap: got keep-alive")
diff --git a/tstest/integration/integration.go b/tstest/integration/integration.go
index 4ff647312..402c6b81c 100644
--- a/tstest/integration/integration.go
+++ b/tstest/integration/integration.go
@@ -213,6 +213,7 @@ type LogCatcher struct {
 	buf    bytes.Buffer
 	gotErr error
 	reqs   int
+	raw    bool // indicates whether to store the raw JSON logs uploaded, instead of just the text
 }
 
 // UseLogf makes the logcatcher implementation use a given logf function
@@ -223,6 +224,13 @@ func (lc *LogCatcher) UseLogf(fn logger.Logf) {
 	lc.logf = fn
 }
 
+// StoreRawJSON instructs lc to save the raw JSON uploads, rather than just the text.
+func (lc *LogCatcher) StoreRawJSON() {
+	lc.mu.Lock()
+	defer lc.mu.Unlock()
+	lc.raw = true
+}
+
 func (lc *LogCatcher) logsContains(sub mem.RO) bool {
 	lc.mu.Lock()
 	defer lc.mu.Unlock()
@@ -315,6 +323,10 @@ func (lc *LogCatcher) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	} else {
 		id := privID.Public().String()[:3] // good enough for integration tests
 		for _, ent := range jreq {
+			if lc.raw {
+				lc.buf.Write(bodyBytes)
+				continue
+			}
 			fmt.Fprintf(&lc.buf, "%s\n", strings.TrimSpace(ent.Text))
 			if lc.logf != nil {
 				lc.logf("logcatch:%s: %s", id, strings.TrimSpace(ent.Text))
diff --git a/tstest/integration/integration_test.go b/tstest/integration/integration_test.go
index db936a387..16eb12a3b 100644
--- a/tstest/integration/integration_test.go
+++ b/tstest/integration/integration_test.go
@@ -149,6 +149,7 @@ func TestCollectPanic(t *testing.T) {
 func TestControlTimeLogLine(t *testing.T) {
 	t.Parallel()
 	env := newTestEnv(t)
+	env.LogCatcher.StoreRawJSON()
 	n := newTestNode(t, env)
 
 	n.StartDaemon()
@@ -157,7 +158,7 @@ func TestControlTimeLogLine(t *testing.T) {
 	n.AwaitRunning()
 
 	if err := tstest.WaitFor(20*time.Second, func() error {
-		const sub = `netmap: control time is 2020-08-03T00:00:00.000000001Z`
+		const sub = `"controltime":"2020-08-03T00:00:00.000000001Z"`
 		if !n.env.LogCatcher.logsContains(mem.S(sub)) {
 			return fmt.Errorf("log catcher didn't see %#q; got %s", sub, n.env.LogCatcher.logsString())
 		}