Move Postgres log rotation parameters to the postgres package

The behavior of these parameters is independent of OpenTelemetry.
This refactor is part of a larger series to make the Postgres log
directory configurable.

Author: cbandy

internal/collector/postgres.go

@@ -9,7 +9,6 @@ import (
 	_ "embed"
 	"encoding/json"
 	"fmt"
-	"math"
 	"slices"
 	"time"
 
@@ -108,21 +107,17 @@ func EnablePostgresLogging(
 		if spec != nil && spec.RetentionPeriod != nil {
 			retentionPeriod = spec.RetentionPeriod.AsDuration()
 		}
-		logFilename, logRotationAge := generateLogFilenameAndRotationAge(retentionPeriod)
 
-		// NOTE: The automated portions of log_filename are *entirely* based
-		// on time. There is no spelling that is guaranteed to be unique or
-		// monotonically increasing.
+		// Rotate log files according to retention.
 		//
-		// TODO(logs): Limit the size/bytes of logs without losing messages;
-		// probably requires another process that deletes the oldest files.
+		// The ".log" suffix is replaced by ".csv" for CSV log files, and
+		// the ".log" suffix is replaced by ".json" for JSON log files.
 		//
-		// The ".log" suffix is replaced by ".json" for JSON log files.
-		outParameters.Add("log_filename", logFilename)
+		// https://www.postgresql.org/docs/current/runtime-config-logging.html
+		for k, v := range postgres.LogRotation(retentionPeriod, "postgresql-", ".log") {
+			outParameters.Add(k, v)
+		}
 		outParameters.Add("log_file_mode", "0660")
-		outParameters.Add("log_rotation_age", logRotationAge)
-		outParameters.Add("log_rotation_size", "0")
-		outParameters.Add("log_truncate_on_rotation", "on")
 
 		// Log in a timezone that the OpenTelemetry Collector will understand.
 		outParameters.Add("log_timezone", "UTC")
@@ -300,37 +295,3 @@ func EnablePostgresLogging(
 		}
 	}
 }
-
-// generateLogFilenameAndRotationAge takes a retentionPeriod and returns a
-// log_filename and log_rotation_age to be used to configure postgres logging
-func generateLogFilenameAndRotationAge(
-	retentionPeriod metav1.Duration,
-) (logFilename, logRotationAge string) {
-	// Given how postgres does its log rotation with the truncate feature, we
-	// will always need to make up the total retention period with multiple log
-	// files that hold subunits of the total time (e.g. if the retentionPeriod
-	// is an hour, there will be 60 1-minute long files; if the retentionPeriod
-	// is a day, there will be 24 1-hour long files, etc)
-
-	hours := math.Ceil(retentionPeriod.Hours())
-
-	switch true {
-	case hours <= 1: // One hour's worth of logs in 60 minute long log files
-		logFilename = "postgresql-%M.log"
-		logRotationAge = "1min"
-	case hours <= 24: // One day's worth of logs in 24 hour long log files
-		logFilename = "postgresql-%H.log"
-		logRotationAge = "1h"
-	case hours <= 24*7: // One week's worth of logs in 7 day long log files
-		logFilename = "postgresql-%a.log"
-		logRotationAge = "1d"
-	case hours <= 24*28: // One month's worth of logs in 28-31 day long log files
-		logFilename = "postgresql-%d.log"
-		logRotationAge = "1d"
-	default: // One year's worth of logs in 365 day long log files
-		logFilename = "postgresql-%j.log"
-		logRotationAge = "1d"
-	}
-
-	return
-}

internal/postgres/config.go

