From d742e7b94fad8d295085dce7acad7f724cc9f8d2 Mon Sep 17 00:00:00 2001 From: Mason Cole <117116981+bt-macole@users.noreply.github.com> Date: Tue, 20 Oct 2026 09:35:51 -0700 Subject: [PATCH 1/2] Mask URL passwords in the SQL query log, fix #1630 With api.create_integration_tables and api.password set, every server start logged the system.backup_* DDL with the API password in the URL() engine argument. LogQuery now masks pass= / password= query string values and user:password@ userinfo in the logged message; the query sent to ClickHouse is unchanged. Co-Authored-By: Claude Opus 5.5 --- ChangeLog.md | 1 + pkg/clickhouse/clickhouse.go | 18 +++++-- pkg/clickhouse/log_query_test.go | 81 ++++++++++++++++++++++++++++++++ 3 files changed, 97 insertions(+), 3 deletions(-) create mode 100644 pkg/clickhouse/log_query_test.go diff --git a/ChangeLog.md b/ChangeLog.md index 33456baf..ecd22067 100644 --- a/ChangeLog.md +++ b/ChangeLog.md @@ -5,6 +5,7 @@ NEW FEATURES - add `azblob.chunk_size` (env `AZBLOB_CHUNK_SIZE`, default `0`), a fixed upload block size used when `ceil(file size / chunk_size) <= max_parts_count`, clamped to [2MiB, 4000MiB], `0` keeps the automatic `file size / max_parts_count` clamped to [2MiB, 10MiB], brings back the explicit size removed together with `AZBLOB_BUFFER_SIZE` in v2.6.6, fix [#1142](https://github.com/Altinity/clickhouse-backup/issues/1142) 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` 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) diff --git a/pkg/clickhouse/clickhouse.go b/pkg/clickhouse/clickhouse.go index d56ffa6c..a44731eb 100644 --- a/pkg/clickhouse/clickhouse.go +++ b/pkg/clickhouse/clickhouse.go @@ -1493,14 +1493,26 @@ func (ch *ClickHouse) LogQuery(query string, args ...interface{}) string { if !ch.Config.LogSQLQueries { level = zerolog.DebugLevel } + msg := query if len(args) > 0 { - log.WithLevel(level).Msg(strings.NewReplacer("\n", " ", "\r", " ", "\t", " ").Replace(fmt.Sprintf("%s with args %#v", query, args))) - } else { - log.WithLevel(level).Msg(strings.NewReplacer("\n", " ", "\r", " ", "\t", " ").Replace(query)) + msg = fmt.Sprintf("%s with args %#v", query, args) } + log.WithLevel(level).Msg(maskURLCredentials(strings.NewReplacer("\n", " ", "\r", " ", "\t", " ").Replace(msg))) return query } +// urlPassParamRe matches the value of a `pass` / `password` query string parameter, the `system.backup_*` integration tables carry `api.password` as `pass=` +var urlPassParamRe = regexp.MustCompile(`(?i)([?&](?:pass|password)=)[^&'"\s]*`) + +// urlUserInfoPassRe matches the password of `scheme://user:password@host` +var urlUserInfoPassRe = regexp.MustCompile(`(://[^:/?#@'"\s]*:)[^@/?#'"\s]*@`) + +// maskURLCredentials replaces passwords inside URLs, such as the URL() table engine argument, before the query is logged +func maskURLCredentials(s string) string { + s = urlPassParamRe.ReplaceAllString(s, "${1}[MASKED]") + return urlUserInfoPassRe.ReplaceAllString(s, "${1}[MASKED]@") +} + func (ch *ClickHouse) IsDbAtomicOrReplicated(database string) (bool, error) { dbEngine, err := ch.GetDatabaseEngine(database) if err != nil { diff --git a/pkg/clickhouse/log_query_test.go b/pkg/clickhouse/log_query_test.go new file mode 100644 index 00000000..33aa0101 --- /dev/null +++ b/pkg/clickhouse/log_query_test.go @@ -0,0 +1,81 @@ +package clickhouse + +import ( + "bytes" + "encoding/json" + "net/url" + "testing" + + "github.com/Altinity/clickhouse-backup/v2/pkg/config" + "github.com/rs/zerolog" + "github.com/rs/zerolog/log" + "github.com/stretchr/testify/assert" +) + +func TestLogQueryMasksURLCredentials(t *testing.T) { + const password = "s3cr&t'p@ss word" + params := url.Values{} + params.Add("user", "backup") + params.Add("pass", password) + encodedPassword := url.QueryEscape(password) + + testCases := []struct { + Name string + Query string + Args []interface{} + Expected string + }{ + { + Name: "integration table URL engine", + Query: "CREATE TABLE system.backup_actions (command String) ENGINE=URL('http://127.0.0.1:7171/backup/actions?" + params.Encode() + "', JSONEachRow) SETTINGS input_format_skip_unknown_fields=1", + Expected: "CREATE TABLE system.backup_actions (command String) ENGINE=URL('http://127.0.0.1:7171/backup/actions?pass=[MASKED]&user=backup', JSONEachRow) SETTINGS input_format_skip_unknown_fields=1", + }, + { + Name: "password parameter after another parameter", + Query: "CREATE TABLE db.t (x String) ENGINE=URL('https://host:8443/data?user=u&password=" + encodedPassword + "', JSONEachRow)", + Expected: "CREATE TABLE db.t (x String) ENGINE=URL('https://host:8443/data?user=u&password=[MASKED]', JSONEachRow)", + }, + { + Name: "password in URL userinfo", + Query: "CREATE TABLE db.t (x String) ENGINE=URL('https://u:" + encodedPassword + "@host:8443/data', JSONEachRow)", + Expected: "CREATE TABLE db.t (x String) ENGINE=URL('https://u:[MASKED]@host:8443/data', JSONEachRow)", + }, + { + Name: "query with args", + Query: "CREATE TABLE db.t (x String) ENGINE=URL('http://host/data?pass=" + encodedPassword + "', JSONEachRow) COMMENT ?", + Args: []interface{}{"c"}, + Expected: `CREATE TABLE db.t (x String) ENGINE=URL('http://host/data?pass=[MASKED]', JSONEachRow) COMMENT ? with args []interface {}{"c"}`, + }, + { + Name: "query without credentials is unchanged", + Query: "SELECT name FROM system.tables WHERE database = 'default' AND engine_full LIKE '%://host:9000/%'", + Expected: "SELECT name FROM system.tables WHERE database = 'default' AND engine_full LIKE '%://host:9000/%'", + }, + } + + originalLogger := log.Logger + originalGlobalLevel := zerolog.GlobalLevel() + t.Cleanup(func() { + log.Logger = originalLogger + zerolog.SetGlobalLevel(originalGlobalLevel) + }) + zerolog.SetGlobalLevel(zerolog.InfoLevel) + ch := ClickHouse{Config: &config.ClickHouseConfig{LogSQLQueries: true}} + + for _, tc := range testCases { + t.Run(tc.Name, func(t *testing.T) { + var buf bytes.Buffer + log.Logger = zerolog.New(&buf) + + assert.Equal(t, tc.Query, ch.LogQuery(tc.Query, tc.Args...), "the executed query must keep the credentials") + output := buf.String() + assert.NotContains(t, output, password) + assert.NotContains(t, output, encodedPassword) + var entry struct { + Message string `json:"message"` + } + assert.NoError(t, json.Unmarshal(buf.Bytes(), &entry)) + assert.Equal(t, tc.Expected, entry.Message) + }) + } +} From 7fbcca1474e5f77458dda4a700801d6742749040 Mon Sep 17 00:00:00 2001 From: slach Date: Wed, 21 Oct 2026 00:31:29 +0500 Subject: [PATCH 2/2] Skip SQL log formatting and masking when they are not needed LogQuery built and masked the message even when the event level was disabled (log_sql_queries: false without debug logging), which became measurably more expensive once the URL credential regexps were added. Return early when the event is disabled, and run the regexps only when the message contains "://", since both masked forms are URL parts. Co-Authored-By: Claude Opus 5.5 --- pkg/clickhouse/clickhouse.go | 9 ++++++++- pkg/clickhouse/log_query_test.go | 9 +++++++++ 2 files changed, 17 insertions(+), 1 deletion(-) diff --git a/pkg/clickhouse/clickhouse.go b/pkg/clickhouse/clickhouse.go index a44731eb..ca011caf 100644 --- a/pkg/clickhouse/clickhouse.go +++ b/pkg/clickhouse/clickhouse.go @@ -1493,11 +1493,15 @@ func (ch *ClickHouse) LogQuery(query string, args ...interface{}) string { if !ch.Config.LogSQLQueries { level = zerolog.DebugLevel } + event := log.WithLevel(level) + if !event.Enabled() { + return query + } msg := query if len(args) > 0 { msg = fmt.Sprintf("%s with args %#v", query, args) } - log.WithLevel(level).Msg(maskURLCredentials(strings.NewReplacer("\n", " ", "\r", " ", "\t", " ").Replace(msg))) + event.Msg(maskURLCredentials(strings.NewReplacer("\n", " ", "\r", " ", "\t", " ").Replace(msg))) return query } @@ -1509,6 +1513,9 @@ var urlUserInfoPassRe = regexp.MustCompile(`(://[^:/?#@'"\s]*:)[^@/?#'"\s]*@`) // maskURLCredentials replaces passwords inside URLs, such as the URL() table engine argument, before the query is logged func maskURLCredentials(s string) string { + if !strings.Contains(s, "://") { + return s + } s = urlPassParamRe.ReplaceAllString(s, "${1}[MASKED]") return urlUserInfoPassRe.ReplaceAllString(s, "${1}[MASKED]@") } diff --git a/pkg/clickhouse/log_query_test.go b/pkg/clickhouse/log_query_test.go index 33aa0101..ec87c535 100644 --- a/pkg/clickhouse/log_query_test.go +++ b/pkg/clickhouse/log_query_test.go @@ -78,4 +78,13 @@ func TestLogQueryMasksURLCredentials(t *testing.T) { assert.Equal(t, tc.Expected, entry.Message) }) } + + t.Run("disabled level writes nothing", func(t *testing.T) { + var buf bytes.Buffer + log.Logger = zerolog.New(&buf) + debugCh := ClickHouse{Config: &config.ClickHouseConfig{LogSQLQueries: false}} + query := testCases[0].Query + assert.Equal(t, query, debugCh.LogQuery(query)) + assert.Empty(t, buf.String()) + }) }