release-19.1: util/log: ensure stderr is only redirected to th… (#40942)

release-19.1: util/log: ensure stderr is only redirected to the main log

pkg/util/log/clog.go

@@ -922,7 +922,7 @@ func (l *loggingT) outputLogEntry(s Severity, file string, line int, msg string)
 		}
 	}
 
-	if s >= l.stderrThreshold.get() || (s == Severity_FATAL && stderrRedirected) {
+	if s >= l.stderrThreshold.get() || (s == Severity_FATAL && l.stderrRedirected()) {
 		// We force-copy FATAL messages to stderr, because the process is bound
 		// to terminate and the user will want to know why.
 		l.outputToStderr(entry, stacks)
@@ -1120,7 +1120,7 @@ func (sb *syncBuffer) rotateFile(now time.Time) error {
 	// stack traces that are written by the Go runtime to stderr. Note that if
 	// --logtostderr is true we'll never enter this code path and panic stack
 	// traces will go to the original stderr as you would expect.
-	if logging.stderrThreshold > Severity_INFO && !logging.noStderrRedirect {
+	if sb.logger.stderrRedirected() {
 		// NB: any concurrent output to stderr may straddle the old and new
 		// files. This doesn't apply to log messages as we won't reach this code
 		// unless we're not logging to stderr.

pkg/util/log/crash_reporting.go

@@ -215,7 +215,7 @@ func (st SafeType) WithCause(cause interface{}) SafeType {
 func ReportPanic(ctx context.Context, sv *settings.Values, r interface{}, depth int) {
 	Shout(ctx, Severity_ERROR, "a panic has occurred!")
 
-	if stderrRedirected {
+	if logging.stderrRedirected() {
 		// We do not use Shout() to print the panic details here, because
 		// if stderr is not redirected (e.g. when logging to file is
 		// disabled) Shout() would copy its argument to stderr

pkg/util/log/log.go

@@ -23,7 +23,7 @@ import (
 	"time"
 
 	"github.com/cockroachdb/cockroach/pkg/util/tracing"
-	"github.com/opentracing/opentracing-go"
+	opentracing "github.com/opentracing/opentracing-go"
 	"github.com/petermattis/goid"
 )
 
@@ -82,7 +82,7 @@ func Shout(ctx context.Context, sev Severity, args ...interface{}) {
 		})
 		defer t.Stop()
 	}
-	if stderrRedirected {
+	if logging.stderrRedirected() {
 		fmt.Fprintf(OrigStderr, "*\n* %s: %s\n*\n", sev.String(),
 			strings.Replace(MakeMessage(ctx, "", args), "\n", "\n* ", -1))
 	}

pkg/util/log/secondary_log_test.go

@@ -16,7 +16,9 @@ package log
 
 import (
 	"context"
+	"fmt"
 	"io/ioutil"
+	"os"
 	"strings"
 	"testing"
 
@@ -73,3 +75,45 @@ func TestSecondaryLog(t *testing.T) {
 	}
 
 }
+
+func TestRedirectStderrWithSecondaryLoggersActive(t *testing.T) {
+	s := ScopeWithoutShowLogs(t)
+	defer s.Close(t)
+
+	setFlags()
+	logging.stderrThreshold = Severity_NONE
+
+	// Ensure that the main log is initialized. This should take over
+	// stderr.
+	Infof(context.Background(), "test123")
+
+	// Now create a secondary logger in the same directory.
+	ctx, cancel := context.WithCancel(context.Background())
+	defer cancel()
+	l := NewSecondaryLogger(ctx, &logging.logDir, "woo", true, false)
+
+	// Log something on the secondary logger.
+	l.Logf(context.Background(), "test456")
+
+	// Send something on stderr.
+	const stderrText = "hello stderr"
+	fmt.Fprint(os.Stderr, stderrText)
+
+	// Check the main log file: we want our stderr text there.
+	contents, err := ioutil.ReadFile(logging.file.(*syncBuffer).file.Name())
+	if err != nil {
+		t.Fatal(err)
+	}
+	if !strings.Contains(string(contents), stderrText) {
+		t.Errorf("log does not contain stderr text\n%s", contents)
+	}
+
+	// Check the secondary log file: we don't want our stderr text there.
+	contents2, err := ioutil.ReadFile(l.logger.file.(*syncBuffer).file.Name())
+	if err != nil {
+		t.Fatal(err)
+	}
+	if strings.Contains(string(contents2), stderrText) {
+		t.Errorf("secondary log erronously contains stderr text\n%s", contents2)
+	}
+}

pkg/util/log/stderr_redirect.go

@@ -26,21 +26,22 @@ var OrigStderr = func() *os.File {
 	return os.NewFile(fd, os.Stderr.Name())
 }()
 
-// stderrRedirected attempts to track whether stderr was redirected.
-// This is used to de-duplicate the panic log.
-var stderrRedirected bool
+// stderrRedirected returns true if and only if logging captures
+// stderr output to the log file. This is used e.g. by Shout() to
+// determine whether to report to standard error in addition to logs.
+func (l *loggingT) stderrRedirected() bool {
+	return l.stderrThreshold > Severity_INFO && !l.noStderrRedirect
+}
 
 // hijackStderr replaces stderr with the given file descriptor.
 //
 // A client that wishes to use the original stderr must use
 // OrigStderr defined above.
 func hijackStderr(f *os.File) error {
-	stderrRedirected = true
 	return redirectStderr(f)
 }
 
 // restoreStderr cancels the effect of hijackStderr().
 func restoreStderr() error {
-	stderrRedirected = false
 	return redirectStderr(OrigStderr)
 }