tstest/integration/vms: use an in-process logcatcher

This adapts the existing in-process logcatcher from tstest/integration
into a public type and uses it on the side of testcontrol. This also
fixes a bug in the Alpine Linux OpenRC unit that makes every value in
`/etc/default/tailscaled` exported into tailscaled's environment, a-la
systemd [Service].EnviromentFile.

Signed-off-by: Christine Dodrill <xe@tailscale.com>

cmd/tailscaled/tailscaled.openrc

@@ -1,6 +1,8 @@
 #!/sbin/openrc-run
 
+set -a
 source /etc/default/tailscaled
+set +a
 
 command="/usr/sbin/tailscaled"
 command_args="--state=/var/lib/tailscale/tailscaled.state --port=$PORT --socket=/var/run/tailscale/tailscaled.sock $FLAGS"

tstest/integration/integration.go

@@ -9,8 +9,14 @@
 package integration
 
 import (
+	"bytes"
 	"crypto/rand"
 	"crypto/tls"
+	"encoding/json"
+	"fmt"
+	"io"
+	"io/ioutil"
+	"log"
 	"net"
 	"net/http"
 	"net/http/httptest"
@@ -24,9 +30,11 @@ import (
 	"testing"
 	"time"
 
+	"go4.org/mem"
 	"tailscale.com/derp"
 	"tailscale.com/derp/derphttp"
 	"tailscale.com/net/stun/stuntest"
+	"tailscale.com/smallzstd"
 	"tailscale.com/tailcfg"
 	"tailscale.com/types/key"
 	"tailscale.com/types/logger"
@@ -160,3 +168,90 @@ func RunDERPAndSTUN(t testing.TB, logf logger.Logf, ipAddress string) (derpMap *
 
 	return m
 }
+
+// LogCatcher is a minimal logcatcher for the logtail upload client.
+type LogCatcher struct {
+	mu     sync.Mutex
+	logf   logger.Logf
+	buf    bytes.Buffer
+	gotErr error
+	reqs   int
+}
+
+// UseLogf makes the logcatcher implementation use a given logf function
+// to dump all logs to.
+func (lc *LogCatcher) UseLogf(fn logger.Logf) {
+	lc.mu.Lock()
+	defer lc.mu.Unlock()
+	lc.logf = fn
+}
+
+func (lc *LogCatcher) logsContains(sub mem.RO) bool {
+	lc.mu.Lock()
+	defer lc.mu.Unlock()
+	return mem.Contains(mem.B(lc.buf.Bytes()), sub)
+}
+
+func (lc *LogCatcher) numRequests() int {
+	lc.mu.Lock()
+	defer lc.mu.Unlock()
+	return lc.reqs
+}
+
+func (lc *LogCatcher) logsString() string {
+	lc.mu.Lock()
+	defer lc.mu.Unlock()
+	return lc.buf.String()
+}
+
+func (lc *LogCatcher) ServeHTTP(w http.ResponseWriter, r *http.Request) {
+	var body io.Reader = r.Body
+	if r.Header.Get("Content-Encoding") == "zstd" {
+		var err error
+		body, err = smallzstd.NewDecoder(body)
+		if err != nil {
+			log.Printf("bad caught zstd: %v", err)
+			http.Error(w, err.Error(), 400)
+			return
+		}
+	}
+	bodyBytes, _ := ioutil.ReadAll(body)
+
+	type Entry struct {
+		Logtail struct {
+			ClientTime time.Time `json:"client_time"`
+			ServerTime time.Time `json:"server_time"`
+			Error      struct {
+				BadData string `json:"bad_data"`
+			} `json:"error"`
+		} `json:"logtail"`
+		Text string `json:"text"`
+	}
+	var jreq []Entry
+	var err error
+	if len(bodyBytes) > 0 && bodyBytes[0] == '[' {
+		err = json.Unmarshal(bodyBytes, &jreq)
+	} else {
+		var ent Entry
+		err = json.Unmarshal(bodyBytes, &ent)
+		jreq = append(jreq, ent)
+	}
+
+	lc.mu.Lock()
+	defer lc.mu.Unlock()
+	lc.reqs++
+	if lc.gotErr == nil && err != nil {
+		lc.gotErr = err
+	}
+	if err != nil {
+		fmt.Fprintf(&lc.buf, "error from %s of %#q: %v\n", r.Method, bodyBytes, err)
+	} else {
+		for _, ent := range jreq {
+			fmt.Fprintf(&lc.buf, "%s\n", strings.TrimSpace(ent.Text))
+			if lc.logf != nil {
+				lc.logf("%s", strings.TrimSpace(ent.Text))
+			}
+		}
+	}
+	w.WriteHeader(200) // must have no content, but not a 204
+}

tstest/integration/integration_test.go

@@ -21,7 +21,6 @@ import (
 	"path/filepath"
 	"regexp"
 	"runtime"
-	"strings"
 	"sync"
 	"sync/atomic"
 	"testing"
@@ -30,7 +29,6 @@ import (
 	"go4.org/mem"
 	"tailscale.com/ipn/ipnstate"
 	"tailscale.com/safesocket"
-	"tailscale.com/smallzstd"
 	"tailscale.com/tailcfg"
 	"tailscale.com/tstest"
 	"tailscale.com/tstest/integration/testcontrol"
@@ -38,7 +36,6 @@ import (
 )
 
 var (
-	verboseLogCatcher = flag.Bool("verbose-log-catcher", false, "verbose log catcher logging")
 	verboseTailscaled = flag.Bool("verbose-tailscaled", false, "verbose tailscaled logging")
 )
 
@@ -292,7 +289,7 @@ type testEnv struct {
 	t        testing.TB
 	Binaries *Binaries
 
-	LogCatcher       *logCatcher
+	LogCatcher       *LogCatcher
 	LogCatcherServer *httptest.Server
 
 	Control       *testcontrol.Server
@@ -321,7 +318,7 @@ func newTestEnv(t testing.TB, bins *Binaries, opts ...testEnvOpt) *testEnv {
 		t.Skip("not tested/working on Windows yet")
 	}
 	derpMap := RunDERPAndSTUN(t, logger.Discard, "127.0.0.1")
-	logc := new(logCatcher)
+	logc := new(LogCatcher)
 	control := &testcontrol.Server{
 		DERPMap: derpMap,
 	}
@@ -594,84 +591,6 @@ func (n *testNode) MustStatus(tb testing.TB) *ipnstate.Status {
 	return st
 }
 
-// logCatcher is a minimal logcatcher for the logtail upload client.
-type logCatcher struct {
-	mu     sync.Mutex
-	buf    bytes.Buffer
-	gotErr error
-	reqs   int
-}
-
-func (lc *logCatcher) logsContains(sub mem.RO) bool {
-	lc.mu.Lock()
-	defer lc.mu.Unlock()
-	return mem.Contains(mem.B(lc.buf.Bytes()), sub)
-}
-
-func (lc *logCatcher) numRequests() int {
-	lc.mu.Lock()
-	defer lc.mu.Unlock()
-	return lc.reqs
-}
-
-func (lc *logCatcher) logsString() string {
-	lc.mu.Lock()
-	defer lc.mu.Unlock()
-	return lc.buf.String()
-}
-
-func (lc *logCatcher) ServeHTTP(w http.ResponseWriter, r *http.Request) {
-	var body io.Reader = r.Body
-	if r.Header.Get("Content-Encoding") == "zstd" {
-		var err error
-		body, err = smallzstd.NewDecoder(body)
-		if err != nil {
-			log.Printf("bad caught zstd: %v", err)
-			http.Error(w, err.Error(), 400)
-			return
-		}
-	}
-	bodyBytes, _ := ioutil.ReadAll(body)
-
-	type Entry struct {
-		Logtail struct {
-			ClientTime time.Time `json:"client_time"`
-			ServerTime time.Time `json:"server_time"`
-			Error      struct {
-				BadData string `json:"bad_data"`
-			} `json:"error"`
-		} `json:"logtail"`
-		Text string `json:"text"`
-	}
-	var jreq []Entry
-	var err error
-	if len(bodyBytes) > 0 && bodyBytes[0] == '[' {
-		err = json.Unmarshal(bodyBytes, &jreq)
-	} else {
-		var ent Entry
-		err = json.Unmarshal(bodyBytes, &ent)
-		jreq = append(jreq, ent)
-	}
-
-	lc.mu.Lock()
-	defer lc.mu.Unlock()
-	lc.reqs++
-	if lc.gotErr == nil && err != nil {
-		lc.gotErr = err
-	}
-	if err != nil {
-		fmt.Fprintf(&lc.buf, "error from %s of %#q: %v\n", r.Method, bodyBytes, err)
-	} else {
-		for _, ent := range jreq {
-			fmt.Fprintf(&lc.buf, "%s\n", strings.TrimSpace(ent.Text))
-			if *verboseLogCatcher {
-				fmt.Fprintf(os.Stderr, "%s\n", strings.TrimSpace(ent.Text))
-			}
-		}
-	}
-	w.WriteHeader(200) // must have no content, but not a 204
-}
-
 // trafficTrap is an HTTP proxy handler to note whether any
 // HTTP traffic tries to leave localhost from tailscaled. We don't
 // expect any, so any request triggers a failure.

tstest/integration/vms/nixos_test.go

@@ -213,6 +213,7 @@ func (h Harness) makeNixOSImage(t *testing.T, d Distro, cdir string) string {
 	}
 	cmd.Env = append(os.Environ(), "NIX_PATH=nixpkgs="+d.url)
 	cmd.Dir = outpath
+	t.Logf("running %s %#v", "nixos-generate", cmd.Args)
 	if err := cmd.Run(); err != nil {
 		t.Fatalf("error while making NixOS image for %s: %v", d.name, err)
 	}

tstest/integration/vms/vms_test.go

@@ -250,7 +250,11 @@ func (h Harness) fetchDistro(t *testing.T, resultDistro Distro) string {
 	cdir = filepath.Join(cdir, "tailscale", "vm-test")
 
 	if strings.HasPrefix(resultDistro.name, "nixos") {
-		return h.makeNixOSImage(t, resultDistro, cdir)
+		var imagePath string
+		t.Run("nix-build", func(t *testing.T) {
+			imagePath = h.makeNixOSImage(t, resultDistro, cdir)
+		})
+		return imagePath
 	}
 
 	qcowPath := filepath.Join(cdir, "qcow2", resultDistro.sha256sum)
@@ -593,6 +597,7 @@ func TestVMIntegrationEndToEnd(t *testing.T) {
 
 	mux := http.NewServeMux()
 	mux.Handle("/", cs)
+	mux.Handle("/c/", &integration.LogCatcher{})
 
 	// This handler will let the virtual machines tell the host information about that VM.
 	// This is used to maintain a list of port->IP address mappings that are known to be