[IMPALA-9022] test_query_profile_storage_load_time_filesystem is flaky

• Type: Bug
• Status: Resolved
• Priority: Critical
• Resolution: Fixed
• Affects Version/s: Impala 3.4.0
• Fix Version/s: Impala 3.4.0
• Component/s: Infrastructure
• Labels: broken-build flaky
• Target Version: Impala 3.4.0
• Epic Color: ghx-label-2
• Assignee: Yongzhi Chen
• Reporter: Tim Armstrong
• Created: 08/Oct/19 04:35
• Updated: 14/Feb/20 19:08
• Resolved: 14/Feb/20 19:08

Description

This test failed a precommit run of an unrelated change for me - https://jenkins.impala.io/job/ubuntu-16.04-dockerised-tests/1374/

query_test.test_observability.TestObservability.test_query_profile_storage_load_time_filesystem (from pytest)

Failing for the past 1 build (Since Failed#1374 )
Took 19 sec.
add description
Error Message
query_test/test_observability.py:682: in test_query_profile_storage_load_time_filesystem     cluster_properties) query_test/test_observability.py:714: in __check_query_profile_storage_load_time     assert storageLoadTime not in runtime_profile E   assert 'StorageLoad.Time' not in 'Query (id=f74d7af...eTime: 43.999ms\n' E     'StorageLoad.Time' is contained here: E       alogFetch.StorageLoad.Time: 0 E              - CatalogFetch.TableNames.Hits: 2 E              - CatalogFetch.TableNames.Requests: 2 E              - CatalogFetch.TableNames.Time: 0 E              - CatalogFetch.Tables.Misses: 1 E              - CatalogFetch.Tables.Requests: 1 E              - CatalogFetch.Tables.Time: 0 E         ImpalaServer: E     Detailed information truncated (569 more lines), use "-vv" to show
Stacktrace
query_test/test_observability.py:682: in test_query_profile_storage_load_time_filesystem
    cluster_properties)
query_test/test_observability.py:714: in __check_query_profile_storage_load_time
    assert storageLoadTime not in runtime_profile
E   assert 'StorageLoad.Time' not in 'Query (id=f74d7af...eTime: 43.999ms\n'
E     'StorageLoad.Time' is contained here:
E       alogFetch.StorageLoad.Time: 0
E              - CatalogFetch.TableNames.Hits: 2
E              - CatalogFetch.TableNames.Requests: 2
E              - CatalogFetch.TableNames.Time: 0
E              - CatalogFetch.Tables.Misses: 1
E              - CatalogFetch.Tables.Requests: 1
E              - CatalogFetch.Tables.Time: 0
E         ImpalaServer:
E     Detailed information truncated (569 more lines), use "-vv" to show
Standard Error
SET client_identifier=query_test/test_observability.py::TestObservability::()::test_query_profile_storage_load_time_filesystem;
SET sync_ddl=False;
-- executing against localhost:21000

DROP DATABASE IF EXISTS `test_query_profile_storage_load_time_filesystem_dd99cc8f` CASCADE;

-- 2019-10-08 01:48:34,019 INFO     MainThread: Started query 1441f1ad0a1eb1b4:8cb8cbb300000000
SET client_identifier=query_test/test_observability.py::TestObservability::()::test_query_profile_storage_load_time_filesystem;
SET sync_ddl=False;
-- executing against localhost:21000

CREATE DATABASE `test_query_profile_storage_load_time_filesystem_dd99cc8f`;

-- 2019-10-08 01:48:34,171 INFO     MainThread: Started query 7f438feb0213dffc:d2f40d7d00000000
-- 2019-10-08 01:48:34,177 INFO     MainThread: Created database "test_query_profile_storage_load_time_filesystem_dd99cc8f" for test ID "query_test/test_observability.py::TestObservability::()::test_query_profile_storage_load_time_filesystem"
-- executing against localhost:21000

create table test_query_profile_storage_load_time_filesystem_dd99cc8f.ld_prof(col1 int);

-- 2019-10-08 01:48:34,663 INFO     MainThread: Started query 2943e6995d9f404d:1a37591100000000
-- executing against localhost:21000

invalidate metadata test_query_profile_storage_load_time_filesystem_dd99cc8f.ld_prof;

-- 2019-10-08 01:48:34,700 INFO     MainThread: Started query fe480acd2fa0f4fe:31d01b6c00000000
-- executing against localhost:21000

select count (*) from test_query_profile_storage_load_time_filesystem_dd99cc8f.ld_prof;

-- 2019-10-08 01:48:34,768 INFO     MainThread: Started query c9484b86d1f78f56:4007f06000000000
-- executing against localhost:21000

select count (*) from test_query_profile_storage_load_time_filesystem_dd99cc8f.ld_prof;

-- 2019-10-08 01:48:47,686 INFO     MainThread: Started query f74d7af8de524d65:3d7135af00000000