Skip to content

Allowlist rdb_test_ DDLWorker UUID-collision upgrade-check restart noise #107126

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
groeneai wants to merge 1 commit into
base: master
Choose a base branch
from
Open

Allowlist rdb_test_ DDLWorker UUID-collision upgrade-check restart noise #107126

Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
17 changes: 17 additions & 0 deletions tests/docker_scripts/upgrade_runner.sh
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -435,6 +435,22 @@ cp /var/log/clickhouse-server/clickhouse-server.upgrade.log /test_output/clickho
# restart the engine probes the server while loading the persisted object and logs `<Error>` for the
# expected connection failure. Filtered to require the MySQL component AND the connection-failure
# symptom together, so real MySQL regressions (auth, protocol, query errors) are not masked.
# `DDLWorker(rdb_test_...)` + `Error on initialization of rdb_test_...` + `Mapping for table with UUID=... already
# exists` + `TABLE_ALREADY_EXISTS` is benign noise from the `--replicated-database` test wrapper during the
# upgrade restart. `clickhouse-test --replicated-database` creates each test's database as
# `ENGINE=Replicated(...)` named `rdb_test_<rnd>_<shard>`. On the upgrade restart the database's DDLWorker
# runs `DatabaseReplicatedDDLWorker::initializeReplication` -> `recoverLostReplica`, which re-creates tables
# from the ZooKeeper metadata snapshot. If a stale local table still owns a table's UUID (e.g. a leftover
# `_tmp_replace_*` from `CREATE OR REPLACE`, or a table not yet finally dropped), `addUUIDMapping` reports the
# collision as a non-fatal `TABLE_ALREADY_EXISTS` (code 57). The DDLWorker main loop catches it, logs this
# `<Error> ... Error on initialization of ...` line, waits 5s and retries; recovery self-heals (after enough
# retries `max_retries_before_automatic_recovery` forces a digest reset). The server stays up - every other
# upgrade-check sub-test (incl. "Server successfully started") passes; only the post-restart `<Error>` scrub
# trips. Filtered via regex in the secondary pipe below to require ALL of: `Error on initialization of`
# (logged at exactly one site, the DDLWorker recovery retry), the `rdb_test_` test-DB prefix, the UUID mapping
# message, AND the `TABLE_ALREADY_EXISTS` code together. So a real `LOGICAL_ERROR` UUID-mapping crash, the same
# collision on a non-test database, a different init failure on an `rdb_test_` DB, and unrelated
# `TABLE_ALREADY_EXISTS` errors all still surface.
echo "Check for Error messages in server log:"
rg -Fav -e "Code: 236. DB::Exception: Cancelled merging parts" \
-e "Code: 236. DB::Exception: Cancelled mutating parts" \
Expand Down Expand Up @@ -511,6 +527,7 @@ rg -Fav -e "Code: 236. DB::Exception: Cancelled merging parts" \
-e "Exception during get topic partitions from Kafka: Local: Broker transport failure" \
/test_output/clickhouse-server.upgrade.log \
| grep -av -e "_repl_01111_.*Mapping for table with UUID" \
| grep -av -e "Error on initialization of rdb_test_.*Mapping for table with UUID=.*already exists.*TABLE_ALREADY_EXISTS" \

@clickhouse-gh clickhouse-gh Bot Jul 20, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

DatabaseReplicatedDDLWorker::initializeMainThread logs this exact Error on initialization of ... line for every failed recovery attempt and then just waits 5s and retries. In this job we only prove that the server process starts and answers a trivial query; we never touch the leftover rdb_test_* databases again, and clickhouse-test --upgrade-check runs with --fake-drop, so those replicated databases are intentionally left behind for the post-upgrade phase.

That means this new grep -av no longer only suppresses transient noise: it also hides a real recoverLostReplica regression if an rdb_test_* database gets stuck in the same UUID-collision retry loop after upgrade. As long as the server answers SELECT 1, the upgrade check will now pass with no remaining signal that replicated-database recovery is broken. We need an extra post-restart assertion that the rdb_test_* databases actually finish recovery before masking this line.

@groeneai groeneai Jul 20, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Verified against source. Your two facts check out:

  • Error on initialization of {db} is emitted at one site, src/Databases/DatabaseReplicatedWorker.cpp:131, in the while (!stop_flag) catch that waits 5s and retries, so grep -av drops every occurrence, not just transient ones.
  • The rdb_test_* DBs are intentionally left by --fake-drop (tests/clickhouse-test:6736) and hit initializeReplication -> recoverLostReplica on restart.

The problem with a post-restart assertion is timing: upgrade_runner.sh stops the server at line 322 and only scrubs clickhouse-server.upgrade.log at line 454, so there is no live server left to query system.databases. The only remaining signal is log-string correlation (require Finishing replica initialization, line 264, for every errored rdb_test_ DB). That is racy: recovery retries on a 5s cadence and stop_server can land between an error and the next successful attempt on a fully benign run, which would fail the upgrade check for every PR. A new cross-PR flake in shared CI is worse than one masked benign line.

Residual risk acknowledged: after max_retries_before_automatic_recovery (default 10, DatabaseReplicatedSettings.cpp:23) the loop force-resets the digest and re-recovers from the ZK snapshot; a regression that still fails past that point would keep this line masked. I am weighing that against the flake cost above, and against the 4-token regex still surfacing a LOGICAL_ERROR UUID crash, the same collision on a non-rdb_test_ DB, a different init failure on an rdb_test_ DB, or an unrelated TABLE_ALREADY_EXISTS. This matches the merged precedent for benign scrub noise (#106616, #106516).

Keeping the line-level allowlist. If a maintainer prefers a stricter guard, a count threshold (fail if the collision repeats more than K times) is the least-fragile option, but the flake-vs-signal call is theirs.

| grep -av -e "Azure::Storage::StorageException.*Not found address of host" \
| grep -av -e "SystemLogQueue.*Queue had been full" \
| grep -av -e "TraceCollector.*CANNOT_READ_FROM_FILE_DESCRIPTOR" \
Expand Down