StatsD metrics are not emitted on shutdown

[gordon-rennie]

I am raising this issue to track the problem and initial findings and intend to raise it as an issue with micrometer.

Summary

Counters incremented near application shutdown are not emitted when using StatsD. (I have not tested gauges or timers, they may also be affected).

Code Analysis

It appears the metrics are being buffered within micrometer and aren't flushed when the resources are torn down. Meters4s appears to be correctly shutting down the micrometer objects by calling .close:

meters4s/statsd/src/main/scala/com/ovoenergy/meters4s/statsd/StatsD.scala

Line 93 in 5b496cc

)(toClose => Sync[F].delay(toClose.close))

Repro

The issue can be reproduced along the lines of this gist, including running a local mock DataDog UDP server.

As an example, I can see the application outputs:

[info] Emitted counter metric of name "375"
[info] Emitted counter metric of name "467"
[info] Emitted counter metric of name "567"
... # redacted
[info] Emitted counter metric of name "2268"
[info] Emitted counter metric of name "2367"
[info] Emitted counter metric of name "2468"
[info] Emitted counter metric of name "2567"
[info] Emitted counter metric of name "2668"
[info] Emitted counter metric of name "2767"
[info] Emitted counter metric of name "2867"
[info] Emitted counter metric of name "2967"
[info] Emitted counter metric of name "3067"
[info] Emitted counter metric of name "3167"
[info] Emitted counter metric of name "3267"
[info] -------------------------------
[info] stopping after 30 metrics

But the mock server does not receive the final metrics:

gordon.375:1|c|#statistic:count,tag:test
gordon.467:1|c|#statistic:count,tag:test
gordon.567:1|c|#statistic:count,tag:test
... # redacted
gordon.2067:1|c|#statistic:count,tag:test
gordon.2167:1|c|#statistic:count,tag:test
gordon.2268:1|c|#statistic:count,tag:test
gordon.2367:1|c|#statistic:count,tag:test
gordon.2468:1|c|#statistic:count,tag:test
# end of output

Reproduced On

meters4s 1.3.1, micrometer 1.9.8 (bundled with meters4s release) and 1.11.0-RC1 and latest.integration on 4th May 1930 BST

To Investigate

micrometer has open issue micrometer-metrics/micrometer#2141. It was suggested it may have been resolved by other, recently fixed, issue micrometer-metrics/micrometer#1882. However the fact that the latest micrometer builds do not resolve the problem indicates not; I haven't had time to dive into the micrometer metrics class hierarchy yet to understand what was fixed.

Workarounds

I found the following resolved the problem:

• adding a magic sleep that exceeds the configured polling time after the last metric call
• OR setting buffered = false in the StatsD config (with performance impact)