compaction failed: unexpected gap to last checkpoint

[Amir Malka]

Hi,

I'm having an issue with my Prometheus setup (version 2.16.0) which used to work just fine. 

The log (attached below) is full with "unexpected gap to last checkpoint". I cannot understand what can cause compaction to fail? What can we learn from these log prints?

Any help would be greatly appreciated!

Already tried removing the WAL directory content, but it didn't help. 

This is how all graphs look in Grafana (over 1 week period):

Focusing on the time frame of the logs, the pattern seen is:

• Gap    00:00-04:00  (4 hours)
• Data   04:00-06:00  (2 hours)
• Gap    06:00-10:00  (4 hours)
• Data   10:00-12:00  (2 hours)

Prometheus Log:

level=info ts=2020-03-30T23:00:34.896Z caller=compact.go:496 component=tsdb msg="write block" mint=1585598400000 maxt=1585605600000 ulid=01E4PTRMCJT0NM62PZB0E6B74R duration=34.878117689s

level=info ts=2020-03-30T23:00:37.520Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.837255544s

level=error ts=2020-03-30T23:00:37.520Z caller=db.go:617 component=tsdb msg="compaction failed" err="reload blocks: head truncate failed: create checkpoint: unexpected gap to last checkpoint. expected:3, requested:966"    

level=info ts=2020-03-31T01:00:34.463Z caller=compact.go:496 component=tsdb msg="write block" mint=1585605600000 maxt=1585612800000 ulid=01E4Q1MBMJZ11RVWGATS622DS4 duration=34.44468805s

level=info ts=2020-03-31T01:00:37.279Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.848789851s

level=info ts=2020-03-31T03:00:33.484Z caller=compact.go:496 component=tsdb msg="write block" mint=1585612800000 maxt=1585620000000 ulid=01E4Q8G2WJW6KA2X7SFZS213AK duration=33.466108112s

level=info ts=2020-03-31T03:00:36.190Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.854566091s

level=error ts=2020-03-31T03:00:36.191Z caller=db.go:617 component=tsdb msg="compaction failed" err="reload blocks: head truncate failed: create checkpoint: unexpected gap to last checkpoint. expected:3, requested:1011"

level=info ts=2020-03-31T05:00:35.309Z caller=compact.go:496 component=tsdb msg="write block" mint=1585620000000 maxt=1585627200000 ulid=01E4QFBT4JD0V06XTMS8VFNJ2D duration=35.29069126s

level=info ts=2020-03-31T05:00:38.187Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.929666679s

level=error ts=2020-03-31T05:00:38.188Z caller=db.go:617 component=tsdb msg="compaction failed" err="reload blocks: head truncate failed: create checkpoint: unexpected gap to last checkpoint. expected:3, requested:1011"

level=info ts=2020-03-31T07:00:34.042Z caller=compact.go:496 component=tsdb msg="write block" mint=1585627200000 maxt=1585634400000 ulid=01E4QP7HCJGD61Q10854GJJYHT duration=34.024137496s

level=info ts=2020-03-31T07:00:36.790Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.792030729s

level=info ts=2020-03-31T07:01:32.329Z caller=compact.go:441 component=tsdb msg="compact blocks" count=3 mint=1585540800000 maxt=1585591200000 ulid=01E4QP8P2HDQ0NPEHGXGJ8CTP7 sources="[01E4N3TTCJ5XPP5FE34NB3P7PV 01E4NRE04JPAJ6MS9HXDA2SBRA 01E4PD15WJ0E70DSZQQ8W3E99H]" duration=54.743904585s

level=info ts=2020-03-31T09:00:37.089Z caller=compact.go:496 component=tsdb msg="write block" mint=1585634400000 maxt=1585641600000 ulid=01E4QX38MJJFHTB79GB628M136 duration=37.071321427s

level=info ts=2020-03-31T09:00:39.938Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.923131191s

level=error ts=2020-03-31T09:00:39.939Z caller=db.go:617 component=tsdb msg="compaction failed" err="reload blocks: head truncate failed: create checkpoint: unexpected gap to last checkpoint. expected:3, requested:1056"

level=info ts=2020-03-31T11:00:36.468Z caller=compact.go:496 component=tsdb msg="write block" mint=1585641600000 maxt=1585648800000 ulid=01E4R3YZWK5ST0Q7V3W5M8W7H4 duration=36.448509363s

level=info ts=2020-03-31T11:00:39.342Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.931454875s

level=error ts=2020-03-31T11:00:39.343Z caller=db.go:617 component=tsdb msg="compaction failed" err="reload blocks: head truncate failed: create checkpoint: unexpected gap to last checkpoint. expected:3, requested:1056"

level=info ts=2020-03-31T13:00:36.005Z caller=compact.go:496 component=tsdb msg="write block" mint=1585648800000 maxt=1585656000000 ulid=01E4RATQ4JPJR05EP712JEFCPK duration=35.98733722s

level=info ts=2020-03-31T13:00:39.154Z caller=head.go:661 component=tsdb msg="head GC completed" duration=2.129951864s

level=info ts=2020-03-31T15:00:35.975Z caller=compact.go:496 component=tsdb msg="write block" mint=1585656000000 maxt=1585663200000 ulid=01E4RHPECJJNGNFZS7ZQ4R4RBT duration=35.956287922s

level=info ts=2020-03-31T15:00:39.104Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.974620411s

level=error ts=2020-03-31T15:00:39.104Z caller=db.go:617 component=tsdb msg="compaction failed" err="reload blocks: head truncate failed: create checkpoint: unexpected gap to last checkpoint. expected:3, requested:1101"

level=info ts=2020-03-31T17:00:35.516Z caller=compact.go:496 component=tsdb msg="write block" mint=1585663200000 maxt=1585670400000 ulid=01E4RRJ5MJJ7SA3Q5Y02MTXDNP duration=35.497638853s

level=info ts=2020-03-31T17:00:38.310Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.873887233s

level=error ts=2020-03-31T17:00:38.310Z caller=db.go:617 component=tsdb msg="compaction failed" err="reload blocks: head truncate failed: create checkpoint: unexpected gap to last checkpoint. expected:3, requested:1101"

level=info ts=2020-03-31T19:00:36.432Z caller=compact.go:496 component=tsdb msg="write block" mint=1585670400000 maxt=1585677600000 ulid=01E4RZDWWJ15ZGWZ4BSX8YXCJS duration=36.414280972s

level=info ts=2020-03-31T19:00:38.783Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.48035623s

level=info ts=2020-03-31T21:00:36.634Z caller=compact.go:496 component=tsdb msg="write block" mint=1585677600000 maxt=1585684800000 ulid=01E4S69M4JF8SX32D10WD9GVAJ duration=36.616154547s

level=info ts=2020-03-31T21:00:39.267Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.646089389s

level=error ts=2020-03-31T21:00:39.268Z caller=db.go:617 component=tsdb msg="compaction failed" err="reload blocks: head truncate failed: create checkpoint: unexpected gap to last checkpoint. expected:3, requested:1148"

level=info ts=2020-03-31T23:00:34.236Z caller=compact.go:496 component=tsdb msg="write block" mint=1585684800000 maxt=1585692000000 ulid=01E4SD5BCJWCFJ9KJ0VQ4YMX8N duration=34.218191291s

level=info ts=2020-03-31T23:00:36.688Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.490422893s

level=error ts=2020-03-31T23:00:36.689Z caller=db.go:617 component=tsdb msg="compaction failed" err="reload blocks: head truncate failed: create checkpoint: unexpected gap to last checkpoint. expected:3, requested:1148"

level=info ts=2020-04-01T01:00:36.304Z caller=compact.go:496 component=tsdb msg="write block" mint=1585692000000 maxt=1585699200000 ulid=01E4SM12MJGXFB0M86ZPPW4QJD duration=36.285890512s

level=info ts=2020-04-01T01:00:38.802Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.506051331s

level=info ts=2020-04-01T01:01:34.546Z caller=compact.go:441 component=tsdb msg="compact blocks" count=3 mint=1585605600000 maxt=1585656000000 ulid=01E4SM29AD0DP5YMMEHQNM3N0P sources="[01E4Q1MBMJZ11RVWGATS622DS4 01E4QP7HCJGD61Q10854GJJYHT 01E4RATQ4JPJR05EP712JEFCPK]" duration=54.916735718s

level=info ts=2020-04-01T03:00:37.974Z caller=compact.go:496 component=tsdb msg="write block" mint=1585699200000 maxt=1585706400000 ulid=01E4STWSWJ11YPH1Q0TJZWW7YA duration=37.955727795s

