Quanlong Huang created IMPALA-10897:
---------------------------------------
Summary: TestEventProcessing.test_event_based_replication is flaky
Key: IMPALA-10897
URL: https://issues.apache.org/jira/browse/IMPALA-10897
Project: IMPALA
Issue Type: Bug
Reporter: Quanlong Huang
Assignee: Vihang Karajgaonkar
Saw this in an ASAN build:
{code:python}
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 {code}
Standard Error
{code}
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{code}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
