endsAt of alert not changed

[lcasi]

What did you do?
Hi, I received multiple resolved alerts for one alert recently from alertmanager,so I collected the alerts data from prometehus.
I set rules like this:

alert: cpu high load
expr: job:cpu_load_per_core{instance_name="jssz-search-basic-10"} > 1
for:  2m
labels:
  repeat_interval: 1800s
  rule_model: v2
  rule_id: 1461578
annotations:
  trigger_value: '{{ $value }}'

then I write a simple http-server to receive alert from prometheus and log them into file:

func main()  {
	// init log config
	log.Init(&log.Config{
		Dir:"/mnt/storage00/",
		Stdout:true,
	})
	// add router
	http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
		b, err := ioutil.ReadAll(r.Body)
		if err != nil {
			log.Error("read request body failed: %v",err)
			w.WriteHeader(200)
			return
		}
		defer r.Body.Close()
		// unmarshal alert
		var alerts []Alert
		if err = json.Unmarshal(b,&alerts);err != nil {
			log.Error("unmarshal alerts failed: %v",err)
			w.WriteHeader(200)
			return
		}
		// log alert
		for _,alert := range alerts {
			var data []byte
			if data,err = json.Marshal(&alert); err != nil {
				log.Error(err.Error())
				continue
			}
			log.Info("%v",string(data))
		}
	})

	// start http server
	err := http.ListenAndServe(fmt.Sprintf(":%d", 8888),nil)
	if err != nil {
		panic(err)
	}
}

What did you expect to see?

• the endsAt of alert send by prometehus should be different every evaluation time.
• endAt should be the time in the future

What did you see instead? Under which circumstances?

• endsAt sometime the same as last and behind the current time
• The alert is resolved actuallly, but prometheus still send alert to alertmanager

[2021/09/30 03:35:57.091] [INFO] [/usr/local/go/src/net/http/server.go:2042] {"labels":{"__host__":"jssz-moni-storage-02","alertname":"cpu high load","identity":"jssz-search-basic-10:9100","instance_name":"jssz-search-basic-10","repeat_interval":"1800s","rule_id":"1461578","rule_model":"v2"},"annotations":{"trigger_value":"1.00125"},"startsAt":"2021-09-30T03:27:55.68686643Z","endsAt":"2021-09-30T03:29:55.68686643Z"}
[2021/09/30 03:37:55.889] [INFO] [/usr/local/go/src/net/http/server.go:2042] {"labels":{"__host__":"jssz-moni-storage-02","alertname":"cpu high load","identity":"jssz-search-basic-10:9100","instance_name":"jssz-search-basic-10","repeat_interval":"1800s","rule_id":"1461578","rule_model":"v2"},"annotations":{"trigger_value":"1.00125"},"startsAt":"2021-09-30T03:27:55.68686643Z","endsAt":"2021-09-30T03:29:55.68686643Z"}
[2021/09/30 03:39:55.845] [INFO] [/usr/local/go/src/net/http/server.go:2042] {"labels":{"__host__":"jssz-moni-storage-02","alertname":"cpu high load","identity":"jssz-search-basic-10:9100","instance_name":"jssz-search-basic-10","repeat_interval":"1800s","rule_id":"1461578","rule_model":"v2"},"annotations":{"trigger_value":"1.00125"},"startsAt":"2021-09-30T03:27:55.68686643Z","endsAt":"2021-09-30T03:29:55.68686643Z"}
[2021/09/30 03:41:55.876] [INFO] [/usr/local/go/src/net/http/server.go:2042] {"labels":{"__host__":"jssz-moni-storage-02","alertname":"cpu high load","identity":"jssz-search-basic-10:9100","instance_name":"jssz-search-basic-10","repeat_interval":"1800s","rule_id":"1461578","rule_model":"v2"},"annotations":{"trigger_value":"1.00125"},"startsAt":"2021-09-30T03:27:55.68686643Z","endsAt":"2021-09-30T03:29:55.68686643Z"}
[2021/09/30 03:43:55.836] [INFO] [/usr/local/go/src/net/http/server.go:2042] {"labels":{"__host__":"jssz-moni-storage-02","alertname":"cpu high load","identity":"jssz-search-basic-10:9100","instance_name":"jssz-search-basic-10","repeat_interval":"1800s","rule_id":"1461578","rule_model":"v2"},"annotations":{"trigger_value":"1.00125"},"startsAt":"2021-09-30T03:27:55.68686643Z","endsAt":"2021-09-30T03:29:55.68686643Z"}
[2021/09/30 03:57:56.010] [INFO] [/usr/local/go/src/net/http/server.go:2042] {"labels":{"__host__":"jssz-moni-storage-02","alertname":"cpu high load","identity":"jssz-search-basic-10:9100","instance_name":"jssz-search-basic-10","repeat_interval":"1800s","rule_id":"1461578","rule_model":"v2"},"annotations":{"trigger_value":"1.038"},"startsAt":"2021-09-30T03:57:55.68686643Z","endsAt":"2021-09-30T04:05:55.68686643Z"}
[2021/09/30 03:59:56.021] [INFO] [/usr/local/go/src/net/http/server.go:2042] {"labels":{"__host__":"jssz-moni-storage-02","alertname":"cpu high load","identity":"jssz-search-basic-10:9100","instance_name":"jssz-search-basic-10","repeat_interval":"1800s","rule_id":"1461578","rule_model":"v2"},"annotations":{"trigger_value":"1.038"},"startsAt":"2021-09-30T03:57:55.68686643Z","endsAt":"2021-09-30T03:59:55.68686643Z"}

the metric:

Environment

• System information:

  Linux 4.9.0-8-amd64 x86_64

• Prometheus version:

  prometheus, version 2.20.1

• Prometheus config

global:
    scrape_interval: 1m
    scrape_timeout: 20s
    evaluation_interval: 2m
    external_labels:
        __host__: jssz-moni-storage-02
alerting:
    alertmanagers:
      - static_configs:
          - targets:
              - 127.0.0.1:8888  
        scheme: http
        path_prefix: /alert
        timeout: 10s
        api_version: v1
        
rule_files:
  - ./record-rule/*.rules.yml
  - ./alert-rule-v2/*.rules.yml
  - ./alert-rule-v3/*.rules.yml

• Logs:

Sep 30 03:00:25 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:00:25.299Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:00:35 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:00:35.585Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:01:03 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:01:03.928Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:01:23 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:01:23.209Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:02:29 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:02:29.574Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:02:40 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:02:40.533Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:03:02 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:03:02.276Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:03:22 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:03:22.401Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:04:26 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:04:26.824Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:04:36 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:04:36.816Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:05:05 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:05:05.612Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:05:24 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:05:24.505Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:06:29 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:06:29.363Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:06:44 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:06:44.788Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:07:01 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:07:01.199Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:07:24 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:07:24.903Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:08:21 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:08:21.415Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:08:31 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:08:31.536Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:09:01 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:09:01.111Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:09:26 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:09:26.013Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:10:34 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:10:34.134Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:10:49 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:10:49.946Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:10:59 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:10:59.991Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:11:13 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:11:13.155Z caller=compact.go:495 component=tsdb msg="write block" mint=1632960000000 maxt=1632967200000 ulid=01FGTA9YYHVTEJD0CCM2GM1SPE duration=11m13.074202502s
Sep 30 03:11:24 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:11:24.448Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:12:08 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:12:08.626Z caller=head.go:804 component=tsdb msg="Head GC completed" duration=38.238079376s
Sep 30 03:12:09 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:12:09.591Z caller=checkpoint.go:96 component=tsdb msg="Creating checkpoint" from_segment=209091 to_segment=209227 mint=1632967200000
Sep 30 03:12:21 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:12:21.379Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:12:36 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:12:36.965Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:12:57 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:12:57.257Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:13:23 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:13:23.318Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:14:57 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:14:57.854Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:15:24 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:15:24.125Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:15:45 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:15:45.033Z caller=head.go:884 component=tsdb msg="WAL checkpoint complete" first=209091 last=209227 duration=3m35.441996761s
Sep 30 03:16:13 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:16:13.919Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:16:24 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:16:24.313Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:16:52 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:16:52.217Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:17:24 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:17:24.523Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:19:00 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:19:00.124Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:19:24 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:19:24.162Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:20:21 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:20:21.712Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:20:31 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:20:31.967Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:20:54 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:20:54.135Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:21:26 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:21:26.623Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:22:58 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:22:58.571Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:23:24 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:23:24.430Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:24:19 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:24:19.132Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:24:29 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:24:29.389Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:24:58 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:24:58.258Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:25:27 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:25:27.030Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:26:55 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:26:55.098Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:27:27 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:27:27.842Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:28:49 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:28:49.487Z caller=main.go:805 msg="Loading configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:29:25 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:29:25.003Z caller=main.go:833 msg="Completed loading of configuration file" filename=/data/app/prom_config/prometheus.yml
Sep 30 03:29:48 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:29:48.853Z caller=compact.go:441 component=tsdb msg="compact blocks" count=3 mint=1632938400000 maxt=1632960000000 ulid=01FGTB79HTGBX54X3V6NTRH4P8 sources="[01FGSNPS6EQD1K423E0KN49
Sep 30 03:52:46 jssz-moni-storage-02 prometheus[21825]: level=info ts=2021-09-30T03:52:46.295Z caller=compact.go:441 component=tsdb msg="compact blocks" count=3 mint=1632895200000 maxt=1632960000000 ulid=01FGTC1Q848SA0ZXR02E0R54NZ sources="[01FGS21EXE976JQE2S12EBX

[roidelapluie]

Thank you, this is not a bug. Prometheus will re-send resolved alerts with a past end date to alertmanager.

I suspect that your multiple resolved alerts issue is unrelated with this.