Beats: [Metricbeat] Flaky test in Elasticsearch module

[sayden]

Flaky Test

• Test Name: Elasticsearch integration test in Metricbeat
• Link: https://beats-ci.elastic.co/job/elastic+beats+pull-request+multijob-linux/beat=metricbeat,label=linux-immutable/5200/console
• Branch: Master
• Notes: I have seen this fail occuring sometimes without any connection between the PR's originating errors (apart that all of them comes from Metricbeat). I discovered this flaky the first time while migrating modules to use the ReporterV2 interface in Metricbeat https://github.com/elastic/beats/issues/10774 but I don't really think it's related.

Stack Trace

17:42:59 --- FAIL: TestFetch (115.91s)
17:42:59    assertions.go:256: 
17:42:59            Error Trace:    elasticsearch_integration_test.go:81
17:42:59            Error:          Received unexpected error:
17:42:59                            Put http://elasticsearch:9200/rats/_ccr/follow: EOF
17:42:59            Test:           TestFetch
17:42:59     --- FAIL: TestFetch/ccr (0.00s)
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:89
17:42:59                Error:          Should be empty, but was [error determining if connected Elasticsearch node is master: error making http request: Get http://elasticsearch:9200/_nodes/_local/nodes: dial tcp 172.18.0.7:9200: connect: connection refused]
17:42:59                Test:           TestFetch/ccr
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:90
17:42:59                Error:          Should NOT be empty, but was []
17:42:59                Test:           TestFetch/ccr
17:42:59     --- FAIL: TestFetch/cluster_stats (0.00s)
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:89
17:42:59                Error:          Should be empty, but was [error determining if connected Elasticsearch node is master: error making http request: Get http://elasticsearch:9200/_nodes/_local/nodes: dial tcp 172.18.0.7:9200: connect: connection refused]
17:42:59                Test:           TestFetch/cluster_stats
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:90
17:42:59                Error:          Should NOT be empty, but was []
17:42:59                Test:           TestFetch/cluster_stats
17:42:59     --- FAIL: TestFetch/index (0.00s)
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:89
17:42:59                Error:          Should be empty, but was [error determining if connected Elasticsearch node is master: error making http request: Get http://elasticsearch:9200/_nodes/_local/nodes: dial tcp 172.18.0.7:9200: connect: connection refused]
17:42:59                Test:           TestFetch/index
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:90
17:42:59                Error:          Should NOT be empty, but was []
17:42:59                Test:           TestFetch/index
17:42:59     --- FAIL: TestFetch/index_recovery (0.01s)
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:89
17:42:59                Error:          Should be empty, but was [error determining if connected Elasticsearch node is master: error making http request: Get http://elasticsearch:9200/_nodes/_local/nodes: dial tcp 172.18.0.7:9200: connect: connection refused]
17:42:59                Test:           TestFetch/index_recovery
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:90
17:42:59                Error:          Should NOT be empty, but was []
17:42:59                Test:           TestFetch/index_recovery
17:42:59     --- FAIL: TestFetch/index_summary (0.01s)
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:89
17:42:59                Error:          Should be empty, but was [error determining if connected Elasticsearch node is master: error making http request: Get http://elasticsearch:9200/_nodes/_local/nodes: dial tcp 172.18.0.7:9200: connect: connection refused]
17:42:59                Test:           TestFetch/index_summary
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:90
17:42:59                Error:          Should NOT be empty, but was []
17:42:59                Test:           TestFetch/index_summary
17:42:59     --- FAIL: TestFetch/ml_job (0.01s)
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:89
17:42:59                Error:          Should be empty, but was [error determining if connected Elasticsearch node is master: error making http request: Get http://elasticsearch:9200/_nodes/_local/nodes: dial tcp 172.18.0.7:9200: connect: connection refused]
17:42:59                Test:           TestFetch/ml_job
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:90
17:42:59                Error:          Should NOT be empty, but was []
17:42:59                Test:           TestFetch/ml_job
17:42:59     --- FAIL: TestFetch/node (0.01s)
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:89
17:42:59                Error:          Should be empty, but was [error making http request: Get http://elasticsearch:9200/_nodes/_local: dial tcp 172.18.0.7:9200: connect: connection refused]
17:42:59                Test:           TestFetch/node
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:90
17:42:59                Error:          Should NOT be empty, but was []
17:42:59                Test:           TestFetch/node
17:42:59     --- FAIL: TestFetch/node_stats (0.00s)
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:89
17:42:59                Error:          Should be empty, but was [error making http request: Get http://elasticsearch:9200/_nodes/_local/stats: dial tcp 172.18.0.7:9200: connect: connection refused]
17:42:59                Test:           TestFetch/node_stats
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:90
17:42:59                Error:          Should NOT be empty, but was []
17:42:59                Test:           TestFetch/node_stats
17:42:59     --- FAIL: TestFetch/shard (0.00s)
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:89
17:42:59                Error:          Should be empty, but was [error determining if connected Elasticsearch node is master: error making http request: Get http://elasticsearch:9200/_nodes/_local/nodes: dial tcp 172.18.0.7:9200: connect: connection refused]
17:42:59                Test:           TestFetch/shard
17:42:59        assertions.go:256: 
17:42:59                Error Trace:    elasticsearch_integration_test.go:90
17:42:59                Error:          Should NOT be empty, but was []
17:42:59                Test:           TestFetch/shard
17:42:59 Killing metricbeatb8f075ca3ba9f0ca8d77c37c7ab1a9ce06333331_http_1 ... 
17:42:59 
17:42:59 Killing metricbeatb8f075ca3ba9f0ca8d77c37c7ab1a9ce06333331_http_1 ... done
17:42:59 Killing metricbeatb8f075ca3ba9f0ca8d77c37c7ab1a9ce06333331_haproxy_1 ... 
17:42:59 
17:42:59 Killing metricbeatb8f075ca3ba9f0ca8d77c37c7ab1a9ce06333331_haproxy_1 ... done
17:42:59 Building elasticsearch
17:42:59 Step 1/2 : FROM docker.elastic.co/elasticsearch/elasticsearch:6.6.0
17:42:59  ---> 13aa43015aa1
17:42:59 Step 2/2 : HEALTHCHECK --interval=1s --retries=300 CMD curl -f http://localhost:9200/_xpack/license
17:42:59  ---> Using cache
17:42:59  ---> 92eb12fcce35
17:42:59 Successfully built 92eb12fcce35
17:42:59 Successfully tagged metricbeatb8f075ca3ba9f0ca8d77c37c7ab1a9ce06333331_elasticsearch:latest
17:42:59 Recreating metricbeatb8f075ca3ba9f0ca8d77c37c7ab1a9ce06333331_elasticsearch_1 ... 
17:42:59 
17:42:59 Recreating metricbeatb8f075ca3ba9f0ca8d77c37c7ab1a9ce06333331_elasticsearch_1 ... done
17:42:59 FAIL
17:42:59 coverage: 14.4% of statements
17:42:59 FAIL   github.com/elastic/beats/metricbeat/module/elasticsearch    163.051s

[sayden]

The error originates here #L81 so it might be something related with the setup of CCR, specifically an EOF when setting up the follower index #L278.

Once it fails, all failures here #L89 and here #L90 after it seems related

[elasticmachine]

Pinging @elastic/stack-monitoring

[cachedout]

@sayden I did not have a lot of luck reproducing this but I take a crack at a mitigation attempt here: https://github.com/elastic/beats/pull/10939

I can't guarantee this will fix it but it should not do much harm.

cc: @ycombinator

[ruflin]

@cachedout Some Elasticsearch test errors went away when I commented out the ccr tests. Not sure if it's related.

[cachedout]

@ruflin Hmm. I have seen other issues around those tests in recent days. I, too, suspect that something funny is going on with them.

[ycombinator]

I also couldn't exactly reproduce the EOF error that's reported in this issue. However, while investigating this issue, I did find another potential source of flakiness, which I'm trying to address in https://github.com/elastic/beats/pull/11172.

[ycombinator]

I did some more testing here. It appears that the EOF error happens when the ES docker container has started up but the ES process in the container itself hasn't completely started up. If the ES integration test starts making ES REST API calls in this time window, the EOF error happens.

[ycombinator]

I'm going to be debugging the ES test flakiness over here in this draft PR: https://github.com/elastic/beats/pull/11224

[cachedout]

@ycombinator Since you have a PR up, I reassigned this. Please let me know if that's all right.

[ycombinator]

@sayden The flaky tests mentioned in this issue have been un-skipped since June 4. AFAICT there haven't been any flakiness issues since then. Are you okay resolving this issue now?

[ycombinator]

@sayden I'm closing this issue per my previous comment. If you disagree, feel free to reopen.