diff --git a/.golangci.yaml b/.golangci.yaml index b1e6c7167..3335ad678 100644 --- a/.golangci.yaml +++ b/.golangci.yaml @@ -75,6 +75,8 @@ linters: desc: Use "go.opentelemetry.io/otel/semconv/v1.27.0" instead. - pkg: io/ioutil desc: Use the "io" and "os" packages instead. See https://go.dev/doc/go1.16#ioutil + - pkg: math/rand$ + desc: Use the "math/rand/v2" package instead. See https://go.dev/doc/go1.22#math_rand_v2 not-tests: files: ['!$test','!**/internal/testing/**'] list-mode: lax @@ -139,6 +141,11 @@ linters: - legacy - std-error-handling rules: + # It is fine for tests to use "math/rand" packages. + - linters: [gosec] + path: '(.+)_test[.]go' + text: weak random number generator + # This internal package is the one place we want to do API discovery. - linters: [depguard] path: internal/kubernetes/discovery.go diff --git a/internal/collector/postgres.go b/internal/collector/postgres.go index a92663909..74fe5cf05 100644 --- a/internal/collector/postgres.go +++ b/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 -} diff --git a/internal/controller/postgrescluster/postgres.go b/internal/controller/postgrescluster/postgres.go index 10901e10d..8922e5f73 100644 --- a/internal/controller/postgrescluster/postgres.go +++ b/internal/controller/postgrescluster/postgres.go @@ -131,7 +131,7 @@ func (*Reconciler) generatePostgresParameters( ) *postgres.ParameterSet { builtin := postgres.NewParameters() pgaudit.PostgreSQLParameters(&builtin) - pgbackrest.PostgreSQL(cluster, &builtin, backupsSpecFound) + pgbackrest.PostgreSQLParameters(cluster, &builtin, backupsSpecFound) pgmonitor.PostgreSQLParameters(ctx, cluster, &builtin) postgres.SetHugePages(cluster, &builtin) diff --git a/internal/pgbackrest/postgres.go b/internal/pgbackrest/postgres.go index 0d05041c7..3d07e81ad 100644 --- a/internal/pgbackrest/postgres.go +++ b/internal/pgbackrest/postgres.go @@ -11,8 +11,8 @@ import ( "github.com/crunchydata/postgres-operator/pkg/apis/postgres-operator.crunchydata.com/v1beta1" ) -// PostgreSQL populates outParameters with any settings needed to run pgBackRest. -func PostgreSQL( +// PostgreSQLParameters populates outParameters with any settings needed to run pgBackRest. +func PostgreSQLParameters( inCluster *v1beta1.PostgresCluster, outParameters *postgres.Parameters, backupsEnabled bool, diff --git a/internal/pgbackrest/postgres_test.go b/internal/pgbackrest/postgres_test.go index 4ec215cec..d7d272905 100644 --- a/internal/pgbackrest/postgres_test.go +++ b/internal/pgbackrest/postgres_test.go @@ -17,7 +17,7 @@ func TestPostgreSQLParameters(t *testing.T) { cluster := new(v1beta1.PostgresCluster) parameters := new(postgres.Parameters) - PostgreSQL(cluster, parameters, true) + PostgreSQLParameters(cluster, parameters, true) assert.DeepEqual(t, parameters.Mandatory.AsMap(), map[string]string{ "archive_mode": "on", "archive_command": `pgbackrest --stanza=db archive-push "%p"`, @@ -28,7 +28,7 @@ func TestPostgreSQLParameters(t *testing.T) { "archive_timeout": "60s", }) - PostgreSQL(cluster, parameters, false) + PostgreSQLParameters(cluster, parameters, false) assert.DeepEqual(t, parameters.Mandatory.AsMap(), map[string]string{ "archive_mode": "on", "archive_command": "true", @@ -40,7 +40,7 @@ func TestPostgreSQLParameters(t *testing.T) { RepoName: "repo99", } - PostgreSQL(cluster, parameters, true) + PostgreSQLParameters(cluster, parameters, true) assert.DeepEqual(t, parameters.Mandatory.AsMap(), map[string]string{ "archive_mode": "on", "archive_command": `pgbackrest --stanza=db archive-push "%p"`, diff --git a/internal/pgbackrest/util_test.go b/internal/pgbackrest/util_test.go index 30ab33fd0..d2fd93455 100644 --- a/internal/pgbackrest/util_test.go +++ b/internal/pgbackrest/util_test.go @@ -6,7 +6,7 @@ package pgbackrest import ( "io" - "math/rand" + "math/rand/v2" "strconv" "testing" diff --git a/internal/postgres/config.go b/internal/postgres/config.go index d0ee8f353..942803975 100644 --- a/internal/postgres/config.go +++ b/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 diff --git a/internal/postgres/config_test.go b/internal/postgres/config_test.go index e1389b0d9..762bd8a0b 100644 --- a/internal/postgres/config_test.go +++ b/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