diff options
39 files changed, 12936 insertions, 3951 deletions
diff --git a/integrationtests/authkey_test.go b/integrationtests/authkey_test.go new file mode 100644 index 0000000..3e5e7e4 --- /dev/null +++ b/integrationtests/authkey_test.go @@ -0,0 +1,467 @@ +package integrationtests + +import ( + "context" + "crypto/rand" + "crypto/rsa" + "crypto/x509" + "encoding/pem" + "fmt" + "os" + "path/filepath" + "strings" + "sync" + "testing" + "time" + + gossh "golang.org/x/crypto/ssh" +) + +const ( + authKeyFastPathLog = "Authorized by in-memory auth key store" + dcatExpectedFirstOutput = "1 Sat 2 Oct 13:46:45 EEST 2021" +) + +func TestAuthKeyFastReconnectIntegration(t *testing.T) { + skipIfNotIntegrationTest(t) + cleanupTmpFiles(t) + + t.Run("RegistrationFastPathAndFallback", testAuthKeyRegistrationFastPathAndFallback) + t.Run("TTLExpiry", testAuthKeyTTLExpiry) + t.Run("MaxKeysPerUser", testAuthKeyMaxKeysPerUser) + t.Run("NoAuthKeyFlag", testNoAuthKeyFlagDisablesFeature) + t.Run("PassphraseProtectedKey", testPassphraseKeyAuthKeyRegistrationAndFastReconnect) +} + +func testAuthKeyRegistrationFastPathAndFallback(t *testing.T) { + authKeyPath := createAuthKeyPair(t, "authkey-registration") + server := startAuthKeyServer(t, "") + defer server.Stop() + + exitCode, err := runDCatWithAuthKey(server.Context(), t, "authkey_registration_1.tmp", server.Address(), authKeyPath, false) + if err != nil || exitCode != 0 { + t.Fatalf("Expected first connection to succeed, exit=%d err=%v", exitCode, err) + } + assertDCatSuccessfulOutput(t, "authkey_registration_1.tmp") + waitForServerLogs() + if got := server.CountLogLinesContaining(authKeyFastPathLog); got != 0 { + t.Fatalf("Expected first connection to use fallback, fast-path count=%d", got) + } + + exitCode, err = runDCatWithAuthKey(server.Context(), t, "authkey_registration_2.tmp", server.Address(), authKeyPath, false) + if err != nil || exitCode != 0 { + t.Fatalf("Expected second connection to succeed, exit=%d err=%v", exitCode, err) + } + assertDCatSuccessfulOutput(t, "authkey_registration_2.tmp") + waitForServerLogs() + if got := server.CountLogLinesContaining(authKeyFastPathLog); got < 1 { + t.Fatalf("Expected fast-path authorization after registration, fast-path count=%d", got) + } + + server.Stop() + time.Sleep(300 * time.Millisecond) + + restartedServer := startAuthKeyServer(t, "") + defer restartedServer.Stop() + + exitCode, err = runDCatWithAuthKey(restartedServer.Context(), t, "authkey_registration_3.tmp", restartedServer.Address(), authKeyPath, false) + if err != nil || exitCode != 0 { + t.Fatalf("Expected fallback after restart to succeed, exit=%d err=%v", exitCode, err) + } + assertDCatSuccessfulOutput(t, "authkey_registration_3.tmp") + waitForServerLogs() + if got := restartedServer.CountLogLinesContaining(authKeyFastPathLog); got != 0 { + t.Fatalf("Expected no fast-path hit on first post-restart connection, fast-path count=%d", got) + } +} + +func testAuthKeyTTLExpiry(t *testing.T) { + authKeyPath := createAuthKeyPair(t, "authkey-ttl") + ttlSeconds := 8 + cfgFile := writeAuthKeyServerConfig(t, ttlSeconds, 5) + server := startAuthKeyServer(t, cfgFile) + defer server.Stop() + + exitCode, err := runDCatWithAuthKey(server.Context(), t, "authkey_ttl_1.tmp", server.Address(), authKeyPath, false) + if err != nil || exitCode != 0 { + t.Fatalf("Expected first connection to succeed, exit=%d err=%v", exitCode, err) + } + assertDCatSuccessfulOutput(t, "authkey_ttl_1.tmp") + + exitCode, err = runDCatWithAuthKey(server.Context(), t, "authkey_ttl_2.tmp", server.Address(), authKeyPath, false) + if err != nil || exitCode != 0 { + t.Fatalf("Expected second connection to succeed, exit=%d err=%v", exitCode, err) + } + assertDCatSuccessfulOutput(t, "authkey_ttl_2.tmp") + fastPathCountAfterSecond := waitForLogCountAtLeast(server, authKeyFastPathLog, 1, 5*time.Second) + if fastPathCountAfterSecond < 1 { + t.Fatalf("Expected fast-path hit before TTL expiry, count=%d\nserver logs:\n%s", + fastPathCountAfterSecond, strings.Join(server.LogLines(), "\n")) + } + + time.Sleep(time.Duration(ttlSeconds+1) * time.Second) + exitCode, err = runDCatWithAuthKey(server.Context(), t, "authkey_ttl_3.tmp", server.Address(), authKeyPath, false) + if err != nil || exitCode != 0 { + t.Fatalf("Expected fallback after TTL expiry to still connect, exit=%d err=%v", exitCode, err) + } + assertDCatSuccessfulOutput(t, "authkey_ttl_3.tmp") + waitForServerLogs() + fastPathCountAfterThird := server.CountLogLinesContaining(authKeyFastPathLog) + if fastPathCountAfterThird != fastPathCountAfterSecond { + t.Fatalf("Expected TTL-expired key to stop fast-path hits: before=%d after=%d", + fastPathCountAfterSecond, fastPathCountAfterThird) + } +} + +func testAuthKeyMaxKeysPerUser(t *testing.T) { + authKeyOne := createAuthKeyPair(t, "authkey-max-one") + authKeyTwo := createAuthKeyPair(t, "authkey-max-two") + cfgFile := writeAuthKeyServerConfig(t, 3600, 1) + server := startAuthKeyServer(t, cfgFile) + defer server.Stop() + + if exitCode, err := runDCatWithAuthKey(server.Context(), t, "authkey_max_1.tmp", server.Address(), authKeyOne, false); err != nil || exitCode != 0 { + t.Fatalf("Expected first key registration to succeed, exit=%d err=%v", exitCode, err) + } + assertDCatSuccessfulOutput(t, "authkey_max_1.tmp") + if exitCode, err := runDCatWithAuthKey(server.Context(), t, "authkey_max_2.tmp", server.Address(), authKeyTwo, false); err != nil || exitCode != 0 { + t.Fatalf("Expected second key registration to succeed, exit=%d err=%v", exitCode, err) + } + assertDCatSuccessfulOutput(t, "authkey_max_2.tmp") + waitForServerLogs() + initialFastPathCount := server.CountLogLinesContaining(authKeyFastPathLog) + + if exitCode, err := runDCatWithAuthKey(server.Context(), t, "authkey_max_3.tmp", server.Address(), authKeyOne, false); err != nil || exitCode != 0 { + t.Fatalf("Expected first key connection (after max eviction) to succeed via fallback, exit=%d err=%v", exitCode, err) + } + assertDCatSuccessfulOutput(t, "authkey_max_3.tmp") + waitForServerLogs() + afterOldKeyCount := server.CountLogLinesContaining(authKeyFastPathLog) + if afterOldKeyCount != initialFastPathCount { + t.Fatalf("Expected evicted old key to avoid fast-path hit: before=%d after=%d", + initialFastPathCount, afterOldKeyCount) + } + + if exitCode, err := runDCatWithAuthKey(server.Context(), t, "authkey_max_4.tmp", server.Address(), authKeyOne, false); err != nil || exitCode != 0 { + t.Fatalf("Expected re-registered first key to succeed, exit=%d err=%v", exitCode, err) + } + assertDCatSuccessfulOutput(t, "authkey_max_4.tmp") + waitForServerLogs() + afterNewKeyCount := server.CountLogLinesContaining(authKeyFastPathLog) + if afterNewKeyCount <= afterOldKeyCount { + t.Fatalf("Expected re-registered key to use fast-path: old-count=%d new-count=%d", afterOldKeyCount, afterNewKeyCount) + } +} + +func testNoAuthKeyFlagDisablesFeature(t *testing.T) { + authKeyPath := createAuthKeyPair(t, "authkey-noauth") + server := startAuthKeyServer(t, "") + defer server.Stop() + + if exitCode, err := runDCatWithAuthKey(server.Context(), t, "authkey_noauth_1.tmp", server.Address(), authKeyPath, true); err != nil || exitCode != 0 { + t.Fatalf("Expected first --no-auth-key connection to succeed, exit=%d err=%v", exitCode, err) + } + assertDCatSuccessfulOutput(t, "authkey_noauth_1.tmp") + if exitCode, err := runDCatWithAuthKey(server.Context(), t, "authkey_noauth_2.tmp", server.Address(), authKeyPath, true); err != nil || exitCode != 0 { + t.Fatalf("Expected second --no-auth-key connection to succeed, exit=%d err=%v", exitCode, err) + } + assertDCatSuccessfulOutput(t, "authkey_noauth_2.tmp") + + waitForServerLogs() + if got := server.CountLogLinesContaining(authKeyFastPathLog); got != 0 { + t.Fatalf("Expected --no-auth-key to prevent fast-path registration, fast-path count=%d", got) + } +} + +func testPassphraseKeyAuthKeyRegistrationAndFastReconnect(t *testing.T) { + const passphrase = "secret-passphrase" + + authKeyPath := createPassphraseAuthKeyPair(t, "authkey-passphrase", passphrase) + server := startAuthKeyServer(t, "") + defer server.Stop() + + env := map[string]string{ + "DTAIL_KEY_PASSPHRASE": passphrase, + } + + exitCode, err := runDCatWithAuthKeyAndEnv(server.Context(), t, + "authkey_passphrase_1.tmp", server.Address(), authKeyPath, false, env) + if err != nil || exitCode != 0 { + t.Fatalf("Expected first passphrase-protected connection to succeed, exit=%d err=%v", exitCode, err) + } + assertDCatSuccessfulOutput(t, "authkey_passphrase_1.tmp") + waitForServerLogs() + if got := server.CountLogLinesContaining(authKeyFastPathLog); got != 0 { + t.Fatalf("Expected first passphrase-protected connection to use fallback, fast-path count=%d", got) + } + + exitCode, err = runDCatWithAuthKeyAndEnv(server.Context(), t, + "authkey_passphrase_2.tmp", server.Address(), authKeyPath, false, env) + if err != nil || exitCode != 0 { + t.Fatalf("Expected second passphrase-protected connection to succeed, exit=%d err=%v", exitCode, err) + } + assertDCatSuccessfulOutput(t, "authkey_passphrase_2.tmp") + fastPathCount := waitForLogCountAtLeast(server, authKeyFastPathLog, 1, 5*time.Second) + if fastPathCount < 1 { + t.Fatalf("Expected passphrase-protected key to use fast-path on reconnect, count=%d\nserver logs:\n%s", + fastPathCount, strings.Join(server.LogLines(), "\n")) + } +} + +type authKeyServer struct { + ctx context.Context + cancel context.CancelFunc + addr string + logs *authKeyServerLogs +} + +func (s *authKeyServer) Stop() { + s.cancel() +} + +func (s *authKeyServer) Context() context.Context { + return s.ctx +} + +func (s *authKeyServer) Address() string { + return s.addr +} + +func (s *authKeyServer) CountLogLinesContaining(substring string) int { + return s.logs.countContaining(substring) +} + +func (s *authKeyServer) LogLines() []string { + return s.logs.snapshot() +} + +type authKeyServerLogs struct { + mu sync.Mutex + lines []string +} + +func newAuthKeyServerLogs() *authKeyServerLogs { + return &authKeyServerLogs{ + lines: make([]string, 0, 128), + } +} + +func (l *authKeyServerLogs) append(line string) { + l.mu.Lock() + defer l.mu.Unlock() + l.lines = append(l.lines, line) +} + +func (l *authKeyServerLogs) countContaining(substring string) int { + l.mu.Lock() + defer l.mu.Unlock() + + count := 0 + for _, line := range l.lines { + if strings.Contains(line, substring) { + count++ + } + } + return count +} + +func (l *authKeyServerLogs) snapshot() []string { + l.mu.Lock() + defer l.mu.Unlock() + + lines := make([]string, len(l.lines)) + copy(lines, l.lines) + return lines +} + +func startAuthKeyServer(t *testing.T, cfgFile string) *authKeyServer { + t.Helper() + + ctx, cancel := context.WithCancel(context.Background()) + port := getUniquePortNumber() + args := []string{ + "--cfg", "none", + "--logger", "stdout", + "--logLevel", "info", + "--bindAddress", "localhost", + "--port", fmt.Sprintf("%d", port), + } + if cfgFile != "" { + args = append(args, "--cfg", cfgFile) + } + + stdoutCh, stderrCh, cmdErrCh, err := startCommandWithEnv(ctx, t, "", "../dserver", + map[string]string{"DTAIL_TURBOBOOST_DISABLE": "yes"}, args...) + if err != nil { + cancel() + t.Fatalf("Unable to start dserver: %v", err) + } + + logs := newAuthKeyServerLogs() + go func() { + for { + select { + case line, ok := <-stdoutCh: + if ok { + logs.append(line) + } + case line, ok := <-stderrCh: + if ok { + logs.append(line) + } + case err := <-cmdErrCh: + if err != nil { + logs.append(err.Error()) + } + return + case <-ctx.Done(): + return + } + } + }() + + if err := waitForServerReady(ctx, "localhost", port); err != nil { + cancel() + t.Fatalf("Unable to start dserver: %v", err) + } + return &authKeyServer{ + ctx: ctx, + cancel: cancel, + addr: fmt.Sprintf("localhost:%d", port), + logs: logs, + } +} + +func runDCatWithAuthKey(ctx context.Context, t *testing.T, outFile, + serverAddress, authKeyPath string, noAuthKey bool) (int, error) { + return runDCatWithAuthKeyAndEnv(ctx, t, outFile, serverAddress, authKeyPath, noAuthKey, nil) +} + +func runDCatWithAuthKeyAndEnv(ctx context.Context, t *testing.T, outFile, + serverAddress, authKeyPath string, noAuthKey bool, env map[string]string) (int, error) { + t.Helper() + + args := []string{ + "--plain", + "--cfg", "none", + "--servers", serverAddress, + "--files", "dcat1a.txt", + "--trustAllHosts", + "--noColor", + "--auth-key-path", authKeyPath, + } + if noAuthKey { + args = append(args, "--no-auth-key") + } + + return runCommandWithEnv(ctx, t, outFile, "../dcat", env, args...) +} + +func assertDCatSuccessfulOutput(t *testing.T, outFile string) { + t.Helper() + + outBytes, err := os.ReadFile(outFile) + if err != nil { + t.Fatalf("Unable to read dcat output file %s: %v", outFile, err) + } + + output := string(outBytes) + if strings.Contains(output, "SSH handshake failed") { + t.Fatalf("Expected successful SSH connection, got handshake failure in %s:\n%s", outFile, output) + } + if !strings.Contains(output, dcatExpectedFirstOutput) { + t.Fatalf("Expected dcat output to contain %q in %s, got:\n%s", dcatExpectedFirstOutput, outFile, output) + } +} + +func writeAuthKeyServerConfig(t *testing.T, ttlSeconds, maxPerUser int) string { + t.Helper() + + cfgPath := filepath.Join(t.TempDir(), "authkey_server_config.json") + cfgContent := fmt.Sprintf( + `{"Server":{"AuthKeyEnabled":true,"AuthKeyTTLSeconds":%d,"AuthKeyMaxPerUser":%d}}`, + ttlSeconds, maxPerUser, + ) + if err := os.WriteFile(cfgPath, []byte(cfgContent), 0600); err != nil { + t.Fatalf("Unable to write auth-key server config: %v", err) + } + return cfgPath +} + +func createAuthKeyPair(t *testing.T, keyName string) string { + t.Helper() + + keyPath := filepath.Join(t.TempDir(), keyName) + privateKey, err := rsa.GenerateKey(rand.Reader, 2048) + if err != nil { + t.Fatalf("Unable to generate private key: %v", err) + } + + privateKeyBytes := pem.EncodeToMemory(&pem.Block{ + Type: "RSA PRIVATE KEY", + Bytes: x509.MarshalPKCS1PrivateKey(privateKey), + }) + if err := os.WriteFile(keyPath, privateKeyBytes, 0600); err != nil { + t.Fatalf("Unable to write private key: %v", err) + } + + publicKey, err := gossh.NewPublicKey(&privateKey.PublicKey) + if err != nil { + t.Fatalf("Unable to generate public key: %v", err) + } + if err := os.WriteFile(keyPath+".pub", gossh.MarshalAuthorizedKey(publicKey), 0600); err != nil { + t.Fatalf("Unable to write public key: %v", err) + } + + return keyPath +} + +func createPassphraseAuthKeyPair(t *testing.T, keyName, passphrase string) string { + t.Helper() + + keyPath := filepath.Join(t.TempDir(), keyName) + privateKey, err := rsa.GenerateKey(rand.Reader, 2048) + if err != nil { + t.Fatalf("Unable to generate private key: %v", err) + } + + privateKeyBlock, err := gossh.MarshalPrivateKeyWithPassphrase(privateKey, "", []byte(passphrase)) + if err != nil { + t.Fatalf("Unable to marshal encrypted private key: %v", err) + } + if err := os.WriteFile(keyPath, pem.EncodeToMemory(privateKeyBlock), 0600); err != nil { + t.Fatalf("Unable to write encrypted private key: %v", err) + } + + publicKey, err := gossh.NewPublicKey(&privateKey.PublicKey) + if err != nil { + t.Fatalf("Unable to generate public key: %v", err) + } + if err := os.WriteFile(keyPath+".pub", gossh.MarshalAuthorizedKey(publicKey), 0600); err != nil { + t.Fatalf("Unable to write public key: %v", err) + } + + return keyPath +} + +func waitForServerLogs() { + time.Sleep(300 * time.Millisecond) +} + +func waitForLogCountAtLeast(server *authKeyServer, substring string, minCount int, timeout time.Duration) int { + if minCount <= 0 { + return server.CountLogLinesContaining(substring) + } + + deadline := time.Now().Add(timeout) + for { + count := server.CountLogLinesContaining(substring) + if count >= minCount { + return count + } + if time.Now().After(deadline) { + return count + } + time.Sleep(100 * time.Millisecond) + } +} diff --git a/integrationtests/commandutils.go b/integrationtests/commandutils.go index 8d81955..1947de4 100644 --- a/integrationtests/commandutils.go +++ b/integrationtests/commandutils.go @@ -2,6 +2,7 @@ package integrationtests import ( "bufio" + "bytes" "context" "fmt" "io" @@ -15,23 +16,38 @@ import ( func runCommand(ctx context.Context, t *testing.T, stdoutFile, cmdStr string, args ...string) (int, error) { + return runCommandWithEnv(ctx, t, stdoutFile, cmdStr, nil, args...) +} +func runCommandWithEnv(ctx context.Context, t *testing.T, stdoutFile, cmdStr string, + env map[string]string, args ...string) (int, error) { if _, err := os.Stat(cmdStr); err != nil { return 0, fmt.Errorf("no such executable '%s', please compile first: %w", cmdStr, err) } + // Log command execution if logger is available + if logger := GetTestLogger(ctx); logger != nil { + logger.LogCommand(cmdStr, args) + } + t.Log("Creating stdout file", stdoutFile) fd, err := os.Create(stdoutFile) if err != nil { - return 0, nil + return 0, err } defer fd.Close() t.Log("Running command", cmdStr, strings.Join(args, " ")) cmd := exec.CommandContext(ctx, cmdStr, args...) + cmd.Env = os.Environ() + for key, value := range env { + cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", key, value)) + } out, err := cmd.CombinedOutput() t.Log("Done running command!", err) - _, _ = fd.Write(out) + if _, copyErr := io.Copy(fd, bytes.NewReader(out)); copyErr != nil { + return exitCodeFromError(err), copyErr + } return exitCodeFromError(err), err } @@ -48,8 +64,54 @@ func runCommandRetry(ctx context.Context, t *testing.T, retries int, stdoutFile, return } +func runCommandUntilValid(ctx context.Context, t *testing.T, attempts int, delay time.Duration, + stdoutFile, cmd string, validate func() error, args ...string) error { + + t.Helper() + + if attempts < 1 { + attempts = 1 + } + + var lastErr error + for i := 0; i < attempts; i++ { + exitCode, err := runCommand(ctx, t, stdoutFile, cmd, args...) + if err == nil { + validateErr := validate() + if validateErr == nil { + return nil + } + lastErr = validateErr + } else { + lastErr = fmt.Errorf("command %s failed with exit code %d: %w", cmd, exitCode, err) + } + + if i == attempts-1 { + break + } + + timer := time.NewTimer(delay) + select { + case <-ctx.Done(): + timer.Stop() + if lastErr != nil { + return lastErr + } + return ctx.Err() + case <-timer.C: + } + } + + return lastErr +} + func startCommand(ctx context.Context, t *testing.T, inPipeFile, cmdStr string, args ...string) (<-chan string, <-chan string, <-chan error, error) { + return startCommandWithEnv(ctx, t, inPipeFile, cmdStr, nil, args...) +} + +func startCommandWithEnv(ctx context.Context, t *testing.T, inPipeFile, + cmdStr string, env map[string]string, args ...string) (<-chan string, <-chan string, <-chan error, error) { stdoutCh := make(chan string) stderrCh := make(chan string) @@ -59,9 +121,23 @@ func startCommand(ctx context.Context, t *testing.T, inPipeFile, fmt.Errorf("no such executable '%s', please compile first: %w", cmdStr, err) } + // Log command execution if logger is available + if logger := GetTestLogger(ctx); logger != nil { + logger.LogCommand(cmdStr, args) + } + t.Log(cmdStr, strings.Join(args, " ")) cmd := exec.CommandContext(ctx, cmdStr, args...) + // Always inherit environment variables + cmd.Env = os.Environ() + // Add any additional environment variables if provided + if env != nil { + for k, v := range env { + cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", k, v)) + } + } + var stdinPipe io.WriteCloser if inPipeFile != "" { var err error diff --git a/integrationtests/dcat1d.txt b/integrationtests/dcat1d.txt deleted file mode 100644 index 074c277..0000000 --- a/integrationtests/dcat1d.txt +++ /dev/null @@ -1 +0,0 @@ -single line without newline
\ No newline at end of file diff --git a/integrationtests/dcat_logpayload_test.go b/integrationtests/dcat_logpayload_test.go new file mode 100644 index 0000000..823e33f --- /dev/null +++ b/integrationtests/dcat_logpayload_test.go @@ -0,0 +1,141 @@ +package integrationtests + +import ( + "context" + "os" + "path/filepath" + "strings" + "testing" + + "github.com/mimecast/dtail/internal/config" +) + +// payloadMarker is the last line of dcat1a.txt. It is distinctive enough that +// its presence in a file proves the retrieved payload was written there. +const payloadMarker = "500 Sat 2 Oct 13:46:46 EEST 2021" + +// readDailyLog concatenates every YYYYMMDD.log file the fout logger may have +// written into dir. A missing/empty dir returns "" (the default logger only +// creates the file on the first write, so a payload-free run may leave none). +func readDailyLog(t *testing.T, dir string) string { + t.Helper() + matches, err := filepath.Glob(filepath.Join(dir, "*.log")) + if err != nil { + t.Fatalf("globbing log dir %s: %v", dir, err) + } + var sb strings.Builder + for _, m := range matches { + content, err := os.ReadFile(m) + if err != nil { + t.Fatalf("reading log file %s: %v", m, err) + } + sb.Write(content) + } + return sb.String() +} + +// TestDCatLogPayload verifies Option B of task dt0: the default client log file +// (the fout logger's daily file) records diagnostics only, and payload teeing +// is opt-in via --log-payload. All sub-tests run serverless so the client log +// output is deterministic (no network timing in diagnostics). +func TestDCatLogPayload(t *testing.T) { + if !config.Env("DTAIL_INTEGRATION_TEST_RUN_MODE") { + t.Log("Skipping") + return + } + + cleanupTmpFiles(t) + testLogger := NewTestLogger("TestDCatLogPayload") + defer testLogger.WriteLogFile() + + inFile := "dcat1a.txt" + + // Default: file must be diagnostics-only, no payload; payload still on stdout. + t.Run("DefaultDiagnosticsOnlyNoPayload", func(t *testing.T) { + logDir := t.TempDir() + outFile := "dcatlogpayload_default.tmp" + ctx := WithTestLogger(context.Background(), testLogger) + + if _, err := runCommand(ctx, t, outFile, "../dcat", + "--logger", "fout", "--logDir", logDir, "--logLevel", "debug", + "--noColor", "--cfg", "none", inFile); err != nil { + t.Fatal(err) + } + + logContent := readDailyLog(t, logDir) + if strings.Contains(logContent, payloadMarker) { + t.Fatalf("payload leaked into the daily client log file by default (found %q)", payloadMarker) + } + // Diagnostics must still land in the file: in integration mode every + // client diagnostic line carries the "integrationtest" hostname token. + if !strings.Contains(logContent, "integrationtest") { + t.Fatalf("expected diagnostics in the daily log file, got none:\n%s", logContent) + } + // Payload must still reach the terminal/stdout. + stdout := readTmpFile(t, outFile) + if !strings.Contains(stdout, payloadMarker) { + t.Fatal("payload missing from stdout; it must always reach the terminal") + } + }) + + // Opt-in: --log-payload restores the legacy full tee into the file. + t.Run("OptInTeesPayloadToFile", func(t *testing.T) { + logDir := t.TempDir() + outFile := "dcatlogpayload_optin.tmp" + ctx := WithTestLogger(context.Background(), testLogger) + + if _, err := runCommand(ctx, t, outFile, "../dcat", + "--logger", "fout", "--logDir", logDir, "--logLevel", "debug", + "--noColor", "--log-payload", "--cfg", "none", inFile); err != nil { + t.Fatal(err) + } + + logContent := readDailyLog(t, logDir) + if !strings.Contains(logContent, payloadMarker) { + t.Fatalf("expected payload teed into the daily log file with --log-payload, not found") + } + }) + + // Stdout must be byte-identical with and without --log-payload: only the + // FILE content changes, never what the user sees on the terminal. + t.Run("StdoutByteIdenticalWithAndWithoutFlag", func(t *testing.T) { + defaultLogDir := t.TempDir() + optinLogDir := t.TempDir() + defaultOut := "dcatlogpayload_stdout_default.tmp" + optinOut := "dcatlogpayload_stdout_optin.tmp" + ctx := WithTestLogger(context.Background(), testLogger) + + if _, err := runCommand(ctx, t, defaultOut, "../dcat", + "--plain", "--logger", "fout", "--logDir", defaultLogDir, + "--cfg", "none", inFile); err != nil { + t.Fatal(err) + } + if _, err := runCommand(ctx, t, optinOut, "../dcat", + "--plain", "--logger", "fout", "--logDir", optinLogDir, + "--log-payload", "--cfg", "none", inFile); err != nil { + t.Fatal(err) + } + + if got, want := readTmpFile(t, optinOut), readTmpFile(t, defaultOut); got != want { + t.Fatalf("stdout differs between default and --log-payload runs:\n got %q\nwant %q", got, want) + } + + // Sanity: file behavior still toggled underneath the identical stdout. + if strings.Contains(readDailyLog(t, defaultLogDir), payloadMarker) { + t.Fatal("default run leaked payload into the log file") + } + if !strings.Contains(readDailyLog(t, optinLogDir), payloadMarker) { + t.Fatal("--log-payload run did not tee payload into the log file") + } + }) +} + +// readTmpFile reads a captured stdout file produced by runCommand. +func readTmpFile(t *testing.T, name string) string { + t.Helper() + content, err := os.ReadFile(name) + if err != nil { + t.Fatalf("reading %s: |