01019_alter_materialized_view_consistent failed

[serxa]

Two types of failures (just one occurrence for each yet):

1. release, analyzer: https://s3.amazonaws.com/clickhouse-test-reports/49099/a67a84d4cce3ea8a24faa719af323d5f5a1630af/stateless_tests__release__analyzer_.html
2. debug: https://s3.amazonaws.com/clickhouse-test-reports/0/16eedb004f58a3c8507cf605f8e563df84dcf1e5/stateless_tests__debug__[1/3].html

[davenger]

This looks like a bug with analyzer. In the log from report https://s3.amazonaws.com/clickhouse-test-reports/49099/a67a84d4cce3ea8a24faa719af323d5f5a1630af/stateless_tests__release__analyzer_.html I see the following

2023.04.26 21:54:51.990655 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Debug> executeQuery: (from [::1]:56302) (comment: 01019_alter_materialized_view_consistent.sh) INSERT INTO TABLE src_b VALUES  (stage: Complete)
2023.04.26 21:54:51.994269 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Trace> ContextAccess (default): Access granted: INSERT(v) ON test_7l1tfwnh.src_b
2023.04.26 21:54:51.994474 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Trace> Planner: Query SELECT test_7l1tfwnh.src_a.v = 1 AS test, test_7l1tfwnh.src_a.v AS case FROM test_7l1tfwnh.src_a to stage Complete only analyze
2023.04.26 21:54:51.994506 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Trace> ContextAccess (default): Access granted: SELECT(v) ON test_7l1tfwnh.src_a
2023.04.26 21:54:51.994565 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Trace> Planner: Query SELECT test_7l1tfwnh.src_a.v = 1 AS test, test_7l1tfwnh.src_a.v AS case FROM test_7l1tfwnh.src_a from stage FetchColumns to stage Complete only analyze
2023.04.26 21:54:52.007051 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Trace> Planner: Query SELECT test_7l1tfwnh.src_b.v = 1 AS test, test_7l1tfwnh.src_b.v AS case FROM test_7l1tfwnh.src_b to stage Complete
2023.04.26 21:54:52.007091 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Trace> ContextAccess (default): Access granted: SELECT(v) ON test_7l1tfwnh.src_b
2023.04.26 21:54:52.007209 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Trace> Planner: Query SELECT test_7l1tfwnh.src_b.v = 1 AS test, test_7l1tfwnh.src_b.v AS case FROM test_7l1tfwnh.src_b from stage FetchColumns to stage Complete
2023.04.26 21:54:52.009698 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Trace> test_7l1tfwnh.`.inner_id.82fdb59c-171b-40a7-a8a5-8b25b4c25315` (d9b98bc7-d8db-4b8a-b917-978ccabc95db): Trying to reserve 1.00 MiB using storage policy from min volume index 0
2023.04.26 21:54:52.009731 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Trace> DiskLocal: Reserved 1.00 MiB on local disk `default`, having unreserved 92.79 GiB.
2023.04.26 21:54:52.010661 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Trace> MergedBlockOutputStream: filled checksums all_48_48_0 (state Temporary)
2023.04.26 21:54:52.010965 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Trace> test_7l1tfwnh.`.inner_id.82fdb59c-171b-40a7-a8a5-8b25b4c25315` (d9b98bc7-d8db-4b8a-b917-978ccabc95db): Renaming temporary part tmp_insert_all_48_48_0 to all_48_48_0 with tid (1, 1, 00000000-0000-0000-0000-000000000000).
2023.04.26 21:54:52.011034 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Test> test_7l1tfwnh.`.inner_id.82fdb59c-171b-40a7-a8a5-8b25b4c25315` (d9b98bc7-d8db-4b8a-b917-978ccabc95db): preparePartForCommit: inserting all_48_48_0 (state PreActive) into data_parts_indexes
2023.04.26 21:54:52.011117 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Trace> PushingToViews: Pushing (sequentially) from test_7l1tfwnh.src_b (8111ad4d-1887-4d25-87e5-2cb5e4dfc3d9) to test_7l1tfwnh.mv (82fdb59c-171b-40a7-a8a5-8b25b4c25315) took 3 ms.
2023.04.26 21:54:52.011269 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Debug> executeQuery: Read 2 rows, 16.00 B in 0.020639 sec., 96.90391976355443 rows/sec., 775.23 B/sec.
2023.04.26 21:54:52.011597 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Debug> MemoryTracker: Peak memory usage (for query): 5.12 MiB.
2023.04.26 21:54:52.011617 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Debug> TCPHandler: Processed in 0.021304908 sec.

Specifically the line

2023.04.26 21:54:52.007051 [ 1573 ] {db9d8e38-955b-479d-92c3-1b5663972296} <Trace> Planner: Query SELECT test_7l1tfwnh.src_b.v = 1 AS test, test_7l1tfwnh.src_b.v AS case FROM test_7l1tfwnh.src_b to stage Complete

But in the test the MV switches between 2 possible queries "... v = 1 ... FROM src_a" and "... v = 2 ... FROM src_b" so "src_b.v = 1" is not expected to happen

[davenger]

Indeed this test was recently added to the list of broken tests https://github.com/ClickHouse/ClickHouse/pull/49562/files#diff-a47b29f1f4296a577ae9384ae220ce01e5ce67bad0ee353ca5324f5f32e96b15R141

[serxa]

There is still another type of a failure.

[davenger]

There is still another type of a failure.

Yep, the second is just unlucky :) There were 12 ALTERs during that test run and all of them did the same "random" alter that didn't change the query. This problem was already fixed here by not using random and didn't reproduce since then: b577101#diff-2203c35e66acf20b821dcdee9d55bc9a29d7754ce94974aa8fa3526222ccbf3fR63

[vdimir]

#56246