Uploaded image for project: 'IMPALA'
  1. IMPALA
  2. IMPALA-8983

TestExecutorGroups.test_max_concurrent_queries seems flaky

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Open
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: Impala 3.4.0
    • Fix Version/s: None
    • Component/s: Backend
    • Labels:
      None
    • Epic Color:
      ghx-label-7

      Description

      It appears the test failed because an expected query admission failure didn't happen. Happened once only so far.

      Error Message
      assert 'Initial admission queue reason: No query slot available on host' in 'Query (id=4a4773e2f93eff7f:754a96ed00000000):\n  DEBUG MODE WARNING: Query profile created while running a DEBUG buil...0)\n     - NumRowsFetchedFromCache: 0 (0)\n     - RowMaterializationRate: 0\n     - RowMaterializationTimer: 0.000ns\n'
      Stacktrace
      custom_cluster/test_executor_groups.py:212: in test_max_concurrent_queries
          assert "Initial admission queue reason: No query slot available on host" in profile
      E   assert 'Initial admission queue reason: No query slot available on host' in 'Query (id=4a4773e2f93eff7f:754a96ed00000000):\n  DEBUG MODE WARNING: Query profile created while running a DEBUG buil...0)\n     - NumRowsFetchedFromCache: 0 (0)\n     - RowMaterializationRate: 0\n     - RowMaterializationTimer: 0.000ns\n'
      Standard Error
      -- 2019-09-26 13:41:15,462 INFO     MainThread: Starting cluster with command: /data/jenkins/workspace/impala-cdh6.x-core-asan/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=1 --num_coordinators=1 --log_dir=/data/jenkins/workspace/impala-cdh6.x-core-asan/repos/Impala/logs/custom_cluster_tests --log_level=1 --use_exclusive_coordinators '--impalad_args= -executor_groups=coordinator ' --impalad_args=--default_query_options=
      13:41:15 MainThread: Starting impala cluster without executors
      13:41:16 MainThread: Found 0 impalad/0 statestored/0 catalogd process(es)
      13:41:16 MainThread: Starting State Store logging to /data/jenkins/workspace/impala-cdh6.x-core-asan/repos/Impala/logs/custom_cluster_tests/statestored.INFO
      13:41:16 MainThread: Starting Catalog Service logging to /data/jenkins/workspace/impala-cdh6.x-core-asan/repos/Impala/logs/custom_cluster_tests/catalogd.INFO
      13:41:16 MainThread: Starting Impala Daemon logging to /data/jenkins/workspace/impala-cdh6.x-core-asan/repos/Impala/logs/custom_cluster_tests/impalad.INFO
      13:41:19 MainThread: Found 1 impalad/1 statestored/1 catalogd process(es)
      13:41:19 MainThread: Found 1 impalad/1 statestored/1 catalogd process(es)
      13:41:19 MainThread: Getting num_known_live_backends from impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com:25000
      13:41:19 MainThread: Debug webpage not yet available: ('Connection aborted.', error(111, 'Connection refused'))
      13:41:21 MainThread: Debug webpage did not become available in expected time.
      13:41:21 MainThread: Waiting for num_known_live_backends=1. Current value: None
      13:41:22 MainThread: Found 1 impalad/1 statestored/1 catalogd process(es)
      13:41:22 MainThread: Getting num_known_live_backends from impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com:25000
      13:41:22 MainThread: num_known_live_backends has reached value: 1
      13:41:22 MainThread: Impala Cluster Running with 1 nodes (1 coordinators, 0 executors).
      -- 2019-09-26 13:41:22,976 DEBUG    MainThread: Found 1 impalad/1 statestored/1 catalogd process(es)
      -- 2019-09-26 13:41:22,976 INFO     MainThread: Getting metric: statestore.live-backends from impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com:25010
      -- 2019-09-26 13:41:22,977 INFO     MainThread: Starting new HTTP connection (1): impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com
      -- 2019-09-26 13:41:22,979 INFO     MainThread: Metric 'statestore.live-backends' has reached desired value: 2
      -- 2019-09-26 13:41:22,980 DEBUG    MainThread: Getting num_known_live_backends from impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com:25000
      -- 2019-09-26 13:41:22,980 INFO     MainThread: Starting new HTTP connection (1): impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com
      -- 2019-09-26 13:41:22,982 INFO     MainThread: num_known_live_backends has reached value: 1
      SET client_identifier=custom_cluster/test_executor_groups.py::TestExecutorGroups::()::test_max_concurrent_queries;
      -- connecting to: localhost:21000
      -- connecting to localhost:21050 with impyla
      -- 2019-09-26 13:41:23,170 INFO     MainThread: Closing active operation
      -- 2019-09-26 13:41:23,172 INFO     MainThread: Adding 2 executors to group default-pool-group1 with minimum size 2
      -- 2019-09-26 13:41:23,172 INFO     MainThread: Starting cluster with command: /data/jenkins/workspace/impala-cdh6.x-core-asan/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=2 --num_coordinators=0 --log_dir=/data/jenkins/workspace/impala-cdh6.x-core-asan/repos/Impala/logs/custom_cluster_tests --log_level=1 --add_executors --impalad_args=-max_concurrent_queries=1 --impalad_args=-executor_groups=default-pool-group1:2 --impalad_args=--default_query_options=
      13:41:23 MainThread: Found 1 impalad/1 statestored/1 catalogd process(es)
      13:41:23 MainThread: Starting Impala Daemon logging to /data/jenkins/workspace/impala-cdh6.x-core-asan/repos/Impala/logs/custom_cluster_tests/impalad_node1.INFO
      13:41:23 MainThread: Starting Impala Daemon logging to /data/jenkins/workspace/impala-cdh6.x-core-asan/repos/Impala/logs/custom_cluster_tests/impalad_node2.INFO
      13:41:26 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      13:41:26 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      13:41:26 MainThread: Getting num_known_live_backends from impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com:25000
      13:41:26 MainThread: Waiting for num_known_live_backends=3. Current value: 1
      13:41:27 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      13:41:27 MainThread: Getting num_known_live_backends from impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com:25000
      13:41:27 MainThread: num_known_live_backends has reached value: 3
      13:41:28 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      13:41:28 MainThread: Getting num_known_live_backends from impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com:25001
      13:41:28 MainThread: num_known_live_backends has reached value: 3
      13:41:28 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      13:41:28 MainThread: Getting num_known_live_backends from impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com:25002
      13:41:28 MainThread: num_known_live_backends has reached value: 3
      13:41:28 MainThread: Impala Cluster Running with 2 nodes (0 coordinators, 2 executors).
      -- 2019-09-26 13:41:28,501 DEBUG    MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      -- 2019-09-26 13:41:28,501 INFO     MainThread: Getting metric: statestore.live-backends from impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com:25010
      -- 2019-09-26 13:41:28,503 INFO     MainThread: Starting new HTTP connection (1): impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com
      -- 2019-09-26 13:41:28,504 INFO     MainThread: Metric 'statestore.live-backends' has reached desired value: 4
      -- 2019-09-26 13:41:28,504 DEBUG    MainThread: Getting num_known_live_backends from impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com:25000
      -- 2019-09-26 13:41:28,505 INFO     MainThread: Starting new HTTP connection (1): impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com
      -- 2019-09-26 13:41:28,507 INFO     MainThread: num_known_live_backends has reached value: 3
      -- 2019-09-26 13:41:28,507 DEBUG    MainThread: Getting num_known_live_backends from impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com:25001
      -- 2019-09-26 13:41:28,508 INFO     MainThread: Starting new HTTP connection (1): impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com
      -- 2019-09-26 13:41:28,510 INFO     MainThread: num_known_live_backends has reached value: 3
      -- 2019-09-26 13:41:28,510 DEBUG    MainThread: Getting num_known_live_backends from impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com:25002
      -- 2019-09-26 13:41:28,511 INFO     MainThread: Starting new HTTP connection (1): impala-ec2-centos74-r4-4xlarge-ondemand-0593.vpc.cloudera.com
      -- 2019-09-26 13:41:28,512 INFO     MainThread: num_known_live_backends has reached value: 3
      -- executing async: localhost:21000
      
      select * from functional_parquet.alltypestiny              where month < 3 and id + random() < sleep(500);;
      
      -- 2019-09-26 13:41:29,541 INFO     MainThread: Started query 00406cb12a61dc27:2255454e00000000
      -- waiting for completion of the admission control processing of the query: <tests.common.impala_connection.OperationHandle object at 0x50ced50>
      -- executing async: localhost:21000
      
      select * from functional_parquet.alltypestiny              where month < 3 and id + random() < sleep(500);;
      
      -- 2019-09-26 13:41:29,612 INFO     MainThread: Started query 4a4773e2f93eff7f:754a96ed00000000
      -- getting runtime profile operation: <tests.common.impala_connection.OperationHandle object at 0x50cef50>
      

        Attachments

          Activity

            People

            • Assignee:
              lv Lars Volker
              Reporter:
              kwho Michael Ho
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated: