release-23.1: roachprod: redirect CRDB logs utility

pkg/BUILD.bazel

@@ -268,6 +268,7 @@ ALL_TESTS = [
     "//pkg/roachprod/cloud:cloud_test",
     "//pkg/roachprod/config:config_test",
     "//pkg/roachprod/install:install_test",
+    "//pkg/roachprod/logger:logger_test",
     "//pkg/roachprod/prometheus:prometheus_test",
     "//pkg/roachprod/ssh:ssh_test",
     "//pkg/roachprod/vm/gce:gce_test",
@@ -1420,6 +1421,7 @@ GO_TARGETS = [
     "//pkg/roachprod/install:install_test",
     "//pkg/roachprod/lock:lock",
     "//pkg/roachprod/logger:logger",
+    "//pkg/roachprod/logger:logger_test",
     "//pkg/roachprod/prometheus:prometheus",
     "//pkg/roachprod/prometheus:prometheus_test",
     "//pkg/roachprod/ssh:ssh",

pkg/cmd/roachtest/BUILD.bazel

@@ -46,9 +46,6 @@ go_library(
         "//pkg/util/ctxgroup",
         "//pkg/util/httputil",
         "//pkg/util/leaktest",
-        "//pkg/util/log",
-        "//pkg/util/log/logconfig",
-        "//pkg/util/log/logpb",
         "//pkg/util/quotapool",
         "//pkg/util/randutil",
         "//pkg/util/stop",

pkg/cmd/roachtest/run.go

@@ -23,9 +23,6 @@ import (
 	"github.com/cockroachdb/cockroach/pkg/roachprod/logger"
 	"github.com/cockroachdb/cockroach/pkg/util/allstacks"
 	"github.com/cockroachdb/cockroach/pkg/util/leaktest"
-	"github.com/cockroachdb/cockroach/pkg/util/log"
-	"github.com/cockroachdb/cockroach/pkg/util/log/logconfig"
-	"github.com/cockroachdb/cockroach/pkg/util/log/logpb"
 	"github.com/cockroachdb/cockroach/pkg/util/stop"
 	"github.com/cockroachdb/cockroach/pkg/util/timeutil"
 	"github.com/cockroachdb/errors"
@@ -109,7 +106,8 @@ func runTests(register func(registry.Registry), filter *registry.TestFilter) err
 		literalArtifactsDir = artifactsDir
 	}
 
-	setLogConfig(artifactsDir)
+	redirectLogger := redirectCRDBLogger(context.Background(), filepath.Join(artifactsDir, "roachtest.crdb.log"))
+	logger.InitCRDBLogConfig(redirectLogger)
 	runnerDir := filepath.Join(artifactsDir, runnerLogsDir)
 	runnerLogPath := filepath.Join(
 		runnerDir, fmt.Sprintf("test_runner-%d.log", timeutil.Now().Unix()))
@@ -167,20 +165,6 @@ func runTests(register func(registry.Registry), filter *registry.TestFilter) err
 	return err
 }
 
-// This diverts all the default non fatal logging to a file in `baseDir`. This is particularly
-// useful in CI, where without this, stderr/stdout are cluttered with logs from various
-// packages used in roachtest like sarama and testutils.
-func setLogConfig(baseDir string) {
-	logConf := logconfig.DefaultStderrConfig()
-	logConf.Sinks.Stderr.Filter = logpb.Severity_FATAL
-	if err := logConf.Validate(&baseDir); err != nil {
-		panic(err)
-	}
-	if _, err := log.ApplyConfig(logConf); err != nil {
-		panic(err)
-	}
-}
-
 // getUser takes the value passed on the command line and comes up with the
 // username to use.
 func getUser(userFlag string) string {
@@ -322,3 +306,14 @@ func testRunnerLogger(
 	shout(ctx, l, os.Stdout, "test runner logs in: %s", runnerLogPath)
 	return l, teeOpt
 }
+
+func redirectCRDBLogger(ctx context.Context, path string) *logger.Logger {
+	verboseCfg := logger.Config{}
+	var err error
+	l, err := verboseCfg.NewLogger(path)
+	if err != nil {
+		panic(err)
+	}
+	shout(ctx, l, os.Stdout, "fallback runner logs in: %s", path)
+	return l
+}

pkg/roachprod/logger/BUILD.bazel

@@ -1,13 +1,29 @@
-load("@io_bazel_rules_go//go:def.bzl", "go_library")
+load("@io_bazel_rules_go//go:def.bzl", "go_library", "go_test")
 
 go_library(
     name = "logger",
-    srcs = ["log.go"],
+    srcs = [
+        "log.go",
+        "log_redirect.go",
+    ],
     importpath = "github.com/cockroachdb/cockroach/pkg/roachprod/logger",
     visibility = ["//visibility:public"],
     deps = [
         "//pkg/cli/exit",
         "//pkg/util/log",
+        "//pkg/util/log/logconfig",
+        "//pkg/util/log/logpb",
         "//pkg/util/syncutil",
     ],
 )
+
+go_test(
+    name = "logger_test",
+    srcs = ["log_redirect_test.go"],
+    args = ["-test.timeout=295s"],
+    embed = [":logger"],
+    deps = [
+        "//pkg/util/log",
+        "@com_github_stretchr_testify//require",
+    ],
+)

pkg/roachprod/logger/log_redirect.go

@@ -0,0 +1,93 @@
+// Copyright 2024 The Cockroach Authors.
+//
+// Use of this software is governed by the CockroachDB Software License
+// included in the /LICENSE file.
+
+package logger
+
+import (
+	"context"
+	"encoding/json"
+	"fmt"
+	"io"
+
+	"github.com/cockroachdb/cockroach/pkg/util/log"
+	"github.com/cockroachdb/cockroach/pkg/util/log/logconfig"
+	"github.com/cockroachdb/cockroach/pkg/util/log/logpb"
+	"github.com/cockroachdb/cockroach/pkg/util/syncutil"
+)
+
+type logRedirect struct {
+	syncutil.Mutex
+	logger          *Logger
+	cancelIntercept func()
+	configured      bool
+}
+
+var logRedirectInst = &logRedirect{}
+
+// InitCRDBLogConfig sets up an interceptor for the CockroachDB log in order to
+// redirect logs to a roachprod logger. This is necessary as the CockroachDB log
+// is used in some test utilities shared between roachtest and CockroachDB.
+// Generally, CockroachDB logs should not be used explicitly in roachtest.
+func InitCRDBLogConfig(logger *Logger) {
+	logRedirectInst.Lock()
+	defer logRedirectInst.Unlock()
+	if logRedirectInst.configured {
+		panic("internal error: CRDB log interceptor already configured")
+	}
+	if logger == nil {
+		panic("internal error: specified logger is nil")
+	}
+	logConf := logconfig.DefaultStderrConfig()
+	logConf.Sinks.Stderr.Filter = logpb.Severity_FATAL
+	// Disable logging to a file. File sinks write the application arguments to
+	// the log by default (see: log_entry.go), and it is best to avoid logging
+	// the roachtest arguments as it may contain sensitive information.
+	if err := logConf.Validate(nil); err != nil {
+		panic(fmt.Errorf("internal error: could not validate CRDB log config: %w", err))
+	}
+	if _, err := log.ApplyConfig(logConf); err != nil {
+		panic(fmt.Errorf("internal error: could not apply CRDB log config: %w", err))
+	}
+	logRedirectInst.logger = logger
+	logRedirectInst.cancelIntercept = log.InterceptWith(context.Background(), logRedirectInst)
+	logRedirectInst.configured = true
+}
+
+// TestingCRDBLogConfig is meant to be used in unit tests to reset the CRDB log,
+// it's interceptor, and the redirect log config. This is necessary to avoid
+// leaking state between tests, that test the logging.
+func TestingCRDBLogConfig(logger *Logger) {
+	logRedirectInst.Lock()
+	defer logRedirectInst.Unlock()
+	if logRedirectInst.cancelIntercept != nil {
+		logRedirectInst.cancelIntercept()
+	}
+	log.TestingResetActive()
+	logRedirectInst = &logRedirect{}
+	InitCRDBLogConfig(logger)
+}
+
+// Intercept intercepts CockroachDB log entries and redirects it to the
+// appropriate roachtest test logger or stderr.
+func (i *logRedirect) Intercept(logData []byte) {
+	var entry logpb.Entry
+	if err := json.Unmarshal(logData, &entry); err != nil {
+		i.logger.Errorf("failed to unmarshal intercepted log entry: %v", err)
+	}
+	l := i.logger
+	if l != nil && !l.Closed() {
+		if entry.Severity == logpb.Severity_ERROR || entry.Severity == logpb.Severity_FATAL {
+			i.writeLog(l.Stderr, entry)
+			return
+		}
+		i.writeLog(l.Stdout, entry)
+	}
+}
+
+func (i *logRedirect) writeLog(dst io.Writer, entry logpb.Entry) {
+	if err := log.FormatLegacyEntry(entry, dst); err != nil {
+		i.logger.Errorf("could not format and write CRDB log entry: %v", err)
+	}
+}

pkg/roachprod/logger/log_redirect_test.go

@@ -0,0 +1,59 @@
+// Copyright 2024 The Cockroach Authors.
+//
+// Use of this software is governed by the CockroachDB Software License
+// included in the /LICENSE file.
+
+package logger
+
+import (
+	"context"
+	"strings"
+	"testing"
+
+	"github.com/cockroachdb/cockroach/pkg/util/log"
+	"github.com/stretchr/testify/require"
+)
+
+type mockLogger struct {
+	logger *Logger
+	writer *mockWriter
+}
+
+type mockWriter struct {
+	lines []string
+}
+
+func (w *mockWriter) Write(p []byte) (n int, err error) {
+	w.lines = append(w.lines, string(p))
+	return len(p), nil
+}
+
+func newMockLogger(t *testing.T) *mockLogger {
+	writer := &mockWriter{}
+	logConf := Config{Stdout: writer, Stderr: writer}
+	l, err := logConf.NewLogger("" /* path */)
+	require.NoError(t, err)
+	return &mockLogger{logger: l, writer: writer}
+}
+
+func requireLine(t *testing.T, l *mockLogger, line string) {
+	t.Helper()
+	found := false
+	for _, logLine := range l.writer.lines {
+		if strings.Contains(logLine, line) {
+			found = true
+			break
+		}
+	}
+	require.True(t, found, "expected line not found: %s", line)
+}
+
+func TestLogRedirect(t *testing.T) {
+	l := newMockLogger(t)
+	TestingCRDBLogConfig(l.logger)
+	ctx := context.Background()
+
+	log.Infof(ctx, "[simple test]")
+	requireLine(t, l, "[simple test]")
+	require.Equal(t, 1, len(l.writer.lines))
+}