@@ -7,9 +7,11 @@ package postgres
 import (
 	"context"
 	"fmt"
+	"math"
 	"strings"
 
 	corev1 "k8s.io/api/core/v1"
+	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 
 	"github.com/crunchydata/postgres-operator/internal/config"
 	"github.com/crunchydata/postgres-operator/internal/feature"
@@ -96,6 +98,71 @@ func LogDirectory() string {
 	return fmt.Sprintf("%s/logs/postgres", dataMountPath)
 }
 
+// LogRotation returns parameters that rotate log files while keeping a minimum amount.
+// Postgres truncates and reuses log files after that minimum amount.
+// Log file names start with filePrefix and end with fileSuffix.
+//
+// NOTE: These parameters do *not* enable logging to files. Set "logging_collector" for that.
+func LogRotation(minimum metav1.Duration, filePrefix, fileSuffix string) map[string]string {
+	hours := math.Ceil(minimum.Hours())
+
+	// The "log_filename" parameter is interpreted similar to `strftime`;
+	// escape percent U+0025 by doubling it.
+	// - https://www.postgresql.org/docs/current/runtime-config-logging.html#GUC-LOG-FILENAME
+	prefix := strings.ReplaceAll(filePrefix, "%", "%%")
+	suffix := strings.ReplaceAll(fileSuffix, "%", "%%")
+
+	// Postgres can "rotate" its own log files by calculating log_filename as needed.
+	// However, the automated portions of log_filename are *entirely* based on time.
+	// An inappropriate pairing of log_filename with other logging parameters could lose log messages.
+	//
+	// TODO(logs): Limit the size/bytes of logs without losing messages;
+	// probably requires another process that deletes the oldest files. TODO(sidecar)
+	//
+	// The parameter combinations below have Postgres discard log messages and reuse log files
+	// only after the minimum time has elapsed.
+
+	result := map[string]string{
+		// Discard old messages when log_filename is reused due to rotation.
+		"log_truncate_on_rotation": "on",
+
+		// To not lose messages, log_rotation_size must be larger than the volume of messages emitted before log_filename changes.
+		// Rather than monitor and accommodate that, disable rotation by size completely.
+		"log_rotation_size": "0",
+	}
+
+	// These pairings have Postgres log to multiple files so a log consumer
+	// has the opportunity to read a prior file while Postgres truncates the next.
+	switch {
+	case hours <= 1:
+		// One hour of logs in minute-long files
+		result["log_filename"] = prefix + "%M" + suffix
+		result["log_rotation_age"] = "1min"
+
+	case hours <= 24:
+		// One day of logs in hour-long files
+		result["log_filename"] = prefix + "%H" + suffix
+		result["log_rotation_age"] = "1h"
+
+	case hours <= 24*7:
+		// One week of logs in day-long files
+		result["log_filename"] = prefix + "%a" + suffix
+		result["log_rotation_age"] = "1d"
+
+	case hours <= 24*28:
+		// One month of logs in day-long files
+		result["log_filename"] = prefix + "%d" + suffix
+		result["log_rotation_age"] = "1d"
+
+	default:
+		// One year of logs in day-long files
+		result["log_filename"] = prefix + "%j" + suffix
+		result["log_rotation_age"] = "1d"
+	}
+
+	return result
+}
+
 // WALDirectory returns the absolute path to the directory where an instance
 // stores its WAL files.
 // - https://www.postgresql.org/docs/current/wal.html

internal/postgres/config_test.go

@@ -9,13 +9,16 @@ import (
 	"context"
 	"errors"
 	"fmt"
+	"math/rand/v2"
 	"os"
 	"os/exec"
 	"path/filepath"
 	"strings"
 	"testing"
+	"time"
 
 	"gotest.tools/v3/assert"
+	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"sigs.k8s.io/yaml"
 
 	"github.com/crunchydata/postgres-operator/internal/testing/cmp"
@@ -37,6 +40,86 @@ func TestDataDirectory(t *testing.T) {
 	assert.Equal(t, DataDirectory(cluster), "/pgdata/pg12")
 }
 
+func TestLogRotation(t *testing.T) {
+	t.Parallel()
+
+	const Day = 24 * time.Hour
+
+	random := func(low, high time.Duration) time.Duration {
+		return low + rand.N(high-low)
+	}
+
+	for _, tt := range []struct {
+		duration time.Duration
+		prefix   string
+		suffix   string
+		expected map[string]string
+	}{
+		// Small duration becomes one hour split into minutes
+		{duration: random(1, time.Hour),
+			expected: map[string]string{
+				"log_filename":             "%M",   // two-digit minute [00, 59]
+				"log_rotation_age":         "1min", // × 1 minute = 1 hour
+				"log_rotation_size":        "0",
+				"log_truncate_on_rotation": "on",
+			}},
+
+		// More than an hour becomes one day split into hours
+		{duration: random(90*time.Minute, 24*time.Hour),
+			expected: map[string]string{
+				"log_filename":             "%H", // two-digit hour [00,23]
+				"log_rotation_age":         "1h", // × 1 hour = 1 day
+				"log_rotation_size":        "0",
+				"log_truncate_on_rotation": "on",
+			}},
+
+		// More than one day becomes one week split into days
+		{duration: random(3*Day, 7*Day),
+			expected: map[string]string{
+				"log_filename":             "%a", // locale weekday name
+				"log_rotation_age":         "1d", // × 1 day = 1 week
+				"log_rotation_size":        "0",
+				"log_truncate_on_rotation": "on",
+			}},
+
+		// More than one week becomes one month split into days
+		{duration: random(11*Day, 25*Day),
+			expected: map[string]string{
+				"log_filename":             "%d", // two-digit day of the month [01, 31]
+				"log_rotation_age":         "1d", // × 1 day = 1 month
+				"log_rotation_size":        "0",
+				"log_truncate_on_rotation": "on",
+			}},
+
+		// More than one month becomes one year split into days
+		{duration: random(70*Day, 300*Day),
+			expected: map[string]string{
+				"log_filename":             "%j", // three-digit day of the year [001, 366]
+				"log_rotation_age":         "1d", // × 1 day = 1 year
+				"log_rotation_size":        "0",
+				"log_truncate_on_rotation": "on",
+			}},
+	} {
+		t.Run(tt.duration.String(), func(t *testing.T) {
+			actual := LogRotation(metav1.Duration{Duration: tt.duration}, tt.prefix, tt.suffix)
+			assert.DeepEqual(t, tt.expected, actual)
+		})
+	}
+
+	t.Run("Escaping", func(t *testing.T) {
+		// any duration
+		duration := metav1.Duration{Duration: random(1, 350*Day)}
+
+		// double-percent prefix
+		assert.Assert(t, cmp.Regexp(`^as%%ddf%[^%]qwerty$`,
+			LogRotation(duration, "as%ddf", "qwerty")["log_filename"]))
+
+		// double-percent suffix
+		assert.Assert(t, cmp.Regexp(`^postgres-%[^%]-x%%y%%zzz$`,
+			LogRotation(duration, "postgres-", "-x%y%zzz")["log_filename"]))
+	})
+}
+
 func TestWALDirectory(t *testing.T) {
 	cluster := new(v1beta1.PostgresCluster)
 	cluster.Spec.PostgresVersion = 13