level=info ts=2020-04-01T03:00:40.555Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.607711496s

level=error ts=2020-04-01T03:00:40.556Z caller=db.go:617 component=tsdb msg="compaction failed" err="reload blocks: head truncate failed: create checkpoint: unexpected gap to last checkpoint. expected:3, requested:1197"

level=info ts=2020-04-01T05:00:40.113Z caller=compact.go:496 component=tsdb msg="write block" mint=1585706400000 maxt=1585713600000 ulid=01E4T1RH4JGRDAHK64AVZA2TKT duration=40.095430754s

level=info ts=2020-04-01T05:00:42.925Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.901580077s

level=error ts=2020-04-01T05:00:42.925Z caller=db.go:617 component=tsdb msg="compaction failed" err="reload blocks: head truncate failed: create checkpoint: unexpected gap to last checkpoint. expected:3, requested:1197"

level=info ts=2020-04-01T07:00:39.725Z caller=compact.go:496 component=tsdb msg="write block" mint=1585713600000 maxt=1585720800000 ulid=01E4T8M8CJSWDT0RKHA7NZZY68 duration=39.706716979s

level=info ts=2020-04-01T07:00:42.130Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.572316274s

level=info ts=2020-04-01T09:00:39.515Z caller=compact.go:496 component=tsdb msg="write block" mint=1585720800000 maxt=1585728000000 ulid=01E4TFFZMJ01G0ZK47E5K6XVFK duration=39.496554755s

level=info ts=2020-04-01T09:00:42.289Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.642528373s

level=error ts=2020-04-01T09:00:42.290Z caller=db.go:617 component=tsdb msg="compaction failed" err="reload blocks: head truncate failed: create checkpoint: unexpected gap to last checkpoint. expected:3, requested:1248"

level=info ts=2020-04-01T11:00:40.015Z caller=compact.go:496 component=tsdb msg="write block" mint=1585728000000 maxt=1585735200000 ulid=01E4TPBPWJZ2W94MMQHXMV0ZJZ duration=39.996865011s

level=info ts=2020-04-01T11:00:42.699Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.607789946s

level=error ts=2020-04-01T11:00:42.699Z caller=db.go:617 component=tsdb msg="compaction failed" err="reload blocks: head truncate failed: create checkpoint: unexpected gap to last checkpoint. expected:3, requested:1248"

level=info ts=2020-04-01T13:00:39.585Z caller=compact.go:496 component=tsdb msg="write block" mint=1585735200000 maxt=1585742400000 ulid=01E4TX7E4JY401CMN4TGDYYVJB duration=39.566445763s

level=info ts=2020-04-01T13:00:42.160Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.545487282s

level=info ts=2020-04-01T15:00:40.900Z caller=compact.go:496 component=tsdb msg="write block" mint=1585742400000 maxt=1585749600000 ulid=01E4V435CJGVWXC1K3NFXB13PX duration=40.881849467s

level=info ts=2020-04-01T15:00:43.722Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.920364899s

level=error ts=2020-04-01T15:00:43.723Z caller=db.go:617 component=tsdb msg="compaction failed" err="reload blocks: head truncate failed: create checkpoint: unexpected gap to last checkpoint. expected:3, requested:1302"

level=error ts=2020-04-01T16:47:00.255Z caller=api.go:1374 component=web msg="error writing response" bytesWritten=0 err="write tcp 172.18.0.2:9090->172.18.0.4:50756: write: broken pipe"

level=info ts=2020-04-01T17:00:41.923Z caller=compact.go:496 component=tsdb msg="write block" mint=1585749600000 maxt=1585756800000 ulid=01E4VAYWMJ7X0QKYPMZYASH6WD duration=41.904641892s

level=info ts=2020-04-01T17:00:44.599Z caller=head.go:661 component=tsdb msg="head GC completed" duration=1.698579448s

level=error ts=2020-04-01T17:00:44.600Z caller=db.go:617 component=tsdb msg="compaction failed" err="reload blocks: head truncate failed: create checkpoint: unexpected gap to last checkpoint. expected:3, requested:1302"

level=warn ts=2020-04-01T18:38:12.103Z caller=scrape.go:972 component="scrape manager" 

[Amir Malka]

Hi, Anyone :) ?

בתאריך יום חמישי, 16 באפריל 2020 בשעה 17:15:02 UTC+3, מאת Amir Malka: