Merge pull request #1625 from Altinity/fix-watch-env-override

Keep --env overrides across watch and server config reloads

Author: Slach

ChangeLog.md

@@ -7,6 +7,7 @@ NEW FEATURES
 BUG FIXES
 - the SQL query log no longer prints passwords embedded in URLs: `pass=` / `password=` query string parameters and `user:password@` are written as `[MASKED]`, with `api.create_integration_tables: true` and `api.password` set every `server` start logged the DDL of `system.backup_actions`, `system.backup_list` and `system.backup_version` with the API password in plain text inside the `URL()` engine argument, at `info` level with the default `clickhouse.log_sql_queries: true`, the query sent to ClickHouse is unchanged, fix [#1630](https://github.com/Altinity/clickhouse-backup/issues/1630)
 - `s3.chunk_size` is now also used when `ceil(file size / chunk_size)` is exactly `s3.max_parts_count`, previously it fell back to `file size / max_parts_count`, ReadMe.md now shows the real default `5242880` and the semantics of `s3.chunk_size`, raise it to upload big files as fewer bigger parts instead of `max_parts_count=1` workaround, each multipart upload allocates about `(s3.concurrency + 2) * chunk_size` bytes, `s3.chunk_size` and `azblob.chunk_size` also apply to uploads into object disks during restore, fix [#1142](https://github.com/Altinity/clickhouse-backup/issues/1142)
+- `watch --env=KEY=VALUE` and `server --env=KEY=VALUE` no longer lose the `--env` overrides, config reload on every `watch` iteration (also inside `server --watch` and `POST /backup/watch`) read only the config file and the real environment, so e.g. `--env=REMOTE_STORAGE=ftp` turned back into the config file value and backups went to the wrong remote storage, and `server` never applied its `--env` to its own config at all (startup, `POST /restart`, `SIGHUP` and every API handler reload); `--env` is now applied to the process environment once at startup and kept for the whole process lifetime, so `/backup/actions` commands and operations resumed after restart (`api.complete_resumable_after_restart`) inherit the `server --env` too, `--env` passed inside a `/backup/actions` command still wins and is restored after the command; a duplicated `--env` key keeps the last value; `server` now exits on an invalid config (including a bad `--env` value) instead of retrying every 5 seconds forever, only the ClickHouse connection is still awaited; `general.disable_environment_override: true` still ignores `--env`
 - `--resume` (and `use_resumable_state: true`) now starts from scratch when the config which defines where the resumable state keys point to changed since the interrupted run: `remote_storage`, the active storage location (`s3` endpoint/bucket/path, `gcs` endpoint/bucket/path, `azblob` endpoint_suffix/account_name/container/path, `cos` url/path, `ftp` address/path, `sftp` address/port/path; `path` is not used by `create`), `object_disk_path`, the customer-provided encryption key (`s3.sse_customer_key`, `gcs.encryption_key`, `azblob.sse_key`, only its digest is stored), `compression_format` for `upload` / `create_remote`, and `restore_database_mapping` / `restore_table_mapping` for `restore` / `restore_remote --streaming`; the state keys are relative to the storage path, so `upload --resume` after changing `s3.path` used to skip every file already uploaded to the old path; tuning concurrency, retries, credentials or `log_level` still keeps the resume; the discarded state is logged as a warning with the changed parameters only; `ResumeOperationsAfterRestart` now passes `--restore-database-mapping` / `--restore-table-mapping` back to the resumed `restore` / `restore_remote --streaming`. **Upgrade note**: resumable states written by previous versions have no config fingerprint and are discarded on the first `--resume` after upgrading, so an interrupted operation restarts from scratch once, fix [#1010](https://github.com/Altinity/clickhouse-backup/issues/1010)
 - `watch` no longer treats a failed `backups_to_keep_remote` / `backups_to_keep_local` retention or `--delete-source` after a completely uploaded backup as a failed upload: the new backup becomes the base of the next increment (previously the next increment was diffed from a stale base) and the failure is not counted towards `too many errors ... abort watching`, so a permanently failing post-upload step no longer stops `watch`, it is reported only by the error log, `/backup/status`, `system.backup_actions` and the callback, with `api.enable_metrics` the `failed_create_remotes` counter keeps growing and `last_create_remote_status` stays `0` while new backups are uploaded; all post-upload steps now run even when a previous one failed and their errors are reported together; with `--schedule` the `full_type: rebase` and `delete_previous_cycle` steps also proceed, a failed rebase is reported together with the post-upload error and the backup is not used as the base; `use_embedded_backup_restore_cluster` initiator waits for the worker nodes before the backup is used as the base, a post-upload failure on a worker node is still counted as a failed upload; `create_remote --streaming` no longer reports such a complete backup as partial; one-shot `create_remote` and `upload` still exit with a non-zero code, fix [#1535](https://github.com/Altinity/clickhouse-backup/issues/1535)
 - `restore --schema --rm` without `restore_schema_on_cluster` on a replica of `ENGINE=Replicated` database, when the database schema was already restored from another replica (ACM restore sequence and `How to back up / restore a sharded cluster` in Examples.md), no longer fails with `code: 529 ... Cannot enqueue query on this replica, because it has replication lag`, `code: 36 ... It's not allowed to specify explicit zookeeper_path and replica_name` or `Table ... already exists`: local `DROP DATABASE` of a Replicated database is skipped (it removed only the current replica, which then recovered from the database DDL log concurrently with the following DROP/CREATE TABLE, tables are still dropped and their DROP TABLE is replicated), `SYSTEM SYNC DATABASE REPLICA` is executed before and after dropping tables (ClickHouse 22.5+), and `{uuid}` macro of `Replicated*MergeTree` path is no longer replaced with the backup table UUID and the replication path is no longer rebound to `default_replica_path` inside a Replicated database, fix [#1611](https://github.com/Altinity/clickhouse-backup/issues/1611)

pkg/config/config.go

@@ -13,6 +13,7 @@ import (
 	"time"
 
 	"github.com/Altinity/clickhouse-backup/v2/pkg/log_helper"
+	"github.com/Altinity/clickhouse-backup/v2/pkg/status"
 	"github.com/aws/aws-sdk-go-v2/aws"
 	s3types "github.com/aws/aws-sdk-go-v2/service/s3/types"
 	"github.com/google/shlex"
@@ -1123,7 +1124,11 @@ func GetConfigFromCli(ctx *cli.Command) *Config {
 	if err != nil {
 		log.Fatal().Stack().Err(err).Send()
 	}
-	RestoreEnvVars(oldEnvValues)
+	// --env stays in the process environment, so config reloads of long-lived `watch` and `server` see it with plain LoadConfig,
+	// only commands re-entered from the API server restore it, their own --env shall not leak into the server process
+	if ctx.Int("command-id") != status.NotFromAPI {
+		RestoreEnvVars(oldEnvValues)
+	}
 	// `restore`/`restore_remote` expose --rebind-replica-path-if-exists to override the config value per invocation.
 	// Only override when passed as true, so the flag's default `false` doesn't clobber a `true` from the config file.
 	// Bool is false for commands that don't declare the flag, so this is safe to evaluate for every command.
@@ -1273,10 +1278,13 @@ func OverrideEnvVars(ctx *cli.Command) map[string]oldEnvValues {
 
 		processEnvFromCli(func(envVariable []string) {
 			log.Info().Msgf("override %s=%s", envVariable[0], maskSensitiveEnvValue(envVariable[0], envVariable[1]))
-			oldValue, wasPresent := os.LookupEnv(envVariable[0])
-			oldValues[envVariable[0]] = oldEnvValues{
-				OldValue:   oldValue,
-				WasPresent: wasPresent,
+			// duplicated --env key, keep the value from before the first override, otherwise restore leaves the first override set
+			if _, alreadyOverridden := oldValues[envVariable[0]]; !alreadyOverridden {
+				oldValue, wasPresent := os.LookupEnv(envVariable[0])
+				oldValues[envVariable[0]] = oldEnvValues{
+					OldValue:   oldValue,
+					WasPresent: wasPresent,
+				}
 			}
 			if err := os.Setenv(envVariable[0], envVariable[1]); err != nil {
 				log.Warn().Msgf("can't override %s=%s, error: %v", envVariable[0], maskSensitiveEnvValue(envVariable[0], envVariable[1]), err)

pkg/config/config_test.go

@@ -237,7 +237,11 @@ func TestDisableEnvironmentOverride(t *testing.T) {
 		t.Fatalf("expected --env override %q, got %q", "from-cli", cfg.S3.Bucket)
 	}
 
-	// disable_environment_override: true ignores --env and doesn't touch the process environment
+	// disable_environment_override: true ignores --env and doesn't touch the process environment,
+	// the --env above stays in the process environment by design, see TestGetConfigFromCliKeepsEnvOverride
+	if err = os.Unsetenv("S3_BUCKET"); err != nil {
+		t.Fatalf("can't unset S3_BUCKET: %v", err)
+	}
 	writeConfig(true)
 	cfg = GetConfigFromCli(newCliContext("S3_BUCKET=from-cli"))
 	if cfg.S3.Bucket != "from-file" {
@@ -248,6 +252,72 @@ func TestDisableEnvironmentOverride(t *testing.T) {
 	}
 }
 
+// TestGetConfigFromCliKeepsEnvOverride - `watch` and `server` reload config with plain LoadConfig on every iteration / API call,
+// --env stays in the process environment after GetConfigFromCli, so reloads keep it
+func TestGetConfigFromCliKeepsEnvOverride(t *testing.T) {
+	configPath := filepath.Join(t.TempDir(), "config.yml")
+	writeConfig := func(disable bool) {
+		content := fmt.Sprintf("general:\n  remote_storage: \"s3\"\n  backups_to_keep_remote: 3\n  disable_environment_override: %v\ns3:\n  bucket: \"from-file\"\n", disable)
+		if err := os.WriteFile(configPath, []byte(content), 0644); err != nil {
+			t.Fatalf("can't write config file: %v", err)
+		}
+	}
+	// t.Setenv snapshots the ambient values and restores them after the test
+	resetEnv := func() {
+		for _, name := range []string{"REMOTE_STORAGE", "BACKUPS_TO_KEEP_REMOTE"} {
+			t.Setenv(name, "")
+			if err := os.Unsetenv(name); err != nil {
+				t.Fatalf("can't unset %s: %v", name, err)
+			}
+		}
+		t.Setenv("S3_BUCKET", "ambient")
+	}
+	// duplicated key, the last value wins
+	envArgs := []string{"--env", "REMOTE_STORAGE=none", "--env", "BACKUPS_TO_KEEP_REMOTE=7", "--env", "S3_BUCKET=first", "--env", "S3_BUCKET=last"}
+	ctx := parseTestFlags(t, append([]string{"--config", configPath}, envArgs...)...)
+	assertOverridden := func(cfg *Config, step string) {
+		t.Helper()
+		if cfg.General.RemoteStorage != "none" || cfg.General.BackupsToKeepRemote != 7 || cfg.S3.Bucket != "last" {
+			t.Fatalf("%s expected --env overrides, got remote_storage=%q backups_to_keep_remote=%d s3->bucket=%q", step, cfg.General.RemoteStorage, cfg.General.BackupsToKeepRemote, cfg.S3.Bucket)
+		}
+	}
+
+	resetEnv()
+	writeConfig(false)
+	assertOverridden(GetConfigFromCli(ctx), "GetConfigFromCli")
+	for i := 0; i < 2; i++ {
+		cfg, err := LoadConfig(GetConfigPath(ctx))
+		if err != nil {
+			t.Fatalf("LoadConfig: %v", err)
+		}
+		assertOverridden(cfg, fmt.Sprintf("reload %d", i))
+	}
+
+	// commands re-entered from the API server restore the environment, their --env shall not leak into the server process
+	resetEnv()
+	cfg := GetConfigFromCli(parseTestFlags(t, append([]string{"--config", configPath, "--command-id", "5"}, envArgs...)...))
+	assertOverridden(cfg, "re-entered GetConfigFromCli")
+	for _, name := range []string{"REMOTE_STORAGE", "BACKUPS_TO_KEEP_REMOTE"} {
+		if _, present := os.LookupEnv(name); present {
+			t.Fatalf("--env %s of the re-entered command leaked into the process environment", name)
+		}
+	}
+	if got := os.Getenv("S3_BUCKET"); got != "ambient" {
+		t.Fatalf("expected ambient S3_BUCKET restored after duplicated --env, got %q", got)
+	}
+
+	// disable_environment_override: true ignores --env and doesn't touch the process environment
+	resetEnv()
+	writeConfig(true)
+	cfg = GetConfigFromCli(ctx)
+	if cfg.General.RemoteStorage != "s3" || cfg.General.BackupsToKeepRemote != 3 || cfg.S3.Bucket != "from-file" {
+		t.Fatalf("expected config file values with disable_environment_override, got remote_storage=%q backups_to_keep_remote=%d s3->bucket=%q", cfg.General.RemoteStorage, cfg.General.BackupsToKeepRemote, cfg.S3.Bucket)
+	}
+	if _, present := os.LookupEnv("REMOTE_STORAGE"); present {
+		t.Fatal("--env leaked into the process environment while disable_environment_override is enabled")
+	}
+}
+
 func newEnvContext(t *testing.T, values ...string) *cli.Command {
 	t.Helper()
 	return parseTestFlags(t, envArgs(values)...)
@@ -274,6 +344,7 @@ func parseTestFlags(t *testing.T, args ...string) *cli.Command {
 		Flags: []cli.Flag{
 			&cli.StringFlag{Name: "config", Aliases: []string{"c"}, Value: DefaultConfigPath},
 			&cli.StringSliceFlag{Name: "environment-override", Aliases: []string{"env"}},
+			&cli.IntFlag{Name: "command-id", Value: -1},
 		},
 		Action: func(_ context.Context, c *cli.Command) error {
 			parsed = c

pkg/server/server.go

@@ -75,21 +75,14 @@ var (
 
 // Run - expose CLI commands as REST API
 func Run(cliCtx *cli.Command, newCliApp func() *cli.Command, configPath string, clickhouseBackupVersion string) error {
-	var (
-		cfg *config.Config
-		err error
-	)
 	// from here on every re-entry into cliApp comes from an API handler which owns
 	// its own status row, see status.SetAPIServerMode
 	status.SetAPIServerMode()
+	// applies --env to the process environment once, so every later ReloadConfig and cliApp re-entry sees it,
+	// invalid config, including a bad --env value, is fatal, only ClickHouse connectivity is worth waiting for
+	cfg := config.GetConfigFromCli(cliCtx)
 	log.Debug().Msg("Wait for ClickHouse")
 	for {
-		cfg, err = config.LoadConfig(configPath)
-		if err != nil {
-			log.Error().Stack().Err(err).Send()
-			time.Sleep(5 * time.Second)
-			continue
-		}
 		ch := clickhouse.NewClickHouse(&cfg.ClickHouse)
 		if connErr := ch.Connect(); connErr != nil {
 			log.Error().Stack().Err(connErr).Send()

test/integration/watchEnvOverride_test.go

@@ -0,0 +1,70 @@
+//go:build integration
+
+package main
+
+import (
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/rs/zerolog/log"
+)
+
+// TestWatchEnvOverride - `watch` reloads config on every iteration, the reload shall keep --env overrides,
+// otherwise backups land in the config file remote path instead of the --env one
+func TestWatchEnvOverride(t *testing.T) {
+	env, r := NewTestEnvironment(t)
+	defer env.Cleanup(t, r)
+	env.connectWithWait(t, r, 0*time.Second, 1*time.Second, 1*time.Minute)
+
+	dbName := "test_watch_env_override"
+	prefix := "envwatch"
+	// keep {version} macro, it isolates concurrent CI runs in the shared bucket
+	envArgs := "--env S3_PATH=backup_watch_env/{cluster}/{shard}/{version}"
+
+	listMatched := func(args string) []string {
+		out, _ := env.DockerExecOut("clickhouse-backup", "bash", "-ce", "clickhouse-backup -c /etc/clickhouse-backup/config-s3.yml "+args+" list remote 2>/dev/null | cut -d ' ' -f 1 | grep '^"+prefix+"-' || true")
+		return strings.Fields(out)
+	}
+	cleanBackups := func() {
+		for _, args := range []string{envArgs, ""} {
+			for _, backupName := range listMatched(args) {
+				env.DockerExecNoError(r, "clickhouse-backup", "bash", "-ce", "clickhouse-backup -c /etc/clickhouse-backup/config-s3.yml "+args+" delete --force remote "+backupName+" 2>/dev/null || true")
+			}
+		}
+		// backups killed mid-flight by pkill may not show up in `list local`, remove leftovers from all backup disks
+		env.DockerExecNoError(r, "clickhouse-backup", "bash", "-ce", "rm -rf /var/lib/clickhouse/backup/"+prefix+"-* /hdd1_data/backup/"+prefix+"-* /hdd2_data/backup/"+prefix+"-* 2>/dev/null || true")
+	}
+	cleanBackups()
+	r.NoError(env.dropDatabase(dbName, true))
+	defer func() {
+		cleanBackups()
+		r.NoError(env.dropDatabase(dbName, true))
+	}()
+
+	env.queryWithNoError(t, r, "CREATE DATABASE "+dbName)
+	env.queryWithNoError(t, r, "CREATE TABLE "+dbName+".t1 (id UInt64) ENGINE=MergeTree() ORDER BY id")
+	env.queryWithNoError(t, r, "INSERT INTO "+dbName+".t1 SELECT number FROM numbers(1000)")
+
+	env.DockerExecBackgroundNoError(r, "clickhouse-backup", "bash", "-ce",
+		"BACKUPS_TO_KEEP_REMOTE=0 clickhouse-backup -c /etc/clickhouse-backup/config-s3.yml "+envArgs+" watch --watch-interval=10s --full-interval=1h --watch-backup-name-template="+prefix+"-{type}-{time:20060102150405} --tables="+dbName+".* &>>/tmp/watch_env_override.log")
+	defer func() {
+		// [c]lickhouse regexp bracket trick, so pkill doesn't match its own `bash -ce` command line and kill itself with SIGTERM;
+		// wait until the watch process actually exits, a backup in flight during pkill can re-create local files after cleanup
+		env.DockerExecNoError(r, "clickhouse-backup", "bash", "-ce", "pkill -f '[c]lickhouse-backup.*watch' || true; for i in $(seq 1 30); do pgrep -f '[c]lickhouse-backup.*watch' >/dev/null || break; sleep 1; done")
+		out, _ := env.DockerExecOut("clickhouse-backup", "bash", "-ce", "cat /tmp/watch_env_override.log; rm -f /tmp/watch_env_override.log")
+		log.Debug().Msg(out)
+	}()
+
+	// the second backup proves the config reload inside the watch loop keeps --env too, not only the initial load
+	var matched []string
+	deadline := time.Now().Add(5 * time.Minute)
+	for time.Now().Before(deadline) {
+		if matched = listMatched(envArgs); len(matched) >= 2 {
+			break
+		}
+		time.Sleep(5 * time.Second)
+	}
+	r.GreaterOrEqual(len(matched), 2, "every watch iteration shall upload into S3_PATH from --env, got %v", matched)
+	r.Empty(listMatched(""), "watch shall not upload into s3->path from the config file when --env S3_PATH is passed")
+}