Consistency in Elastic stack metricsets' code #8308

ycombinator · 2018-09-13T18:59:42Z

This PR makes error messages, reporting, and logging consistent across all metricsets for Elastic stack products, including the xpack monitoring code paths:

andrewkroh · 2018-09-13T20:46:15Z

metricbeat/module/elasticsearch/cluster_stats/cluster_stats.go

@@ -57,25 +56,35 @@ func New(base mb.BaseMetricSet) (mb.MetricSet, error) {
 func (m *MetricSet) Fetch(r mb.ReporterV2) {
 	isMaster, err := elasticsearch.IsMaster(m.HTTP, m.HostData().SanitizedURI+clusterStatsPath)
 	if err != nil {
-		r.Error(fmt.Errorf("Error fetching master info: %s", err))
+		msg := errors.Wrap(err, "error determining if connected Elasticsearch node is master.")


Errors strings should not end with punctuation. https://github.com/golang/go/wiki/CodeReviewComments#error-strings.

andrewkroh · 2018-09-13T20:54:04Z

metricbeat/module/elasticsearch/metricset.go

 	return &MetricSet{
 		base,
 		http,
 		config.XPack,
+		log,


You might as will inline the logp.NewLogger statement.

andrewkroh · 2018-09-13T20:58:54Z

metricbeat/module/elasticsearch/index_recovery/index_recovery.go

@@ -92,11 +92,15 @@ func (m *MetricSet) Fetch(r mb.ReporterV2) {
 	}

 	if m.MetricSet.XPack {
-		eventsMappingXPack(r, m, content)
+		err = eventsMappingXPack(r, m, content)


This error is never reported. Is that intentional?

Yeah, we don't want to report X-Pack errors because they would end up in the metricbeat-* index, not the .monitoring-* index which is where all the "success" documents go.

Obviously this is something we want to change at some point, but for now we're just trying to achieve parity with existing documents in .monitoring-*.

andrewkroh · 2018-09-13T20:59:37Z

metricbeat/module/elasticsearch/index_recovery/index_recovery.go

 	} else {
 		err = eventsMapping(r, content)
 		if err != nil {
 			r.Error(err)
 		}
 	}
+
+	if err != nil {
+		m.Log.Error(err)


Why are the reporting and logging handled separately?

Mainly because we want to log x-pack and non-xpack errors but want to report only non-xpack errors. I agree, it's not very pleasant.

andrewkroh · 2018-09-13T21:01:29Z

metricbeat/module/elasticsearch/index_recovery/data.go

@@ -20,6 +20,11 @@ package index_recovery
 import (
 	"encoding/json"

+	"github.com/elastic/beats/metricbeat/helper/elastic"


This import should be grouped with the other github.com/elastic imports.

andrewkroh · 2018-09-13T21:02:58Z

metricbeat/module/elasticsearch/index/index.go

+	err = eventsMapping(r, *info, content)
+	if err != nil {
+		r.Error(err)
+		m.Log.Error(err)


This seems like a common pattern. I wonder if it would make sense to have the Metricbeat framework log any error that is reported by a metricset.

I was wondering this too but I have a fairly narrow and relatively recent view in Metricbeat. I'll defer to folks who've worked more broadly in it than me for their opinion: @jsoriano @ruflin, your thoughts?

It would definitively nice to make this more generic.

Best in a follow up PR.

andrewkroh · 2018-09-13T21:03:57Z

metricbeat/module/elasticsearch/cluster_stats/cluster_stats.go

 		return
 	}

 	if m.MetricSet.XPack {
-		eventMappingXPack(r, m, content)
+		err = eventMappingXPack(r, m, content)


This error is never reported. Is that intentional?

Yes, xpack data structure cannot make sense of the errors.

andrewkroh · 2018-09-13T21:10:54Z

metricbeat/module/elasticsearch/elasticsearch.go

@@ -32,6 +32,9 @@ import (
 // Global clusterIdCache. Assumption is that the same node id never can belong to a different cluster id
 var clusterIDCache = map[string]string{}

+// ModuleName is the ame of this module


s/ame/name/

And godocs should have proper punctuation. Wouldn't it be nicer if the descriptions here ended in punctuation. 😄

andrewkroh · 2018-09-13T21:20:56Z

metricbeat/module/elasticsearch/index/data.go

@@ -58,16 +59,14 @@ func eventsMapping(r mb.ReporterV2, info elasticsearch.Info, content []byte) err

 	err := json.Unmarshal(content, &indicesStruct)
 	if err != nil {
-		r.Error(err)
-		return err
+		return errors.Wrap(err, "failure parsing Elasticsearch Stats API response")
 	}

 	var errors multierror.Errors
 	for name, index := range indicesStruct.Indices {
 		event := mb.Event{}
 		event.MetricSetFields, err = schema.Apply(index)


The event can also contain an error. I think it would make sense to store/report the error alongside the data that it's associated with.

I think this is now solved with the more resent commits?

ycombinator · 2018-09-13T22:51:29Z

Good stuff, @andrewkroh. Appreciate the early feedback so I don't have to make the same fixes in a number of places later 😄!

ycombinator · 2018-09-19T00:03:10Z

CI is failing because of unrelated flaky test: #8208

ycombinator · 2018-09-29T01:15:29Z

@ruflin @andrewkroh The CI intake job is failing with this error:

18:08:40 ./module/elasticsearch/elasticsearch_integration_test.go
18:08:40 Code differs from goimports' style ^
18:08:40 ../libbeat/scripts/Makefile:115: recipe for target 'check' failed

I checked the imports in elasticsearch_integration_test.go and I'm not seeing anything odd. I didn't even mess with the imports in that file in is PR 😄 Could you help me figure out what I'm missing? Thanks.

ruflin · 2018-10-01T08:54:44Z

Can you try to run make fmt to see if you get a diff?

…#8497) This PR makes the Metricbeat `logstash` module code consistent with other Elastic stack modules by: * using `FetchContent()` instead of `FetchJSON()` to fetch data from LS APIs before passing it to the event mapping function. * adding unit tests. Further consistency around event reporting and error handling will be achieved in #8308.

ycombinator · 2018-10-01T19:14:41Z

Can you try to run make fmt to see if you get a diff?

@ruflin I did get a diff but it was in a file completely unrelated to this PR or the error shown by the intake job in CI. Still I tried to commit that diff in da30d94 but it didn't help either.

ruflin · 2018-10-01T19:15:23Z

Which go version do you have locally?

ycombinator · 2018-10-01T19:16:29Z

1.11 😬 Let me try downgrading to 1.10.

ruflin · 2018-10-01T19:17:03Z

Yes, 1.10 will do different indentations I learned today.

ruflin

Glad to see much more user friendly error messages. Very nice to have everything on v2Reporter now. Thanks for doing all this cleanup. Left some minor comments.

The discussion around error reporting is more general for modules / metricbeat not only the stack modules. We can also delay it.

ruflin · 2018-10-02T18:48:56Z

metricbeat/module/elasticsearch/cluster_stats/cluster_stats.go

 		return
 	}

 	if m.MetricSet.XPack {
-		eventMappingXPack(r, m, content)
+		err = eventMappingXPack(r, m, content)


Yes, xpack data structure cannot make sense of the errors.

ruflin · 2018-10-02T18:51:15Z

metricbeat/module/elasticsearch/index/data.go

 	for name, index := range indicesStruct.Indices {
 		event := mb.Event{}
 		event.MetricSetFields, err = schema.Apply(index)
 		if err != nil {
-			r.Error(err)
-			errors = append(errors, err)
+			errs = append(errs, errors.Wrap(err, "failure applying index schema"))


I think we should keep the old behaviour that we have 1 error per index. +1 on what andrew suggestions above.

+1 to reporting 1 error per event, but only in the non-xpack code paths (since reporting errors into xpack indices doesn't make sense, at least today). I will fix all non-xpack code paths in this PR to go back to reporting 1 error per event.

ruflin · 2018-10-02T18:52:18Z

metricbeat/module/elasticsearch/index/index.go

-		eventsMappingXPack(r, m, *info, content)
+		err = eventsMappingXPack(r, m, *info, content)
+		if err != nil {
+			m.Log.Error(err)


This should make debugging easier. I wonder if we should do it really on the Error level or only Info or Debug. Reasons is that I assume also when Elasticsearch is down, an Error is logged but it's not an error in the sense of the Error log I would argue.

I definitely don't think Info, because then it would get logged all the time? I can see the argument both ways for Error vs. Debug. I'd rather keep it at Error because we only log it if something has gone wrong. Whereas Debug logging tends to happen regardless, just to provide additional detail.

Why would info get logged all the time?

I think I might've misunderstood. When you suggested using Info, I thought you meant something like this:

err = eventsMappingXPack(r, m, *info, content) m.Log.Info(err)

Notice, no if check.

But I guess we could still log at Info level while keeping the if check. Still, feels a bit odd to me that we'd log errors at Info level. err could contain "fake" errors like ES being down but err could also contain a real error like a parsing error that happened inside eventsMappingXPack.

ruflin · 2018-10-02T18:54:34Z

metricbeat/module/elasticsearch/index_recovery/data_xpack.go

@@ -38,23 +41,23 @@ func eventsMappingXPack(r mb.ReporterV2, m *MetricSet, content []byte) error {
 	for indexName, indexData := range data {
 		indexData, ok := indexData.(map[string]interface{})
 		if !ok {
-			continue
+			return fmt.Errorf("%v is not a map", indexName)


This is a change in behaviour. Should we really skip all metrics if one is wrong? Same for the things below.

It is probably unlikely that one is wrong and the others are not?

My thinking with the new approach is:

It's unlikely that one is wrong and others are not, and also

In the case when some data might be erroneous, is it better to make a best effort or is it better to fail fast? I decided to go with the latter because I think it makes it easier to spot an issue.

The other way of looking at it: What if the data inside one index object is wiered and all the others are ok. It would mean we don't ship all the valid index data. Perhaps the solution is somewhere in between that we send just 1 error doc but still send the valid ones (I think you did that further down).

Let's move forward with the way it is at the moment and fix it if it breaks.

ruflin · 2018-10-02T18:55:39Z

metricbeat/module/elasticsearch/index_summary/data_xpack.go

 	}

-	nodeInfo, err := elasticsearch.GetNodeInfo(m.HTTP, m.HostData().SanitizedURI+statsPath, "")


Was this code obsolete or is that the one that will be fixed in an other PR?

It's obsolete because the monitoring UI does not need source_node for indices_stats documents.

ruflin · 2018-10-02T18:56:58Z

metricbeat/module/elasticsearch/ml_job/data.go

@@ -58,11 +60,12 @@ func eventsMapping(r mb.ReporterV2, content []byte) error {

 		event.MetricSetFields, err = schema.Apply(job)
 		if err != nil {
-			errs = append(errs, err)
+			errs = append(errs, errors.Wrap(err, "failure applying ml job schema"))


This is a change in behaviour as in case of an error, still an incomplete event was sent. We should discuss what our general expectation in modules here are.

I think this is the same as https://github.com/elastic/beats/pull/8308/files#r222085637.

ruflin · 2018-10-02T18:58:33Z

metricbeat/module/elasticsearch/node_stats/data.go

@@ -120,7 +121,8 @@ func eventsMapping(r mb.ReporterV2, content []byte) error {

 		event.MetricSetFields, err = schema.Apply(node)
 		if err != nil {
-			r.Error(err)
+			errs = append(errs, errors.Wrap(err, "failure to apply node schema"))


Change in behaviour. Instead of 5 errors now only 1 overall error is sent. We should discuss what our expectation here is.

Same as https://github.com/elastic/beats/pull/8308/files#r222085637.

ruflin · 2018-10-02T19:00:59Z

metricbeat/module/kibana/stats/data.go

 	}

 	dataFields, err := schema.Apply(data)
 	if err != nil {
-		r.Error(err)
+		return errors.Wrap(err, "failure to apply stats schema")


Ties into the discussion above on what our expecation on error is.

Yep, same as https://github.com/elastic/beats/pull/8308/files#r222085637. For non-xpack code paths (like this one here) I will update the PR to report one error per event.

ruflin · 2018-10-02T19:04:46Z

metricbeat/module/logstash/node_stats/node_stats_integration_test.go

 )

-func TestFetch(t *testing.T) {


I assume this is removed because of the reporter change. But I was not sure where this is covered now?

Yes, I removed this because Fetch no longer returns an event. And now this file is consistent with other Elastic stack integration test files; they also only have a TestData function that ultimately exercises Fetch via the mbtest.WriteEventsReporterV2 call in the test code.

TestData is not run by default in our tests. What I did for the Elasticsearch module you can find here: https://github.com/elastic/beats/blob/master/metricbeat/module/elasticsearch/elasticsearch_integration_test.go It basically imports all the metricsets with a fetcher and then runs the tests automatically. We should this here too for all the ones where TestFetch was removed.

ycombinator · 2018-10-02T20:09:31Z

@ruflin @andrewkroh I've attempted to address your review feedback around error reporting with events by making changes just to the elasticsearch/ccr metricset in 928d27b. Please take a look at this commit and let me know what you think. Once we agree on the pattern with this metricset, I'll apply the same pattern to other metricsets in this PR as well.

Specifically, I've tried to establish the following pattern in this sample commit:

For non-x-pack event parsing, report errors via the reporter v2 API. If the error is applicable to a single event, report it via the event's Error field.
For x-pack and non-x-pack event parsing alike, log errors.

ruflin · 2018-10-03T11:29:50Z

Normally I would ask you to split up this PR into multiple PR's. I think there are lots of parts that need no discussion and could be directly merged, like the additional log messages you added or introducing the logger. Like this a big part of the changes could already be merged and the discussion would be only holding back a small part of the PR. At the same time I see it would be quite a bit of work to extract the non controversial parts now.

…#8497) (#8525) This PR makes the Metricbeat `logstash` module code consistent with other Elastic stack modules by: * using `FetchContent()` instead of `FetchJSON()` to fetch data from LS APIs before passing it to the event mapping function. * adding unit tests. Further consistency around event reporting and error handling will be achieved in #8308. (cherry picked from commit 909d789)

ycombinator · 2018-10-03T12:45:05Z

@ruflin Initially this PR started out small but then it grew because at the time of development I wasn't sure how far these changes will cascade. But now that all metricsets are done and we've identified the parts we like (e.g. additional log messages + logger) I'm happy to extract out those parts into a separate PR to keep things moving. That will also make the controversial parts easier to discuss.

So I'm going to keep this PR open for the controversial parts, since there is discussion history building up here. But I will put up a separate PR(s) that will only handle better log messages and the logger. Let's get those "easy" PR(s) merged first, then come back to this PR (after rebasing it, etc.) for further discussion?

ycombinator · 2018-10-04T00:09:08Z

Per my previous comment, I've teased out just the error message consistency improvements into their own PR: #8551.

ycombinator · 2018-10-23T07:53:06Z

@ruflin Other PR (#8592) is merged into master and this PR has been rebased on master now. Ready for your 👀 again.

ruflin

I like the error logging / reporting model we have now in the Elasticsearch and Kibana Module. We should probably make that our standard when changing other modules.

ruflin · 2018-10-25T14:14:03Z

metricbeat/module/elasticsearch/ccr/data.go

 			event.MetricSetFields, err = schema.Apply(shard)
 			if err != nil {
-				errors = append(errors, err)
+				event.Error = errors.Wrap(err, "failure applying shard schema")


I like that we report partial documents events even on failure. We should probably document this somewhere.

ruflin · 2018-10-25T14:15:37Z

metricbeat/module/elasticsearch/index/data.go

@@ -58,16 +59,14 @@ func eventsMapping(r mb.ReporterV2, info elasticsearch.Info, content []byte) err

 	err := json.Unmarshal(content, &indicesStruct)
 	if err != nil {
-		r.Error(err)
-		return err
+		return errors.Wrap(err, "failure parsing Elasticsearch Stats API response")
 	}

 	var errors multierror.Errors
 	for name, index := range indicesStruct.Indices {
 		event := mb.Event{}
 		event.MetricSetFields, err = schema.Apply(index)


I think this is now solved with the more resent commits?

ruflin · 2018-10-25T14:17:25Z

metricbeat/module/elasticsearch/index/index.go

+	err = eventsMapping(r, *info, content)
+	if err != nil {
+		r.Error(err)
+		m.Log.Error(err)


It would definitively nice to make this more generic.

Best in a follow up PR.

ruflin · 2018-10-25T14:18:18Z

metricbeat/module/elasticsearch/index_recovery/data_xpack.go

@@ -38,23 +41,23 @@ func eventsMappingXPack(r mb.ReporterV2, m *MetricSet, content []byte) error {
 	for indexName, indexData := range data {
 		indexData, ok := indexData.(map[string]interface{})
 		if !ok {
-			continue
+			return fmt.Errorf("%v is not a map", indexName)


Let's move forward with the way it is at the moment and fix it if it breaks.

…de (#8755) Cherry-pick of PR #8308 to 6.x branch. Original message: This PR makes error messages, reporting, and logging consistent across all metricsets for Elastic stack products, including the xpack monitoring code paths: * [x] `elasticsearch/ccr` * [x] `elasticsearch/cluster_stats` * [x] `elasticsearch/index` * [x] `elasticsearch/index_recovery` * [x] `elasticsearch/index_summary` * [x] `elasticsearch/ml_job` * [x] `elasticsearch/node` * [x] `elasticsearch/node_stats` * [x] `elasticsearch/pending_tasks` * [x] `elasticsearch/shard` * [x] `kibana/status` * [x] `kibana/stats` * [x] `logstash/node` * [x] `logstash/node_stats`

The cleanup in #8308 introduced a regression which caused the `xpack.enabled` flag in the `kibana` module to stop having any effect. This PR fixes that issue by reverting the troublesome bits from #8308, ensuring that the struct field for the parsed configuration setting is exported.

Cherry-pick of PR #9642 to 6.x branch. Original message: The cleanup in #8308 introduced a regression which caused the `xpack.enabled` flag in the `kibana` module to stop having any effect. This PR fixes that issue by reverting the troublesome bits from #8308, ensuring that the struct field for the parsed configuration setting is exported.

ycombinator added in progress Pull request is currently in progress. Metricbeat Metricbeat needs_backport PR is waiting to be backported to other branches. v7.0.0-alpha1 v6.5.0 labels Sep 13, 2018

andrewkroh reviewed Sep 13, 2018

View reviewed changes

ycombinator changed the title ~~Consistency in Elastic stack metricsets' error handling~~ Consistency in Elastic stack metricsets' code Sep 18, 2018

ycombinator mentioned this pull request Sep 29, 2018

Make logstash module code consistent with other Elastic stack modules #8497

Merged

ycombinator mentioned this pull request Oct 1, 2018

Cherry-pick #8497 to 6.x: Make logstash module code consistent with other Elastic stack modules #8525

Merged

ycombinator added review and removed in progress Pull request is currently in progress. labels Oct 2, 2018

ycombinator requested a review from ruflin October 2, 2018 11:12

ycombinator mentioned this pull request Oct 2, 2018

Use FetchJSON instead of FetchContent #8539

Closed

14 tasks

ruflin reviewed Oct 2, 2018

View reviewed changes

ycombinator added in progress Pull request is currently in progress. and removed review labels Oct 4, 2018

ycombinator added 17 commits October 23, 2018 00:51

Consistent code in elasticsearch/ccr metricset

e32d2b1

Making code in kibana module metricsets consistent

1e5c38d

Making fully-qualified metricset name consistent

2baf502

Use elasticsearch.ModuleName constant instead of string literal

a847e4e

Making logstash/node metricset code consistent

8701cb9

Making the logstash/node_stats metricset code consistent

c3631b4

Refactoring common reporting and error pattern into helper function

40f3406

Updating unit tests

acf6930

Changes from running make fmt

db6a2d2

Re-running make fmt after downgrading golang to 10.3

12a4015

Fixes due to make update

0befa82

Updating LS module integration tests

a864b21

Update kibana/status integration test

6b6bb3c

Report error with event (for non x-pack path)

5291885

Attaching errors to events

35447b1

Fixing imports in integration tests

3be2ae3

Fixing error

ab3a9ce

ruflin approved these changes Oct 25, 2018

View reviewed changes

ycombinator merged commit 3b2399d into elastic:master Oct 25, 2018

ycombinator deleted the metricbeat-xpack-log-errors branch October 25, 2018 21:23

ycombinator mentioned this pull request Oct 25, 2018

Cherry-pick #8308 to 6.x: Consistency in Elastic stack metricsets' code #8755

Merged

14 tasks

ycombinator added v6.6.0 and removed needs_backport PR is waiting to be backported to other branches. labels Oct 25, 2018

ycombinator mentioned this pull request Dec 18, 2018

Export field for xpack.enabled setting #9642

Merged

ycombinator mentioned this pull request Dec 19, 2018

Cherry-pick #9642 to 6.x: Export field for xpack.enabled setting #9655

Merged

erik-stephens mentioned this pull request Jan 3, 2019

Unable to metricbeat elasticsearch when xpack.watcher disabled #9875

Closed

		}

		nodeInfo, err := elasticsearch.GetNodeInfo(m.HTTP, m.HostData().SanitizedURI+statsPath, "")

Consistency in Elastic stack metricsets' code #8308

Consistency in Elastic stack metricsets' code #8308

Conversation

ycombinator commented Sep 13, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ycombinator Sep 13, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ycombinator commented Sep 13, 2018

ycombinator commented Sep 19, 2018

ycombinator commented Sep 29, 2018 • edited Loading

ruflin commented Oct 1, 2018

ycombinator commented Oct 1, 2018

ruflin commented Oct 1, 2018

ycombinator commented Oct 1, 2018

ruflin commented Oct 1, 2018

ruflin left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ycombinator commented Oct 2, 2018 • edited Loading

ruflin commented Oct 3, 2018

ycombinator commented Oct 3, 2018

ycombinator commented Oct 4, 2018

ycombinator commented Oct 23, 2018

ruflin left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ycombinator commented Sep 13, 2018 •

edited

Loading

ycombinator Sep 13, 2018 •

edited

Loading

ycombinator commented Sep 29, 2018 •

edited

Loading

ycombinator commented Oct 2, 2018 •

edited

Loading