Clickhouse: impossible to drop partition with incorrect data

[floxard]

Describe the bug
Can't drop partition 197001 from ReplicatedMergeTree table created with old syntax.

How to reproduce

• any version
• default settings

CREATE TABLE test (`d` Date) ENGINE = ReplicatedMergeTree('/test/test','test', d,d,d,8192);

insert into test values ('0000-00-00');

insert into test values (today());

SELECT * FROM test
┌──────────d─┐
│ 2020-08-31 │
└────────────┘
┌──────────d─┐
│ 0000-00-00 │
└────────────┘
2 rows in set. Elapsed: 0.002 sec. 

alter table test drop partition 197001;

SELECT * FROM test
┌──────────d─┐
│ 2020-08-31 │
└────────────┘
┌──────────d─┐
│ 0000-00-00 │
└────────────┘
2 rows in set. Elapsed: 0.002 sec. 

Expected behavior

SELECT * FROM test
┌──────────d─┐
│ 2020-08-31 │
└────────────┘
1 rows in set. Elapsed: 0.002 sec. 

Error message and/or stacktrace

2020.08.06 17:18:14.357323 [ 459 ] {c78f373d-0067-4cf8-82b1-a363e1cb013d} <Information> database.table: Will not drop partition 19700101_19700101_0_0_0, it is empty.

Additional context
It works as expected with tables created with new syntax, or non-Replicated MergeTree Engine

[den-crane]

CH version?

I could not reproduce with 20.8.1.4508

[filimonov]

Checked on 20.1.8: can't reproduce.

[floxard]

ClickHouse server version 20.3.12 revision 54433

CREATE TABLE test
(
    `d` Date
)
ENGINE = ReplicatedMergeTree('/test/test', 'test', d, d, d, 8192)

Ok.

0 rows in set. Elapsed: 0.065 sec. 

:) insert into test values ('0000-00-00');
INSERT INTO test VALUES

Ok.

:) insert into test values (today());
INSERT INTO test VALUES

Ok.

SELECT DISTINCT partition
FROM system.parts
WHERE table = 'test'

┌─partition─┐
│ 197001    │
│ 202008    │
└───────────┘

2 rows in set. Elapsed: 0.002 sec. 

ALTER TABLE test
    DROP PARTITION 197001

Ok.

flxpc :) select * from test;

SELECT *
FROM test

┌──────────d─┐
│ 0000-00-00 │
└────────────┘
┌──────────d─┐
│ 2020-08-31 │
└────────────┘

2 rows in set. Elapsed: 0.001 sec. 

same on 20.6.4 revision 54436 (latest from "deb http://repo.yandex.ru/clickhouse/deb/stable/ main/")

same on 19.17.9 revision 54428

same on random versions on production and test environments

I'll test on 20.1.8 and 20.8.1.4508 soon

[floxard]

same on 20.1.8 revision 54431

[floxard]

same on 20.8.1 revision 54438

[floxard]

It is important to use old syntax like "ReplicatedMergeTree(zkpath,replica,other,params)" and ReplicatedMergeTree engine to reproduce

[den-crane]

Connected to ClickHouse server version 20.8.1 revision 54438.

tail -20000 /var/log/clickhouse-server/clickhouse-server.log|grep test

2020.08.31 15:20:06.970246 [ 18342 ] {b679799f-b7d6-45e2-86d2-16b19d0dd7c9} <Debug> executeQuery: (from [::1]:40918) CREATE TABLE test ( `d` Date ) ENGINE = ReplicatedMergeTree('/test/test', 'test', d, d, d, 8192)
2020.08.31 15:20:06.970295 [ 18342 ] {b679799f-b7d6-45e2-86d2-16b19d0dd7c9} <Trace> ContextAccess (default): Access granted: CREATE TABLE ON dw.test
2020.08.31 15:20:06.970771 [ 18342 ] {b679799f-b7d6-45e2-86d2-16b19d0dd7c9} <Debug> dw.test: Loading data parts
2020.08.31 15:20:06.970812 [ 18342 ] {b679799f-b7d6-45e2-86d2-16b19d0dd7c9} <Debug> dw.test: Loaded data parts (0 items)
2020.08.31 15:20:06.974073 [ 18342 ] {b679799f-b7d6-45e2-86d2-16b19d0dd7c9} <Debug> dw.test: Creating table /test/test
2020.08.31 15:20:06.987646 [ 18322 ] {} <Debug> dw.test (ReplicatedMergeTreeRestartingThread): Activating replica.
2020.08.31 15:20:06.988956 [ 18322 ] {} <Debug> dw.test (ReplicatedMergeTreeQueue): Loading queue from /test/test/replicas/test/queue
2020.08.31 15:20:06.989152 [ 18322 ] {} <Debug> dw.test (ReplicatedMergeTreeQueue): Having 0 queue entries to load, 0 entries already loaded.
2020.08.31 15:20:06.989282 [ 18322 ] {} <Trace> dw.test (ReplicatedMergeTreeQueue): Loaded queue
2020.08.31 15:20:06.991645 [ 18317 ] {} <Information> dw.test: Became leader
2020.08.31 15:20:13.278554 [ 18342 ] {c7d916cc-0d70-4547-a852-2d811eeb1a21} <Debug> executeQuery: (from [::1]:40918) insert into test values
2020.08.31 15:20:13.278610 [ 18342 ] {c7d916cc-0d70-4547-a852-2d811eeb1a21} <Trace> ContextAccess (default): Access granted: INSERT(d) ON dw.test
2020.08.31 15:20:13.279024 [ 18342 ] {c7d916cc-0d70-4547-a852-2d811eeb1a21} <Debug> dw.test (Replicated OutputStream): Wrote block with ID '197001_16463125221289835019_10190872195227644580', 1 rows
2020.08.31 15:20:13.282567 [ 18342 ] {c7d916cc-0d70-4547-a852-2d811eeb1a21} <Trace> dw.test: Renaming temporary part tmp_insert_19700101_19700101_1_1_0 to 19700101_19700101_0_0_0.
2020.08.31 15:20:13.286315 [ 18286 ] {} <Debug> dw.test (ReplicatedMergeTreeQueue): Pulling 1 entries to queue: log-0000000000 - log-0000000000
2020.08.31 15:20:13.287183 [ 18286 ] {} <Debug> dw.test (ReplicatedMergeTreeQueue): Pulled 1 entries to queue.
2020.08.31 15:20:18.468256 [ 18342 ] {9c49defb-f827-4aaa-9b64-654b5b611970} <Debug> executeQuery: (from [::1]:40918) insert into test values
2020.08.31 15:20:18.468321 [ 18342 ] {9c49defb-f827-4aaa-9b64-654b5b611970} <Trace> ContextAccess (default): Access granted: INSERT(d) ON dw.test
2020.08.31 15:20:18.469209 [ 18342 ] {9c49defb-f827-4aaa-9b64-654b5b611970} <Debug> dw.test (Replicated OutputStream): Wrote block with ID '202008_9575859307650111706_3329156197479415715', 1 rows
2020.08.31 15:20:18.472946 [ 18342 ] {9c49defb-f827-4aaa-9b64-654b5b611970} <Trace> dw.test: Renaming temporary part tmp_insert_20200831_20200831_2_2_0 to 20200831_20200831_0_0_0.
2020.08.31 15:20:18.474004 [ 18289 ] {} <Debug> dw.test (ReplicatedMergeTreeQueue): Pulling 1 entries to queue: log-0000000001 - log-0000000001
2020.08.31 15:20:18.474841 [ 18289 ] {} <Debug> dw.test (ReplicatedMergeTreeQueue): Pulled 1 entries to queue.
2020.08.31 15:20:23.605073 [ 18342 ] {38bde2d6-25d1-42da-844f-7982e5acdf7a} <Debug> executeQuery: (from [::1]:40918) SELECT DISTINCT partition FROM system.parts WHERE table = 'test'
2020.08.31 15:20:29.573884 [ 18342 ] {34e1d3cb-5fb2-45d3-b83c-e5ad9bffd648} <Debug> executeQuery: (from [::1]:40918) ALTER TABLE test DROP PARTITION 197001
2020.08.31 15:20:29.573933 [ 18342 ] {34e1d3cb-5fb2-45d3-b83c-e5ad9bffd648} <Trace> ContextAccess (default): Access granted: ALTER DELETE ON dw.test
2020.08.31 15:20:29.582300 [ 18342 ] {34e1d3cb-5fb2-45d3-b83c-e5ad9bffd648} <Trace> dw.test: Deleted 1 deduplication block IDs in partition ID 197001
2020.08.31 15:20:29.582314 [ 18342 ] {34e1d3cb-5fb2-45d3-b83c-e5ad9bffd648} <Debug> dw.test: Disabled merges covered by range 19700101_19700131_0_0_999999999
2020.08.31 15:20:29.583051 [ 18342 ] {34e1d3cb-5fb2-45d3-b83c-e5ad9bffd648} <Debug> dw.test: Waiting for test to pull log-0000000002 to queue
2020.08.31 15:20:29.583369 [ 18336 ] {} <Debug> dw.test (ReplicatedMergeTreeQueue): Pulling 1 entries to queue: log-0000000002 - log-0000000002
2020.08.31 15:20:29.584253 [ 18336 ] {} <Debug> dw.test (ReplicatedMergeTreeQueue): Pulled 1 entries to queue.
2020.08.31 15:20:29.584281 [ 18342 ] {34e1d3cb-5fb2-45d3-b83c-e5ad9bffd648} <Debug> dw.test: Looking for node corresponding to log-0000000002 in test queue
2020.08.31 15:20:29.584283 [ 18300 ] {} <Debug> dw.test (ReplicatedMergeTreeQueue): Removed 0 entries from queue. Waiting for 0 entries that are currently executing.
2020.08.31 15:20:29.584294 [ 18300 ] {} <Debug> dw.test: Removing parts.
2020.08.31 15:20:29.584424 [ 18342 ] {34e1d3cb-5fb2-45d3-b83c-e5ad9bffd648} <Debug> dw.test: Waiting for queue-0000000002 to disappear from test queue
2020.08.31 15:20:29.585036 [ 18300 ] {} <Debug> dw.test: Removed 1 parts inside 19700101_19700131_0_0_999999999.
2020.08.31 15:20:29.585059 [ 18329 ] {} <Trace> dw.test: Found 1 old parts to remove.
2020.08.31 15:20:29.585070 [ 18329 ] {} <Debug> dw.test: Removing 1 old parts from ZooKeeper
2020.08.31 15:20:29.585740 [ 18329 ] {} <Debug> dw.test: There is no part 19700101_19700101_0_0_0 in ZooKeeper, it was only in filesystem
2020.08.31 15:20:29.585749 [ 18329 ] {} <Debug> dw.test: Removed 1 old parts from ZooKeeper. Removing them from filesystem.
2020.08.31 15:20:29.585835 [ 18329 ] {} <Debug> dw.test: Removed 1 old parts
2020.08.31 15:20:29.585997 [ 18329 ] {} <Trace> dw.test (ReplicatedMergeTreeCleanupThread): Checking 1 blocks (1 are not cached) to clear old ones from ZooKeeper.
2020.08.31 15:20:36.001434 [ 18342 ] {1f8ae482-a680-4468-8134-7738a656c6eb} <Debug> executeQuery: (from [::1]:40918) SELECT * FROM test
2020.08.31 15:20:36.001581 [ 18342 ] {1f8ae482-a680-4468-8134-7738a656c6eb} <Trace> ContextAccess (default): Access granted: SELECT(d) ON dw.test
2020.08.31 15:20:36.001625 [ 18342 ] {1f8ae482-a680-4468-8134-7738a656c6eb} <Debug> dw.test (SelectExecutor): Key condition: unknown
2020.08.31 15:20:36.001628 [ 18342 ] {1f8ae482-a680-4468-8134-7738a656c6eb} <Debug> dw.test (SelectExecutor): MinMax index condition: unknown
2020.08.31 15:20:36.001634 [ 18342 ] {1f8ae482-a680-4468-8134-7738a656c6eb} <Trace> dw.test (SelectExecutor): Not using primary index on part 20200831_20200831_0_0_0
2020.08.31 15:20:36.001638 [ 18342 ] {1f8ae482-a680-4468-8134-7738a656c6eb} <Debug> dw.test (SelectExecutor): Selected 1 parts by date, 1 parts by key, 1 marks by primary key, 1 marks to read from 1 ranges
2020.08.31 15:20:36.001656 [ 18342 ] {1f8ae482-a680-4468-8134-7738a656c6eb} <Trace> dw.test (SelectExecutor): Reading approx. 8192 rows with 1 streams
2020.08.31 15:21:11.053020 [ 18342 ] {8c9ea500-458d-4114-b9c8-53736345b63e} <Debug> executeQuery: (from [::1]:40918) SELECT DISTINCT partition FROM system.parts WHERE table = 'test'

[floxard]

2020.08.31 15:20:29.585740 [ 18329 ] {} <Debug> dw.test: There is no part 19700101_19700101_0_0_0 in ZooKeeper, it was only in filesystem

How to get this state, @den-crane ? Did you removed part 19700101_19700101_0_0_0 from zookeeper manually?

[den-crane]

2020.08.31 15:20:29.585740 [ 18329 ] {} <Debug> dw.test: There is no part 19700101_19700101_0_0_0 in ZooKeeper, it was only in filesystem

How to get this state, @den-crane ? Did you removed part 19700101_19700101_0_0_0 from zookeeper manually?

I did nothing except your SQL commands. Can you show your logs ?