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

Testcase test_query_log_table_lower_max_sql_plan failed in ubsan builds

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Major
    • Resolution: Fixed
    • Impala 4.4.0
    • Impala 4.4.0
    • Backend
    • None
    • ghx-label-3

    Description

      Testcase test_query_log_table_lower_max_sql_plan failed in ubsan builds with following messages:
      Error Message

      test setup failure
      

      Stacktrace

      common/custom_cluster_test_suite.py:226: in teardown_method
          impalad.wait_for_exit()
      common/impala_cluster.py:471: in wait_for_exit
          while self.__get_pid() is not None:
      common/impala_cluster.py:414: in __get_pid
          assert len(pids) < 2, "Expected single pid but found %s" % ", ".join(map(str, pids))
      E   AssertionError: Expected single pid but found 892, 31942
      

      Standard Error

      -- 2024-03-28 04:21:44,105 INFO     MainThread: Starting cluster with command: /data/jenkins/workspace/impala-cdw-master-staging-core-ubsan/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-cdw-master-staging-core-ubsan/repos/Impala/logs/custom_cluster_tests --log_level=1 '--impalad_args=--enable_workload_mgmt --query_log_write_interval_s=1 --cluster_id=test_max_select --shutdown_grace_period_s=10 --shutdown_deadline_s=60 --query_log_max_sql_length=2000 --query_log_max_plan_length=2000 ' '--state_store_args=None ' '--catalogd_args=--enable_workload_mgmt ' --impalad_args=--default_query_options=
      04:21:44 MainThread: Found 0 impalad/0 statestored/0 catalogd process(es)
      04:21:44 MainThread: Starting State Store logging to /data/jenkins/workspace/impala-cdw-master-staging-core-ubsan/repos/Impala/logs/custom_cluster_tests/statestored.INFO
      04:21:44 MainThread: Starting Catalog Service logging to /data/jenkins/workspace/impala-cdw-master-staging-core-ubsan/repos/Impala/logs/custom_cluster_tests/catalogd.INFO
      04:21:44 MainThread: Starting Impala Daemon logging to /data/jenkins/workspace/impala-cdw-master-staging-core-ubsan/repos/Impala/logs/custom_cluster_tests/impalad.INFO
      04:21:44 MainThread: Starting Impala Daemon logging to /data/jenkins/workspace/impala-cdw-master-staging-core-ubsan/repos/Impala/logs/custom_cluster_tests/impalad_node1.INFO
      04:21:44 MainThread: Starting Impala Daemon logging to /data/jenkins/workspace/impala-cdw-master-staging-core-ubsan/repos/Impala/logs/custom_cluster_tests/impalad_node2.INFO
      04:21:47 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      04:21:47 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      04:21:47 MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-174b.vpc.cloudera.com:25000
      04:21:47 MainThread: Waiting for num_known_live_backends=3. Current value: 0
      04:21:48 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      04:21:48 MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-174b.vpc.cloudera.com:25000
      04:21:48 MainThread: Waiting for num_known_live_backends=3. Current value: 0
      04:21:49 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      04:21:49 MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-174b.vpc.cloudera.com:25000
      04:21:49 MainThread: Waiting for num_known_live_backends=3. Current value: 2
      04:21:50 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      04:21:50 MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-174b.vpc.cloudera.com:25000
      04:21:50 MainThread: num_known_live_backends has reached value: 3
      04:21:51 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      04:21:51 MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-174b.vpc.cloudera.com:25001
      04:21:51 MainThread: num_known_live_backends has reached value: 3
      04:21:51 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      04:21:51 MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-174b.vpc.cloudera.com:25002
      04:21:51 MainThread: num_known_live_backends has reached value: 3
      04:21:52 MainThread: Impala Cluster Running with 3 nodes (3 coordinators, 3 executors).
      -- 2024-03-28 04:21:52,490 DEBUG    MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      -- 2024-03-28 04:21:52,490 INFO     MainThread: Getting metric: statestore.live-backends from impala-ec2-centos79-m6i-4xlarge-ondemand-174b.vpc.cloudera.com:25010
      -- 2024-03-28 04:21:52,492 INFO     MainThread: Metric 'statestore.live-backends' has reached desired value: 4
      -- 2024-03-28 04:21:52,493 DEBUG    MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-174b.vpc.cloudera.com:25000
      -- 2024-03-28 04:21:52,494 INFO     MainThread: num_known_live_backends has reached value: 3
      -- 2024-03-28 04:21:52,494 DEBUG    MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-174b.vpc.cloudera.com:25001
      -- 2024-03-28 04:21:52,496 INFO     MainThread: num_known_live_backends has reached value: 3
      -- 2024-03-28 04:21:52,496 DEBUG    MainThread: Getting num_known_live_backends from impala-ec2-centos79-m6i-4xlarge-ondemand-174b.vpc.cloudera.com:25002
      -- 2024-03-28 04:21:52,498 INFO     MainThread: num_known_live_backends has reached value: 3
      SET client_identifier=custom_cluster/test_query_log.py::TestQueryLogTableBeeswax::()::test_query_log_table_lower_max_sql_plan[protocol:beeswax|exec_option:{'test_replan':1;'batch_size':0;'num_nodes':0;'disable_codegen_rows_threshold':5000;'disable_codegen':False;'abort_on_erro;
      -- connecting to: localhost:21000
      -- 2024-03-28 04:21:52,498 INFO     MainThread: Could not connect to ('::1', 21000, 0, 0)
      Traceback (most recent call last):
        File "/data0/jenkins/workspace/impala-cdw-master-staging-core-ubsan/repos/Impala/infra/python/env-gcc10.4.0/lib/python2.7/site-packages/thrift/transport/TSocket.py", line 137, in open
          handle.connect(sockaddr)
        File "/data/jenkins/workspace/impala-cdw-master-staging-core-ubsan/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
      -- 2024-03-28 04:21:52,499 INFO     MainThread: Could not connect to ('::1', 21050, 0, 0)
      Traceback (most recent call last):
        File "/data0/jenkins/workspace/impala-cdw-master-staging-core-ubsan/repos/Impala/infra/python/env-gcc10.4.0/lib/python2.7/site-packages/thrift/transport/TSocket.py", line 137, in open
          handle.connect(sockaddr)
        File "/data/jenkins/workspace/impala-cdw-master-staging-core-ubsan/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
      -- 2024-03-28 04:21:52,522 INFO     MainThread: Closing active operation
      -- connecting to localhost:28000 with impyla
      -- 2024-03-28 04:21:52,539 INFO     MainThread: Closing active operation
      -- connecting to localhost:11050 with impyla
      -- executing async: localhost:21000
      
      select 'AiasBHSrxOLzVzlCSNghXApmNdbCBXjcNbmuSOarlWWjpLkDdyOsxeZodtTXOuHdGaXtactAirjQouXpUgTjLBJOfyJubTXsRSvRlOdUojyflhzhwBpMbTunJeYunRbLQQqpslsSpGFQHntMjZOOtfRVnuNbGAdAcKprpAkZiPqwcXaKBeZVFupuGkEFFXFMjpwIScMPgJJLzNFMeMsuCqkOFNPmFdKRkMBtfJSjpbXnEaPiWbmdsgFdWjylhsAwQggdKpJhCxzplJQOhKRcfATWSCzbaqFjcoXlKQGPnuOLpqXJZoFbOgEpqTLNjaYQjeXUJWqFmLKDdacXJKecUNybfEBVADAJQqngExoTPWpoMAPfURVpIKQpXXELtuDwUtAGQVuoIfwXYXpAKiLeXaEmtObYzHqlZLeZgTBJdZLGWMCRxLQFEEktahZIsCVxfdcTTnJpBMPkIYYSDvHJxipGIeKyaBjKgdAdWlcvjwxxksdRnuNWYkPwQHnwUGIQRjBtDXwGdkMedEECzCxblYVbmYuLZZIREyGdWgJKQwDeATugIeljRxKKscNFxByfylKWCrCAKBraIdeNLTKzLcVmcewfRfMiiDYrdxuRKQxJaWkOAgbZCmrYbrTLubfTdRWVPdvCYgolhYyYcsIDJwbcOtOCASkQrqKAHxrxNrVgXRSIuzbQmVfLRNJiObOWRaZwgwLXMdcEWVTEtLXzEkFADITIXumLqCCoHBQSKuuTaSysRNgbWCoAdNncmMkvMJkpjYNXZplRxOFpKYzxzKqOGxgafWKRanVIPWCvsNzHGesxyDcvtGUoxmAOCyLfQynLjOUQIoxbVMXzQtFPwBGcYdeSdmHfnWQUNgqmlrDtuSoixiCHKIOXgBhkThvbYbQdZJUdglofDuuWEpjUifxCAlDqPdCSKcQCjyFGfsLZmYDCtkRWRGxjsbFTvNFzlbscXVZvRiRaFcQLWVrVmXKcBFCAqJsVztEeJvmJcJxpuJckItbVezHRrXlJRTybhTgQcntrDJCpCZnXFAfucizqSAHmffdhuyPSlfPhfHhdrICdZrqDoWPGnpuAldfDsvhokPqkSLRvjYiiBoLdUVtHDDYjyCgEdamZIdUdLtIEsfvKuMHAelWFgGikrVBgehBqoHqvSvdbXClWuCdgCIsdioymhZKdSxvldrbcnDUHETYSuKIpkzXpgqNjWiZYoGtnbOzVTzxIFDykftZkEwPFWatyIEBNTcBNAoBMDTVtWajrnIzHiCOaHicHunHERiLQYSwhXtLetCitxCntuZuKXPBmVDbjIYLzrjEKiZfDNZKDuekEyUbxkqKhOcCviJfmeSNRDGroPDLKXHQUYViNNYKSMkqiVQSEpibwrRxakgmyJUDtJhtWoPprgGhxFoiBBMhWSXrfBCUnnxOwPAhSdrSOmupGATEEpuKMQoWqqQJUFQKQjeoRBIUIuJbYDzFmWsLRwMmParCfrEUESelyIbJOhaAjFiqFXwJXmnXGAZskCUPzhuvRIuiiUstpxsayPCiKRersQbqdZqJshRuSuHAYnsRtNiGanlnVYYNfovbFNnCrxDykrHIWPUtdlZojJknGCVbQRbKUnEWsxOuywwUYkaeLNKmlEKkcdcEweavwsXCpBXsqqLFCJtjxAbyycMFyaojFfmtjvccXajdDeIcsGSxmCzAxyxHVWIqeDduaUImMtDcVOcjNpUefkvIDDkYnrAmcQKfQwybtnUSPtpbSRhQftCaKzzifqOeTihsUHglxCHwEBTTElHsAvaOEPAdiRTLTCjKtSRgczFtSwuJqCxPgCzpEGQACuFemWScEBGqapnzmswHZhVtrTKCJoJNMTMeAYxVIMZpuqEZWHIbDposEkAcTskpRFdVvNpUjsuFIeqYEqWOznCkNdvLBzgsQZVEYFOKdDUxYvKSznfpIHoyBGHcvAIrbADKEdrcaLpltncxXTFlzGTZqoEvKXERYXjmjxLbt';
      
      -- 2024-03-28 04:21:52,711 INFO     MainThread: Started query a24e3312cbb9e7a3:9493406900000000
      -- waiting for query to reach FINISHED state: <tests.common.impala_connection.OperationHandle object at 0x7fd23c0efad0>
      -- closing query for operation handle: <tests.common.impala_connection.OperationHandle object at 0x7fd23c0efad0>
      -- 2024-03-28 04:21:52,763 INFO     MainThread: Getting metric: impala-server.completed-queries.written from impala-ec2-centos79-m6i-4xlarge-ondemand-174b.vpc.cloudera.com:25000
      -- 2024-03-28 04:21:52,766 INFO     MainThread: Waiting for metric value 'impala-server.completed-queries.written'=1. Current value: 0
      -- 2024-03-28 04:21:52,766 INFO     MainThread: Sleeping 1s before next retry.
      -- 2024-03-28 04:21:53,767 INFO     MainThread: Getting metric: impala-server.completed-queries.written from impala-ec2-centos79-m6i-4xlarge-ondemand-174b.vpc.cloudera.com:25000
      -- 2024-03-28 04:21:53,771 INFO     MainThread: Waiting for metric value 'impala-server.completed-queries.written'=1. Current value: 0
      -- 2024-03-28 04:21:53,771 INFO     MainThread: Sleeping 1s before next retry.
      -- 2024-03-28 04:21:54,772 INFO     MainThread: Getting metric: impala-server.completed-queries.written from impala-ec2-centos79-m6i-4xlarge-ondemand-174b.vpc.cloudera.com:25000
      -- 2024-03-28 04:21:54,776 INFO     MainThread: Metric 'impala-server.completed-queries.written' has reached desired value: 1
      -- executing against localhost:21000
      refresh sys.impala_query_log;
      -- 2024-03-28 04:21:54,783 INFO     MainThread: Started query 7f4f65d6f3e4c1c1:f02df28d00000000
      -- executing against localhost:21000
      select length(sql),plan from sys.impala_query_log where query_id='a24e3312cbb9e7a3:9493406900000000';
      -- 2024-03-28 04:21:55,048 INFO     MainThread: Started query b94f8df873a1b9e5:5168f65c00000000
      

      Attachments

        Activity

          People

            MikaelSmith Michael Smith
            baggio000 Yida Wu
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: