Reloading telegraf prevents prometheus output from updating

[cosmopetrich]

Bug report

Reloading telegraf via a SIGHUP appears to prevent the output from the prometheus_client plugin from updating, even though telegraf itself continues to collect metrics as normal.

Relevant telegraf.conf:

The config below can be used to replicate the issue. The same symptoms occur when using 'real' metrics (CPU, mem, etc).

[agent]
  interval = "5s"
  round_interval = true
  metric_buffer_limit = 1000
  flush_buffer_when_full = true
  collection_jitter = "0s"
  flush_interval = "10s"
  flush_jitter = "0s"
  debug = true
  quiet = false

[[outputs.prometheus_client]]
  listen = ":9126"

[[inputs.exec]]
commands = ['/bin/bash -c "echo testmetric $(date +%s) $(date +%s)"']
data_format = "graphite"

System info:

Telegraf 1.1.1 & 1.1.2 on Ubuntu 14.04.

I built 1.2 from source to see if the changes to prometheus_client caching would have any impact, but the issue still appears to be present there.

Steps to reproduce:

1. Start telegraf with the config above, then hit the prometheus endpoint periodically.

   date +%s && curl -s localhost:9126/metrics | grep ^testmetric

   Telegraf's metric will be within a couple of seconds of the real time.

2. Reload telegraf.

   date +%s && service telegraf reload

3. Start hitting the prometheus endpoint again, the testmetric will remain as it was before the reload, even hours later.

   Telegraf itself will still report the correct value when called with -test.

   date +%s && telegraf -test | grep testmetric

Additional info:

There were previously reload-related issues with the prometheus_client plugin that were fixed in #1753.

Here's some sample debug log entries before/after a reload.

2017/01/18 01:05:15 I! Output [prometheus_client] buffer fullness: 2 / 1000 metrics. Total gathered metrics: 763. Total dropped metrics: 0.
2017/01/18 01:05:15 I! Output [prometheus_client] wrote batch of 2 metrics in 94.555µs
2017/01/18 01:05:17 I! Reloading Telegraf config
2017/01/18 01:05:17 I! Hang on, flushing any cached metrics before shutdown
2017/01/18 01:05:17 I! Output [prometheus_client] buffer fullness: 0 / 1000 metrics. Total gathered metrics: 763. Total dropped metrics: 0.
2017/01/18 01:05:17 D! Attempting connection to output: prometheus_client
2017/01/18 01:05:17 D! Successfully connected to output: prometheus_client
2017/01/18 01:05:17 I! Starting Telegraf (version 1.1.2)
2017/01/18 01:05:17 I! Loaded outputs: prometheus_client
2017/01/18 01:05:17 I! Loaded inputs: inputs.exec
2017/01/18 01:05:17 I! Tags enabled: host=XXX
2017/01/18 01:05:17 I! Agent Config: Interval:5s, Quiet:false, Hostname:"XXX", Flush Interval:10s
2017/01/18 01:05:20 D! Input [inputs.exec] gathered metrics, (5s interval) in 4.174276ms
2017/01/18 01:05:25 D! Input [inputs.exec] gathered metrics, (5s interval) in 4.201608ms
2017/01/18 01:05:30 D! Input [inputs.exec] gathered metrics, (5s interval) in 4.124453ms
2017/01/18 01:05:30 I! Output [prometheus_client] buffer fullness: 3 / 1000 metrics. Total gathered metrics: 3. Total dropped metrics: 0.
2017/01/18 01:05:30 I! Output [prometheus_client] wrote batch of 3 metrics in 107.546µs

[cosmopetrich]

Here's an example from prometheus. This shows a few hours of cpu_idle data for a number of telegraf instances which received a config update via puppet that triggered a reload.

[sparrc]

I've got a PR to fix this, but it requires Go version 1.8: #2309

As soon as Go 1.8 is released I will get that merged into master and it will be ready for the 1.3 telegraf release, or possibly a 1.2.1+ telegraf release

[cosmopetrich]

Great, thanks for the fast response!