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

TestEventProcessing.test_event_based_replication is flaky

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Critical
    • Resolution: Fixed
    • None
    • Impala 4.0.1
    • None
    • None
    • ghx-label-5

    Description

      Saw this in an ASAN build:

      metadata/test_event_processing.py:185: in test_event_based_replication
          self.__run_event_based_replication_tests()
      metadata/test_event_processing.py:326: in __run_event_based_replication_tests
          EventProcessorUtils.wait_for_event_processing(self)
      util/event_processor_utils.py:61: in wait_for_event_processing
          within {1} seconds".format(current_event_id, timeout))
      E   Exception: Event processor did not sync till last known event id 34722           within 10 seconds 

      Standard Error

      SET client_identifier=metadata/test_event_processing.py::TestEventProcessing::()::test_event_based_replication;
      -- connecting to: localhost:21000
      -- connecting to localhost:21050 with impyla
      -- 2021-08-28 23:43:40,300 INFO     MainThread: Closing active operation
      -- connecting to localhost:28000 with impyla
      -- 2021-08-28 23:43:40,323 INFO     MainThread: Closing active operation
      -- connecting to localhost:11050 with impyla
      -- 2021-08-28 23:43:48,026 INFO     MainThread: Waiting until events processor syncs to event id:31451
      -- 2021-08-28 23:43:48,759 DEBUG    MainThread: Metric last-synced-event-id has reached the desired value:31455
      -- 2021-08-28 23:43:48,790 DEBUG    MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      -- 2021-08-28 23:43:48,820 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:43:48,824 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:43:49,825 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:43:49,829 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:43:50,830 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:43:50,835 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:43:51,836 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:43:51,840 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:43:52,841 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:43:52,846 INFO     MainThread: Metric 'catalog.curr-version' has reached desired value: 2364
      -- 2021-08-28 23:43:52,846 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25001
      -- 2021-08-28 23:43:52,851 INFO     MainThread: Metric 'catalog.curr-version' has reached desired value: 2364
      -- 2021-08-28 23:43:52,851 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25002
      -- 2021-08-28 23:43:52,855 INFO     MainThread: Metric 'catalog.curr-version' has reached desired value: 2364
      -- executing against localhost:21000
      
      create table repl_source_ugchr.unpart_tbl (a string, b string) stored as parquet tblproperties ('transactional'='true','transactional_properties'='insert_only');
      
      -- 2021-08-28 23:43:52,878 INFO     MainThread: Started query 394339b6db812c59:a5e5039a00000000
      -- executing against localhost:21000
      
      create table repl_source_ugchr.part_tbl (id int, bool_col boolean, tinyint_col tinyint, smallint_col smallint, int_col int, bigint_col bigint, float_col float, double_col double, date_string string, string_col string, timestamp_col timestamp) partitioned by (year int, month int) stored as parquet tblproperties ('transactional'='true','transactional_properties'='insert_only');
      
      -- 2021-08-28 23:43:52,900 INFO     MainThread: Started query b74f5e32e4c1790a:4641075000000000
      -- executing against localhost:21000
      
      insert into repl_source_ugchr.unpart_tbl select * from functional.tinytable;
      
      -- 2021-08-28 23:43:56,132 INFO     MainThread: Started query ee4b5eb533882fe4:b0d0e77400000000
      -- executing against localhost:21000
      
      insert into repl_source_ugchr.part_tbl partition(year,month) select * from functional_parquet.alltypessmall;
      
      -- 2021-08-28 23:44:00,135 INFO     MainThread: Started query 344a832f2c85d754:8cf420d500000000
      -- executing against localhost:21000
      
      select count(*) from repl_source_ugchr.unpart_tbl;
      
      -- 2021-08-28 23:44:00,911 INFO     MainThread: Started query a24c567cd4d8ebc3:636ac3be00000000
      -- executing against localhost:21000
      
      select count(*) from repl_source_ugchr.part_tbl;
      
      -- 2021-08-28 23:44:01,084 INFO     MainThread: Started query 23484c04b7d1ebab:4d88715000000000
      -- executing against localhost:21000
      
      create database repl_target_ggfut;
      
      -- 2021-08-28 23:49:06,182 INFO     MainThread: Started query 1848bc953f987711:95ae346800000000
      -- 2021-08-28 23:49:12,238 INFO     MainThread: Waiting until events processor syncs to event id:31994
      -- 2021-08-28 23:49:12,240 DEBUG    MainThread: Metric last-synced-event-id has reached the desired value:31994
      -- 2021-08-28 23:49:12,273 DEBUG    MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      -- 2021-08-28 23:49:12,296 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:49:12,300 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:49:13,301 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:49:13,307 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:49:14,308 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:49:14,315 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:49:15,315 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:49:15,323 INFO     MainThread: Metric 'catalog.curr-version' has reached desired value: 2994
      -- 2021-08-28 23:49:15,323 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25001
      -- 2021-08-28 23:49:15,329 INFO     MainThread: Metric 'catalog.curr-version' has reached desired value: 2994
      -- 2021-08-28 23:49:15,329 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25002
      -- 2021-08-28 23:49:15,336 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:49:16,336 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25002
      -- 2021-08-28 23:49:16,341 INFO     MainThread: Metric 'catalog.curr-version' has reached desired value: 2994
      -- executing against localhost:21000
      
      show tables in repl_target_ggfut;
      
      -- 2021-08-28 23:49:16,349 INFO     MainThread: Started query ec408a6a710ed5e5:829dcc6600000000
      -- executing against localhost:21000
      
      show tables in repl_target_ggfut;
      
      -- 2021-08-28 23:49:16,358 INFO     MainThread: Started query 614a91a04602a762:d3a9685900000000
      -- executing against localhost:21000
      
      select count(*) from repl_target_ggfut.unpart_tbl;
      
      -- 2021-08-28 23:49:20,928 INFO     MainThread: Started query b64d2a2099ed7a87:b61d380d00000000
      -- executing against localhost:21000
      
      select count(*) from repl_target_ggfut.part_tbl;
      
      -- 2021-08-28 23:49:25,032 INFO     MainThread: Started query 4a4f3caf1f814961:a6e7cece00000000
      -- executing against localhost:21000
      
      insert into repl_source_ugchr.unpart_tbl select * from functional.tinytable;
      
      -- 2021-08-28 23:49:25,585 INFO     MainThread: Started query 7c4c5910217c3c63:7bd7a6fe00000000
      -- executing against localhost:21000
      
      insert into repl_source_ugchr.part_tbl partition(year,month) select * from functional_parquet.alltypessmall;
      
      -- 2021-08-28 23:49:26,079 INFO     MainThread: Started query 1e4d5559508bdc23:bce2a60800000000
      -- 2021-08-28 23:49:56,228 INFO     MainThread: Waiting until events processor syncs to event id:32160
      -- 2021-08-28 23:49:56,440 DEBUG    MainThread: Metric last-synced-event-id has reached the desired value:32160
      -- 2021-08-28 23:49:56,484 DEBUG    MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      -- 2021-08-28 23:49:56,512 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:49:56,518 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:49:57,519 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:49:57,524 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:49:58,524 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:49:58,530 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:49:59,531 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:49:59,539 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:50:00,539 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:50:00,546 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:50:01,547 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:50:01,554 INFO     MainThread: Metric 'catalog.curr-version' has reached desired value: 3122
      -- 2021-08-28 23:50:01,555 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25001
      -- 2021-08-28 23:50:01,571 INFO     MainThread: Metric 'catalog.curr-version' has reached desired value: 3122
      -- 2021-08-28 23:50:01,571 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25002
      -- 2021-08-28 23:50:01,578 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:50:02,579 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25002
      -- 2021-08-28 23:50:02,589 INFO     MainThread: Metric 'catalog.curr-version' has reached desired value: 3122
      -- executing against localhost:21000
      
      select count(*) from repl_target_ggfut.unpart_tbl;
      
      -- 2021-08-28 23:50:02,641 INFO     MainThread: Started query 3f4978dd5f24b4af:558c1b8000000000
      -- executing against localhost:21000
      
      select count(*) from repl_target_ggfut.part_tbl;
      
      -- 2021-08-28 23:50:02,934 INFO     MainThread: Started query bc4e464a9fa39221:f9c3f41300000000
      -- executing against localhost:21000
      
      insert overwrite table repl_source_ugchr.unpart_tbl select * from functional.tinytable;
      
      -- 2021-08-28 23:50:03,263 INFO     MainThread: Started query a740ee894752df2a:2feb8f3b00000000
      -- executing against localhost:21000
      
      insert overwrite table repl_source_ugchr.part_tbl partition(year,month) select * from functional_parquet.alltypessmall;
      
      -- 2021-08-28 23:50:03,704 INFO     MainThread: Started query 884052c65ecd5fdc:b892b7f300000000
      -- 2021-08-28 23:50:23,074 INFO     MainThread: Waiting until events processor syncs to event id:32344
      -- 2021-08-28 23:50:23,808 DEBUG    MainThread: Metric last-synced-event-id has reached the desired value:32349
      -- 2021-08-28 23:50:23,855 DEBUG    MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      -- 2021-08-28 23:50:23,885 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:50:23,890 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:50:24,890 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:50:24,896 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:50:25,897 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:50:25,905 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:50:26,906 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:50:26,913 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:50:27,914 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:50:27,921 INFO     MainThread: Metric 'catalog.curr-version' has reached desired value: 3255
      -- 2021-08-28 23:50:27,921 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25001
      -- 2021-08-28 23:50:27,926 INFO     MainThread: Metric 'catalog.curr-version' has reached desired value: 3255
      -- 2021-08-28 23:50:27,926 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25002
      -- 2021-08-28 23:50:27,931 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:50:28,931 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25002
      -- 2021-08-28 23:50:28,938 INFO     MainThread: Metric 'catalog.curr-version' has reached desired value: 3255
      -- executing against localhost:21000
      
      select count(*) from repl_target_ggfut.unpart_tbl;
      
      -- 2021-08-28 23:50:28,946 INFO     MainThread: Started query a44c2b14b5ce1be9:d98ecd5100000000
      -- executing against localhost:21000
      
      select count(*) from repl_target_ggfut.part_tbl;
      
      -- 2021-08-28 23:50:29,178 INFO     MainThread: Started query 9a42fc19d507d8d3:da6eb99e00000000
      -- executing against localhost:21000
      
      create table repl_source_ugchr.insertonly_nopart_ctas tblproperties ('transactional'='true','transactional_properties'='insert_only') as select * from repl_source_ugchr.unpart_tbl;
      
      -- 2021-08-28 23:50:29,564 INFO     MainThread: Started query fa471f8363e57a20:d4bc21f000000000
      -- executing against localhost:21000
      
      create table repl_source_ugchr.insertonly_part_ctas partitioned by (year, month) tblproperties ('transactional'='true','transactional_properties'='insert_only') as select * from repl_source_ugchr.part_tbl;
      
      -- 2021-08-28 23:50:29,925 INFO     MainThread: Started query a147d6e6c4cb7498:4f0d50ab00000000
      -- 2021-08-28 23:50:44,729 INFO     MainThread: Waiting until events processor syncs to event id:32625
      -- 2021-08-28 23:50:44,940 DEBUG    MainThread: Metric last-synced-event-id has reached the desired value:32625
      -- 2021-08-28 23:50:44,989 DEBUG    MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
      -- 2021-08-28 23:50:45,017 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:50:45,023 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:50:46,024 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:50:46,030 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:50:47,031 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:50:47,037 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:50:48,038 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:50:48,045 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:50:49,045 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:50:49,051 INFO     MainThread: Sleeping 1s before next retry.
      -- 2021-08-28 23:50:50,053 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25000
      -- 2021-08-28 23:50:50,060 INFO     MainThread: Metric 'catalog.curr-version' has reached desired value: 3448
      -- 2021-08-28 23:50:50,060 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25001
      -- 2021-08-28 23:50:50,064 INFO     MainThread: Metric 'catalog.curr-version' has reached desired value: 3448
      -- 2021-08-28 23:50:50,065 INFO     MainThread: Getting metric: catalog.curr-version from impala-ec2-centos74-m5-4xlarge-ondemand-1787.vpc.cloudera.com:25002
      -- 2021-08-28 23:50:50,070 INFO     MainThread: Metric 'catalog.curr-version' has reached desired value: 3448
      -- executing against localhost:21000
      
      select count(*) from repl_source_ugchr.insertonly_nopart_ctas;
      
      -- 2021-08-28 23:50:50,080 INFO     MainThread: Started query 7a4e918888e0f7b8:dee3360f00000000
      -- executing against localhost:21000
      
      select count(*) from repl_target_ggfut.insertonly_nopart_ctas;
      
      -- 2021-08-28 23:50:53,149 INFO     MainThread: Started query 524d8ef3b6baf55e:efafcdf700000000
      -- executing against localhost:21000
      
      select count(*) from repl_source_ugchr.insertonly_part_ctas;
      
      -- 2021-08-28 23:50:53,324 INFO     MainThread: Started query 58449b031b3e1e2b:fe00988a00000000
      -- executing against localhost:21000
      
      select count(*) from repl_target_ggfut.insertonly_part_ctas;
      
      -- 2021-08-28 23:50:57,154 INFO     MainThread: Started query f4415892ac775fe0:c6ed79be00000000
      -- executing against localhost:21000
      
      truncate table repl_source_ugchr.unpart_tbl;
      
      -- 2021-08-28 23:50:57,501 INFO     MainThread: Started query 174e9849e4194f73:a4bf3a2c00000000
      -- executing against localhost:21000
      
      truncate table repl_source_ugchr.part_tbl;
      
      -- 2021-08-28 23:50:57,641 INFO     MainThread: Started query ba42b9e471b16479:02bee03300000000
      -- 2021-08-28 23:51:16,369 INFO     MainThread: Waiting until events processor syncs to event id:34722

      Attachments

        Activity

          People

            vihangk1 Vihang Karajgaonkar
            stigahuang Quanlong Huang
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: