one alert firing,but over two resloved message received

[gjpei2]

What did you do?
i am using Alertmanager HA in my cluster, sometimes,when a large number of warnings in one group are triggered, i usually receive two resloved message but only one alert. of course，the second resloved message often appears in the second group interval which also has similar alert message.

What did you expect to see?
one alert has only one resloved message, if one group has alert message again, shouldn't have resloved message which has been sent.

What did you see instead? Under which circumstances?
in one group ,when have alert message again , the resloved message which has been sent also send again
Environment
two Alertmanager HA

• Alertmanager version:

  Alertmanager: v0.20.0

• Prometheus version:

  2.14

• Alertmanager configuration file:

route:
      group_by: ['alertname']
      group_wait: 60s
      group_interval: 5m
      repeat_interval: 3h

args:
        - "--config.file=/etc/alertmanager/alertmanager.yml"
        - "--storage.path=/data"
        - "--web.listen-address=:9095"
        - "--cluster.listen-address=0.0.0.0:8003"
        - "--cluster.peer=172.21.164.20:8003"
        - "--cluster.peer-timeout=30s"
        - "--cluster.gossip-interval=50ms"
        - "--cluster.pushpull-interval=2s"
        - "--log.level=debug"

• Prometheus configuration file:

scrape_interval: 30s
  scrape_timeout: 10s
  evaluation_interval: 15s

• Logs:

level=debug ts=2019-12-31T06:10:54.577Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:10:54 [DEBUG] memberlist: Stream connection from=172.21.164.20:24116\n"
level=debug ts=2019-12-31T06:10:54.577Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:10:54 [DEBUG] memberlist: Initiating push/pull sync with: 172.21.164.20:8003\n"
level=debug ts=2019-12-31T06:10:56.578Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:10:56 [DEBUG] memberlist: Initiating push/pull sync with: 172.21.164.20:8003\n"
level=debug ts=2019-12-31T06:10:56.578Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:10:56 [DEBUG] memberlist: Stream connection from=172.21.164.20:24126\n"
level=debug ts=2019-12-31T06:10:58.579Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:10:58 [DEBUG] memberlist: Initiating push/pull sync with: 172.21.164.20:8003\n"
level=debug ts=2019-12-31T06:10:58.579Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:10:58 [DEBUG] memberlist: Stream connection from=172.21.164.20:24146\n"
level=debug ts=2019-12-31T06:11:00.580Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:00 [DEBUG] memberlist: Stream connection from=172.21.164.20:24154\n"
level=debug ts=2019-12-31T06:11:00.580Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:00 [DEBUG] memberlist: Initiating push/pull sync with: 172.21.164.20:8003\n"
level=debug ts=2019-12-31T06:11:02.582Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:02 [DEBUG] memberlist: Initiating push/pull sync with: 172.21.164.20:8003\n"
level=debug ts=2019-12-31T06:11:02.582Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:02 [DEBUG] memberlist: Stream connection from=172.21.164.20:24166\n"
level=debug ts=2019-12-31T06:11:04.583Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:04 [DEBUG] memberlist: Initiating push/pull sync with: 172.21.164.20:8003\n"
level=debug ts=2019-12-31T06:11:04.584Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:04 [DEBUG] memberlist: Stream connection from=172.21.164.20:24178\n"
level=debug ts=2019-12-31T06:11:06.585Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:06 [DEBUG] memberlist: Stream connection from=172.21.164.20:24188\n"
level=debug ts=2019-12-31T06:11:06.585Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:06 [DEBUG] memberlist: Initiating push/pull sync with: 172.21.164.20:8003\n"
level=debug ts=2019-12-31T06:11:08.586Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:08 [DEBUG] memberlist: Initiating push/pull sync with: 172.21.164.20:8003\n"
level=debug ts=2019-12-31T06:11:08.586Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:08 [DEBUG] memberlist: Stream connection from=172.21.164.20:24204\n"
level=debug ts=2019-12-31T06:11:08.613Z caller=dispatch.go:135 component=dispatcher msg="Received alert" alert=qos-deployment-erro[36baa7e][active]
level=debug ts=2019-12-31T06:11:10.587Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:10 [DEBUG] memberlist: Initiating push/pull sync with: 172.21.164.20:8003\n"
level=debug ts=2019-12-31T06:11:10.588Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:10 [DEBUG] memberlist: Stream connection from=172.21.164.20:24212\n"
level=debug ts=2019-12-31T06:11:12.207Z caller=dispatch.go:135 component=dispatcher msg="Received alert" alert=node-notready[10a8ef6][active]
level=debug ts=2019-12-31T06:11:12.588Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:12 [DEBUG] memberlist: Initiating push/pull sync with: 172.21.164.20:8003\n"
level=debug ts=2019-12-31T06:11:12.589Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:12 [DEBUG] memberlist: Stream connection from=172.21.164.20:24224\n"
level=debug ts=2019-12-31T06:11:14.589Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:14 [DEBUG] memberlist: Initiating push/pull sync with: 172.21.164.20:8003\n"
level=debug ts=2019-12-31T06:11:14.590Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:14 [DEBUG] memberlist: Stream connection from=172.21.164.20:24248\n"
level=debug ts=2019-12-31T06:11:16.591Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:16 [DEBUG] memberlist: Initiating push/pull sync with: 172.21.164.20:8003\n"
level=debug ts=2019-12-31T06:11:16.591Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:16 [DEBUG] memberlist: Stream connection from=172.21.164.20:24252\n"
level=debug ts=2019-12-31T06:11:18.592Z caller=cluster.go:306 component=cluster memberlist="2019/12/31 06:11:18 [DEBUG] memberlist: Initiating push/pull sync with: 172.21.164.20:8003\n"

looking forward to your reply

[roidelapluie]

I have always noticed this and never considered it a bug. I even find it practical.

[gjpei2]

I have always noticed this and never considered it a bug. I even find it practical.

thanks for your reply, when a large number of alerts were triggered，alert email bombingare. are there some measures to reduce this situation?

we have another question when above problem appears，we often receive some resloved message that no alert corresponds to it

[simonpasquier]

I'm not sure to understand your issue. Can you show us an example of notification that you get and what you would expect instead?

[MCNVI]

I suppose this issue is connected with resending alerts from prometheus. It's about 15 minutes interval when prometheus resends alerts (even resolved) to alertmanager every minute by default. I'm not splitting alerts by groups and sometimes already resolved alert comes one more time with alerts that has been resolved after such alert.

[simonpasquier]

Sorry but it isn't very clear from the screenshot what is happening here. It would be easier to share Alertmanager's logs in debug mode.

[MCNVI]

Alertmanager's config:

route:
  group_wait: 30s
  group_interval: 1m
  repeat_interval: 30m
  receiver: alertmanager-bot

receivers:
  - name: alertmanager-bot
    webhook_configs:
      - send_resolved: true
        url: 'http://alertmanager-bot:8070/api/alerts'

Alertmanager's logs:

What I see in my custom webhook receiver:

Maybe I misunderstood something but I expect only one message "High CPU load on localNode"

[simonpasquier]

Ok I understand now. What happens is that the Lost connection with localNode alert has been firing and resolved between 11:22 and 11:23. Though it was never notified as firing, the resolved alert is indeed included in the last notification. As @roidelapluie noted, it sounds useful and I'd be inclined to leave this behavior as-is.

[MCNVI]

I totally agree with you about behaviour connected with Lost connection with localNode alert, but I don't think there should be High CPU load on localNode resolved alert because it has been already sent and there was no High CPU load on localNode firing between 11:21 and 11:23

[Gaozizhong]

特殊情况

• 有些resolved alert没有对应的firing alert
  • firing alert发送给alertmanager时其所在的group恰好处在睡眠状态下
  • 而其对应的resolved消息也在同一睡眠周期内被发送给alertmanager
  • 接收到resolved消息后，group将其对应的firing消息覆盖，因此在唤醒时就只接收到了resolved消息