Micrometer: Duplicate metrics

[monkeymq]

micrometer-registry-influx: 1.1.4

I think the problem of #53 still exist,

1557393683288000000 200 0 0.0.0.0:9999 0 histogram /de/v1/testtimeconsuming 0:0:0:0:0:0:0:1:63143 0 0
1557393683288000000 200 0 0.0.0.0:9999 0 histogram /de/v1/testtimeconsuming 0:0:0:0:0:0:0:1:63233 0 0
1557393673292000000 200 0 0.0.0.0:9999 0 histogram /de/v1/testtimeconsuming 0:0:0:0:0:0:0:1:63143 0 0
1557393673292000000 200 0 0.0.0.0:9999 0 histogram /de/v1/testtimeconsuming 0:0:0:0:0:0:0:1:63233 0 0
1557393663289000000 200 0 0.0.0.0:9999 0 histogram /de/v1/testtimeconsuming 0:0:0:0:0:0:0:1:63143 0 0
1557393663289000000 200 0 0.0.0.0:9999 0 histogram /de/v1/testtimeconsuming 0:0:0:0:0:0:0:1:63233 0 0
1557393653290000000 200 0 0.0.0.0:9999 0 histogram /de/v1/testtimeconsuming 0:0:0:0:0:0:0:1:63143 0 0
1557393653290000000 200 0 0.0.0.0:9999 0 histogram /de/v1/testtimeconsuming 0:0:0:0:0:0:0:1:63233 0 0

it will continually send some metrics to influxDB, could someone help me out?

[izeye]

@monkeymq Thanks for the report but I'm not sure which metrics are duplicate as none of rows you provided doesn't seem to be a duplicate each other. Am I missing something?

[monkeymq]

@izeye Thanks for the reply. Let me describe my issue in detail. I visited a URL /de/v1/testtimeconsuming, so you could see the local address x.x.x: 63143, obviously the same metrics data will appear every once in a while, even though the request is over, and these the same metrics data will continue to increase unless I close my app. So far I have found that the two metrics http_server_connections and http_server_responseTime are constantly being repeated.

[izeye]

@monkeymq Thanks for the quick feedback! Can you please share a sample project reproducing this via a GitHub repo or by attaching a zip to this issue? You seem to have one already based on the logs you provided.

[monkeymq]

Hi @izeye , since i can't post the internal code, so i wrote a sample as an attachment, but it also shows the problem. Send metrics data without interruption, as described previously. In the sample, the main code is in the Main.java. Thanks a lot.
MetricsDemo.zip

[izeye]

@monkeymq Thanks for the sample!

To try to understand this issue, I did the following:

• Run the sample.
• Hit the endpoint (/demo).
• Shutdown the sample after 6 metrics publiciations since the endpoint has been hit as follows:

03:55:04.503 [pool-1-thread-1] DEBUG io.micrometer.influx.InfluxMeterRegistry - successfully sent 58 metrics to InfluxDB.
03:55:14.502 [pool-1-thread-1] DEBUG io.micrometer.influx.InfluxMeterRegistry - successfully sent 58 metrics to InfluxDB.
03:55:24.506 [pool-1-thread-1] DEBUG io.micrometer.influx.InfluxMeterRegistry - successfully sent 58 metrics to InfluxDB.
03:55:34.505 [pool-1-thread-1] DEBUG io.micrometer.influx.InfluxMeterRegistry - successfully sent 58 metrics to InfluxDB.
03:55:44.498 [pool-1-thread-1] DEBUG io.micrometer.influx.InfluxMeterRegistry - successfully sent 58 metrics to InfluxDB.
03:55:54.500 [pool-1-thread-1] DEBUG io.micrometer.influx.InfluxMeterRegistry - successfully sent 58 metrics to InfluxDB.

Querying vertx_http_server_responseTime and vertx_http_server_requestCount measurements in InfluxDB, there are 6 rows respectively:

> select * from vertx_http_server_responseTime
name: vertx_http_server_responseTime
time                code count local        mean      metric_type path  remote                sum       upper
----                ---- ----- -----        ----      ----------- ----  ------                ---       -----
1557514504498000000 200  1     0.0.0.0:9999 22.514182 histogram   /demo 0:0:0:0:0:0:0:1:53408 22.514182 22.514182
1557514514493000000 200  0     0.0.0.0:9999 0         histogram   /demo 0:0:0:0:0:0:0:1:53408 0         22.514182
1557514524495000000 200  0     0.0.0.0:9999 0         histogram   /demo 0:0:0:0:0:0:0:1:53408 0         22.514182
1557514534496000000 200  0     0.0.0.0:9999 0         histogram   /demo 0:0:0:0:0:0:0:1:53408 0         0
1557514544492000000 200  0     0.0.0.0:9999 0         histogram   /demo 0:0:0:0:0:0:0:1:53408 0         0
1557514554493000000 200  0     0.0.0.0:9999 0         histogram   /demo 0:0:0:0:0:0:0:1:53408 0         0
> select * from vertx_http_server_requestCount
name: vertx_http_server_requestCount
time                code local        metric_type path  remote                value
----                ---- -----        ----------- ----  ------                -----
1557514504501000000 200  0.0.0.0:9999 counter     /demo 0:0:0:0:0:0:0:1:53408 1
1557514514497000000 200  0.0.0.0:9999 counter     /demo 0:0:0:0:0:0:0:1:53408 0
1557514524500000000 200  0.0.0.0:9999 counter     /demo 0:0:0:0:0:0:0:1:53408 0
1557514534500000000 200  0.0.0.0:9999 counter     /demo 0:0:0:0:0:0:0:1:53408 0
1557514544494000000 200  0.0.0.0:9999 counter     /demo 0:0:0:0:0:0:0:1:53408 0
1557514554496000000 200  0.0.0.0:9999 counter     /demo 0:0:0:0:0:0:0:1:53408 0
>

This seems to work as expected.

I'm not sure I understand this issue correctly. Could you explain what you expect for this in more details?

[checketts]

Perhaps @monkeymq is confused by the successfully sent 58 metrics to InfluxDB and they were assuming it wouldn't send any metrics when there isn't traffic for a given endpoint?

I believe that is how statsd/graphite behave so the fact the Micrometer uses an aggregate approach instead of sending each action confused them?

[monkeymq]

@izeye Thanks for reply. I think the problem is that if don't shutdown the sample, metrics like

1557514554493000000 200 0 0.0.0.0:9999 0 histogram /demo 0:0:0:0:0:0:0:1:53408 0

will continue to be written to influxDB, which may not be correct, because /demo is over, it should have no metrics data. Is my understanding right?

[shakuzen]

@monkeymq the Influx registry implementation aggregates metrics and sends them periodically, as @checketts mentioned. We document this in the Micrometer documentation for Influx:

Metrics are rate-aggregated and pushed to Influx on a periodic interval. Rate aggregation performed by the registry yields datasets that are quite similar to those produced by Telegraf.

It is sending values of 0 when there are no updates to the metrics, so it should not affect the accuracy of metrics in the backend.
Does this clear things up?

[monkeymq]

@izeye @checketts @shakuzen Thank you for your warm help. I didn't understand this sentence correctly befroe.

Metrics are rate-aggregated and pushed to Influx on a periodic interval. Rate aggregation performed by the registry yields datasets that are quite similar to those produced by Telegraf.

it's clear now and thanks again.

[izeye]

@monkeymq Thanks for the confirmation! Closing as answered.