Zip output, more tasks, redaction tweaks and tests

tools/sgcollect/redact.go

@@ -2,7 +2,6 @@ package main
 
 import (
 	"bufio"
-	"bytes"
 	"crypto/sha1"
 	"encoding/hex"
 	"errors"
@@ -13,8 +12,8 @@ import (
 // CopyFunc is the signature of io.Copy.
 type CopyFunc func(io.Writer, io.Reader) (int64, error)
 
-// Copier returns a CopyFunc appropriate for the configured redaction level.
-func Copier(opts *SGCollectOptions) CopyFunc {
+// RedactCopier returns a CopyFunc appropriate for the configured redaction level.
+func RedactCopier(opts *SGCollectOptions) CopyFunc {
 	if opts.LogRedactionLevel == RedactNone {
 		return io.Copy
 	}
@@ -133,46 +132,3 @@ func Copier(opts *SGCollectOptions) CopyFunc {
 		return written, err
 	}
 }
-
-// maybeRedactBuffer searches the given buffer for a redacted chunk (data wrapped in <ud></ud> tags). If it finds one,
-// it returns a copy of buf with the contents redacted. If it finds an opening tag, but no closing tag, it returns
-// needMore=true, in this case the caller should call it again with more data (with the same starting position).
-// Note that only the first redacted string in the buffer will be redacted.
-func maybeRedactBuffer(buf []byte, salt []byte) (newBuf []byte, needMore bool) {
-	const startingTag = "<ud>"
-	const endingTag = "</ud>"
-
-	redactStartPos := bytes.Index(buf, []byte(startingTag))
-	if redactStartPos == -1 {
-		return buf, false
-	}
-	var beforeRedactBuf, redactBuf, afterRedactBuf []byte
-	beforeRedactBuf = buf[0:redactStartPos]
-
-	const startingTagLen = len(startingTag)
-	const endingTagLen = len(endingTag)
-
-	// This handles cases like <ud><ud>stuff</ud></ud> - we want the outermost tags to be redacted
-	depth := 1
-	for i := redactStartPos + startingTagLen; i < len(buf)-(startingTagLen+1); i++ {
-		if bytes.Equal(buf[i:i+startingTagLen+1], []byte(startingTag)) {
-			depth++
-			continue
-		}
-		if bytes.Equal(buf[i:i+endingTagLen+1], []byte(endingTag)) {
-			depth--
-			if depth == 0 {
-				beforeRedactBuf = buf[0:redactStartPos]
-				redactBuf = buf[redactStartPos+1 : i-1]
-				afterRedactBuf = buf[i+endingTagLen:]
-				redacted := sha1.Sum(append(salt, redactBuf...))
-				return append(append(beforeRedactBuf, redacted[:]...), afterRedactBuf...), false
-			}
-		}
-	}
-	if depth > 0 {
-		// We've seen an opening redact tag, but not a closing redact tag.
-		return nil, true
-	}
-	panic("unreachable")
-}

tools/sgcollect/redact_test.go

@@ -72,7 +72,7 @@ func TestRedactCopy(t *testing.T) {
 	for _, tc := range cases {
 		t.Run(tc.Name, func(t *testing.T) {
 			var buf bytes.Buffer
-			n, err := Copier(opts)(&buf, strings.NewReader(tc.Input))
+			n, err := RedactCopier(opts)(&buf, strings.NewReader(tc.Input))
 			require.NoError(t, err)
 			require.Equal(t, tc.Expected, buf.String())
 			require.Equal(t, int64(buf.Len()), n)
@@ -88,8 +88,26 @@ func FuzzRedactCopy(f *testing.F) {
 	f.Add("foo <ud>bar</ud> baz")
 	f.Fuzz(func(t *testing.T, in string) {
 		var buf bytes.Buffer
-		n, err := Copier(opts)(&buf, strings.NewReader(in))
+		n, err := RedactCopier(opts)(&buf, strings.NewReader(in))
 		require.NoError(t, err)
 		require.Equal(t, int64(buf.Len()), n)
 	})
 }
+
+// Verifies that RedactCopier doesn't change its input if it has nothing to do.
+func FuzzRedactCopyIdempotent(f *testing.F) {
+	opts := &SGCollectOptions{
+		LogRedactionSalt: "SALT",
+	}
+	f.Add("foo bar")
+	f.Fuzz(func(t *testing.T, in string) {
+		if strings.Contains(in, "<ud>") && strings.Contains(in, "</ud>") {
+			t.SkipNow()
+		}
+		var buf bytes.Buffer
+		n, err := RedactCopier(opts)(&buf, strings.NewReader(in))
+		require.NoError(t, err)
+		require.Equal(t, int64(buf.Len()), n)
+		require.Equal(t, buf.String(), in)
+	})
+}

tools/sgcollect/sgcollect_info.go

@@ -4,6 +4,7 @@ import (
 	"bytes"
 	"encoding/json"
 	"fmt"
+	"io"
 	"log"
 	"net/http"
 	"net/url"
@@ -13,6 +14,7 @@ import (
 	"sync"
 	"time"
 
+	"github.com/couchbase/sync_gateway/base"
 	"github.com/couchbase/sync_gateway/rest"
 	"github.com/google/uuid"
 	"gopkg.in/alecthomas/kingpin.v2"
@@ -167,6 +169,7 @@ var sgBinPaths = [...]string{
 	"/opt/couchbase-sync-gateway/bin/sync_gateway",
 	`C:\Program Files (x86)\Couchbase\sync_gateway.exe`,
 	`C:\Program Files\Couchbase\Sync Gateway\sync_gateway.exe`,
+	"./sync_gateway",
 }
 
 var bootstrapConfigLocations = [...]string{
@@ -176,6 +179,7 @@ var bootstrapConfigLocations = [...]string{
 	"/etc/sync_gateway/sync_gateway.json",
 	`C:\Program Files (x86)\Couchbase\serviceconfig.json`,
 	`C:\Program Files\Couchbase\Sync Gateway\serviceconfig.json`,
+	"./sync_gateway.json",
 }
 
 func findSGBinaryAndConfigs(sgURL *url.URL, opts *SGCollectOptions) (string, string) {
@@ -205,6 +209,7 @@ func findSGBinaryAndConfigs(sgURL *url.URL, opts *SGCollectOptions) (string, str
 			break
 		}
 	}
+	log.Printf("SG binary at %q and config at %q.", binary, config)
 	return binary, config
 }
 
@@ -215,6 +220,12 @@ func main() {
 		os.Exit(1)
 	}
 
+	// This also sets up logging into the output file.
+	tr, err := NewTaskRunner(opts)
+	if err != nil {
+		log.Fatal(err)
+	}
+
 	sgURL, ok := determineSGURL(opts)
 	if !ok {
 		log.Println("Failed to communicate with Sync Gateway. Check that Sync Gateway is reachable.")
@@ -227,33 +238,27 @@ func main() {
 		zipFilename += ".zip"
 	}
 	zipDir := filepath.Dir(zipFilename)
-	_, err := os.Stat(zipDir)
+	_, err = os.Stat(zipDir)
 	if err != nil {
 		log.Fatalf("Failed to check if output directory (%s) is accesible: %v", zipDir, err)
 	}
 
-	//shouldRedact := opts.LogRedactionLevel != RedactNone
-	//var uploadURL string
-	//var redactedZipFilename string
-	//if shouldRedact {
-	//	redactedZipFilename = strings.TrimSuffix(zipFilename, ".zip") + "-redacted.zip"
-	//	uploadURL = generateUploadURL(opts, redactedZipFilename)
-	//} else {
-	//	uploadURL = generateUploadURL(opts, zipFilename)
-	//}
+	shouldRedact := opts.LogRedactionLevel != RedactNone
+	var redactedZipFilename string
+	if shouldRedact {
+		redactedZipFilename = strings.TrimSuffix(zipFilename, ".zip") + "-redacted.zip"
+	}
 
 	var config rest.RunTimeServerConfigResponse
 	err = getJSONOverHTTP(sgURL.String()+"/_config?include_runtime=true", opts, &config)
 	if err != nil {
 		log.Printf("Failed to get SG config. Some information might not be collected.")
 	}
 
-	tr, err := NewTaskRunner(opts)
-	if err != nil {
-		log.Fatal(err)
-	}
-	defer tr.Finalize()
-
+	tr.Run(RawStringTask{
+		name: "sgcollect_info version",
+		val:  base.LongVersionString,
+	})
 	tr.Run(new(SGCollectOptionsTask))
 
 	for _, task := range makeOSTasks() {
@@ -264,4 +269,21 @@ func main() {
 	for _, task := range tasks {
 		tr.Run(task)
 	}
+
+	tr.Finalize()
+	log.Printf("Writing unredacted logs to %s", zipFilename)
+	hostname, _ := os.Hostname()
+	prefix := fmt.Sprintf("sgcollect_info_%s_%s", hostname, time.Now().Format("20060102-150405"))
+	err = tr.ZipResults(zipFilename, prefix, io.Copy)
+	if err != nil {
+		log.Printf("WARNING: failed to produce output file %s: %v", zipFilename, err)
+	}
+	if shouldRedact {
+		log.Printf("Writing redacted logs to %s", zipFilename)
+		err = tr.ZipResults(redactedZipFilename, prefix, RedactCopier(opts))
+		if err != nil {
+			log.Printf("WARNING: failed to produce output file %s: %v", redactedZipFilename, err)
+		}
+	}
+	log.Println("Done.")
 }

tools/sgcollect/task_runner.go

@@ -1,9 +1,11 @@
 package main
 
 import (
+	"archive/zip"
 	"context"
 	"fmt"
 	"io"
+	"io/fs"
 	"log"
 	"os"
 	"path/filepath"
@@ -41,6 +43,7 @@ func NewTaskRunner(opts *SGCollectOptions) (*TaskRunner, error) {
 }
 
 func (tr *TaskRunner) Finalize() {
+	log.Println("Task runner finalizing...")
 	for _, fd := range tr.files {
 		err := fd.Close()
 		if err != nil {
@@ -49,6 +52,56 @@ func (tr *TaskRunner) Finalize() {
 	}
 }
 
+func (tr *TaskRunner) ZipResults(outputPath string, prefix string, copier CopyFunc) error {
+	fd, err := os.OpenFile(outputPath, os.O_CREATE|os.O_TRUNC|os.O_WRONLY, 0644)
+	if err != nil {
+		return fmt.Errorf("failed to reate output: %w", err)
+	}
+	defer func(fd *os.File) {
+		err := fd.Close()
+		if err != nil {
+			log.Printf("WARN: failed to close unredacted output file: %v", err)
+		}
+	}(fd)
+
+	zw := zip.NewWriter(fd)
+	defer func(zw *zip.Writer) {
+		err := zw.Close()
+		if err != nil {
+			log.Printf("WARN: failed to close unredacted output zipper: %v", err)
+		}
+	}(zw)
+
+	err = filepath.WalkDir(tr.tmpDir, func(path string, d fs.DirEntry, err error) error {
+		if d.IsDir() {
+			return nil
+		}
+		// Returning a non-nil error will stop the walker completely - we want to capture as much as we can.
+		fileFd, err := os.Open(path)
+		if err != nil {
+			log.Printf("WARN: failed to open %s: %v", path, err)
+			return nil
+		}
+		defer fileFd.Close()
+
+		zipPath := prefix + string(os.PathSeparator) + strings.TrimPrefix(path, tr.tmpDir+string(os.PathSeparator)) // TODO: properly remove prefix
+		zipFile, err := zw.Create(zipPath)
+		if err != nil {
+			log.Printf("WARN: failed to open %s in zip: %v", zipPath, err)
+			return nil
+		}
+		_, err = copier(zipFile, fileFd)
+		if err != nil {
+			log.Printf("WARN: failed to copy to %s in zip: %v", zipPath, err)
+		}
+		return nil
+	})
+	if err != nil {
+		return fmt.Errorf("walker error: %w", err)
+	}
+	return nil
+}
+
 // setupSGCollectLog will redirect the standard library log package's output to both stderr and a log file in the temporary directory.
 func (tr *TaskRunner) setupSGCollectLog() error {
 	fd, err := tr.createFile("sgcollect_info.log")
@@ -62,17 +115,22 @@ func (tr *TaskRunner) setupSGCollectLog() error {
 
 func (tr *TaskRunner) createFile(name string) (*os.File, error) {
 	path := filepath.Join(tr.tmpDir, name)
-	return os.OpenFile(path, os.O_CREATE|os.O_TRUNC|os.O_RDWR, 0644)
+	return os.OpenFile(path, os.O_CREATE|os.O_APPEND|os.O_RDWR, 0644)
 }
 
 func (tr *TaskRunner) writeHeader(w io.Writer, task SGCollectTask) error {
 	separator := strings.Repeat("=", 78)
 	// example:
 	// ==============================================================================
 	// Collect server status
-	// *main.URLTask: http://127.0.0.1:4985/_status
+	// main.SGCollectTaskEx (main.URLTask): http://127.0.0.1:4985/_status
 	// ==============================================================================
-	_, err := fmt.Fprintf(w, "%s\n%s\n%T: %s\n%s\n", separator, task.Name(), task, task.Header(), separator)
+	var err error
+	if tex, ok := task.(SGCollectTaskEx); ok {
+		_, err = fmt.Fprintf(w, "%s\n%s\n%T (%T): %s\n%s\n", separator, task.Name(), task, tex.SGCollectTask, task.Header(), separator)
+	} else {
+		_, err = fmt.Fprintf(w, "%s\n%s\n%T: %s\n%s\n", separator, task.Name(), task, task.Header(), separator)
+	}
 	return err
 }
 
@@ -97,7 +155,7 @@ func (tr *TaskRunner) Run(task SGCollectTask) {
 	fd, ok := tr.files[outputFile]
 	if !ok {
 		var err error
-		fd, err = os.OpenFile(filepath.Join(tr.tmpDir, outputFile), os.O_CREATE|os.O_TRUNC|os.O_WRONLY, 0644)
+		fd, err = tr.createFile(outputFile)
 		if err != nil {
 			log.Printf("FAILed to run %q - failed to create file: %v", task.Name(), err)
 			return
@@ -114,15 +172,23 @@ func (tr *TaskRunner) Run(task SGCollectTask) {
 	}
 
 	run := func() {
+		defer func() {
+			if panicked := recover(); panicked != nil {
+				log.Printf("PANIC - %s [%s]: %v", task.Name(), task.Header(), panicked)
+			}
+		}()
 		ctx := context.Background()
 		if to := tex.Timeout(); to > 0 {
 			var cancel context.CancelFunc
 			ctx, cancel = context.WithTimeout(ctx, to)
 			defer cancel()
 		}
+		log.Printf("RUN - %s [%s]", task.Name(), task.Header())
+		name := task.Name()
+		_ = name
 		err := task.Run(ctx, tr.opts, fd)
 		if err != nil {
-			log.Printf("FAILed to run %q [%s]: %v", task.Name(), task.Header(), err)
+			log.Printf("FAIL - %q [%s]: %v", task.Name(), task.Header(), err)
 			_, _ = fmt.Fprintln(fd, err.Error())
 			return
 		}
@@ -131,14 +197,16 @@ func (tr *TaskRunner) Run(task SGCollectTask) {
 
 	if tex.NumSamples() > 0 {
 		for i := 0; i < tex.NumSamples(); i++ {
-			log.Printf("Taking sample %d of %q [%s] after %v seconds", i+1, task.Name(), task.Header(), tex.Interval())
 			run()
-			time.Sleep(tex.Interval())
+			if i != tex.NumSamples()-1 {
+				log.Printf("Taking sample %d of %q [%s] after %v seconds", i+2, task.Name(), task.Header(), tex.Interval())
+				time.Sleep(tex.Interval())
+			}
 		}
 	} else {
 		run()
 	}
-	_, err := fd.WriteString("\n\n")
+	_, err := fd.WriteString("\n")
 	if err != nil {
 		log.Printf("WARN %s [%s] - failed to write closing newline: %v", task.Name(), task.Header(), err)
 	}