Fix metrics registering #1258

matevzmihalic · 2017-03-08T14:36:33Z

Functions prometheus.NewCounterFrom and prometheus.NewHistogramFrom are using stdprometheus.MustRegister which will panic if you try to register the same metric multiple times.

Because of this you would get Error in Go routine: duplicate metrics collector registration attempted when traefik tries to update configuration and new services will not get added.

With this fix traefik will use already registered metrics if that happens.

emilevauge · 2017-03-08T16:41:13Z

@matevzmihalic I think it would be better to rebase this PR on branch v1.2 in order to get this in the next release :)

matevzmihalic · 2017-03-08T17:22:29Z

Rebased to v1.2

timoreimann

Nice catch! I also ran into this problem but couldn't identify the cause immediately.

Could we maybe add some testing for the new functionality?

matevzmihalic · 2017-03-09T08:59:56Z

Added tests

emilevauge

Great job @matevzmihalic, thanks a lot :)
LGTM!

timoreimann · 2017-03-09T10:55:49Z

middlewares/prometheus_test.go

+	n.ServeHTTP(recorder, req2)
+
+	body = recorder.Body.String()
+	re := regexp.MustCompile(`(?m)traefik_requests_total.*?(\d)$`)


This test seems to be testing the implementation of the metrics handler. While I'm all in favor of doing that, I believe it should go into (the yet missing) metrics_test.go.

More importantly though, I'd probably test it differently by means of comparing the counter label name and value of the underlying LabelPair. Doing a regular expression to extract the number of total requests is somewhat brittle since we rely on an implementation detail of Prometheus that could change in a future version.

