Details
-
Bug
-
Status: Resolved
-
Major
-
Resolution: Cannot Reproduce
-
Impala 2.8.0
-
None
Description
Tim, I picked you since you touched test_exchange_delays.py last. Feel free to re-assign.
Failed build:
http://sandbox.jenkins.cloudera.com/view/Impala/view/Evergreen-asf-master/job/impala-asf-master-core-isilon/65/
There are two issues:
- It looks like the test query ran successfully, but an exception was expected.
- There is an issue impala_test_suite.py that does not properly report the reason for the test failure (expected exception, but encountered success)
Relevant snipped from Jenkins console:
03:20:49.019 custom_cluster/test_admission_controller.py ...... 03:20:49.019 custom_cluster/test_alloc_fail.py .. 03:20:49.019 custom_cluster/test_breakpad.py sssssss 03:20:49.019 custom_cluster/test_client_ssl.py ..x 03:20:49.019 custom_cluster/test_delegation.py ... 03:20:49.019 custom_cluster/test_exchange_delays.py FF 03:20:49.019 custom_cluster/test_hdfs_fd_caching.py . 03:20:49.019 custom_cluster/test_hive_parquet_timestamp_conversion.py .. 03:20:49.019 custom_cluster/test_insert_behaviour.py .. 03:20:49.019 custom_cluster/test_kudu_not_available.py . 03:20:49.019 custom_cluster/test_legacy_joins_aggs.py . 03:20:49.019 custom_cluster/test_parquet_max_page_header.py s 03:20:49.019 custom_cluster/test_permanent_udfs.py .ss. 03:20:49.019 custom_cluster/test_query_expiration.py ... 03:20:49.019 custom_cluster/test_redaction.py .... 03:20:49.019 custom_cluster/test_rpc_timeout.py sssssss 03:20:49.019 custom_cluster/test_s3a_access.py ss 03:20:49.019 custom_cluster/test_scratch_disk.py .... 03:20:49.019 custom_cluster/test_seq_file_filtering.py . 03:20:49.019 custom_cluster/test_session_expiration.py . 03:20:49.019 custom_cluster/test_spilling.py sss. 03:20:49.019 authorization/test_authorization.py .. 03:20:49.019 authorization/test_grant_revoke.py . 03:20:49.019 ../../Impala-auxiliary-tests/tests/aux_custom_cluster_tests/test_ldap.py xxxxx 03:20:49.019 03:20:49.019 =================================== FAILURES =================================== 03:20:49.019 TestExchangeDelays.test_exchange_small_delay[exec_option: {'disable_codegen': False, 'abort_on_error': 1, 'exec_single_node_rows_threshold': 0, 'batch_size': 0, 'num_nodes': 0} | table_format: text/none] 03:20:49.019 03:20:49.019 self = <test_exchange_delays.TestExchangeDelays object at 0x43b2110> 03:20:49.019 vector = <tests.common.test_vector.TestVector object at 0x4c36750> 03:20:49.019 03:20:49.019 @pytest.mark.execute_serially 03:20:49.019 @CustomClusterTestSuite.with_args("--stress_datastream_recvr_delay_ms=10000" 03:20:49.019 " --datastream_sender_timeout_ms=5000") 03:20:49.019 def test_exchange_small_delay(self, vector): 03:20:49.019 """Test delays in registering data stream receivers where the first one or two 03:20:49.019 batches will time out before the receiver registers, but subsequent batches will 03:20:49.019 arrive after the receiver registers. Before IMPALA-2987, this scenario resulted in 03:20:49.019 incorrect results. 03:20:49.019 """ 03:20:49.019 > self.run_test_case('QueryTest/exchange-delays', vector) 03:20:49.019 03:20:49.019 custom_cluster/test_exchange_delays.py:39: 03:20:49.019 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 03:20:49.019 03:20:49.019 self = <test_exchange_delays.TestExchangeDelays object at 0x43b2110> 03:20:49.019 test_file_name = 'QueryTest/exchange-delays' 03:20:49.019 vector = <tests.common.test_vector.TestVector object at 0x4c36750> 03:20:49.019 use_db = None, multiple_impalad = False, encoding = None 03:20:49.019 wait_secs_between_stmts = None 03:20:49.019 03:20:49.019 def run_test_case(self, test_file_name, vector, use_db=None, multiple_impalad=False, 03:20:49.019 encoding=None, wait_secs_between_stmts=None): 03:20:49.019 """ 03:20:49.019 Runs the queries in the specified test based on the vector values 03:20:49.019 03:20:49.019 Runs the query using targeting the file format/compression specified in the test 03:20:49.019 vector and the exec options specified in the test vector. If multiple_impalad=True 03:20:49.019 a connection to a random impalad will be chosen to execute each test section. 03:20:49.019 Otherwise, the default impalad client will be used. 03:20:49.019 Additionally, the encoding for all test data can be specified using the 'encoding' 03:20:49.019 parameter. This is useful when data is ingested in a different encoding (ex. 03:20:49.019 latin). If not set, the default system encoding will be used. 03:20:49.019 """ 03:20:49.019 table_format_info = vector.get_value('table_format') 03:20:49.019 exec_options = vector.get_value('exec_option') 03:20:49.019 03:20:49.019 # Resolve the current user's primary group name. 03:20:49.019 group_id = pwd.getpwnam(getuser()).pw_gid 03:20:49.019 group_name = grp.getgrgid(group_id).gr_name 03:20:49.019 03:20:49.019 target_impalad_clients = list() 03:20:49.019 if multiple_impalad: 03:20:49.019 target_impalad_clients =\ 03:20:49.019 map(ImpalaTestSuite.create_impala_client, IMPALAD_HOST_PORT_LIST) 03:20:49.019 else: 03:20:49.019 target_impalad_clients = [self.client] 03:20:49.019 03:20:49.019 # Change the database to reflect the file_format, compression codec etc, or the 03:20:49.019 # user specified database for all targeted impalad. 03:20:49.019 for impalad_client in target_impalad_clients: 03:20:49.019 ImpalaTestSuite.change_database(impalad_client, 03:20:49.019 table_format_info, use_db, pytest.config.option.scale_factor) 03:20:49.019 impalad_client.set_configuration(exec_options) 03:20:49.019 03:20:49.019 sections = self.load_query_test_file(self.get_workload(), test_file_name, 03:20:49.019 encoding=encoding) 03:20:49.019 for test_section in sections: 03:20:49.019 if 'SHELL' in test_section: 03:20:49.019 assert len(test_section) == 1, \ 03:20:49.019 "SHELL test sections can't contain other sections" 03:20:49.019 cmd = test_section['SHELL']\ 03:20:49.019 .replace('$FILESYSTEM_PREFIX', FILESYSTEM_PREFIX)\ 03:20:49.019 .replace('$IMPALA_HOME', IMPALA_HOME) 03:20:49.019 if use_db: cmd = cmd.replace('$DATABASE', use_db) 03:20:49.019 LOG.info("Shell command: " + cmd) 03:20:49.019 check_call(cmd, shell=True) 03:20:49.019 continue 03:20:49.019 03:20:49.019 if 'QUERY' not in test_section: 03:20:49.019 assert 0, 'Error in test file %s. Test cases require a -- QUERY section.\n%s' %\ 03:20:49.019 (test_file_name, pprint.pformat(test_section)) 03:20:49.019 03:20:49.019 if 'SETUP' in test_section: 03:20:49.019 self.execute_test_case_setup(test_section['SETUP'], table_format_info) 03:20:49.019 03:20:49.019 # TODO: support running query tests against different scale factors 03:20:49.019 query = QueryTestSectionReader.build_query(test_section['QUERY'] 03:20:49.019 .replace('$GROUP_NAME', group_name) 03:20:49.019 .replace('$IMPALA_HOME', IMPALA_HOME) 03:20:49.019 .replace('$FILESYSTEM_PREFIX', FILESYSTEM_PREFIX) 03:20:49.019 .replace('$SECONDARY_FILESYSTEM', os.getenv("SECONDARY_FILESYSTEM") or str())) 03:20:49.019 if use_db: query = query.replace('$DATABASE', use_db) 03:20:49.019 03:20:49.019 if 'QUERY_NAME' in test_section: 03:20:49.019 LOG.info('Query Name: \n%s\n' % test_section['QUERY_NAME']) 03:20:49.019 03:20:49.019 # Support running multiple queries within the same test section, only verifying the 03:20:49.019 # result of the final query. The main use case is to allow for 'USE database' 03:20:49.019 # statements before a query executes, but it is not limited to that. 03:20:49.019 # TODO: consider supporting result verification of all queries in the future 03:20:49.019 result = None 03:20:49.019 target_impalad_client = choice(target_impalad_clients) 03:20:49.019 query_options_changed = [] 03:20:49.019 try: 03:20:49.019 user = None 03:20:49.019 if 'USER' in test_section: 03:20:49.019 # Create a new client so the session will use the new username. 03:20:49.019 user = test_section['USER'].strip() 03:20:49.019 target_impalad_client = self.create_impala_client() 03:20:49.019 for query in query.split(';'): 03:20:49.019 set_pattern_match = SET_PATTERN.match(query) 03:20:49.019 if set_pattern_match != None: 03:20:49.019 query_options_changed.append(set_pattern_match.groups()[0]) 03:20:49.019 result = self.__execute_query(target_impalad_client, query, user=user) 03:20:49.019 if wait_secs_between_stmts: 03:20:49.019 time.sleep(wait_secs_between_stmts) 03:20:49.019 except Exception as e: 03:20:49.019 if 'CATCH' in test_section: 03:20:49.019 self.__verify_exceptions(test_section['CATCH'], str(e), use_db) 03:20:49.019 continue 03:20:49.019 raise 03:20:49.019 finally: 03:20:49.019 if len(query_options_changed) > 0: 03:20:49.019 self.__restore_query_options(query_options_changed) 03:20:49.019 03:20:49.019 if 'CATCH' in test_section: 03:20:49.019 > assert test_section['CATCH'].strip() == '' 03:20:49.019 E AttributeError: 'list' object has no attribute 'strip' 03:20:49.019 03:20:49.019 common/impala_test_suite.py:333: AttributeError 03:20:49.019 ---------------------------- Captured stdout setup ----------------------------- 03:20:49.019 Starting State Store logging to /data/jenkins/workspace/impala-umbrella-build-and-test-isilon/repos/Impala/logs/custom_cluster_tests/statestored.INFO 03:20:49.019 Starting Catalog Service logging to /data/jenkins/workspace/impala-umbrella-build-and-test-isilon/repos/Impala/logs/custom_cluster_tests/catalogd.INFO 03:20:49.019 Starting Impala Daemon logging to /data/jenkins/workspace/impala-umbrella-build-and-test-isilon/repos/Impala/logs/custom_cluster_tests/impalad.INFO 03:20:49.019 Starting Impala Daemon logging to /data/jenkins/workspace/impala-umbrella-build-and-test-isilon/repos/Impala/logs/custom_cluster_tests/impalad_node1.INFO 03:20:49.019 Starting Impala Daemon logging to /data/jenkins/workspace/impala-umbrella-build-and-test-isilon/repos/Impala/logs/custom_cluster_tests/impalad_node2.INFO 03:20:49.019 Waiting for Catalog... Status: 53 DBs / 1070 tables (ready=True) 03:20:49.019 Waiting for Catalog... Status: 53 DBs / 1070 tables (ready=True) 03:20:49.019 Waiting for Catalog... Status: 53 DBs / 1070 tables (ready=True) 03:20:49.019 Impala Cluster Running with 3 nodes. 03:20:49.019 ---------------------------- Captured stderr setup ----------------------------- 03:20:49.019 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es) 03:20:49.019 MainThread: Getting num_known_live_backends from impala-boost-static-burst-slave-1fbd.vpc.cloudera.com:25000 03:20:49.019 MainThread: Waiting for num_known_live_backends=3. Current value: 0 03:20:49.019 MainThread: Getting num_known_live_backends from impala-boost-static-burst-slave-1fbd.vpc.cloudera.com:25000 03:20:49.019 MainThread: Waiting for num_known_live_backends=3. Current value: 0 03:20:49.019 MainThread: Getting num_known_live_backends from impala-boost-static-burst-slave-1fbd.vpc.cloudera.com:25000 03:20:49.019 MainThread: Waiting for num_known_live_backends=3. Current value: 0 03:20:49.019 MainThread: Getting num_known_live_backends from impala-boost-static-burst-slave-1fbd.vpc.cloudera.com:25000 03:20:49.019 MainThread: Waiting for num_known_live_backends=3. Current value: 2 03:20:49.019 MainThread: Getting num_known_live_backends from impala-boost-static-burst-slave-1fbd.vpc.cloudera.com:25000 03:20:49.019 MainThread: Waiting for num_known_live_backends=3. Current value: 2 03:20:49.019 MainThread: Getting num_known_live_backends from impala-boost-static-burst-slave-1fbd.vpc.cloudera.com:25000 03:20:49.019 MainThread: num_known_live_backends has reached value: 3 03:20:49.019 MainThread: Getting num_known_live_backends from impala-boost-static-burst-slave-1fbd.vpc.cloudera.com:25001 03:20:49.019 MainThread: num_known_live_backends has reached value: 3 03:20:49.019 MainThread: Getting num_known_live_backends from impala-boost-static-burst-slave-1fbd.vpc.cloudera.com:25002 03:20:49.019 MainThread: num_known_live_backends has reached value: 3 03:20:49.019 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es) 03:20:49.019 MainThread: Getting metric: statestore.live-backends from impala-boost-static-burst-slave-1fbd.vpc.cloudera.com:25010 03:20:49.019 MainThread: Metric 'statestore.live-backends' has reach desired value: 4 03:20:49.019 MainThread: Getting num_known_live_backends from impala-boost-static-burst-slave-1fbd.vpc.cloudera.com:25000 03:20:49.019 MainThread: num_known_live_backends has reached value: 3 03:20:49.019 MainThread: Getting num_known_live_backends from impala-boost-static-burst-slave-1fbd.vpc.cloudera.com:25001 03:20:49.019 MainThread: num_known_live_backends has reached value: 3 03:20:49.019 MainThread: Getting num_known_live_backends from impala-boost-static-burst-slave-1fbd.vpc.cloudera.com:25002 03:20:49.019 MainThread: num_known_live_backends has reached value: 3 03:20:49.019 -- connecting to: localhost:21000 03:20:49.019 ----------------------------- Captured stderr call ----------------------------- 03:20:49.019 -- executing against localhost:21000 03:20:49.019 use functional; 03:20:49.019 03:20:49.019 SET disable_codegen=False; 03:20:49.019 SET abort_on_error=1; 03:20:49.019 SET exec_single_node_rows_threshold=0; 03:20:49.019 SET batch_size=0; 03:20:49.019 SET num_nodes=0; 03:20:49.019 -- executing against localhost:21000 03:20:49.019 select count(*) 03:20:49.019 from tpch.lineitem 03:20:49.019 inner join tpch.orders on l_orderkey = o_orderkey; 03:20:49.019 03:20:49.019 TestExchangeDelays.test_exchange_large_delay[exec_option: {'disable_codegen': False, 'abort_on_error': 1, 'exec_single_node_rows_threshold': 0, 'batch_size': 0, 'num_nodes': 0} | table_format: text/none] 03:20:49.019 03:20:49.019 self = <test_exchange_delays.TestExchangeDelays object at 0x4285910> 03:20:49.019 vector = <tests.common.test_vector.TestVector object at 0x4c36ad0> 03:20:49.019 03:20:49.019 @pytest.mark.execute_serially 03:20:49.019 @CustomClusterTestSuite.with_args("--stress_datastream_recvr_delay_ms=10000" 03:20:49.019 " --datastream_sender_timeout_ms=1") 03:20:49.019 def test_exchange_large_delay(self, vector): 03:20:49.019 """Test delays in registering data stream receivers where all of the batches sent 03:20:49.019 will time out before the receiver registers. Before IMPALA-2987, this scenario 03:20:49.019 resulted in the query hanging. 03:20:49.019 """ 03:20:49.019 > self.run_test_case('QueryTest/exchange-delays', vector) 03:20:49.019 03:20:49.019 custom_cluster/test_exchange_delays.py:49: 03:20:49.019 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 03:20:49.019 03:20:49.019 self = <test_exchange_delays.TestExchangeDelays object at 0x4285910> 03:20:49.019 test_file_name = 'QueryTest/exchange-delays' 03:20:49.019 vector = <tests.common.test_vector.TestVector object at 0x4c36ad0> 03:20:49.019 use_db = None, multiple_impalad = False, encoding = None 03:20:49.019 wait_secs_between_stmts = None 03:20:49.019 03:20:49.019 def run_test_case(self, test_file_name, vector, use_db=None, multiple_impalad=False, 03:20:49.019 encoding=None, wait_secs_between_stmts=None): 03:20:49.019 """ 03:20:49.019 Runs the queries in the specified test based on the vector values 03:20:49.019 03:20:49.019 Runs the query using targeting the file format/compression specified in the test 03:20:49.019 vector and the exec options specified in the test vector. If multiple_impalad=True 03:20:49.019 a connection to a random impalad will be chosen to execute each test section. 03:20:49.019 Otherwise, the default impalad client will be used. 03:20:49.019 Additionally, the encoding for all test data can be specified using the 'encoding' 03:20:49.019 parameter. This is useful when data is ingested in a different encoding (ex. 03:20:49.019 latin). If not set, the default system encoding will be used. 03:20:49.019 """ 03:20:49.019 table_format_info = vector.get_value('table_format') 03:20:49.019 exec_options = vector.get_value('exec_option') 03:20:49.019 03:20:49.019 # Resolve the current user's primary group name. 03:20:49.019 group_id = pwd.getpwnam(getuser()).pw_gid 03:20:49.019 group_name = grp.getgrgid(group_id).gr_name 03:20:49.019 03:20:49.019 target_impalad_clients = list() 03:20:49.019 if multiple_impalad: 03:20:49.019 target_impalad_clients =\ 03:20:49.019 map(ImpalaTestSuite.create_impala_client, IMPALAD_HOST_PORT_LIST) 03:20:49.019 else: 03:20:49.019 target_impalad_clients = [self.client] 03:20:49.019 03:20:49.019 # Change the database to reflect the file_format, compression codec etc, or the 03:20:49.019 # user specified database for all targeted impalad. 03:20:49.019 for impalad_client in target_impalad_clients: 03:20:49.019 ImpalaTestSuite.change_database(impalad_client, 03:20:49.019 table_format_info, use_db, pytest.config.option.scale_factor) 03:20:49.019 impalad_client.set_configuration(exec_options) 03:20:49.019 03:20:49.019 sections = self.load_query_test_file(self.get_workload(), test_file_name, 03:20:49.019 encoding=encoding) 03:20:49.019 for test_section in sections: 03:20:49.019 if 'SHELL' in test_section: 03:20:49.019 assert len(test_section) == 1, \ 03:20:49.019 "SHELL test sections can't contain other sections" 03:20:49.019 cmd = test_section['SHELL']\ 03:20:49.019 .replace('$FILESYSTEM_PREFIX', FILESYSTEM_PREFIX)\ 03:20:49.019 .replace('$IMPALA_HOME', IMPALA_HOME) 03:20:49.019 if use_db: cmd = cmd.replace('$DATABASE', use_db) 03:20:49.019 LOG.info("Shell command: " + cmd) 03:20:49.019 check_call(cmd, shell=True) 03:20:49.019 continue 03:20:49.019 03:20:49.019 if 'QUERY' not in test_section: 03:20:49.019 assert 0, 'Error in test file %s. Test cases require a -- QUERY section.\n%s' %\ 03:20:49.019 (test_file_name, pprint.pformat(test_section)) 03:20:49.019 03:20:49.019 if 'SETUP' in test_section: 03:20:49.019 self.execute_test_case_setup(test_section['SETUP'], table_format_info) 03:20:49.019 03:20:49.019 # TODO: support running query tests against different scale factors 03:20:49.019 query = QueryTestSectionReader.build_query(test_section['QUERY'] 03:20:49.019 .replace('$GROUP_NAME', group_name) 03:20:49.019 .replace('$IMPALA_HOME', IMPALA_HOME) 03:20:49.019 .replace('$FILESYSTEM_PREFIX', FILESYSTEM_PREFIX) 03:20:49.019 .replace('$SECONDARY_FILESYSTEM', os.getenv("SECONDARY_FILESYSTEM") or str())) 03:20:49.019 if use_db: query = query.replace('$DATABASE', use_db) 03:20:49.019 03:20:49.019 if 'QUERY_NAME' in test_section: 03:20:49.019 LOG.info('Query Name: \n%s\n' % test_section['QUERY_NAME']) 03:20:49.019 03:20:49.019 # Support running multiple queries within the same test section, only verifying the 03:20:49.019 # result of the final query. The main use case is to allow for 'USE database' 03:20:49.019 # statements before a query executes, but it is not limited to that. 03:20:49.019 # TODO: consider supporting result verification of all queries in the future 03:20:49.019 result = None 03:20:49.019 target_impalad_client = choice(target_impalad_clients) 03:20:49.019 query_options_changed = [] 03:20:49.019 try: 03:20:49.019 user = None 03:20:49.019 if 'USER' in test_section: 03:20:49.019 # Create a new client so the session will use the new username. 03:20:49.019 user = test_section['USER'].strip() 03:20:49.019 target_impalad_client = self.create_impala_client() 03:20:49.019 for query in query.split(';'): 03:20:49.019 set_pattern_match = SET_PATTERN.match(query) 03:20:49.019 if set_pattern_match != None: 03:20:49.019 query_options_changed.append(set_pattern_match.groups()[0]) 03:20:49.019 result = self.__execute_query(target_impalad_client, query, user=user) 03:20:49.019 if wait_secs_between_stmts: 03:20:49.019 time.sleep(wait_secs_between_stmts) 03:20:49.019 except Exception as e: 03:20:49.019 if 'CATCH' in test_section: 03:20:49.019 self.__verify_exceptions(test_section['CATCH'], str(e), use_db) 03:20:49.019 continue 03:20:49.019 raise 03:20:49.019 finally: 03:20:49.019 if len(query_options_changed) > 0: 03:20:49.019 self.__restore_query_options(query_options_changed) 03:20:49.019 03:20:49.019 if 'CATCH' in test_section: 03:20:49.019 > assert test_section['CATCH'].strip() == '' 03:20:49.019 E AttributeError: 'list' object has no attribute 'strip' 03:20:49.019 03:20:49.019 common/impala_test_suite.py:333: AttributeError 03:20:49.019 ---------------------------- Captured stdout setup -----------------------------