[
https://issues.apache.org/jira/browse/IMPALA-15255?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18104011#comment-18104011
]
Arnab Karmakar commented on IMPALA-15255:
-----------------------------------------
Thanks for creating the ticket for the bug!
I found from the logs the root cause behind this. Calcite planner is slower for
this query than the normal planner and with a 1s TTL, the table expires
mid-query, gets invalidated, gets re-requested by the coordinator, and expires
again - all before test 1 reads the metric accounting for 2 invalidations.
The normal planner finishes {{{}SELECT count(*{}}}) quickly enough that test 1
only observes one invalidation.
Opened a CR for this -> [patch|https://gerrit.cloudera.org/#/c/24678/]. Looking
forward for reviews.
> TestAutomaticCatalogInvalidation.test_invalidation_metrics Failing
> ------------------------------------------------------------------
>
> Key: IMPALA-15255
> URL: https://issues.apache.org/jira/browse/IMPALA-15255
> Project: IMPALA
> Issue Type: Bug
> Reporter: Jason Fehr
> Assignee: Arnab Karmakar
> Priority: Major
> Labels: broken-build
>
> The TestAutomaticCatalogInvalidation.test_invalidation_metrics test is
> failing with the error “AssertionError: TTL invalidation metric should be 1
> (got 2)”
> Stack Trace:
> {noformat}
> custom_cluster/test_automatic_invalidation.py:262: in
> test_invalidation_metrics
> assert ttl_count_after_first == 1, ("TTL invalidation metric should be 1
> (got %d)"
> E AssertionError: TTL invalidation metric should be 1 (got 2)
> E assert 2 == 1
> E +2
> E -1
> baseline_memory_count = 0
> baseline_ttl_count = 0
> catalogd = <tests.common.impala_service.CatalogdService object at
> 0x7f304ca23c10>
> last_mem_ms = 'catalog.last-memory-pressure-invalidation-ms'
> last_mem_tables = 'catalog.last-memory-pressure-invalidated-tables'
> last_ttl_ms = 'catalog.last-ttl-invalidation-ms'
> last_ttl_tables = 'catalog.last-ttl-invalidated-tables'
> loaded_tables_metric = 'catalog.num-loaded-tables'
> max_wait_time = 18
> memory_metric = 'catalog.num-memory-pressure-invalidated-tables'
> self =
> <tests.custom_cluster.test_automatic_invalidation.TestAutomaticCatalogInvalidation
> object at 0x7f304ca20450>
> ttl_10s = 'catalog.ttl-invalidations-10s'
> ttl_1m = 'catalog.ttl-invalidations-01m'
> ttl_30m = 'catalog.ttl-invalidations-30m'
> ttl_5m = 'catalog.ttl-invalidations-05m'
> ttl_count_after_first = 2
> ttl_metric = 'catalog.num-ttl-invalidated-tables'
> {noformat}
> *StdErr:*
> {noformat}
> --------------------------------- Captured Err
> ---------------------------------
> -- 2026-08-09 20:02:57,900 INFO MainThread: Starting cluster with
> command:
> /data/jenkins/workspace/impala-asf-master-core-calcite/repos/Impala/bin/start-impala-cluster.py
> '--state_store_args=--statestore_update_frequency_ms=50
> --statestore_priority_update_frequency_ms=50
> --statestore_heartbeat_frequency_ms=50' --cluster_size=3 --num_coordinators=3
> --log_dir=/data/jenkins/workspace/impala-asf-master-core-calcite/repos/Impala/logs/custom_cluster_tests/TestAutomaticCatalogInvalidation/test_invalidation_metrics
> --log_level=1 '--impalad_args=--invalidate_tables_timeout_s=1 '
> '--catalogd_args=--invalidate_tables_timeout_s=1 '
> --impalad_args=--default_query_options=
> -- 2026-08-09 20:03:02,213 DEBUG MainThread: Found 3 impalad/1
> statestored/1 catalogd process(es)
> -- 2026-08-09 20:03:02,213 INFO MainThread: Getting metric:
> statestore.live-backends from
> impala-ec2-redhat86-m6i-4xlarge-ondemand-10a7.vpc.cloudera.com:25010
> -- 2026-08-09 20:03:02,216 INFO MainThread: Metric
> 'statestore.live-backends' has reached desired value: 4. total_wait: 0s
> -- 2026-08-09 20:03:02,216 DEBUG MainThread: Getting
> num_known_live_backends from
> impala-ec2-redhat86-m6i-4xlarge-ondemand-10a7.vpc.cloudera.com:25000
> -- 2026-08-09 20:03:02,219 INFO MainThread: num_known_live_backends has
> reached value: 3
> -- 2026-08-09 20:03:02,219 DEBUG MainThread: Getting
> num_known_live_backends from
> impala-ec2-redhat86-m6i-4xlarge-ondemand-10a7.vpc.cloudera.com:25001
> -- 2026-08-09 20:03:02,221 INFO MainThread: num_known_live_backends has
> reached value: 3
> -- 2026-08-09 20:03:02,221 DEBUG MainThread: Getting
> num_known_live_backends from
> impala-ec2-redhat86-m6i-4xlarge-ondemand-10a7.vpc.cloudera.com:25002
> -- 2026-08-09 20:03:02,224 INFO MainThread: num_known_live_backends has
> reached value: 3
> -- 2026-08-09 20:03:02,224 INFO MainThread: hs2:
> set
> client_identifier=custom_cluster/test_automatic_invalidation.py::TestAutomaticCatalogInvalidation::test_invalidation_metrics;
> -- 2026-08-09 20:03:02,224 INFO MainThread: hs2: connected to
> impala-ec2-redhat86-m6i-4xlarge-ondemand-10a7.vpc.cloudera.com:21050 with
> impyla hs2
> -- 2026-08-09 20:03:02,224 INFO MainThread: hs2-http:
> set
> client_identifier=custom_cluster/test_automatic_invalidation.py::TestAutomaticCatalogInvalidation::test_invalidation_metrics;
> -- 2026-08-09 20:03:02,225 INFO MainThread: hs2-http: connected to
> impala-ec2-redhat86-m6i-4xlarge-ondemand-10a7.vpc.cloudera.com:28000 with
> impyla hs2-http
> -- 2026-08-09 20:03:02,227 INFO MainThread: hs2: executing against Impala
> at impala-ec2-redhat86-m6i-4xlarge-ondemand-10a7.vpc.cloudera.com:21050.
> session: 8442cd78737a05d7:48543dd6268feba6 main_cursor: True user: None
> INVALIDATE METADATA;
> -- 2026-08-09 20:03:02,814 INFO MainThread:
> 064f4fc568a5ac79:304712f600000000: query started
> -- 2026-08-09 20:03:02,814 INFO MainThread:
> 064f4fc568a5ac79:304712f600000000: getting log for operation
> -- 2026-08-09 20:03:02,814 INFO MainThread:
> 064f4fc568a5ac79:304712f600000000: getting runtime profile operation
> -- 2026-08-09 20:03:02,815 INFO MainThread:
> 064f4fc568a5ac79:304712f600000000: closing query for operation
> -- 2026-08-09 20:03:02,815 INFO MainThread: Getting metric:
> catalog.num-loaded-tables from
> impala-ec2-redhat86-m6i-4xlarge-ondemand-10a7.vpc.cloudera.com:25020
> -- 2026-08-09 20:03:02,830 INFO MainThread: Metric
> 'catalog.num-loaded-tables' has reached desired value: 0. total_wait: 0s
> -- 2026-08-09 20:03:02,836 INFO MainThread: hs2: executing against Impala
> at impala-ec2-redhat86-m6i-4xlarge-ondemand-10a7.vpc.cloudera.com:21050.
> session: 8442cd78737a05d7:48543dd6268feba6 main_cursor: True user: None
> select count(*) from functional.alltypes;
> -- 2026-08-09 20:03:04,698 INFO MainThread:
> 0148b4e94f323012:64f1c52c00000000: query started
> -- 2026-08-09 20:03:04,700 INFO MainThread:
> 0148b4e94f323012:64f1c52c00000000: getting log for operation
> -- 2026-08-09 20:03:04,701 INFO MainThread:
> 0148b4e94f323012:64f1c52c00000000: getting runtime profile operation
> -- 2026-08-09 20:03:04,702 INFO MainThread:
> 0148b4e94f323012:64f1c52c00000000: closing query for operation
> -- 2026-08-09 20:03:04,702 INFO MainThread: Getting metric:
> catalog.num-loaded-tables from
> impala-ec2-redhat86-m6i-4xlarge-ondemand-10a7.vpc.cloudera.com:25020
> -- 2026-08-09 20:03:04,706 INFO MainThread: Metric
> 'catalog.num-loaded-tables' has reached desired value: 1. total_wait: 0s
> -- 2026-08-09 20:03:04,706 INFO MainThread: Getting metric:
> catalog.num-loaded-tables from
> impala-ec2-redhat86-m6i-4xlarge-ondemand-10a7.vpc.cloudera.com:25020
> -- 2026-08-09 20:03:04,709 INFO MainThread: Waiting for metric value
> 'catalog.num-loaded-tables'=0. Current value: 1. total_wait: 0s
> -- 2026-08-09 20:03:04,709 INFO MainThread: Sleeping 2s before next retry.
> -- 2026-08-09 20:03:06,709 INFO MainThread: Getting metric:
> catalog.num-loaded-tables from
> impala-ec2-redhat86-m6i-4xlarge-ondemand-10a7.vpc.cloudera.com:25020
> -- 2026-08-09 20:03:06,714 INFO MainThread: Metric
> 'catalog.num-loaded-tables' has reached desired value: 0. total_wait:
> 2.0031933784484863s
> -- 2026-08-09 20:03:06,714 INFO MainThread: Getting metric:
> catalog.num-ttl-invalidated-tables from
> impala-ec2-redhat86-m6i-4xlarge-ondemand-10a7.vpc.cloudera.com:25020
> -- 2026-08-09 20:03:06,716 INFO MainThread: Metric
> 'catalog.num-ttl-invalidated-tables' has reached desired value: 2.
> total_wait: 0s
> {noformat}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
