{"action":"created","issue":{"url":"https://api.github.com/repos/prometheus/prometheus/issues/3943","repository_url":"https://api.github.com/repos/prometheus/prometheus","labels_url":"https://api.github.com/repos/prometheus/prometheus/issues/3943/labels{/name}","comments_url":"https://api.github.com/repos/prometheus/prometheus/issues/3943/comments","events_url":"https://api.github.com/repos/prometheus/prometheus/issues/3943/events","html_url":"https://github.com/prometheus/prometheus/issues/3943","id":303949067,"number":3943,"title":"Prometheus 2.2.0 missing metrics after upgrade","user":{"login":"hgranillo","id":16230136,"avatar_url":"https://avatars2.githubusercontent.com/u/16230136?v=4","gravatar_id":"","url":"https://api.github.com/users/hgranillo","html_url":"https://github.com/hgranillo","followers_url":"https://api.github.com/users/hgranillo/followers","following_url":"https://api.github.com/users/hgranillo/following{/other_user}","gists_url":"https://api.github.com/users/hgranillo/gists{/gist_id}","starred_url":"https://api.github.com/users/hgranillo/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/hgranillo/subscriptions","organizations_url":"https://api.github.com/users/hgranillo/orgs","repos_url":"https://api.github.com/users/hgranillo/repos","events_url":"https://api.github.com/users/hgranillo/events{/privacy}","received_events_url":"https://api.github.com/users/hgranillo/received_events","type":"User","site_admin":false},"labels":[{"id":365567268,"url":"https://api.github.com/repos/prometheus/prometheus/labels/component/local%20storage","name":"component/local storage","color":"0052cc","default":false},{"id":365563588,"url":"https://api.github.com/repos/prometheus/prometheus/labels/kind/bug","name":"kind/bug","color":"ff0000","default":false},{"id":365563605,"url":"https://api.github.com/repos/prometheus/prometheus/labels/priority/P0","name":"priority/P0","color":"df0101","default":false}],"state":"closed","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":49,"created_at":"2018-03-09T19:12:06Z","updated_at":"2018-03-28T08:27:25Z","closed_at":"2018-03-13T20:20:04Z","author_association":"NONE","body":"**What did you do?**\r\n* Upgraded Prometheus to 2.2.0 from 2.1.0. I have Prometheus running on a container.\r\n\r\n**What did you expect to see?**\r\nAll metrics except the ones missing during container reload and start. No more than a few minutes.\r\n\r\n**What did you see instead? Under which circumstances?**\r\nAfter I updated everything was running fine. New metrics were being collected and stored. A day after a gap of metrics went missing. A few hours ago I was able to see the now missing metrics. They were there and a second after they not.\r\n\r\nThe really weird thing here is that I have 4 Prometheus running and all 4 have the same issue, they were upgraded almost at the same time. Theres a long missing gap of metrics (all kind of metrics from different exporters) and no errors on logs.\r\n\r\nThese 4 Prometheus are running on separated environments on two different AWS regions.\r\n\r\n**Environment**\r\n\r\n* System information:\r\n\r\n`Linux 4.4.0-1050-aws x86_64`\r\n\r\n* Prometheus version:\r\n\r\n```\r\nprometheus, version 2.2.0 (branch: HEAD, revision: f63e7db4cbdb616337ca877b306b9b96f7f4e381)\r\n  build user:       root@52af9f66ce71\r\n  build date:       20180308-16:40:42\r\n  go version:       go1.10\r\n```\r\n* Prometheus configuration file:\r\n```\r\nglobal:\r\n  scrape_interval:     30s\r\n  evaluation_interval: 30s\r\n\r\nrule_files:\r\n  - \"/etc/prometheus-rules/*.yaml\"\r\n```\r\nI cut the scrap rules here. I can include some of them.\r\n* Logs:\r\n```\r\n➜  ~ oc logs prometheus-0                                                                                            \r\nlevel=info ts=2018-03-08T19:58:19.858089342Z caller=main.go:220 msg=\"Starting Prometheus\" version=\"(version=2.2.0, branch=HEAD, revision=f63e7db4cbdb616337ca877b306b9b96f7f4e381)\"\r\nlevel=info ts=2018-03-08T19:58:19.858143946Z caller=main.go:221 build_context=\"(go=go1.10, user=root@52af9f66ce71, date=20180308-16:40:42)\"\r\nlevel=info ts=2018-03-08T19:58:19.85817058Z caller=main.go:222 host_details=\"(Linux 4.4.0-1050-aws #59-Ubuntu SMP Tue Jan 30 19:57:10 UTC 2018 x86_64 prometheus-0 (none))\"\r\nlevel=info ts=2018-03-08T19:58:19.858192518Z caller=main.go:223 fd_limits=\"(soft=1048576, hard=1048576)\"\r\nlevel=info ts=2018-03-08T19:58:19.860731333Z caller=main.go:504 msg=\"Starting TSDB ...\"\r\nlevel=info ts=2018-03-08T19:58:19.860805283Z caller=web.go:382 component=web msg=\"Start listening for connections\" address=0.0.0.0:9090\r\nlevel=info ts=2018-03-08T19:58:19.861098766Z caller=repair.go:41 component=tsdb msg=\"fixing broken block\" ulid=01C6BPGD3E1EH9N7XPAVWD3NSE\r\nlevel=info ts=2018-03-08T19:59:25.431695736Z caller=repair.go:41 component=tsdb msg=\"fixing broken block\" ulid=01C7ZP0PKNFRPMFKCSZ482VQ4C\r\nlevel=info ts=2018-03-08T20:01:31.382327527Z caller=repair.go:41 component=tsdb msg=\"fixing broken block\" ulid=01C81J69ME1Y5WSSAPERH4C94V\r\nlevel=info ts=2018-03-08T20:01:43.390153611Z caller=repair.go:41 component=tsdb msg=\"fixing broken block\" ulid=01C83FYTCPZS7KMSM2FR4A98V6\r\nlevel=info ts=2018-03-08T20:04:04.520191875Z caller=main.go:514 msg=\"TSDB started\"\r\nlevel=info ts=2018-03-08T20:04:04.520258667Z caller=main.go:588 msg=\"Loading configuration file\" filename=/etc/prometheus/prometheus.yml\r\nlevel=info ts=2018-03-08T20:04:04.523593179Z caller=kubernetes.go:191 component=\"discovery manager scrape\" discovery=k8s msg=\"Using pod service account via in-cluster config\"\r\nlevel=info ts=2018-03-08T20:04:04.525461109Z caller=kubernetes.go:191 component=\"discovery manager scrape\" discovery=k8s msg=\"Using pod service account via in-cluster config\"\r\nlevel=info ts=2018-03-08T20:04:04.526788217Z caller=kubernetes.go:191 component=\"discovery manager scrape\" discovery=k8s msg=\"Using pod service account via in-cluster config\"\r\nlevel=info ts=2018-03-08T20:04:04.527932416Z caller=kubernetes.go:191 component=\"discovery manager scrape\" discovery=k8s msg=\"Using pod service account via in-cluster config\"\r\nlevel=info ts=2018-03-08T20:04:04.528997091Z caller=kubernetes.go:191 component=\"discovery manager scrape\" discovery=k8s msg=\"Using pod service account via in-cluster config\"\r\nlevel=info ts=2018-03-08T20:04:04.530311675Z caller=kubernetes.go:191 component=\"discovery manager scrape\" discovery=k8s msg=\"Using pod service account via in-cluster config\"\r\nlevel=info ts=2018-03-08T20:04:04.535204808Z caller=main.go:491 msg=\"Server is ready to receive web requests.\"\r\nlevel=info ts=2018-03-08T21:00:00.34165268Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=1 mint=1520532000000 maxt=1520539200000\r\nlevel=info ts=2018-03-08T21:01:52.439372087Z caller=head.go:348 component=tsdb msg=\"head GC completed\" duration=8.816932002s\r\nlevel=info ts=2018-03-08T21:02:44.010010328Z caller=head.go:357 component=tsdb msg=\"WAL truncation completed\" duration=51.570547607s\r\nlevel=info ts=2018-03-08T23:00:00.347972278Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=1 mint=1520539200000 maxt=1520546400000\r\nlevel=info ts=2018-03-08T23:01:32.876783605Z caller=head.go:348 component=tsdb msg=\"head GC completed\" duration=6.039842235s\r\nlevel=info ts=2018-03-08T23:02:32.551701808Z caller=head.go:357 component=tsdb msg=\"WAL truncation completed\" duration=59.674864681s\r\nlevel=info ts=2018-03-09T01:00:00.388711357Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=1 mint=1520546400000 maxt=1520553600000\r\nlevel=info ts=2018-03-09T01:00:59.131562889Z caller=head.go:348 component=tsdb msg=\"head GC completed\" duration=2.507758629s\r\nlevel=info ts=2018-03-09T01:01:18.039357855Z caller=head.go:357 component=tsdb msg=\"WAL truncation completed\" duration=18.907736139s\r\nlevel=info ts=2018-03-09T03:00:00.380318607Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=1 mint=1520553600000 maxt=1520560800000\r\nlevel=info ts=2018-03-09T03:00:58.488065341Z caller=head.go:348 component=tsdb msg=\"head GC completed\" duration=2.314473094s\r\nlevel=info ts=2018-03-09T03:01:13.31888004Z caller=head.go:357 component=tsdb msg=\"WAL truncation completed\" duration=14.830755016s\r\nlevel=info ts=2018-03-09T03:01:18.881154001Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=3 mint=1520532000000 maxt=1520553600000\r\nlevel=info ts=2018-03-09T05:00:00.388120222Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=1 mint=1520560800000 maxt=1520568000000\r\nlevel=info ts=2018-03-09T05:00:57.704584177Z caller=head.go:348 component=tsdb msg=\"head GC completed\" duration=2.51049056s\r\nlevel=info ts=2018-03-09T05:01:12.057612041Z caller=head.go:357 component=tsdb msg=\"WAL truncation completed\" duration=14.352969524s\r\nlevel=info ts=2018-03-09T07:00:00.387250785Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=1 mint=1520568000000 maxt=1520575200000\r\nlevel=info ts=2018-03-09T07:00:58.776859178Z caller=head.go:348 component=tsdb msg=\"head GC completed\" duration=2.339181202s\r\nlevel=info ts=2018-03-09T07:01:13.64668469Z caller=head.go:357 component=tsdb msg=\"WAL truncation completed\" duration=14.869760955s\r\nlevel=info ts=2018-03-09T09:00:00.398864782Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=1 mint=1520575200000 maxt=1520582400000\r\nlevel=info ts=2018-03-09T09:00:58.889449072Z caller=head.go:348 component=tsdb msg=\"head GC completed\" duration=2.79196883s\r\nlevel=info ts=2018-03-09T09:01:13.508749265Z caller=head.go:357 component=tsdb msg=\"WAL truncation completed\" duration=14.619235883s\r\nlevel=info ts=2018-03-09T09:01:18.898146261Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=3 mint=1520553600000 maxt=1520575200000\r\nlevel=info ts=2018-03-09T11:00:00.387036989Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=1 mint=1520582400000 maxt=1520589600000\r\nlevel=info ts=2018-03-09T11:00:57.685609508Z caller=head.go:348 component=tsdb msg=\"head GC completed\" duration=2.371068823s\r\nlevel=info ts=2018-03-09T11:01:12.734211593Z caller=head.go:357 component=tsdb msg=\"WAL truncation completed\" duration=15.048545238s\r\nlevel=info ts=2018-03-09T13:00:00.389210695Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=1 mint=1520589600000 maxt=1520596800000\r\nlevel=info ts=2018-03-09T13:00:58.341825994Z caller=head.go:348 component=tsdb msg=\"head GC completed\" duration=2.466301791s\r\nlevel=info ts=2018-03-09T13:01:13.191514211Z caller=head.go:357 component=tsdb msg=\"WAL truncation completed\" duration=14.849637465s\r\nlevel=info ts=2018-03-09T15:00:00.373007915Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=1 mint=1520596800000 maxt=1520604000000\r\nlevel=info ts=2018-03-09T15:01:30.790025421Z caller=head.go:348 component=tsdb msg=\"head GC completed\" duration=4.111489989s\r\nlevel=info ts=2018-03-09T15:02:04.571961721Z caller=head.go:357 component=tsdb msg=\"WAL truncation completed\" duration=33.7818842s\r\nlevel=info ts=2018-03-09T15:02:18.425767053Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=3 mint=1520575200000 maxt=1520596800000\r\nlevel=info ts=2018-03-09T15:03:30.118738573Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=2 mint=1520532000000 maxt=1520575200000\r\nlevel=info ts=2018-03-09T15:05:31.944625635Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=3 mint=1520402400000 maxt=1520596800000\r\nlevel=info ts=2018-03-09T17:00:00.347731895Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=1 mint=1520604000000 maxt=1520611200000\r\nlevel=info ts=2018-03-09T17:01:35.110319556Z caller=head.go:348 component=tsdb msg=\"head GC completed\" duration=6.699952835s\r\nlevel=info ts=2018-03-09T17:02:46.732035127Z caller=head.go:357 component=tsdb msg=\"WAL truncation completed\" duration=1m11.62087854s\r\nlevel=info ts=2018-03-09T17:02:51.604621507Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=2 mint=1520402400000 maxt=1520575200000\r\n```\r\n\r\n**Production Ireland** \r\nThe last metric of 2.1.0 is the green one and ends when I upgraded Prometheus (19:58). On the logs you can see that the cointainer started at 19:58:19\r\n![image](https://user-images.githubusercontent.com/16230136/37223016-e8ee9d48-23ad-11e8-9a97-abf67b94c088.png)\r\n![screenshot from 2018-03-09 15-33-34](https://user-images.githubusercontent.com/16230136/37223552-ac1e7076-23af-11e8-9d39-07425df75a03.png)\r\n\r\n**Staging Virginia**\r\n![image](https://user-images.githubusercontent.com/16230136/37223054-0ff7fc36-23ae-11e8-9867-9c838b4a1844.png)\r\n\r\n**Prometheus Dashboard Production Ireland**\r\n![image](https://user-images.githubusercontent.com/16230136/37225402-4af3523e-23b5-11e8-8004-ea0fff8c4374.png)\r\n  \r\n------\r\n\r\nI know this look really sketchy. But I didnt had restart or network error on the environments that run Prometheus. Thats why I choose a Prometheus metric as a example but all metrics where affected.\r\n"},"comment":{"url":"https://api.github.com/repos/prometheus/prometheus/issues/comments/376804296","html_url":"https://github.com/prometheus/prometheus/issues/3943#issuecomment-376804296","issue_url":"https://api.github.com/repos/prometheus/prometheus/issues/3943","id":376804296,"user":{"login":"Gouthamve","id":7354143,"avatar_url":"https://avatars0.githubusercontent.com/u/7354143?v=4","gravatar_id":"","url":"https://api.github.com/users/Gouthamve","html_url":"https://github.com/Gouthamve","followers_url":"https://api.github.com/users/Gouthamve/followers","following_url":"https://api.github.com/users/Gouthamve/following{/other_user}","gists_url":"https://api.github.com/users/Gouthamve/gists{/gist_id}","starred_url":"https://api.github.com/users/Gouthamve/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/Gouthamve/subscriptions","organizations_url":"https://api.github.com/users/Gouthamve/orgs","repos_url":"https://api.github.com/users/Gouthamve/repos","events_url":"https://api.github.com/users/Gouthamve/events{/privacy}","received_events_url":"https://api.github.com/users/Gouthamve/received_events","type":"User","site_admin":false},"created_at":"2018-03-28T08:27:24Z","updated_at":"2018-03-28T08:27:24Z","author_association":"OWNER","body":"Can you share the logs until the compaction failed error happened on 2.2.1?\n\nOn Wed, Mar 28, 2018 at 1:47 PM Daniel Swarbrick <notifications@github.com>\nwrote:\n\n> I installed 2.2.0 last Friday, around midday. It ran fine until Sunday,\n> when the log started to report these:\n>\n> Mar 25 11:00:00 fkb-prom prometheus[20055]: level=info ts=2018-03-25T09:00:00.371572247Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=1 mint=1521957600000 maxt=1521964800000\n> Mar 25 11:00:01 fkb-prom prometheus[20055]: level=info ts=2018-03-25T09:00:01.652055946Z caller=head.go:348 component=tsdb msg=\"head GC completed\" duration=64.254505ms\n> Mar 25 11:00:02 fkb-prom prometheus[20055]: level=info ts=2018-03-25T09:00:02.26184745Z caller=head.go:357 component=tsdb msg=\"WAL truncation completed\" duration=609.038738ms\n> Mar 25 11:00:02 fkb-prom prometheus[20055]: level=info ts=2018-03-25T09:00:02.388959377Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=3 mint=1521936000000 maxt=1521957600000\n> Mar 25 11:00:04 fkb-prom prometheus[20055]: level=info ts=2018-03-25T09:00:04.082174394Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=2 mint=1521892800000 maxt=1521936000000\n> Mar 25 11:00:06 fkb-prom prometheus[20055]: level=info ts=2018-03-25T09:00:06.414524076Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=3 mint=1521799200000 maxt=1521957600000\n> Mar 25 11:00:11 fkb-prom prometheus[20055]: level=error ts=2018-03-25T09:00:11.083160017Z caller=db.go:281 component=tsdb msg=\"compaction failed\" err=\"reload blocks: invalid block sequence: block time ranges overlap (1521892800000, 1521957600000)\"\n> Mar 25 11:00:12 fkb-prom prometheus[20055]: level=info ts=2018-03-25T09:00:12.09218052Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=2 mint=1521892800000 maxt=1521957600000\n> Mar 25 11:00:15 fkb-prom prometheus[20055]: level=error ts=2018-03-25T09:00:15.18509509Z caller=db.go:281 component=tsdb msg=\"compaction failed\" err=\"reload blocks: invalid block sequence: block time ranges overlap (1521799200000, 1521828000000)\"\n>\n> At one point it ran out of space on the 50 GB filesystem:\n>\n> Mar 25 11:30:04 fkb-prom prometheus[20055]: level=info ts=2018-03-25T09:30:04.488714476Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=11 mint=1521892800000 maxt=1521957600000\n> Mar 25 11:34:33 fkb-prom prometheus[20055]: level=error ts=2018-03-25T09:34:33.128006388Z caller=db.go:281 component=tsdb msg=\"compaction failed\" err=\"compact [/srv/prometheus/metrics2/01C9E67YYV73KNNCWD01TAYSFT /srv/prometheus/metrics2/01C9E65NKJ8AFP6NJSYQVPKNJX /srv/prometheus/metrics2/01C9E6SZNNAABH0KW6A4KZXV2J /srv/prometheus/metrics2/01C9E65XDW74BHDR7NPBNAGXJ2 /srv/prometheus/metrics2/01C9E70R0XAT2QG2BEENG2FD11 /srv/prometheus/metrics2/01C9E6A4H1FPAAGRW8SRKDWNTE /srv/prometheus/metrics2/01C9E6CKZ9452ERA52VPHWKK41 /srv/prometheus/metrics2/01C9E6FMJY0C2Y1KYJPNRHBXAT /srv/prometheus/metrics2/01C9E6KRHFMXV5K3SES7QX72X6 /srv/prometheus/metrics2/01C9E788ESAF5F2AT1YAX51HZY /srv/prometheus/metrics2/01C9E65KYME9TEKF8J212QK38J]: write compaction: write chunks: no space left on device\"\n>\n> This gradually became worse:\n>\n> Mar 25 16:39:27 fkb-prom prometheus[20055]: level=info ts=2018-03-25T14:39:27.268797602Z caller=compact.go:394 component=tsdb msg=\"compact blocks\" count=1 mint=1521964800000 maxt=1521972000000\n> Mar 25 16:39:28 fkb-prom prometheus[20055]: level=error ts=2018-03-25T14:39:28.925386435Z caller=db.go:281 component=tsdb msg=\"compaction failed\" err=\"reload blocks: open block /srv/prometheus/metrics2/01C9EQRRJ6GW1GMCQYVBV5AGA7: mmap files: mmap: cannot allocate memory\"\n>\n> ... until eventually it died:\n>\n> Mar 25 17:21:22 fkb-prom prometheus[20055]: fatal error: runtime: cannot allocate memory\n>\n> When I tried to restart it on Monday, it would not start and died with:\n>\n> Mar 26 10:01:18 fkb-prom prometheus[6806]: level=error ts=2018-03-26T08:01:18.048223898Z caller=main.go:575 err=\"Opening storage failed invalid block sequence: block time ranges overlap (1521799200000, 1521957600000)\"\n> Mar 26 10:01:18 fkb-prom prometheus[6806]: level=info ts=2018-03-26T08:01:18.048388413Z caller=main.go:577 msg=\"See you next time!\"\n>\n> This is the point at which I removed the entire contents of\n> /srv/prometheus/metrics2, and upgraded to Prometheus 2.2.1. This obviously\n> started fine with an empty DB.\n>\n> Later on Tuesday, I started to see the same \"block time ranges overlap\"\n> error again, and the filesystem again started to rapidly fill, as if the\n> compaction process was failing with leftover temporary files.\n>\n> Mar 27 17:00:14 fkb-prom prometheus[14007]: level=error ts=2018-03-27T15:00:14.672804202Z caller=db.go:281 component=tsdb msg=\"compaction failed\" err=\"reload blocks: invalid block sequence: block time ranges overlap (1522087200000, 1522152000000)\"\n>\n> I tried to restart Prometheus, and once again it failed to start with:\n>\n> Mar 27 18:38:19 fkb-prom prometheus[7437]: level=error ts=2018-03-27T16:38:19.768740127Z caller=main.go:575 err=\"Opening storage failed invalid block sequence: block time ranges overlap (1522051200000, 1522152000000)\"\n> Mar 27 18:38:19 fkb-prom prometheus[7437]: level=info ts=2018-03-27T16:38:19.768880142Z caller=main.go:577 msg=\"See you next time!\"\n>\n> At this point I again removed the contents of /srv/prometheus/metrics2,\n> and started with a fresh DB again. So far it's been running ok for about 14\n> hours.\n>\n> —\n> You are receiving this because you commented.\n>\n>\n> Reply to this email directly, view it on GitHub\n> <https://github.com/prometheus/prometheus/issues/3943#issuecomment-376801318>,\n> or mute the thread\n> <https://github.com/notifications/unsubscribe-auth/AHA3H0ZHKchAX248U508E4xGCkSYzwbnks5ti0cJgaJpZM4Sku1O>\n> .\n>\n"}}
{"actor":{"display_login":"Gouthamve"}}