[BEAM-5925] Test flake in ElasticsearchIOTest.testWriteFullAddressing

• Type: Bug
• Status: Resolved
• Priority: P1
• Resolution: Fixed
• Fix Version/s: 2.10.0
• Component/s: io-java-elasticsearch
• Labels: flake
• Assignee: Wout Scheepers
• Reporter: Kenneth Knowles
• Created: 30/Oct/18 21:19
• Updated: 19/May/20 15:52
• Resolved: 16/Jan/19 09:25

Description

https://builds.apache.org/view/A-D/view/Beam/job/beam_PostCommit_Java_GradleBuild/1789/
https://scans.gradle.com/s/j42mwdsn5svcs

org.apache.beam.sdk.Pipeline$PipelineExecutionException: java.io.IOException: listener timeout after waiting for [30000] ms

Log looks like this:

[2018-10-31T04:06:07,571][INFO ][o.a.b.s.i.e.ElasticsearchIOTest] [testWriteFullAddressing]: before test
[2018-10-31T04:06:07,572][INFO ][o.a.b.s.i.e.ElasticsearchIOTest] [ElasticsearchIOTest#testWriteFullAddressing]: setting up test
[2018-10-31T04:06:07,589][INFO ][o.e.c.m.MetaDataIndexTemplateService] [node_s0] adding template [random_index_template] for index patterns [*]
[2018-10-31T04:06:07,645][INFO ][o.a.b.s.i.e.ElasticsearchIOTest] [ElasticsearchIOTest#testWriteFullAddressing]: all set up test
[2018-10-31T04:06:10,536][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_s0] [galilei] creating index, cause [auto(bulk api)], templates [random_index_template], shards [6]/[0], mappings []
[2018-10-31T04:06:33,963][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_s0] [curie] creating index, cause [auto(bulk api)], templates [random_index_template], shards [6]/[0], mappings []
[2018-10-31T04:06:34,034][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_s0] [darwin] creating index, cause [auto(bulk api)], templates [random_index_template], shards [6]/[0], mappings []
[2018-10-31T04:06:34,050][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_s0] [copernicus] creating index, cause [auto(bulk api)], templates [random_index_template], shards [6]/[0], mappings []
[2018-10-31T04:06:34,075][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_s0] [faraday] creating index, cause [auto(bulk api)], templates [random_index_template], shards [6]/[0], mappings []
[2018-10-31T04:06:34,095][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_s0] [bohr] creating index, cause [auto(bulk api)], templates [random_index_template], shards [6]/[0], mappings []
[2018-10-31T04:06:34,113][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_s0] [pasteur] creating index, cause [auto(bulk api)], templates [random_index_template], shards [6]/[0], mappings []
[2018-10-31T04:06:34,142][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_s0] [einstein] creating index, cause [auto(bulk api)], templates [random_index_template], shards [6]/[0], mappings []
[2018-10-31T04:06:34,205][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_s0] [maxwell] creating index, cause [auto(bulk api)], templates [random_index_template], shards [6]/[0], mappings []
[2018-10-31T04:06:34,226][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_s0] [newton] creating index, cause [auto(bulk api)], templates [random_index_template], shards [6]/[0], mappings []
[2018-10-31T04:06:36,914][INFO ][o.e.c.r.a.AllocationService] [node_s0] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[galilei][4], [galilei][5]] ...]).
[2018-10-31T04:06:36,970][INFO ][o.e.c.m.MetaDataMappingService] [node_s0] [galilei/Vn1b8XXVSAmrTb5BVe2IJQ] create_mapping [TYPE_1]
[2018-10-31T04:06:37,137][INFO ][o.e.c.m.MetaDataMappingService] [node_s0] [newton/bjnImLt_QguBGEFH9lBJ6Q] create_mapping [TYPE_-1]
[2018-10-31T04:06:37,385][INFO ][o.e.c.m.MetaDataMappingService] [node_s0] [maxwell/-RZ32NbRRZWaGaVfaptFIA] create_mapping [TYPE_0]
[2018-10-31T04:06:37,636][INFO ][o.e.c.m.MetaDataMappingService] [node_s0] [einstein/2lgF5Vj6Ti2KTS-pYSzv3Q] create_mapping [TYPE_1]
[2018-10-31T04:06:37,806][INFO ][o.e.c.m.MetaDataMappingService] [node_s0] [pasteur/832OwzleRSOHsWx85vOH-w] create_mapping [TYPE_0]
[2018-10-31T04:06:38,103][INFO ][o.e.c.m.MetaDataMappingService] [node_s0] [bohr/9YTwB1yvTYKf9YjYCmHjwg] create_mapping [TYPE_1]
[2018-10-31T04:06:38,229][INFO ][o.e.c.m.MetaDataMappingService] [node_s0] [faraday/vIMYG8vpTQKqNkyajcFOxw] create_mapping [TYPE_0]
[2018-10-31T04:06:38,576][INFO ][o.e.c.m.MetaDataMappingService] [node_s0] [copernicus/NzCZssInSiOdZKTmLCoXRw] create_mapping [TYPE_1]
[2018-10-31T04:06:38,890][INFO ][o.e.c.m.MetaDataMappingService] [node_s0] [darwin/g_sIfS5aQwi6BAXw_--vgw] create_mapping [TYPE_1]
[2018-10-31T04:06:39,201][INFO ][o.e.c.m.MetaDataMappingService] [node_s0] [curie/PDuZqTZQROytGLowXGMxhA] create_mapping [TYPE_0]
[2018-10-31T04:06:40,030][INFO ][o.a.b.s.i.e.ElasticsearchIOTest] [ElasticsearchIOTest#testWriteFullAddressing]: cleaning up after test
[2018-10-31T04:06:40,185][INFO ][o.e.c.m.MetaDataDeleteIndexService] [node_s0] [bohr/9YTwB1yvTYKf9YjYCmHjwg] deleting index
[2018-10-31T04:06:40,185][INFO ][o.e.c.m.MetaDataDeleteIndexService] [node_s0] [copernicus/NzCZssInSiOdZKTmLCoXRw] deleting index
[2018-10-31T04:06:40,185][INFO ][o.e.c.m.MetaDataDeleteIndexService] [node_s0] [maxwell/-RZ32NbRRZWaGaVfaptFIA] deleting index
[2018-10-31T04:06:40,185][INFO ][o.e.c.m.MetaDataDeleteIndexService] [node_s0] [pasteur/832OwzleRSOHsWx85vOH-w] deleting index
[2018-10-31T04:06:40,185][INFO ][o.e.c.m.MetaDataDeleteIndexService] [node_s0] [einstein/2lgF5Vj6Ti2KTS-pYSzv3Q] deleting index
[2018-10-31T04:06:40,185][INFO ][o.e.c.m.MetaDataDeleteIndexService] [node_s0] [newton/bjnImLt_QguBGEFH9lBJ6Q] deleting index
[2018-10-31T04:06:40,185][INFO ][o.e.c.m.MetaDataDeleteIndexService] [node_s0] [darwin/g_sIfS5aQwi6BAXw_--vgw] deleting index
[2018-10-31T04:06:40,185][INFO ][o.e.c.m.MetaDataDeleteIndexService] [node_s0] [galilei/Vn1b8XXVSAmrTb5BVe2IJQ] deleting index
[2018-10-31T04:06:40,185][INFO ][o.e.c.m.MetaDataDeleteIndexService] [node_s0] [curie/PDuZqTZQROytGLowXGMxhA] deleting index
[2018-10-31T04:06:40,185][INFO ][o.e.c.m.MetaDataDeleteIndexService] [node_s0] [faraday/vIMYG8vpTQKqNkyajcFOxw] deleting index
[2018-10-31T04:06:40,801][INFO ][o.e.c.m.MetaDataIndexTemplateService] [node_s0] removing template [random_index_template]
[2018-10-31T04:06:40,811][INFO ][o.a.b.s.i.e.ElasticsearchIOTest] [ElasticsearchIOTest#testWriteFullAddressing]: cleaned up after test
[2018-10-31T04:06:40,811][INFO ][o.a.b.s.i.e.ElasticsearchIOTest] [testWriteFullAddressing]: after test

So perhaps it is just too tight a timeout?

Issue Links

• links to: GitHub Pull Request #7065