My proposal would be to remove this part of the test and leave it for another PR (which I'd be happy to do as well). I think the next test paragraph covers what we want to achieve with the PR at hand.

timoreimann · 2017-03-09T10:56:25Z

middlewares/prometheus_test.go

+	}
+
+	metrics, _ := prometheus.DefaultGatherer.Gather()
+	if metrics[len(metrics)-1].Metric[0].GetCounter().GetValue() != 3 {


One thing I don't understand: Why do we expect a total request count of 2 in line 61 and 3 here? Can you explain? I suppose I'm missing something.

First we make 2 requests, then we make another request (line 57) which outputs metrics and after that the counter gets updated to 3.

Since the request happens on line 57, I'd have expected the check on line 61 to also compare against 3; however, it expects 2.

What am I missing?

At the time when request 3 happens the counter still has value 2 and this value is outputted to body (which is used in comparison on line 61). Only after that the counter increases. (But this doesn't really matter because I will remove the regex check.)

timoreimann · 2017-03-09T10:59:25Z

middlewares/prometheus_test.go

+	metrics, _ := prometheus.DefaultGatherer.Gather()
+	if metrics[len(metrics)-1].Metric[0].GetCounter().GetValue() != 3 {
+		t.Error("gathered metrics does not contain correct value for total requests")
+	}


Can we extend the test to also cover the Histogram tracking the request duration? I think we can use the Histogram SampleCount to assert on.

timoreimann · 2017-03-09T10:59:53Z

middlewares/prometheus_test.go

+		t.Error("body does not contain correct value for total requests")
+	}
+
+	metrics, _ := prometheus.DefaultGatherer.Gather()


Can we check the error and panic if it's non-nil? It's basically an invariant we want to ensure.

Can we rename metrics to metricsFamily? This will make understanding the next line easier I think.

matevzmihalic · 2017-03-09T12:20:32Z

I've added labels tests and histogram test.

timoreimann · 2017-03-09T12:30:53Z

middlewares/prometheus_test.go

+
+	metricsFamily, err := prometheus.DefaultGatherer.Gather()
+	if err != nil {
+		t.Error(err)


Please change to

t.Fatalf("could not gather metrics family: %s", err)

Fatal because we shouldn't try to continue the test if we cannot even gather the metrics family.

Hum, I really do not agree on this. Why would Traefik stop because of this?

To be clear: this isn't about Traefik stopping; it's about the test bailing out because the remainder of it relies upon the metric family being available.

Oops... Again, read too quickly sorry... I didn't see it was in a test...

timoreimann · 2017-03-09T12:33:28Z

middlewares/prometheus_test.go

+	}
+
+	if reqsMetricFamily == nil {
+		t.Errorf("gathered metrics doesn not contain request total entry '%s'", reqsName)


Typo: doesn -> doesn't.

timoreimann · 2017-03-09T12:35:16Z

middlewares/prometheus_test.go

+	}
+
+	if latencyMetricFamily == nil {
+		t.Errorf("gathered metrics doesn not contain request duration entry '%s'", latencyName)


Repeated typo.

timoreimann · 2017-03-09T12:37:14Z

middlewares/prometheus_test.go

+	}
+
+	if reqsMetricFamily == nil {
+		t.Errorf("gathered metrics does not contain request total entry '%s'", reqsName)


Grammar: do not

timoreimann · 2017-03-09T12:37:23Z

middlewares/prometheus_test.go

+	}
+
+	if latencyMetricFamily == nil {
+		t.Errorf("gathered metrics does not contain request duration entry '%s'", latencyName)


Grammar: do not

timoreimann · 2017-03-09T12:40:53Z

middlewares/prometheus_test.go

+	}
+
+	if reqsMetricFamily.Metric[0].Counter.GetValue() != 3 {
+		t.Error("gathered metrics does not contain correct value for total requests")


Let's do t.Errorf here and include the actual counter value.

timoreimann · 2017-03-09T12:41:05Z

middlewares/prometheus_test.go

+	}
+
+	if latencyMetricFamily.Metric[0].Histogram.GetSampleCount() != 3 {
+		t.Error("gathered metrics does not contain correct sample count for request duration")


Let's do t.Errorf here and include the actual sample count value.

timoreimann · 2017-03-09T12:54:23Z

middlewares/prometheus_test.go

+		labels       map[string]string
+	}{
+		{
+			reqsName,


Could you please add the struct field names on each line, i.e., name: reqsName here? This improves readability and pleases some linters.

timoreimann · 2017-03-09T15:09:01Z

middlewares/prometheus_test.go

+		}
+	}
+
+	if reqsMetricFamily == nil {


The test in its current implementation has two shortcomings:

If reqsMetricFamily here (or latencyMetricFamily later) is nil, we still continue with the test execution. At best, this leads to follow-up test errors that we should not have to care about but will aggravate interpreting the test result. At worst, we run into nil pointer dereferences in lines 106, 117, and/or 121.

We cannot easily ignore/shortcut an individual nil case given the chosen test design.

There are a few options to fix this. Here's the one I prefer:

Rename the expectedLabelsForMetricFamily struct into tests and have it include a custom assert field of type func(*dto.MetricFamily). This function is supposed to implement the check in line 117 for the reqsMetricFamily case and the one in line 121 for latencyMetricFamily. (The idea is somewhat similar to the parserFunc in this test.)

Move the lookup of the metric families by metric name into the test loop (i.e., between line 105 and 106). This way, we can t.Errorf and continue the loop if we cannot find a metric family. Also, we can move the metricFamily variable from the test struct to the stack inside the loop.

Execute assert in the loop, passing it the metric family we just looked up.

I'd also suggest to move the lookup functionality into a small helper function, i.e., findMetricFamily(name string, families []*dto.MetricFamily) *dto.MetricFamily.

timoreimann · 2017-03-09T15:14:20Z

middlewares/prometheus_test.go

+				"service": "test",
+			},
+		},
+	}


Right after the definition of the test cases, I think we should do a check between the number of metric families we found and the number of test cases we have. This way, we can catch the situation where have added a new metric without updating the test.

matevzmihalic · 2017-03-10T10:43:28Z

Updated tests with your suggestions.

timoreimann

Superb job, @matevzmihalic -- thanks for bearing with me.

LGTM! 🎉

timoreimann · 2017-03-10T13:14:31Z

Syncing with master via Github UI and merging afterwards if CI goes green.

timoreimann · 2017-03-10T20:35:48Z

