You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues-all@impala.apache.org by "Quanlong Huang (Jira)" <ji...@apache.org> on 2023/06/02 02:56:00 UTC

[jira] [Assigned] (IMPALA-12180) TestShellInteractive.test_query_retries_show_profiles failed by timeout

     [ https://issues.apache.org/jira/browse/IMPALA-12180?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Quanlong Huang reassigned IMPALA-12180:
---------------------------------------

    Assignee: Quanlong Huang

> TestShellInteractive.test_query_retries_show_profiles failed by timeout
> -----------------------------------------------------------------------
>
>                 Key: IMPALA-12180
>                 URL: https://issues.apache.org/jira/browse/IMPALA-12180
>             Project: IMPALA
>          Issue Type: Bug
>            Reporter: Quanlong Huang
>            Assignee: Quanlong Huang
>            Priority: Critical
>
> Saw this failure on a S3 build:
> {code:python}
> custom_cluster/test_shell_interactive.py:134: in test_query_retries_show_profiles
>     proc.expect("3650", timeout=300)
> ../infra/python/env-gcc10.4.0/lib/python2.7/site-packages/pexpect/__init__.py:1451: in expect
>     timeout, searchwindowsize)
> ../infra/python/env-gcc10.4.0/lib/python2.7/site-packages/pexpect/__init__.py:1466: in expect_list
>     timeout, searchwindowsize)
> ../infra/python/env-gcc10.4.0/lib/python2.7/site-packages/pexpect/__init__.py:1568: in expect_loop
>     raise TIMEOUT(str(err) + '\n' + str(self))
> E   TIMEOUT: Timeout exceeded.
> E   <pexpect.spawn object at 0x7fecafda9b10>
> E   version: 3.3
> E   command: /data/jenkins/workspace/impala-cdwh-2023.0.14.2-core-s3/repos/Impala/shell/build/impala-shell-4.3.0-SNAPSHOT/impala-shell
> E   args: ['/data/jenkins/workspace/impala-cdwh-2023.0.14.2-core-s3/repos/Impala/shell/build/impala-shell-4.3.0-SNAPSHOT/impala-shell', '--protocol=hs2', '-ilocalhost:21050', '-p']
> E   searcher: <pexpect.searcher_re object at 0x7fecafd97c10>
> E   buffer (last 100 chars): 'loudera.com:25000/query_plan?query_id=604827b00c33643e:8a9d6c2900000000\r\n[localhost:21050] default> '
> E   before (last 100 chars): 'loudera.com:25000/query_plan?query_id=604827b00c33643e:8a9d6c2900000000\r\n[localhost:21050] default> '
> E   after: <class 'pexpect.TIMEOUT'>
> E   match: None
> E   match_index: None
> E   exitstatus: None
> E   flag_eof: False
> E   pid: 464
> E   child_fd: 25
> E   closed: False
> E   timeout: 30
> E   delimiter: <class 'pexpect.EOF'>
> E   logfile: None
> E   logfile_read: None
> E   logfile_send: None
> E   maxread: 2000
> E   ignorecase: False
> E   searchwindowsize: None
> E   delaybeforesend: 0.05
> E   delayafterclose: 0.1
> E   delayafterterminate: 0.1 {code}
> Standard Output
> {code}
> {u'stmt_type': u'QUERY', u'resource_pool': u'default-pool', u'waiting': False, u'last_event': u'Query submitted', u'start_time': u'2023-05-27 07:32:12.059963000', u'rows_fetched': 0, u'stmt': u'select count(*) from functional.alltypes where bool_col = sleep(50)', u'executing': True, u'state': u'CREATED', u'query_id': u'9944926c9306051e:ed61c07600000000', u'end_time': u'1969-12-31 16:00:00.000000000', u'duration': u'904.679ms', u'progress': u'N/A', u'effective_user': u'jenkins', u'default_db': u'default', u'waiting_time': u''}
> {u'stmt_type': u'QUERY', u'resource_pool': u'default-pool', u'waiting': False, u'last_event': u'All 3 execution backends (4 fragment instances) started', u'start_time': u'2023-05-27 07:32:12.059963000', u'rows_fetched': 0, u'stmt': u'select count(*) from functional.alltypes where bool_col = sleep(50)', u'executing': True, u'state': u'RUNNING', u'query_id': u'9944926c9306051e:ed61c07600000000', u'end_time': u'1969-12-31 16:00:00.000000000', u'duration': u'1s907ms', u'progress': u'0 / 24 (   0%)', u'effective_user': u'jenkins', u'default_db': u'default', u'waiting_time': u'926ms'} {code}
> Standard Error
> {code}
> -- 2023-05-27 07:32:02,741 INFO     MainThread: Starting cluster with command: /data/jenkins/workspace/impala-cdwh-2023.0.14.2-core-s3/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-cdwh-2023.0.14.2-core-s3/repos/Impala/logs/custom_cluster_tests --log_level=1 --impalad_args=--default_query_options=
> 07:32:03 MainThread: Found 0 impalad/0 statestored/0 catalogd process(es)
> 07:32:03 MainThread: Starting State Store logging to /data/jenkins/workspace/impala-cdwh-2023.0.14.2-core-s3/repos/Impala/logs/custom_cluster_tests/statestored.INFO
> 07:32:03 MainThread: Starting Catalog Service logging to /data/jenkins/workspace/impala-cdwh-2023.0.14.2-core-s3/repos/Impala/logs/custom_cluster_tests/catalogd.INFO
> 07:32:03 MainThread: Starting Impala Daemon logging to /data/jenkins/workspace/impala-cdwh-2023.0.14.2-core-s3/repos/Impala/logs/custom_cluster_tests/impalad.INFO
> 07:32:03 MainThread: Starting Impala Daemon logging to /data/jenkins/workspace/impala-cdwh-2023.0.14.2-core-s3/repos/Impala/logs/custom_cluster_tests/impalad_node1.INFO
> 07:32:03 MainThread: Starting Impala Daemon logging to /data/jenkins/workspace/impala-cdwh-2023.0.14.2-core-s3/repos/Impala/logs/custom_cluster_tests/impalad_node2.INFO
> 07:32:06 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
> 07:32:06 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
> 07:32:06 MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-13c8.vpc.cloudera.com:25000
> 07:32:06 MainThread: Debug webpage not yet available: HTTPConnectionPool(host='impala-ec2-centos79-m6i-4xlarge-ondemand-13c8.vpc.cloudera.com', port=25000): Max retries exceeded with url: /backends?json (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f52cb60bc90>: Failed to establish a new connection: [Errno 111] Connection refused',))
> 07:32:08 MainThread: Debug webpage did not become available in expected time.
> 07:32:08 MainThread: Waiting for num_known_live_backends=3. Current value: None
> 07:32:09 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
> 07:32:09 MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-13c8.vpc.cloudera.com:25000
> 07:32:09 MainThread: num_known_live_backends has reached value: 3
> 07:32:09 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
> 07:32:09 MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-13c8.vpc.cloudera.com:25001
> 07:32:09 MainThread: num_known_live_backends has reached value: 3
> 07:32:10 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
> 07:32:10 MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-13c8.vpc.cloudera.com:25002
> 07:32:10 MainThread: num_known_live_backends has reached value: 3
> 07:32:10 MainThread: Impala Cluster Running with 3 nodes (3 coordinators, 3 executors).
> -- 2023-05-27 07:32:11,013 DEBUG    MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
> -- 2023-05-27 07:32:11,013 INFO     MainThread: Getting metric: statestore.live-backends from impala-ec2-centos79-m6i-4xlarge-ondemand-13c8.vpc.cloudera.com:25010
> -- 2023-05-27 07:32:11,015 INFO     MainThread: Metric 'statestore.live-backends' has reached desired value: 4
> -- 2023-05-27 07:32:11,015 DEBUG    MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-13c8.vpc.cloudera.com:25000
> -- 2023-05-27 07:32:11,017 INFO     MainThread: num_known_live_backends has reached value: 3
> -- 2023-05-27 07:32:11,017 DEBUG    MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-13c8.vpc.cloudera.com:25001
> -- 2023-05-27 07:32:11,018 INFO     MainThread: num_known_live_backends has reached value: 3
> -- 2023-05-27 07:32:11,018 DEBUG    MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-13c8.vpc.cloudera.com:25002
> -- 2023-05-27 07:32:11,020 INFO     MainThread: num_known_live_backends has reached value: 3
> SET client_identifier=custom_cluster/test_shell_interactive.py::TestShellInteractive::()::test_query_retries_show_profiles;
> -- connecting to: localhost:21000
> -- 2023-05-27 07:32:11,020 INFO     MainThread: Could not connect to ('::1', 21000, 0, 0)
> Traceback (most recent call last):
>   File "/data/jenkins/workspace/impala-cdwh-2023.0.14.2-core-s3/Impala-Toolchain/toolchain-packages-gcc10.4.0/thrift-0.16.0-p3/python/lib/python2.7/site-packages/thrift/transport/TSocket.py", line 137, in open
>     handle.connect(sockaddr)
>   File "/data/jenkins/workspace/impala-cdwh-2023.0.14.2-core-s3/Impala-Toolchain/toolchain-packages-gcc10.4.0/python-2.7.16/lib/python2.7/socket.py", line 228, in meth
>     return getattr(self._sock,name)(*args)
> error: [Errno 111] Connection refused
> -- connecting to localhost:21050 with impyla
> -- 2023-05-27 07:32:11,021 INFO     MainThread: Could not connect to ('::1', 21050, 0, 0)
> Traceback (most recent call last):
>   File "/data/jenkins/workspace/impala-cdwh-2023.0.14.2-core-s3/Impala-Toolchain/toolchain-packages-gcc10.4.0/thrift-0.16.0-p3/python/lib/python2.7/site-packages/thrift/transport/TSocket.py", line 137, in open
>     handle.connect(sockaddr)
>   File "/data/jenkins/workspace/impala-cdwh-2023.0.14.2-core-s3/Impala-Toolchain/toolchain-packages-gcc10.4.0/python-2.7.16/lib/python2.7/socket.py", line 228, in meth
>     return getattr(self._sock,name)(*args)
> error: [Errno 111] Connection refused
> -- 2023-05-27 07:32:11,169 INFO     MainThread: Closing active operation
> -- connecting to localhost:28000 with impyla
> -- 2023-05-27 07:32:11,185 INFO     MainThread: Closing active operation
> -- connecting to localhost:11050 with impyla
> -- 2023-05-27 07:32:11,957 INFO     MainThread: Getting num_in_flight_queries from localhost:25000
> -- 2023-05-27 07:32:12,961 INFO     MainThread: Getting num_in_flight_queries from localhost:25000
> -- 2023-05-27 07:32:13,992 INFO     MainThread: Killing <ImpaladProcess PID: 31089 (/data/jenkins/workspace/impala-cdwh-2023.0.14.2-core-s3/repos/Impala/be/build/latest/service/impalad -disconnected_session_timeout 21600 -kudu_client_rpc_timeout_ms 0 -kudu_master_hosts localhost -mem_limit=12884901888 -logbufsecs=5 -v=1 -max_log_files=0 -log_filename=impalad_node1 -log_dir=/data/jenkins/workspace/impala-cdwh-2023.0.14.2-core-s3/repos/Impala/logs/custom_cluster_tests -beeswax_port=21001 -hs2_port=21051 -hs2_http_port=28001 -krpc_port=27001 -state_store_subscriber_port=23001 -webserver_port=25001 --default_query_options= -geospatial_library=HIVE_ESRI)> with signal 9 {code}



--
This message was sent by Atlassian Jira
(v8.20.10#820010)

---------------------------------------------------------------------
To unsubscribe, e-mail: issues-all-unsubscribe@impala.apache.org
For additional commands, e-mail: issues-all-help@impala.apache.org