collected metric ... was collected before with the same name and label values

[MrRothstein]

I'm saw this error with rc48. It went away after restart, and when I looked at the source of the metric in question (from /json), I see two sources from the same program (lines 1 and 11). The program is 9 lines long... Is it possible reloading mtail using "kill -SIGHUP $(pidofproc $PROGNAME)" caused it to load the program twice somehow?

[jaqx0r]

Its certainly possible, though what's supposed to happen is the metric objects get reused when the program loads. This error says there's two programs using the same metrics. So my guess is a race condition during program reload, if there's a log line that matches that coincides. I'm away from the keyboard but will investigate further when I return. If you'd like to follow the debugging guide in the meantime you're more than welcome.

…

On Fri, 15 Apr 2022, 07:31 MrRothstein, ***@***.***> wrote: I'm saw this error with rc48. It went away after restart, and when I looked at the source of the metric in question (from /json), I see two sources from the same program (lines 1 and 11). The program is 9 lines long... Is it possible reloading mtail using "kill -SIGHUP $(pidofproc $PROGNAME)" caused it to load the program twice somehow? — Reply to this email directly, view it on GitHub <#636>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAXFX6YZ4U4S5IE3IWW7Z23VFCFDRANCNFSM5TO6B2DA> . You are receiving this because you are subscribed to this thread.Message ID: ***@***.***>

[MrRothstein]

I think I see what happened. The previous version of the program did declare the same variable on line 11. So, the following appears to have happened:

1. A program declares a counter on line 11
2. Metrics are generated with the counter
3. A program is updated with a version where the counter is declared on line 1
4. Mtail is reloaded, but metrics still include the counter sourced from line 11
5. Metrics are generated with the counter on line 1
6. Prometheus receives 500 response trying to scrape "metric ... was collected before with the same name and label values"

Not sure if this is correct or the expected behavior

[jaqx0r]

Oh that's interesting, the variable moved places? Yes I can see how that would trigger the error! That's not ideal behaviour. I'll see what we can do about it and try to preserve the intent of the check.

…

On Fri, 15 Apr 2022, 09:47 MrRothstein, ***@***.***> wrote: I think I see what happened. The previous version of the program did declare the same variable on line 11. So, the following appears to have happened: 1. A program declares a counter on line 11 2. Metrics are generated with the counter 3. A program is updated with a version where the variable is declared on line 1 4. Mtail is reloaded, but metrics still include the counter sourced from line 11 5. Metrics are generated with the counter on line 1 6. Prometheus receives 500 response trying to scrape "metric ... was collected before with the same name and label values" Not sure if this is correct or the expected behavior — Reply to this email directly, view it on GitHub <#636 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAXFX6YNHUZGUYMGWAJZT43VFCU7ZANCNFSM5TO6B2DA> . You are receiving this because you commented.Message ID: ***@***.***>

[MrRothstein]

This fails (adds two metrics):

func TestSameMetricWithDifferentSourcePositions(t *testing.T) {
 expectedMetrics := 1
 s := NewStore()
 firstPositionMetric := NewMetric("foo", "prog", Counter, Int)
 firstPositionMetric.SetSource("some_source.mtail:1:9-50")
 _ = s.Add(firstPositionMetric)

 secondPositionMetric := NewMetric("foo", "prog", Counter, Int)
 secondPositionMetric.SetSource("some_source.mtail:2:9-50")
 _ = s.Add(secondPositionMetric)
 glog.Infof("Store: %v", s)
 if len(s.Metrics["foo"]) != expectedMetrics {
     t.Fatalf("should not add metric with different source position: %v", s)
 }
}

It looks like the dupe check is skipped for metrics where the sources are different, but the check does not differentiate between the program being different or only the position:

mtail/internal/metrics/store.go

Line 56 in bba4c70

if v.Source != m.Source {

I don't see a "FromString" type function available for Position and I'm not completely sure if the source and position represent the same thing. If this is the issue, would it make sense to convert Source in Metric from string to Position and compare only the file name during the dupe check?