fix(db): redact bound query arguments at every log level

internal/database/connection.go

@@ -417,18 +417,16 @@ func isSensitiveKey(k string) bool {
 	return k == "password" || k == "secret" || k == "token"
 }
 
-// sanitizeLogData returns a copy of data with sensitive fields removed.
-// At debug level, the pgx "args" key (SQL bound parameters) is also removed
-// unless DB_LOG_BIND_PARAMETERS=true is set, because bound values can carry
-// session tokens, bcrypt hashes, or approval tokens.
-func sanitizeLogData(level tracelog.LogLevel, data map[string]any) map[string]any {
+// Bound parameters can carry credentials even when a query fails.
+// Only DB_LOG_BIND_PARAMETERS=true opts into logging them at any level.
+func sanitizeLogData(data map[string]any) map[string]any {
 	bindParams := os.Getenv("DB_LOG_BIND_PARAMETERS") == "true"
 	safe := make(map[string]any, len(data))
 	for k, v := range data {
 		if isSensitiveKey(k) {
 			continue
 		}
-		if k == "args" && level == tracelog.LogLevelDebug && !bindParams {
+		if k == "args" && !bindParams {
 			continue
 		}
 		safe[k] = v
@@ -437,7 +435,7 @@ func sanitizeLogData(level tracelog.LogLevel, data map[string]any) map[string]an
 }
 
 func (l *stdLogger) Log(ctx context.Context, level tracelog.LogLevel, msg string, data map[string]any) {
-	safeData := sanitizeLogData(level, data)
+	safeData := sanitizeLogData(data)
 
 	switch level {
 	case tracelog.LogLevelDebug:

internal/database/query_logging_integration_test.go

@@ -0,0 +1,86 @@
+//go:build integration
+
+package database_test
+
+import (
+	"bytes"
+	"context"
+	"strings"
+	"sync"
+	"testing"
+
+	"github.com/LeanerCloud/cloud-commitments-go/pkg/logging"
+	"github.com/LeanerCloud/cloud-commitments-platform/internal/database/postgres/testhelpers"
+	"github.com/jackc/pgx/v5/pgconn"
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+)
+
+type queryLogBuffer struct {
+	mu  sync.Mutex
+	buf bytes.Buffer
+}
+
+func (b *queryLogBuffer) Write(p []byte) (int, error) {
+	b.mu.Lock()
+	defer b.mu.Unlock()
+	return b.buf.Write(p)
+}
+
+func (b *queryLogBuffer) take() string {
+	b.mu.Lock()
+	defer b.mu.Unlock()
+	text := b.buf.String()
+	b.buf.Reset()
+	return text
+}
+
+func TestQueryLogging_RedactsBoundSecretsOnFailure(t *testing.T) {
+	ctx := context.Background()
+	container := testhelpers.RequirePostgresContainer(ctx, t)
+	var output queryLogBuffer
+	previousOutput := logging.SetOutput(&output)
+	previousLevel := logging.GetLevel()
+	logging.SetLevelValue(logging.LevelDebug)
+	t.Cleanup(func() {
+		assert.NoError(t, container.Cleanup(context.Background()))
+		logging.SetOutput(previousOutput)
+		logging.SetLevelValue(previousLevel)
+	})
+
+	_, err := container.DB.Exec(ctx, `CREATE TABLE query_logging_secrets (
+		session_token text, password_hash text, approval_token text,
+		accepted integer CHECK (accepted > 0))`)
+	require.NoError(t, err)
+	secrets := []string{strings.Repeat("a", 64), strings.Repeat("b", 60), strings.Repeat("c", 64)}
+	for _, optIn := range []string{"", "true"} {
+		t.Run("bind_parameters="+optIn, func(t *testing.T) {
+			t.Setenv("DB_LOG_BIND_PARAMETERS", optIn)
+			output.take()
+			_, err := container.DB.Exec(ctx,
+				`INSERT INTO query_logging_secrets VALUES ($1, $2, $3, $4)`,
+				secrets[0], secrets[1], secrets[2], 0)
+			var pgErr *pgconn.PgError
+			require.ErrorAs(t, err, &pgErr)
+			require.Equal(t, "23514", pgErr.Code)
+			for _, secret := range secrets {
+				require.NotContains(t, pgErr.Error(), secret)
+			}
+			logged := output.take()
+			assert.Contains(t, logged, "Query")
+			assert.Contains(t, logged, pgErr.Error())
+			for _, secret := range secrets {
+				if optIn == "true" {
+					assert.Contains(t, logged, secret)
+				} else {
+					assert.NotContains(t, logged, secret)
+				}
+			}
+			if optIn == "true" {
+				assert.Contains(t, logged, "args:")
+			} else {
+				assert.NotContains(t, logged, "args:")
+			}
+		})
+	}
+}

internal/database/security_test.go

@@ -8,6 +8,7 @@ import (
 	"testing"
 	"time"
 
+	"github.com/LeanerCloud/cloud-commitments-go/pkg/logging"
 	"github.com/jackc/pgx/v5/tracelog"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
@@ -155,85 +156,34 @@ func TestBuildPoolConfig_ParseError_NoPasswordLeak(t *testing.T) {
 	// The placeholder "REDACTED" may appear, which is acceptable.
 }
 
-// TestSanitizeLogData_ArgsKeyStrippedAtDebugByDefault is a regression test for
-// issue #446: pgx logs SQL bound parameters under the "args" key at debug
-// level. Without the fix, these would be included in log output and could
-// expose session tokens, bcrypt hashes, or approval tokens.
-//
-// By default (DB_LOG_BIND_PARAMETERS not set) the "args" key must be stripped
-// from debug-level log data.
-func TestSanitizeLogData_ArgsKeyStrippedAtDebugByDefault(t *testing.T) {
-	t.Setenv("DB_LOG_BIND_PARAMETERS", "")
-
-	tests := []struct {
-		inputData     map[string]any
-		name          string
-		level         tracelog.LogLevel
-		wantArgsInOut bool
-	}{
-		{
-			name: "args stripped at debug level by default",
-			inputData: map[string]any{
-				"args": []any{"session-token-abc", "bcrypt-hash-xyz"},
-				"sql":  "SELECT * FROM users WHERE token = $1",
-			},
-			level:         tracelog.LogLevelDebug,
-			wantArgsInOut: false,
-		},
-		{
-			name: "args kept at warn level",
-			inputData: map[string]any{
-				"args": []any{"value"},
-				"sql":  "SELECT 1",
-			},
-			level:         tracelog.LogLevelWarn,
-			wantArgsInOut: true,
-		},
-		{
-			name: "args kept at error level",
-			inputData: map[string]any{
-				"args": []any{"value"},
-			},
-			level:         tracelog.LogLevelError,
-			wantArgsInOut: true,
-		},
-		{
-			name: "password always stripped at warn level",
-			inputData: map[string]any{
-				"password": "secret",
-				"safe":     "ok",
-			},
-			level:         tracelog.LogLevelWarn,
-			wantArgsInOut: false, // "args" key not in input, not relevant
-		},
+func TestSanitizeLogData_BoundArgumentsRequireExplicitOptIn(t *testing.T) {
+	input := map[string]any{
+		"args": []any{"session-token", "bcrypt-hash"},
+		"sql":  "SELECT $1", "err": "query failed",
+		"password": "private-password", "secret": "private-secret", "token": "private-token",
 	}
-
-	for _, tc := range tests {
-		t.Run(tc.name, func(t *testing.T) {
-			safe := sanitizeLogData(tc.level, tc.inputData)
-			_, hasArgs := safe["args"]
-			assert.Equal(t, tc.wantArgsInOut, hasArgs,
-				"args key presence mismatch for level %v", tc.level)
+	for _, optIn := range []string{"", "false", "TRUE", "1", "true"} {
+		t.Run("bind_parameters="+optIn, func(t *testing.T) {
+			t.Setenv("DB_LOG_BIND_PARAMETERS", optIn)
+			safe := sanitizeLogData(input)
+			assert.Equal(t, input["sql"], safe["sql"])
+			assert.Equal(t, input["err"], safe["err"])
+			for _, key := range []string{"password", "secret", "token"} {
+				assert.NotContains(t, safe, key)
+				assert.Contains(t, input, key)
+			}
+			if optIn == "true" {
+				assert.Equal(t, input["args"], safe["args"])
+			} else {
+				assert.NotContains(t, safe, "args")
+			}
+			assert.Equal(t, []any{"session-token", "bcrypt-hash"}, input["args"])
+			safe["sql"] = "changed"
+			assert.Equal(t, "SELECT $1", input["sql"])
 		})
 	}
 }
 
-// TestSanitizeLogData_ArgsKeyKeptWhenOptedIn verifies that setting
-// DB_LOG_BIND_PARAMETERS=true allows the "args" key through at debug level.
-func TestSanitizeLogData_ArgsKeyKeptWhenOptedIn(t *testing.T) {
-	t.Setenv("DB_LOG_BIND_PARAMETERS", "true")
-
-	inputData := map[string]any{
-		"args": []any{"param1", "param2"},
-		"sql":  "SELECT 1",
-	}
-
-	safe := sanitizeLogData(tracelog.LogLevelDebug, inputData)
-	_, hasArgs := safe["args"]
-	assert.True(t, hasArgs,
-		"args key must be preserved when DB_LOG_BIND_PARAMETERS=true")
-}
-
 // TestIsSensitiveKey verifies the sensitive-key predicate covers all expected names.
 func TestIsSensitiveKey(t *testing.T) {
 	assert.True(t, isSensitiveKey("password"))
@@ -244,48 +194,65 @@ func TestIsSensitiveKey(t *testing.T) {
 	assert.False(t, isSensitiveKey("host"))
 }
 
-// TestStdLogger_DoesNotPanicWithArgsKey exercises the live stdLogger.Log path
-// with an "args" entry to confirm it does not panic when the key is filtered.
-func TestStdLogger_DoesNotPanicWithArgsKey(t *testing.T) {
-	t.Setenv("DB_LOG_BIND_PARAMETERS", "")
-
-	logger := &stdLogger{}
-	ctx := context.Background()
+func TestStdLogger_RedactsBoundArguments(t *testing.T) {
+	var output bytes.Buffer
+	previousOutput := logging.SetOutput(&output)
+	previousLevel := logging.GetLevel()
+	logging.SetLevelValue(logging.LevelDebug)
+	t.Cleanup(func() {
+		logging.SetOutput(previousOutput)
+		logging.SetLevelValue(previousLevel)
+	})
 
 	data := map[string]any{
 		"args":     []any{"session-token", "hash-value"},
 		"sql":      "INSERT INTO sessions VALUES ($1, $2)",
-		"password": "should-be-stripped",
+		"password": "private-password", "secret": "private-secret", "token": "private-token",
+	}
+	for _, optIn := range []string{"", "true"} {
+		t.Run("bind_parameters="+optIn, func(t *testing.T) {
+			t.Setenv("DB_LOG_BIND_PARAMETERS", optIn)
+			for _, level := range []tracelog.LogLevel{tracelog.LogLevelDebug, tracelog.LogLevelInfo, tracelog.LogLevelWarn, tracelog.LogLevelError} {
+				t.Run(level.String(), func(t *testing.T) {
+					output.Reset()
+					(&stdLogger{}).Log(context.Background(), level, "Query", data)
+					logged := output.String()
+					assert.Contains(t, logged, "Query")
+					for _, value := range []string{"private-password", "private-secret", "private-token"} {
+						assert.NotContains(t, logged, value)
+					}
+					if optIn == "true" && level != tracelog.LogLevelInfo {
+						assert.Contains(t, logged, "args:")
+						assert.Contains(t, logged, "session-token")
+						assert.Contains(t, logged, "hash-value")
+					} else {
+						assert.NotContains(t, logged, "args:")
+						assert.NotContains(t, logged, "session-token")
+						assert.NotContains(t, logged, "hash-value")
+					}
+					if level == tracelog.LogLevelInfo {
+						assert.NotContains(t, logged, "sql:")
+					} else {
+						assert.Contains(t, logged, data["sql"])
+					}
+				})
+			}
+		})
 	}
-
-	assert.NotPanics(t, func() {
-		logger.Log(ctx, tracelog.LogLevelDebug, "Query", data)
-	})
-	assert.NotPanics(t, func() {
-		logger.Log(ctx, tracelog.LogLevelInfo, "Query", data)
-	})
 }
 
-// TestSanitizeLogData_PasswordStrippedAtAllLevels confirms password/secret/token
-// keys are removed regardless of log level.
-func TestSanitizeLogData_PasswordStrippedAtAllLevels(t *testing.T) {
-	t.Setenv("DB_LOG_BIND_PARAMETERS", "")
-
+func TestSanitizeLogData_SensitiveKeysWithoutArgs(t *testing.T) {
 	sensitive := map[string]any{
 		"password": "my-password",
 		"secret":   "my-secret",
 		"token":    "my-token",
 		"safe":     "visible",
 	}
 
-	for _, level := range []tracelog.LogLevel{
-		tracelog.LogLevelDebug,
-		tracelog.LogLevelInfo,
-		tracelog.LogLevelWarn,
-		tracelog.LogLevelError,
-	} {
-		t.Run(level.String(), func(t *testing.T) {
-			safe := sanitizeLogData(level, sensitive)
+	for _, optIn := range []string{"", "true"} {
+		t.Run("bind_parameters="+optIn, func(t *testing.T) {
+			t.Setenv("DB_LOG_BIND_PARAMETERS", optIn)
+			safe := sanitizeLogData(sensitive)
 			assert.NotContains(t, safe, "password")
 			assert.NotContains(t, safe, "secret")
 			assert.NotContains(t, safe, "token")