Rebased like a good Traefik citizen (and squashed those fixup commits). :-)

matevzmihalic force-pushed the fix/metrics branch from d180b08 to 587e268 Compare March 8, 2017 17:15

matevzmihalic changed the base branch from master to v1.2 March 8, 2017 17:16

matevzmihalic force-pushed the fix/metrics branch from 587e268 to 3597105 Compare March 8, 2017 17:20

emilevauge added the status/2-needs-review label Mar 8, 2017

timoreimann self-requested a review March 8, 2017 17:54

timoreimann reviewed Mar 9, 2017

View reviewed changes

matevzmihalic force-pushed the fix/metrics branch from f7accdb to f4bdfbd Compare March 9, 2017 08:56

emilevauge approved these changes Mar 9, 2017

View reviewed changes

timoreimann suggested changes Mar 9, 2017

View reviewed changes

matevzmihalic force-pushed the fix/metrics branch from 0cb2a15 to 1629839 Compare March 9, 2017 12:35

timoreimann suggested changes Mar 9, 2017

View reviewed changes

timoreimann approved these changes Mar 10, 2017

View reviewed changes

emilevauge added status/3-needs-merge and removed status/2-needs-review labels Mar 10, 2017

Fix metrics registering

b5de37e

timoreimann force-pushed the fix/metrics branch from ce67ee3 to b5de37e Compare March 10, 2017 20:27

timoreimann merged commit c582ea5 into traefik:v1.2 Mar 11, 2017

emilevauge mentioned this pull request Mar 14, 2017

v1.2.0-rc2 traefik does not respond to kubernetes ingress create/delete events #1251

Closed

This was referenced Mar 15, 2017

Possible bug using --web.metrics.prometheus #1261

Closed

Error in Go routine: duplicate metrics collector registration attempted. 502 Gateway error on every request. #1146

Closed

ldez added the kind/bug/fix a bug fix label May 2, 2017

ldez added this to the 1.2 milestone May 19, 2017

ldez removed the status/3-needs-merge label May 19, 2017

ldez added the area/middleware/metrics label May 25, 2017

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix metrics registering #1258

Fix metrics registering #1258

matevzmihalic commented Mar 8, 2017

emilevauge commented Mar 8, 2017

matevzmihalic commented Mar 8, 2017

timoreimann left a comment

matevzmihalic commented Mar 9, 2017

emilevauge left a comment

timoreimann Mar 9, 2017

timoreimann Mar 9, 2017

matevzmihalic Mar 9, 2017

timoreimann Mar 9, 2017

matevzmihalic Mar 9, 2017

timoreimann Mar 9, 2017

timoreimann Mar 9, 2017

timoreimann Mar 9, 2017

matevzmihalic commented Mar 9, 2017

timoreimann Mar 9, 2017

emilevauge Mar 9, 2017

timoreimann Mar 9, 2017

emilevauge Mar 9, 2017

timoreimann Mar 9, 2017

timoreimann Mar 9, 2017

timoreimann Mar 9, 2017

timoreimann Mar 9, 2017

timoreimann Mar 9, 2017

timoreimann Mar 9, 2017

timoreimann Mar 9, 2017

timoreimann Mar 9, 2017 •

edited

Loading

timoreimann Mar 9, 2017

matevzmihalic commented Mar 10, 2017

timoreimann left a comment

timoreimann commented Mar 10, 2017

timoreimann commented Mar 10, 2017

Fix metrics registering #1258

Fix metrics registering #1258

Conversation

matevzmihalic commented Mar 8, 2017

emilevauge commented Mar 8, 2017

matevzmihalic commented Mar 8, 2017

timoreimann left a comment

Choose a reason for hiding this comment

matevzmihalic commented Mar 9, 2017

emilevauge 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

matevzmihalic commented Mar 9, 2017

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

timoreimann Mar 9, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

matevzmihalic commented Mar 10, 2017

timoreimann left a comment

Choose a reason for hiding this comment

timoreimann commented Mar 10, 2017

timoreimann commented Mar 10, 2017

timoreimann Mar 9, 2017 •

edited

Loading