Jason Fehr created IMPALA-15255:
-----------------------------------

             Summary: 
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


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)

Reply via email to