Thanos: compact: fails with "invalid plan block" error

Created on 25 May 2018  路  24Comments  路  Source: thanos-io/thanos

Those chunks are from an old pod (we're using deployments, so the replica label doesn't exist anymore, in case this could help for debugging) 

level=info ts=2018-05-24T22:01:03.10004204Z caller=compact.go:245 msg="starting compact node"
level=info ts=2018-05-24T22:01:03.100144202Z caller=compact.go:131 msg="start sync of metas"
level=debug ts=2018-05-24T22:01:03.426927339Z caller=compact.go:165 msg="download meta" block=01CE75YJXFASBNC40BYG8EHD1N
level=debug ts=2018-05-24T22:01:03.528081002Z caller=compact.go:165 msg="download meta" block=01CE7CTA5BG05CXPDZTTPQZ1WX
level=debug ts=2018-05-24T22:01:03.549836998Z caller=compact.go:165 msg="download meta" block=01CE7KP1DCEYPB1J7SYKNKSXB8
level=debug ts=2018-05-24T22:01:03.572966127Z caller=compact.go:165 msg="download meta" block=01CE7THRND9X4YAHZJP17QP9MY
level=debug ts=2018-05-24T22:01:03.623778574Z caller=compact.go:165 msg="download meta" block=01CE81DFXA83PF5ZA34XJH1GJH
level=debug ts=2018-05-24T22:01:03.645886122Z caller=compact.go:165 msg="download meta" block=01CE88975E33ARVHPQNEX8K8TJ
level=debug ts=2018-05-24T22:01:03.704790623Z caller=compact.go:165 msg="download meta" block=01CE8F4YDGM3CC57HKXFBBSWQ2
level=debug ts=2018-05-24T22:01:03.75381572Z caller=compact.go:165 msg="download meta" block=01CE8P0NMQ16JDFD619390KJQH
level=debug ts=2018-05-24T22:01:03.784011615Z caller=compact.go:165 msg="download meta" block=01CE8WWCW8VR2H1YZ92HTK0WS2
level=debug ts=2018-05-24T22:01:03.806186002Z caller=compact.go:165 msg="download meta" block=01CE8WWCWQK9GZE8K6XWRZ9ME1
level=debug ts=2018-05-24T22:01:03.870331206Z caller=compact.go:165 msg="download meta" block=01CE93R44DQWHR2CFG0CXTP5QJ
level=debug ts=2018-05-24T22:01:03.898889804Z caller=compact.go:165 msg="download meta" block=01CE93R44V6DFZEQY1F4F3NVQH
level=debug ts=2018-05-24T22:01:03.919810068Z caller=compact.go:165 msg="download meta" block=01CE9AKVC52RKEJ7Y3EN4VPEFT
level=debug ts=2018-05-24T22:01:03.940709351Z caller=compact.go:165 msg="download meta" block=01CE9AKVCGCSX7VNDS6HGR9CTY
level=debug ts=2018-05-24T22:01:04.026893239Z caller=compact.go:165 msg="download meta" block=01CE9HFJMGYHTQFP2SWM78H8DG
level=debug ts=2018-05-24T22:01:04.049993424Z caller=compact.go:165 msg="download meta" block=01CE9HFJMJ8GB9JX7FB3CJ9094
level=debug ts=2018-05-24T22:01:04.068987694Z caller=compact.go:165 msg="download meta" block=01CE9RB9WG5C11SHFMBP9524W0
level=debug ts=2018-05-24T22:01:04.090585575Z caller=compact.go:165 msg="download meta" block=01CE9RB9WJ501MZ1FFFG0VH0F7
level=debug ts=2018-05-24T22:01:04.123175132Z caller=compact.go:165 msg="download meta" block=01CE9Z714G2BARSFT68HHKAT4M
level=debug ts=2018-05-24T22:01:04.148953081Z caller=compact.go:165 msg="download meta" block=01CE9Z714JHRXJ7BA4D0J8WAAV
level=info ts=2018-05-24T22:01:04.168912292Z caller=compact.go:137 msg="start of GC"


level=error ts=2018-05-24T22:01:27.662643337Z caller=main.go:147 msg="running command failed" err="compaction: invalid plan block /var/thanos/compact/compact/0@{monitor=\"prometheus\",replica=\"prometheus-thanos-1-86d6c8569d-x22rl\"}/01CE75YJXFASBNC40BYG8EHD1N: No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 4160. Complete: 0"

01CE75YJXFASBNC40BYG8EHD1N/meta.json

{
    "version": 1,
    "ulid": "01CE75YJXFASBNC40BYG8EHD1N",
    "minTime": 1527091200000,
    "maxTime": 1527098400000,
    "stats": {
        "numSamples": 1879211741,
        "numSeries": 2858110,
        "numChunks": 16550746
    },
    "compaction": {
        "level": 1,
        "sources": [
            "01CE75YJXFASBNC40BYG8EHD1N"
        ]
    },
    "thanos": {
        "labels": {
            "monitor": "prometheus",
            "replica": "prometheus-thanos-1-86d6c8569d-x22rl"
        },
        "downsample": {
            "resolution": 0
        }
    }
}
bug
Source
picture clmssz
👍1

Most helpful comment

Thanks all for helping with this issue!

Thanos now handles these blocks gracefully (it repairs them in place). The TSDB it not yet fixed (since it is not straightforward), but when the issue occurs, Thanos handles it well now.

Feel free to use master-2018-06-15-5b66b72 docker tag or above. New release candidate will produce soon.

Thanks to @BenoitKnecht who figured the root cause and @clmssz for reporting it! Nice work!

picture bwplotka on 15 Jun 2018
🎉2

All 24 comments

Same issue here

{
    "version": 1,
    "ulid": "01C5W82QX8KV1XVNPKJSMBW1CE",
    "minTime": 1518134400000,
    "maxTime": 1518141600000,
    "stats": {
        "numSamples": 135632106,
        "numSeries": 1097731,
        "numChunks": 1098565
    },
    "compaction": {
        "level": 1,
        "sources": [
            "01C5W82QX8KV1XVNPKJSMBW1CE"
        ]
    },
    "thanos": {
        "labels": {
            "replica": "hvs-3e86f1c.ams2"
        }
    }
}

level=error ts=2018-05-31T03:17:45.200714938Z caller=compact.go:194 msg="critical error detected; halting" err="compaction: invalid plan block /tmp/thanos-ams2-hvs/compact/0@{replica=\"hvs-3e86f1c.ams2\"}/01C5W82QX8KV1XVNPKJSMBW1CE: No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 834. Complete: 0"
I've got this repeatedly across a few different compaction attempts.

TimSimmons picture TimSimmons on 31 May 2018

KK, @TimSimmons how many sources (prom+sidecars) you have? You have only single external label - "replica" so I hope only few replicas (there are no 2 sidecars that are uploading blocks with same external labels? Do you have sidecar compaction enabled? What about rest compactor logs, can we have them? Any detail would be nice here, since I cannot repro it. Have you touched your buckets manually?

bwplotka picture bwplotka on 31 May 2018

@TimSimmons it is S3, right?

bwplotka picture bwplotka on 31 May 2018

@clmssz it is GCS for you?

bwplotka picture bwplotka on 31 May 2018

@Bplotka yep GCS. FYI we're running Prometheus v2.2.1.

thanos bucket verify outputs the same messages on all directories

level=warn ts=2018-05-31T14:55:38.8598572Z caller=index_issue.go:60 msg="detected issue" id=01CE75YJXFASBNC40BYG8EHD1N err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 4160. Complete: 0" issue=index_issue
clmssz picture clmssz on 31 May 2018

Yeah it's 2 sidecars with different replica labels.

It's a pretty old version of the sidecar a5a7246 that uploaded these blocks originally. I don't know what sidecar compaction is :) the blocks should not have been compacted when they were uploaded, if that's what it is.

These are the only two logs for that block:

level=debug ts=2018-05-30T23:26:16.05868901Z caller=compact.go:165 msg="download meta" block=01C5W82QX8KV1XVNPKJSMBW1CE
level=error ts=2018-05-31T03:17:45.200714938Z caller=compact.go:194 msg="critical error detected; halting" err="compaction: invalid plan block /tmp/thanos-ams2-hvs/compact/0@{replica=\"hvs-3e86f1c.ams2\"}/01C5W82QX8KV1XVNPKJSMBW1CE: No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 834. Complete: 0"

It is the s3 plugin, latest compactor 2c636654cf04d7cbfd70d2dcacd017b3a44de6b1

This is the log of the entire run
https://gist.github.com/TimSimmons/74db728cfb786eded7d20d2ca9a24955

I did touch my buckets manually to delete some old corrupt data. But that block is still extant in the bucket and I didn't start the compactor until after I had deleted some older blocks.

TimSimmons picture TimSimmons on 31 May 2018

Hit this overnight running thanos compact --wait

level=error ts=2018-05-30T22:06:58.888519502Z caller=compact.go:218 msg="critical error detected; halting" err="compaction: invalid plan block /var/thanos/compact/compact/0@{cluster=\"kubernetes-ause1a-stg-uops\",monitor=\"prometheus\",replica=\"thanos-prom-0\"}/01CEPV6M574EV7D8YTPWF2943R: No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 4. Complete: 0"

meta.json

{ "version": 1, "ulid": "01CEPV6M574EV7D8YTPWF2943R", "minTime": 1527616800000, "maxTime": 1527624000000, "stats": { "numSamples": 307019144, "numSeries": 1391617, "numChunks": 2657065 }, "compaction": { "level": 1, "sources": [ "01CEPV6M574EV7D8YTPWF2943R" ] }, "thanos": { "labels": { "cluster": "kubernetes-ause1a-stg-uops", "monitor": "prometheus", "replica": "thanos-prom-0" }, "downsample": { "resolution": 0 } } }

single replica
improbable/thanos:v0.1.0-rc.0

stevenkehrli-trelnex picture stevenkehrli-trelnex on 31 May 2018

I grabbed the files from our gcs bucket plus the thanos-compact logs. Should be accessible here (249.3MB): https://s3-us-west-2.amazonaws.com/steven-thanos/354.zip

stevenkehrli-trelnex picture stevenkehrli-trelnex on 31 May 2018

I think I have the same issue. I'm running Thanos in a Docker container, and my bucket is on a local S3-like object store. When I run thanos bucket verify, I get the following errors:

$ thanos bucket verify
level=warn ts=2018-06-01T06:19:22.953839396Z caller=verify.go:48 msg="GLOBAL COMPACTOR SHOULD __NOT__ BE RUNNING ON THE SAME BUCKET" issues=2 repair=false
level=info ts=2018-06-01T06:19:22.953922745Z caller=index_issue.go:26 msg="started verifying issue" with-repair=false issue=index_issue
level=warn ts=2018-06-01T06:19:28.113735798Z caller=index_issue.go:60 msg="detected issue" id=01CEVS4B0BB9X0JBSN9A8WB1Y2 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 12. Complete: 0" issue=index_issue
level=warn ts=2018-06-01T06:19:32.864177442Z caller=index_issue.go:60 msg="detected issue" id=01CEW0028589NDMDDS2KCHKBB4 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 12. Complete: 0" issue=index_issue
level=info ts=2018-06-01T06:19:50.799564491Z caller=index_issue.go:114 msg="verified issue" with-repair=false issue=index_issue
level=info ts=2018-06-01T06:19:50.799584525Z caller=overlapped_blocks.go:20 msg="started verifying issue" with-repair=false issue=overlapped_blocks
level=info ts=2018-06-01T06:19:51.398539911Z caller=verify.go:67 msg="verify completed" issues=2 repair=false
level=info ts=2018-06-01T06:19:51.398842669Z caller=main.go:146 msg=exiting

(I had errors on every block but cut the logs for brevity's sake.)

To get a better idea of what's going on, I applied the following patch:

diff --git a/pkg/block/index.go b/pkg/block/index.go
index 9d02b6c..1a8dd7b 100644
--- a/pkg/block/index.go
+++ b/pkg/block/index.go
@@ -3,6 +3,7 @@ package block
 import (
        "encoding/json"
        "hash/crc32"
+       "log"
        "math/rand"
        "os"
        "path/filepath"
@@ -241,6 +242,7 @@ func GatherIndexIssueStats(fn string, minTime int64, maxTime int64) (stats Index
                ooo := 0
                if chks[0].MinTime < minTime || chks[0].MaxTime > maxTime {
                        stats.Outsiders++
+                       log.Printf("DEBUG0: outsiders=%d, minTime=%d, chks[0].MinTime=%d, maxTime=%d, chks[0].MaxTime=%d\n", stats.Outsiders, minTime, chks[0].MinTime, maxTime, chks[0].MaxTime)
                        if chks[0].MinTime > maxTime || chks[0].MaxTime < minTime {
                                stats.CompleteOutsiders++
                        }
@@ -250,6 +252,7 @@ func GatherIndexIssueStats(fn string, minTime int64, maxTime int64) (stats Index

                        if c.MinTime < minTime || c.MaxTime > maxTime {
                                stats.Outsiders++
+                               log.Printf("DEBUG1: outsiders=%d, minTime=%d, c.MinTime=%d, maxTime=%d, c.MaxTime=%d\n", stats.Outsiders, minTime, c.MinTime, maxTime, c.MaxTime)
                                if c.MinTime > maxTime || c.MaxTime < minTime {
                                        stats.CompleteOutsiders++
                                }

and ran thanos bucket verify again:

$ thanos bucket verify
level=warn ts=2018-06-01T06:19:22.953839396Z caller=verify.go:48 msg="GLOBAL COMPACTOR SHOULD __NOT__ BE RUNNING ON THE SAME BUCKET" issues=2 repair=false
level=info ts=2018-06-01T06:19:22.953922745Z caller=index_issue.go:26 msg="started verifying issue" with-repair=false issue=index_issue
2018/06/01 06:19:28 DEBUG1: outsiders=1, minTime=1527782400000, c.MinTime=1527789600000, maxTime=1527789600000, c.MaxTime=1527791980000
2018/06/01 06:19:28 DEBUG1: outsiders=2, minTime=1527782400000, c.MinTime=1527789600000, maxTime=1527789600000, c.MaxTime=1527791980000
2018/06/01 06:19:28 DEBUG1: outsiders=3, minTime=1527782400000, c.MinTime=1527789600000, maxTime=1527789600000, c.MaxTime=1527791980000
2018/06/01 06:19:28 DEBUG1: outsiders=4, minTime=1527782400000, c.MinTime=1527789600000, maxTime=1527789600000, c.MaxTime=1527791980000
2018/06/01 06:19:28 DEBUG1: outsiders=5, minTime=1527782400000, c.MinTime=1527789600000, maxTime=1527789600000, c.MaxTime=1527791980000
2018/06/01 06:19:28 DEBUG1: outsiders=6, minTime=1527782400000, c.MinTime=1527789600000, maxTime=1527789600000, c.MaxTime=1527791980000
2018/06/01 06:19:28 DEBUG1: outsiders=7, minTime=1527782400000, c.MinTime=1527789600000, maxTime=1527789600000, c.MaxTime=1527791980000
2018/06/01 06:19:28 DEBUG1: outsiders=8, minTime=1527782400000, c.MinTime=1527789600000, maxTime=1527789600000, c.MaxTime=1527791980000
2018/06/01 06:19:28 DEBUG1: outsiders=9, minTime=1527782400000, c.MinTime=1527789600000, maxTime=1527789600000, c.MaxTime=1527791980000
2018/06/01 06:19:28 DEBUG1: outsiders=10, minTime=1527782400000, c.MinTime=1527789600000, maxTime=1527789600000, c.MaxTime=1527791980000
2018/06/01 06:19:28 DEBUG1: outsiders=11, minTime=1527782400000, c.MinTime=1527789600000, maxTime=1527789600000, c.MaxTime=1527791980000
2018/06/01 06:19:28 DEBUG1: outsiders=12, minTime=1527782400000, c.MinTime=1527789600000, maxTime=1527789600000, c.MaxTime=1527791980000
level=warn ts=2018-06-01T06:19:28.113735798Z caller=index_issue.go:60 msg="detected issue" id=01CEVS4B0BB9X0JBSN9A8WB1Y2 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 12. Complete: 0" issue=index_issue
2018/06/01 06:19:32 DEBUG1: outsiders=1, minTime=1527789600000, c.MinTime=1527796800000, maxTime=1527796800000, c.MaxTime=1527799180000
2018/06/01 06:19:32 DEBUG1: outsiders=2, minTime=1527789600000, c.MinTime=1527796800000, maxTime=1527796800000, c.MaxTime=1527799180000
2018/06/01 06:19:32 DEBUG1: outsiders=3, minTime=1527789600000, c.MinTime=1527796800000, maxTime=1527796800000, c.MaxTime=1527799180000
2018/06/01 06:19:32 DEBUG1: outsiders=4, minTime=1527789600000, c.MinTime=1527796800000, maxTime=1527796800000, c.MaxTime=1527799180000
2018/06/01 06:19:32 DEBUG1: outsiders=5, minTime=1527789600000, c.MinTime=1527796800000, maxTime=1527796800000, c.MaxTime=1527799180000
2018/06/01 06:19:32 DEBUG1: outsiders=6, minTime=1527789600000, c.MinTime=1527796800000, maxTime=1527796800000, c.MaxTime=1527799180000
2018/06/01 06:19:32 DEBUG1: outsiders=7, minTime=1527789600000, c.MinTime=1527796800000, maxTime=1527796800000, c.MaxTime=1527799180000
2018/06/01 06:19:32 DEBUG1: outsiders=8, minTime=1527789600000, c.MinTime=1527796800000, maxTime=1527796800000, c.MaxTime=1527799180000
2018/06/01 06:19:32 DEBUG1: outsiders=9, minTime=1527789600000, c.MinTime=1527796800000, maxTime=1527796800000, c.MaxTime=1527799180000
2018/06/01 06:19:32 DEBUG1: outsiders=10, minTime=1527789600000, c.MinTime=1527796800000, maxTime=1527796800000, c.MaxTime=1527799180000
2018/06/01 06:19:32 DEBUG1: outsiders=11, minTime=1527789600000, c.MinTime=1527796800000, maxTime=1527796800000, c.MaxTime=1527799180000
2018/06/01 06:19:32 DEBUG1: outsiders=12, minTime=1527789600000, c.MinTime=1527796800000, maxTime=1527796800000, c.MaxTime=1527799180000
level=warn ts=2018-06-01T06:19:32.864177442Z caller=index_issue.go:60 msg="detected issue" id=01CEW0028589NDMDDS2KCHKBB4 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 12. Complete: 0" issue=index_issue
level=info ts=2018-06-01T06:19:50.799564491Z caller=index_issue.go:114 msg="verified issue" with-repair=false issue=index_issue
level=info ts=2018-06-01T06:19:50.799584525Z caller=overlapped_blocks.go:20 msg="started verifying issue" with-repair=false issue=overlapped_blocks
level=info ts=2018-06-01T06:19:51.398539911Z caller=verify.go:67 msg="verify completed" issues=2 repair=false
level=info ts=2018-06-01T06:19:51.398842669Z caller=main.go:146 msg=exiting

So if I compare minTime and c.MinTime on the first outsider, I get:

$ date -d @1527818400   
Fri Jun  1 04:00:00 CEST 2018
$ date -d @1527825600   
Fri Jun  1 06:00:00 CEST 2018

Exactly two hours off, and I happen to be in UTC+2. The strange thing is that both Prometheus and Thanos are running in Docker containers, and both are in the UTC timezone:

$ docker exec prometheus date
Fri Jun  1 07:01:08 UTC 2018
$ docker exec thanos date
Fri Jun  1 07:01:08 UTC 2018

Can this be caused by a scrape target returning metrics in the wrong timezone?

BenoitKnecht picture BenoitKnecht on 1 Jun 2018

OK, I think I was wrong to suspect timezone issues; the 2-hour difference I was seeing is due to the fact that the blocks span 2 hours.

Looking at the outsider chunks more closely, it looks like all of them start exactly on the block's maxTime, and end exactly 39 minutes and 40 seconds after that.

In other words, all the outsider chunks satisfy maxTime == c.MinTime:

```console
$ thanos bucket verify
level=warn ts=2018-06-01T11:19:03.317535052Z caller=verify.go:48 msg="GLOBAL COMPACTOR SHOULD __NOT__ BE RUNNING ON THE SAME BUCKET" issues=2 repair=false
level=info ts=2018-06-01T11:19:03.317580433Z caller=index_issue.go:26 msg="started verifying issue" with-repair=false issue=index_issue
2018/06/01 11:19:05 DEBUG1: outsiders=1, minTime=2018-05-31 16:00:00 +0000 UTC, maxTime=2018-05-31 18:00:00 +0000 UTC, c.MinTime=2018-05-31 18:00:00 +0000 UTC, c.MaxTime=2018-05-31 18:39:40 +0000 UTC
2018/06/01 11:19:05 DEBUG1: outsiders=2, minTime=2018-05-31 16:00:00 +0000 UTC, maxTime=2018-05-31 18:00:00 +0000 UTC, c.MinTime=2018-05-31 18:00:00 +0000 UTC, c.MaxTime=2018-05-31 18:39:40 +0000 UTC
2018/06/01 11:19:05 DEBUG1: outsiders=3, minTime=2018-05-31 16:00:00 +0000 UTC, maxTime=2018-05-31 18:00:00 +0000 UTC, c.MinTime=2018-05-31 18:00:00 +0000 UTC, c.MaxTime=2018-05-31 18:39:40 +0000 UTC
2018/06/01 11:19:05 DEBUG1: outsiders=4, minTime=2018-05-31 16:00:00 +0000 UTC, maxTime=2018-05-31 18:00:00 +0000 UTC, c.MinTime=2018-05-31 18:00:00 +0000 UTC, c.MaxTime=2018-05-31 18:39:40 +0000 UTC
2018/06/01 11:19:05 DEBUG1: outsiders=5, minTime=2018-05-31 16:00:00 +0000 UTC, maxTime=2018-05-31 18:00:00 +0000 UTC, c.MinTime=2018-05-31 18:00:00 +0000 UTC, c.MaxTime=2018-05-31 18:39:40 +0000 UTC
2018/06/01 11:19:05 DEBUG1: outsiders=6, minTime=2018-05-31 16:00:00 +0000 UTC, maxTime=2018-05-31 18:00:00 +0000 UTC, c.MinTime=2018-05-31 18:00:00 +0000 UTC, c.MaxTime=2018-05-31 18:39:40 +0000 UTC
2018/06/01 11:19:05 DEBUG1: outsiders=7, minTime=2018-05-31 16:00:00 +0000 UTC, maxTime=2018-05-31 18:00:00 +0000 UTC, c.MinTime=2018-05-31 18:00:00 +0000 UTC, c.MaxTime=2018-05-31 18:39:40 +0000 UTC
2018/06/01 11:19:05 DEBUG1: outsiders=8, minTime=2018-05-31 16:00:00 +0000 UTC, maxTime=2018-05-31 18:00:00 +0000 UTC, c.MinTime=2018-05-31 18:00:00 +0000 UTC, c.MaxTime=2018-05-31 18:39:40 +0000 UTC
2018/06/01 11:19:05 DEBUG1: outsiders=9, minTime=2018-05-31 16:00:00 +0000 UTC, maxTime=2018-05-31 18:00:00 +0000 UTC, c.MinTime=2018-05-31 18:00:00 +0000 UTC, c.MaxTime=2018-05-31 18:39:40 +0000 UTC
2018/06/01 11:19:05 DEBUG1: outsiders=10, minTime=2018-05-31 16:00:00 +0000 UTC, maxTime=2018-05-31 18:00:00 +0000 UTC, c.MinTime=2018-05-31 18:00:00 +0000 UTC, c.MaxTime=2018-05-31 18:39:40 +0000 UTC
2018/06/01 11:19:05 DEBUG1: outsiders=11, minTime=2018-05-31 16:00:00 +0000 UTC, maxTime=2018-05-31 18:00:00 +0000 UTC, c.MinTime=2018-05-31 18:00:00 +0000 UTC, c.MaxTime=2018-05-31 18:39:40 +0000 UTC
2018/06/01 11:19:05 DEBUG1: outsiders=12, minTime=2018-05-31 16:00:00 +0000 UTC, maxTime=2018-05-31 18:00:00 +0000 UTC, c.MinTime=2018-05-31 18:00:00 +0000 UTC, c.MaxTime=2018-05-31 18:39:40 +0000 UTC
level=warn ts=2018-06-01T11:19:05.026805979Z caller=index_issue.go:60 msg="detected issue" id=01CEVS4B0BB9X0JBSN9A8WB1Y2 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 12. Complete: 0" issue=index_issue
2018/06/01 11:19:07 DEBUG1: outsiders=1, minTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 20:00:00 +0000 UTC, c.MinTime=2018-05-31 20:00:00 +0000 UTC, c.MaxTime=2018-05-31 20:39:40 +0000 UTC
2018/06/01 11:19:07 DEBUG1: outsiders=2, minTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 20:00:00 +0000 UTC, c.MinTime=2018-05-31 20:00:00 +0000 UTC, c.MaxTime=2018-05-31 20:39:40 +0000 UTC
2018/06/01 11:19:07 DEBUG1: outsiders=3, minTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 20:00:00 +0000 UTC, c.MinTime=2018-05-31 20:00:00 +0000 UTC, c.MaxTime=2018-05-31 20:39:40 +0000 UTC
2018/06/01 11:19:07 DEBUG1: outsiders=4, minTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 20:00:00 +0000 UTC, c.MinTime=2018-05-31 20:00:00 +0000 UTC, c.MaxTime=2018-05-31 20:39:40 +0000 UTC
2018/06/01 11:19:07 DEBUG1: outsiders=5, minTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 20:00:00 +0000 UTC, c.MinTime=2018-05-31 20:00:00 +0000 UTC, c.MaxTime=2018-05-31 20:39:40 +0000 UTC
2018/06/01 11:19:07 DEBUG1: outsiders=6, minTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 20:00:00 +0000 UTC, c.MinTime=2018-05-31 20:00:00 +0000 UTC, c.MaxTime=2018-05-31 20:39:40 +0000 UTC
2018/06/01 11:19:07 DEBUG1: outsiders=7, minTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 20:00:00 +0000 UTC, c.MinTime=2018-05-31 20:00:00 +0000 UTC, c.MaxTime=2018-05-31 20:39:40 +0000 UTC
2018/06/01 11:19:07 DEBUG1: outsiders=8, minTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 20:00:00 +0000 UTC, c.MinTime=2018-05-31 20:00:00 +0000 UTC, c.MaxTime=2018-05-31 20:39:40 +0000 UTC
2018/06/01 11:19:07 DEBUG1: outsiders=9, minTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 20:00:00 +0000 UTC, c.MinTime=2018-05-31 20:00:00 +0000 UTC, c.MaxTime=2018-05-31 20:39:40 +0000 UTC
2018/06/01 11:19:07 DEBUG1: outsiders=10, minTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 20:00:00 +0000 UTC, c.MinTime=2018-05-31 20:00:00 +0000 UTC, c.MaxTime=2018-05-31 20:39:40 +0000 UTC
2018/06/01 11:19:07 DEBUG1: outsiders=11, minTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 20:00:00 +0000 UTC, c.MinTime=2018-05-31 20:00:00 +0000 UTC, c.MaxTime=2018-05-31 20:39:40 +0000 UTC
2018/06/01 11:19:07 DEBUG1: outsiders=12, minTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 20:00:00 +0000 UTC, c.MinTime=2018-05-31 20:00:00 +0000 UTC, c.MaxTime=2018-05-31 20:39:40 +0000 UTC
level=warn ts=2018-06-01T11:19:07.312529645Z caller=index_issue.go:60 msg="detected issue" id=01CEW0028589NDMDDS2KCHKBB4 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 12. Complete: 0" issue=index_issue
2018/06/01 11:19:08 DEBUG1: outsiders=1, minTime=2018-05-31 20:00:00 +0000 UTC, maxTime=2018-05-31 22:00:00 +0000 UTC, c.MinTime=2018-05-31 22:00:00 +0000 UTC, c.MaxTime=2018-05-31 22:39:40 +0000 UTC
2018/06/01 11:19:08 DEBUG1: outsiders=2, minTime=2018-05-31 20:00:00 +0000 UTC, maxTime=2018-05-31 22:00:00 +0000 UTC, c.MinTime=2018-05-31 22:00:00 +0000 UTC, c.MaxTime=2018-05-31 22:39:40 +0000 UTC
2018/06/01 11:19:08 DEBUG1: outsiders=3, minTime=2018-05-31 20:00:00 +0000 UTC, maxTime=2018-05-31 22:00:00 +0000 UTC, c.MinTime=2018-05-31 22:00:00 +0000 UTC, c.MaxTime=2018-05-31 22:39:40 +0000 UTC
2018/06/01 11:19:08 DEBUG1: outsiders=4, minTime=2018-05-31 20:00:00 +0000 UTC, maxTime=2018-05-31 22:00:00 +0000 UTC, c.MinTime=2018-05-31 22:00:00 +0000 UTC, c.MaxTime=2018-05-31 22:39:40 +0000 UTC
2018/06/01 11:19:08 DEBUG1: outsiders=5, minTime=2018-05-31 20:00:00 +0000 UTC, maxTime=2018-05-31 22:00:00 +0000 UTC, c.MinTime=2018-05-31 22:00:00 +0000 UTC, c.MaxTime=2018-05-31 22:39:40 +0000 UTC
2018/06/01 11:19:08 DEBUG1: outsiders=6, minTime=2018-05-31 20:00:00 +0000 UTC, maxTime=2018-05-31 22:00:00 +0000 UTC, c.MinTime=2018-05-31 22:00:00 +0000 UTC, c.MaxTime=2018-05-31 22:39:40 +0000 UTC
2018/06/01 11:19:08 DEBUG1: outsiders=7, minTime=2018-05-31 20:00:00 +0000 UTC, maxTime=2018-05-31 22:00:00 +0000 UTC, c.MinTime=2018-05-31 22:00:00 +0000 UTC, c.MaxTime=2018-05-31 22:39:40 +0000 UTC
2018/06/01 11:19:08 DEBUG1: outsiders=8, minTime=2018-05-31 20:00:00 +0000 UTC, maxTime=2018-05-31 22:00:00 +0000 UTC, c.MinTime=2018-05-31 22:00:00 +0000 UTC, c.MaxTime=2018-05-31 22:39:40 +0000 UTC
2018/06/01 11:19:08 DEBUG1: outsiders=9, minTime=2018-05-31 20:00:00 +0000 UTC, maxTime=2018-05-31 22:00:00 +0000 UTC, c.MinTime=2018-05-31 22:00:00 +0000 UTC, c.MaxTime=2018-05-31 22:39:40 +0000 UTC
2018/06/01 11:19:08 DEBUG1: outsiders=10, minTime=2018-05-31 20:00:00 +0000 UTC, maxTime=2018-05-31 22:00:00 +0000 UTC, c.MinTime=2018-05-31 22:00:00 +0000 UTC, c.MaxTime=2018-05-31 22:39:40 +0000 UTC
2018/06/01 11:19:08 DEBUG1: outsiders=11, minTime=2018-05-31 20:00:00 +0000 UTC, maxTime=2018-05-31 22:00:00 +0000 UTC, c.MinTime=2018-05-31 22:00:00 +0000 UTC, c.MaxTime=2018-05-31 22:39:40 +0000 UTC
2018/06/01 11:19:08 DEBUG1: outsiders=12, minTime=2018-05-31 20:00:00 +0000 UTC, maxTime=2018-05-31 22:00:00 +0000 UTC, c.MinTime=2018-05-31 22:00:00 +0000 UTC, c.MaxTime=2018-05-31 22:39:40 +0000 UTC
level=warn ts=2018-06-01T11:19:08.564376992Z caller=index_issue.go:60 msg="detected issue" id=01CEW6VSG525ME45V9Y0GX4XB1 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 12. Complete: 0" issue=index_issue
2018/06/01 11:19:09 DEBUG1: outsiders=1, minTime=2018-05-31 22:00:00 +0000 UTC, maxTime=2018-06-01 00:00:00 +0000 UTC, c.MinTime=2018-06-01 00:00:00 +0000 UTC, c.MaxTime=2018-06-01 00:39:40 +0000 UTC
2018/06/01 11:19:09 DEBUG1: outsiders=2, minTime=2018-05-31 22:00:00 +0000 UTC, maxTime=2018-06-01 00:00:00 +0000 UTC, c.MinTime=2018-06-01 00:00:00 +0000 UTC, c.MaxTime=2018-06-01 00:39:40 +0000 UTC
2018/06/01 11:19:09 DEBUG1: outsiders=3, minTime=2018-05-31 22:00:00 +0000 UTC, maxTime=2018-06-01 00:00:00 +0000 UTC, c.MinTime=2018-06-01 00:00:00 +0000 UTC, c.MaxTime=2018-06-01 00:39:40 +0000 UTC
2018/06/01 11:19:09 DEBUG1: outsiders=4, minTime=2018-05-31 22:00:00 +0000 UTC, maxTime=2018-06-01 00:00:00 +0000 UTC, c.MinTime=2018-06-01 00:00:00 +0000 UTC, c.MaxTime=2018-06-01 00:39:40 +0000 UTC
2018/06/01 11:19:09 DEBUG1: outsiders=5, minTime=2018-05-31 22:00:00 +0000 UTC, maxTime=2018-06-01 00:00:00 +0000 UTC, c.MinTime=2018-06-01 00:00:00 +0000 UTC, c.MaxTime=2018-06-01 00:39:40 +0000 UTC
2018/06/01 11:19:09 DEBUG1: outsiders=6, minTime=2018-05-31 22:00:00 +0000 UTC, maxTime=2018-06-01 00:00:00 +0000 UTC, c.MinTime=2018-06-01 00:00:00 +0000 UTC, c.MaxTime=2018-06-01 00:39:40 +0000 UTC
2018/06/01 11:19:09 DEBUG1: outsiders=7, minTime=2018-05-31 22:00:00 +0000 UTC, maxTime=2018-06-01 00:00:00 +0000 UTC, c.MinTime=2018-06-01 00:00:00 +0000 UTC, c.MaxTime=2018-06-01 00:39:40 +0000 UTC
2018/06/01 11:19:09 DEBUG1: outsiders=8, minTime=2018-05-31 22:00:00 +0000 UTC, maxTime=2018-06-01 00:00:00 +0000 UTC, c.MinTime=2018-06-01 00:00:00 +0000 UTC, c.MaxTime=2018-06-01 00:39:40 +0000 UTC
2018/06/01 11:19:09 DEBUG1: outsiders=9, minTime=2018-05-31 22:00:00 +0000 UTC, maxTime=2018-06-01 00:00:00 +0000 UTC, c.MinTime=2018-06-01 00:00:00 +0000 UTC, c.MaxTime=2018-06-01 00:39:40 +0000 UTC
2018/06/01 11:19:09 DEBUG1: outsiders=10, minTime=2018-05-31 22:00:00 +0000 UTC, maxTime=2018-06-01 00:00:00 +0000 UTC, c.MinTime=2018-06-01 00:00:00 +0000 UTC, c.MaxTime=2018-06-01 00:39:40 +0000 UTC
2018/06/01 11:19:09 DEBUG1: outsiders=11, minTime=2018-05-31 22:00:00 +0000 UTC, maxTime=2018-06-01 00:00:00 +0000 UTC, c.MinTime=2018-06-01 00:00:00 +0000 UTC, c.MaxTime=2018-06-01 00:39:40 +0000 UTC
2018/06/01 11:19:10 DEBUG1: outsiders=12, minTime=2018-05-31 22:00:00 +0000 UTC, maxTime=2018-06-01 00:00:00 +0000 UTC, c.MinTime=2018-06-01 00:00:00 +0000 UTC, c.MaxTime=2018-06-01 00:39:40 +0000 UTC
level=warn ts=2018-06-01T11:19:10.003212231Z caller=index_issue.go:60 msg="detected issue" id=01CEWDQGRDYJXFVVDXPGBCNN36 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 12. Complete: 0" issue=index_issue
2018/06/01 11:19:11 DEBUG1: outsiders=1, minTime=2018-06-01 00:00:00 +0000 UTC, maxTime=2018-06-01 02:00:00 +0000 UTC, c.MinTime=2018-06-01 02:00:00 +0000 UTC, c.MaxTime=2018-06-01 02:39:40 +0000 UTC
2018/06/01 11:19:11 DEBUG1: outsiders=2, minTime=2018-06-01 00:00:00 +0000 UTC, maxTime=2018-06-01 02:00:00 +0000 UTC, c.MinTime=2018-06-01 02:00:00 +0000 UTC, c.MaxTime=2018-06-01 02:39:40 +0000 UTC
2018/06/01 11:19:11 DEBUG1: outsiders=3, minTime=2018-06-01 00:00:00 +0000 UTC, maxTime=2018-06-01 02:00:00 +0000 UTC, c.MinTime=2018-06-01 02:00:00 +0000 UTC, c.MaxTime=2018-06-01 02:39:40 +0000 UTC
2018/06/01 11:19:11 DEBUG1: outsiders=4, minTime=2018-06-01 00:00:00 +0000 UTC, maxTime=2018-06-01 02:00:00 +0000 UTC, c.MinTime=2018-06-01 02:00:00 +0000 UTC, c.MaxTime=2018-06-01 02:39:40 +0000 UTC
2018/06/01 11:19:11 DEBUG1: outsiders=5, minTime=2018-06-01 00:00:00 +0000 UTC, maxTime=2018-06-01 02:00:00 +0000 UTC, c.MinTime=2018-06-01 02:00:00 +0000 UTC, c.MaxTime=2018-06-01 02:39:40 +0000 UTC
2018/06/01 11:19:11 DEBUG1: outsiders=6, minTime=2018-06-01 00:00:00 +0000 UTC, maxTime=2018-06-01 02:00:00 +0000 UTC, c.MinTime=2018-06-01 02:00:00 +0000 UTC, c.MaxTime=2018-06-01 02:39:40 +0000 UTC
2018/06/01 11:19:11 DEBUG1: outsiders=7, minTime=2018-06-01 00:00:00 +0000 UTC, maxTime=2018-06-01 02:00:00 +0000 UTC, c.MinTime=2018-06-01 02:00:00 +0000 UTC, c.MaxTime=2018-06-01 02:39:40 +0000 UTC
2018/06/01 11:19:11 DEBUG1: outsiders=8, minTime=2018-06-01 00:00:00 +0000 UTC, maxTime=2018-06-01 02:00:00 +0000 UTC, c.MinTime=2018-06-01 02:00:00 +0000 UTC, c.MaxTime=2018-06-01 02:39:40 +0000 UTC
2018/06/01 11:19:11 DEBUG1: outsiders=9, minTime=2018-06-01 00:00:00 +0000 UTC, maxTime=2018-06-01 02:00:00 +0000 UTC, c.MinTime=2018-06-01 02:00:00 +0000 UTC, c.MaxTime=2018-06-01 02:39:40 +0000 UTC
2018/06/01 11:19:11 DEBUG1: outsiders=10, minTime=2018-06-01 00:00:00 +0000 UTC, maxTime=2018-06-01 02:00:00 +0000 UTC, c.MinTime=2018-06-01 02:00:00 +0000 UTC, c.MaxTime=2018-06-01 02:39:40 +0000 UTC
2018/06/01 11:19:11 DEBUG1: outsiders=11, minTime=2018-06-01 00:00:00 +0000 UTC, maxTime=2018-06-01 02:00:00 +0000 UTC, c.MinTime=2018-06-01 02:00:00 +0000 UTC, c.MaxTime=2018-06-01 02:39:40 +0000 UTC
2018/06/01 11:19:11 DEBUG1: outsiders=12, minTime=2018-06-01 00:00:00 +0000 UTC, maxTime=2018-06-01 02:00:00 +0000 UTC, c.MinTime=2018-06-01 02:00:00 +0000 UTC, c.MaxTime=2018-06-01 02:39:40 +0000 UTC
level=warn ts=2018-06-01T11:19:11.810806644Z caller=index_issue.go:60 msg="detected issue" id=01CEWMK80A90ESMN8ERCV2R0J6 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 12. Complete: 0" issue=index_issue
2018/06/01 11:19:13 DEBUG1: outsiders=1, minTime=2018-06-01 02:00:00 +0000 UTC, maxTime=2018-06-01 04:00:00 +0000 UTC, c.MinTime=2018-06-01 04:00:00 +0000 UTC, c.MaxTime=2018-06-01 04:39:40 +0000 UTC
2018/06/01 11:19:13 DEBUG1: outsiders=2, minTime=2018-06-01 02:00:00 +0000 UTC, maxTime=2018-06-01 04:00:00 +0000 UTC, c.MinTime=2018-06-01 04:00:00 +0000 UTC, c.MaxTime=2018-06-01 04:39:40 +0000 UTC
2018/06/01 11:19:13 DEBUG1: outsiders=3, minTime=2018-06-01 02:00:00 +0000 UTC, maxTime=2018-06-01 04:00:00 +0000 UTC, c.MinTime=2018-06-01 04:00:00 +0000 UTC, c.MaxTime=2018-06-01 04:39:40 +0000 UTC
2018/06/01 11:19:13 DEBUG1: outsiders=4, minTime=2018-06-01 02:00:00 +0000 UTC, maxTime=2018-06-01 04:00:00 +0000 UTC, c.MinTime=2018-06-01 04:00:00 +0000 UTC, c.MaxTime=2018-06-01 04:39:40 +0000 UTC
2018/06/01 11:19:13 DEBUG1: outsiders=5, minTime=2018-06-01 02:00:00 +0000 UTC, maxTime=2018-06-01 04:00:00 +0000 UTC, c.MinTime=2018-06-01 04:00:00 +0000 UTC, c.MaxTime=2018-06-01 04:39:40 +0000 UTC
2018/06/01 11:19:13 DEBUG1: outsiders=6, minTime=2018-06-01 02:00:00 +0000 UTC, maxTime=2018-06-01 04:00:00 +0000 UTC, c.MinTime=2018-06-01 04:00:00 +0000 UTC, c.MaxTime=2018-06-01 04:39:40 +0000 UTC
2018/06/01 11:19:13 DEBUG1: outsiders=7, minTime=2018-06-01 02:00:00 +0000 UTC, maxTime=2018-06-01 04:00:00 +0000 UTC, c.MinTime=2018-06-01 04:00:00 +0000 UTC, c.MaxTime=2018-06-01 04:39:40 +0000 UTC
2018/06/01 11:19:13 DEBUG1: outsiders=8, minTime=2018-06-01 02:00:00 +0000 UTC, maxTime=2018-06-01 04:00:00 +0000 UTC, c.MinTime=2018-06-01 04:00:00 +0000 UTC, c.MaxTime=2018-06-01 04:39:40 +0000 UTC
2018/06/01 11:19:13 DEBUG1: outsiders=9, minTime=2018-06-01 02:00:00 +0000 UTC, maxTime=2018-06-01 04:00:00 +0000 UTC, c.MinTime=2018-06-01 04:00:00 +0000 UTC, c.MaxTime=2018-06-01 04:39:40 +0000 UTC
2018/06/01 11:19:13 DEBUG1: outsiders=10, minTime=2018-06-01 02:00:00 +0000 UTC, maxTime=2018-06-01 04:00:00 +0000 UTC, c.MinTime=2018-06-01 04:00:00 +0000 UTC, c.MaxTime=2018-06-01 04:39:40 +0000 UTC
2018/06/01 11:19:13 DEBUG1: outsiders=11, minTime=2018-06-01 02:00:00 +0000 UTC, maxTime=2018-06-01 04:00:00 +0000 UTC, c.MinTime=2018-06-01 04:00:00 +0000 UTC, c.MaxTime=2018-06-01 04:39:40 +0000 UTC
2018/06/01 11:19:13 DEBUG1: outsiders=12, minTime=2018-06-01 02:00:00 +0000 UTC, maxTime=2018-06-01 04:00:00 +0000 UTC, c.MinTime=2018-06-01 04:00:00 +0000 UTC, c.MaxTime=2018-06-01 04:39:40 +0000 UTC
level=warn ts=2018-06-01T11:19:13.304758295Z caller=index_issue.go:60 msg="detected issue" id=01CEWVEZ89H00B9RBFH63G0BDK err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 12. Complete: 0" issue=index_issue
2018/06/01 11:19:14 DEBUG1: outsiders=1, minTime=2018-06-01 04:00:00 +0000 UTC, maxTime=2018-06-01 06:00:00 +0000 UTC, c.MinTime=2018-06-01 06:00:00 +0000 UTC, c.MaxTime=2018-06-01 06:39:40 +0000 UTC
2018/06/01 11:19:14 DEBUG1: outsiders=2, minTime=2018-06-01 04:00:00 +0000 UTC, maxTime=2018-06-01 06:00:00 +0000 UTC, c.MinTime=2018-06-01 06:00:00 +0000 UTC, c.MaxTime=2018-06-01 06:39:40 +0000 UTC
2018/06/01 11:19:14 DEBUG1: outsiders=3, minTime=2018-06-01 04:00:00 +0000 UTC, maxTime=2018-06-01 06:00:00 +0000 UTC, c.MinTime=2018-06-01 06:00:00 +0000 UTC, c.MaxTime=2018-06-01 06:39:40 +0000 UTC
2018/06/01 11:19:14 DEBUG1: outsiders=4, minTime=2018-06-01 04:00:00 +0000 UTC, maxTime=2018-06-01 06:00:00 +0000 UTC, c.MinTime=2018-06-01 06:00:00 +0000 UTC, c.MaxTime=2018-06-01 06:39:40 +0000 UTC
2018/06/01 11:19:14 DEBUG1: outsiders=5, minTime=2018-06-01 04:00:00 +0000 UTC, maxTime=2018-06-01 06:00:00 +0000 UTC, c.MinTime=2018-06-01 06:00:00 +0000 UTC, c.MaxTime=2018-06-01 06:39:40 +0000 UTC
2018/06/01 11:19:14 DEBUG1: outsiders=6, minTime=2018-06-01 04:00:00 +0000 UTC, maxTime=2018-06-01 06:00:00 +0000 UTC, c.MinTime=2018-06-01 06:00:00 +0000 UTC, c.MaxTime=2018-06-01 06:39:40 +0000 UTC
2018/06/01 11:19:14 DEBUG1: outsiders=7, minTime=2018-06-01 04:00:00 +0000 UTC, maxTime=2018-06-01 06:00:00 +0000 UTC, c.MinTime=2018-06-01 06:00:00 +0000 UTC, c.MaxTime=2018-06-01 06:39:40 +0000 UTC
2018/06/01 11:19:14 DEBUG1: outsiders=8, minTime=2018-06-01 04:00:00 +0000 UTC, maxTime=2018-06-01 06:00:00 +0000 UTC, c.MinTime=2018-06-01 06:00:00 +0000 UTC, c.MaxTime=2018-06-01 06:39:40 +0000 UTC
2018/06/01 11:19:14 DEBUG1: outsiders=9, minTime=2018-06-01 04:00:00 +0000 UTC, maxTime=2018-06-01 06:00:00 +0000 UTC, c.MinTime=2018-06-01 06:00:00 +0000 UTC, c.MaxTime=2018-06-01 06:39:40 +0000 UTC
2018/06/01 11:19:14 DEBUG1: outsiders=10, minTime=2018-06-01 04:00:00 +0000 UTC, maxTime=2018-06-01 06:00:00 +0000 UTC, c.MinTime=2018-06-01 06:00:00 +0000 UTC, c.MaxTime=2018-06-01 06:39:40 +0000 UTC
2018/06/01 11:19:14 DEBUG1: outsiders=11, minTime=2018-06-01 04:00:00 +0000 UTC, maxTime=2018-06-01 06:00:00 +0000 UTC, c.MinTime=2018-06-01 06:00:00 +0000 UTC, c.MaxTime=2018-06-01 06:39:40 +0000 UTC
2018/06/01 11:19:14 DEBUG1: outsiders=12, minTime=2018-06-01 04:00:00 +0000 UTC, maxTime=2018-06-01 06:00:00 +0000 UTC, c.MinTime=2018-06-01 06:00:00 +0000 UTC, c.MaxTime=2018-06-01 06:39:40 +0000 UTC
level=warn ts=2018-06-01T11:19:14.687568039Z caller=index_issue.go:60 msg="detected issue" id=01CEX2APG9W7ZV4QA5JGWENGF3 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 12. Complete: 0" issue=index_issue
2018/06/01 11:19:15 DEBUG1: outsiders=1, minTime=2018-06-01 06:00:00 +0000 UTC, maxTime=2018-06-01 08:00:00 +0000 UTC, c.MinTime=2018-06-01 08:00:00 +0000 UTC, c.MaxTime=2018-06-01 08:39:40 +0000 UTC
2018/06/01 11:19:15 DEBUG1: outsiders=2, minTime=2018-06-01 06:00:00 +0000 UTC, maxTime=2018-06-01 08:00:00 +0000 UTC, c.MinTime=2018-06-01 08:00:00 +0000 UTC, c.MaxTime=2018-06-01 08:39:40 +0000 UTC
2018/06/01 11:19:15 DEBUG1: outsiders=3, minTime=2018-06-01 06:00:00 +0000 UTC, maxTime=2018-06-01 08:00:00 +0000 UTC, c.MinTime=2018-06-01 08:00:00 +0000 UTC, c.MaxTime=2018-06-01 08:39:40 +0000 UTC
2018/06/01 11:19:15 DEBUG1: outsiders=4, minTime=2018-06-01 06:00:00 +0000 UTC, maxTime=2018-06-01 08:00:00 +0000 UTC, c.MinTime=2018-06-01 08:00:00 +0000 UTC, c.MaxTime=2018-06-01 08:39:40 +0000 UTC
2018/06/01 11:19:15 DEBUG1: outsiders=5, minTime=2018-06-01 06:00:00 +0000 UTC, maxTime=2018-06-01 08:00:00 +0000 UTC, c.MinTime=2018-06-01 08:00:00 +0000 UTC, c.MaxTime=2018-06-01 08:39:40 +0000 UTC
2018/06/01 11:19:15 DEBUG1: outsiders=6, minTime=2018-06-01 06:00:00 +0000 UTC, maxTime=2018-06-01 08:00:00 +0000 UTC, c.MinTime=2018-06-01 08:00:00 +0000 UTC, c.MaxTime=2018-06-01 08:39:40 +0000 UTC
2018/06/01 11:19:15 DEBUG1: outsiders=7, minTime=2018-06-01 06:00:00 +0000 UTC, maxTime=2018-06-01 08:00:00 +0000 UTC, c.MinTime=2018-06-01 08:00:00 +0000 UTC, c.MaxTime=2018-06-01 08:39:40 +0000 UTC
2018/06/01 11:19:15 DEBUG1: outsiders=8, minTime=2018-06-01 06:00:00 +0000 UTC, maxTime=2018-06-01 08:00:00 +0000 UTC, c.MinTime=2018-06-01 08:00:00 +0000 UTC, c.MaxTime=2018-06-01 08:39:40 +0000 UTC
2018/06/01 11:19:15 DEBUG1: outsiders=9, minTime=2018-06-01 06:00:00 +0000 UTC, maxTime=2018-06-01 08:00:00 +0000 UTC, c.MinTime=2018-06-01 08:00:00 +0000 UTC, c.MaxTime=2018-06-01 08:39:40 +0000 UTC
2018/06/01 11:19:15 DEBUG1: outsiders=10, minTime=2018-06-01 06:00:00 +0000 UTC, maxTime=2018-06-01 08:00:00 +0000 UTC, c.MinTime=2018-06-01 08:00:00 +0000 UTC, c.MaxTime=2018-06-01 08:39:40 +0000 UTC
2018/06/01 11:19:15 DEBUG1: outsiders=11, minTime=2018-06-01 06:00:00 +0000 UTC, maxTime=2018-06-01 08:00:00 +0000 UTC, c.MinTime=2018-06-01 08:00:00 +0000 UTC, c.MaxTime=2018-06-01 08:39:40 +0000 UTC
2018/06/01 11:19:15 DEBUG1: outsiders=12, minTime=2018-06-01 06:00:00 +0000 UTC, maxTime=2018-06-01 08:00:00 +0000 UTC, c.MinTime=2018-06-01 08:00:00 +0000 UTC, c.MaxTime=2018-06-01 08:39:40 +0000 UTC
level=warn ts=2018-06-01T11:19:15.932247151Z caller=index_issue.go:60 msg="detected issue" id=01CEX96DRG4AZ8JECWX0ZNBVZC err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 12. Complete: 0" issue=index_issue
2018/06/01 11:19:17 DEBUG1: outsiders=1, minTime=2018-06-01 08:00:00 +0000 UTC, maxTime=2018-06-01 10:00:00 +0000 UTC, c.MinTime=2018-06-01 10:00:00 +0000 UTC, c.MaxTime=2018-06-01 10:39:40 +0000 UTC
2018/06/01 11:19:17 DEBUG1: outsiders=2, minTime=2018-06-01 08:00:00 +0000 UTC, maxTime=2018-06-01 10:00:00 +0000 UTC, c.MinTime=2018-06-01 10:00:00 +0000 UTC, c.MaxTime=2018-06-01 10:39:40 +0000 UTC
2018/06/01 11:19:17 DEBUG1: outsiders=3, minTime=2018-06-01 08:00:00 +0000 UTC, maxTime=2018-06-01 10:00:00 +0000 UTC, c.MinTime=2018-06-01 10:00:00 +0000 UTC, c.MaxTime=2018-06-01 10:39:40 +0000 UTC
2018/06/01 11:19:17 DEBUG1: outsiders=4, minTime=2018-06-01 08:00:00 +0000 UTC, maxTime=2018-06-01 10:00:00 +0000 UTC, c.MinTime=2018-06-01 10:00:00 +0000 UTC, c.MaxTime=2018-06-01 10:39:40 +0000 UTC
2018/06/01 11:19:17 DEBUG1: outsiders=5, minTime=2018-06-01 08:00:00 +0000 UTC, maxTime=2018-06-01 10:00:00 +0000 UTC, c.MinTime=2018-06-01 10:00:00 +0000 UTC, c.MaxTime=2018-06-01 10:39:40 +0000 UTC
2018/06/01 11:19:17 DEBUG1: outsiders=6, minTime=2018-06-01 08:00:00 +0000 UTC, maxTime=2018-06-01 10:00:00 +0000 UTC, c.MinTime=2018-06-01 10:00:00 +0000 UTC, c.MaxTime=2018-06-01 10:39:40 +0000 UTC
2018/06/01 11:19:17 DEBUG1: outsiders=7, minTime=2018-06-01 08:00:00 +0000 UTC, maxTime=2018-06-01 10:00:00 +0000 UTC, c.MinTime=2018-06-01 10:00:00 +0000 UTC, c.MaxTime=2018-06-01 10:39:40 +0000 UTC
2018/06/01 11:19:17 DEBUG1: outsiders=8, minTime=2018-06-01 08:00:00 +0000 UTC, maxTime=2018-06-01 10:00:00 +0000 UTC, c.MinTime=2018-06-01 10:00:00 +0000 UTC, c.MaxTime=2018-06-01 10:39:40 +0000 UTC
2018/06/01 11:19:17 DEBUG1: outsiders=9, minTime=2018-06-01 08:00:00 +0000 UTC, maxTime=2018-06-01 10:00:00 +0000 UTC, c.MinTime=2018-06-01 10:00:00 +0000 UTC, c.MaxTime=2018-06-01 10:39:40 +0000 UTC
2018/06/01 11:19:17 DEBUG1: outsiders=10, minTime=2018-06-01 08:00:00 +0000 UTC, maxTime=2018-06-01 10:00:00 +0000 UTC, c.MinTime=2018-06-01 10:00:00 +0000 UTC, c.MaxTime=2018-06-01 10:39:40 +0000 UTC
2018/06/01 11:19:17 DEBUG1: outsiders=11, minTime=2018-06-01 08:00:00 +0000 UTC, maxTime=2018-06-01 10:00:00 +0000 UTC, c.MinTime=2018-06-01 10:00:00 +0000 UTC, c.MaxTime=2018-06-01 10:39:40 +0000 UTC
2018/06/01 11:19:17 DEBUG1: outsiders=12, minTime=2018-06-01 08:00:00 +0000 UTC, maxTime=2018-06-01 10:00:00 +0000 UTC, c.MinTime=2018-06-01 10:00:00 +0000 UTC, c.MaxTime=2018-06-01 10:39:40 +0000 UTC
level=warn ts=2018-06-01T11:19:17.160682194Z caller=index_issue.go:60 msg="detected issue" id=01CEXG250723Y0B8VDMVWGKYGT err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 12. Complete: 0" issue=index_issue
level=info ts=2018-06-01T11:19:17.165100105Z caller=index_issue.go:114 msg="verified issue" with-repair=false issue=index_issue
level=info ts=2018-06-01T11:19:17.165124305Z caller=overlapped_blocks.go:20 msg="started verifying issue" with-repair=false issue=overlapped_blocks
level=info ts=2018-06-01T11:19:18.493952585Z caller=verify.go:67 msg="verify completed" issues=2 repair=false
level=info ts=2018-06-01T11:19:18.494229043Z caller=main.go:146 msg=exiting

BenoitKnecht picture BenoitKnecht on 1 Jun 2018

@BenoitKnecht nice observations! Is it compacted block or compaction level 1 ?

bwplotka picture bwplotka on 1 Jun 2018

Let's add some debug logs and additional verifies as well as some checksums. Some verify BEFORE the block is uploaded would be quite interesting to see (:

bwplotka picture bwplotka on 1 Jun 2018

Maybe you have still this block somewhere locally in the sidecar? so we can verify it?

bwplotka picture bwplotka on 1 Jun 2018

@Bplotka blocks in the logs above were not compacted (compaction level is 1 in meta.json), but they have been compacted on the local storage since then.

Newer block have the exact same issue and have not been compacted yet, so I took checksums on those: they are identical on the local and remote versions. I took the checksums after the block was uploaded, but is there any chance that the sidecar would modify the local version in any way?

I ran thanos bucket verify --log.level=debug but didn't get more detailed logs, so I guess you mean add more debug statements in the code; can you be more specific?

Given that the remote and local blocks have identical checksums, I'm not sure what else I can check on it, but if you have any suggestions, I'd be happy to try.

My feeling at the moment is that Prometheus produces those blocks with chunks that barely make it in (i.e. the chuck start right where the block ends) and that it's the expected behavior: the minTime and maxTime in meta.json mean that this block contains data for that time range, but it doesn't mean that it cannot contain a little more. But if that's the case, then the next block should also contain that last chunk, at the very beginning. Does that make any sense, or am I missing something?

BenoitKnecht picture BenoitKnecht on 1 Jun 2018

I've applied the same patch, to bucket verify and in my case I have meta.json:

{
        "version": 1,
        "ulid": "01CF4BSD0EWVXN32JA8R3J9XVB",
        "minTime": 1528070400000,
        "maxTime": 1528077600000,
        "stats": {
                "numSamples": 45999820,
                "numSeries": 204669,
                "numChunks": 394315
        },
        "compaction": {
                "level": 1,
                "sources": [
                        "01CF4BSD0EWVXN32JA8R3J9XVB"
                ]
        },
        "thanos": {
                "labels": {
                        "monitor": "sys-mon-prometheus",
                        "replica": "sys-mon-prometheus-0"
                },
                "downsample": {
                        "resolution": 0
                }
        }
}

and the output:


2018/06/05 22:12:31 DEBUG1: outsiders=1, minTime=1527861600000, c.MinTime=1527868800000, maxTime=1527868800000, c.MaxTime=1527871680000
level=warn ts=2018-06-05T19:12:32.187859885Z caller=index_issue.go:60 msg="detected issue" id=01CEY4NASDH4W02BX0X0Y2RXZD err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:12:37 DEBUG1: outsiders=1, minTime=1527868800000, c.MinTime=1527876000000, maxTime=1527876000000, c.MaxTime=1527878880000
level=warn ts=2018-06-05T19:12:38.265334341Z caller=index_issue.go:60 msg="detected issue" id=01CEYBH1YKAHH7CBRPDCAZ4JC6 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:12:43 DEBUG1: outsiders=1, minTime=1527876000000, c.MinTime=1527883200000, maxTime=1527883200000, c.MaxTime=1527886080000
level=warn ts=2018-06-05T19:12:44.05841261Z caller=index_issue.go:60 msg="detected issue" id=01CEYJCS6K11ZMKEGDC0AM7M1H err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:12:49 DEBUG1: outsiders=1, minTime=1527883200000, c.MinTime=1527890400000, maxTime=1527890400000, c.MaxTime=1527893280000
level=warn ts=2018-06-05T19:12:49.558534874Z caller=index_issue.go:60 msg="detected issue" id=01CEYS8GEKM6Z8RK78YJ9X4XYY err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:12:54 DEBUG1: outsiders=1, minTime=1527890400000, c.MinTime=1527897600000, maxTime=1527897600000, c.MaxTime=1527900480000
level=warn ts=2018-06-05T19:12:55.253488161Z caller=index_issue.go:60 msg="detected issue" id=01CEZ047PKYMGF3MPDXSJWH5TQ err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:13:00 DEBUG1: outsiders=1, minTime=1527897600000, c.MinTime=1527904800000, maxTime=1527904800000, c.MaxTime=1527907680000
level=warn ts=2018-06-05T19:13:01.161680653Z caller=index_issue.go:60 msg="detected issue" id=01CEZ6ZYYK6M54HJ2ZBDPB9CYZ err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:13:05 DEBUG1: outsiders=1, minTime=1527904800000, c.MinTime=1527912000000, maxTime=1527912000000, c.MaxTime=1527914880000
level=warn ts=2018-06-05T19:13:06.812564819Z caller=index_issue.go:60 msg="detected issue" id=01CEZDVP6NJR2GXWGQDGRC54TE err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:13:12 DEBUG1: outsiders=1, minTime=1527912000000, c.MinTime=1527919200000, maxTime=1527919200000, c.MaxTime=1527922080000
level=warn ts=2018-06-05T19:13:12.671464146Z caller=index_issue.go:60 msg="detected issue" id=01CEZMQDEKB4XD2GK4DT4PT4HY err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:13:17 DEBUG1: outsiders=1, minTime=1527919200000, c.MinTime=1527926400000, maxTime=1527926400000, c.MaxTime=1527929280000
level=warn ts=2018-06-05T19:13:18.38696356Z caller=index_issue.go:60 msg="detected issue" id=01CEZVK4PKZ1D864FQHY14X897 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:13:24 DEBUG1: outsiders=1, minTime=1527926400000, c.MinTime=1527933600000, maxTime=1527933600000, c.MaxTime=1527936480000
level=warn ts=2018-06-05T19:13:24.491747021Z caller=index_issue.go:60 msg="detected issue" id=01CF02EVYKFW2XFYBK4VTZ5CX5 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:13:29 DEBUG1: outsiders=1, minTime=1527933600000, c.MinTime=1527940800000, maxTime=1527940800000, c.MaxTime=1527943680000
level=warn ts=2018-06-05T19:13:29.928552997Z caller=index_issue.go:60 msg="detected issue" id=01CF09AK6KSN7SV9VNEME4XV43 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:13:34 DEBUG1: outsiders=1, minTime=1527940800000, c.MinTime=1527948000000, maxTime=1527948000000, c.MaxTime=1527950880000
level=warn ts=2018-06-05T19:13:35.295466624Z caller=index_issue.go:60 msg="detected issue" id=01CF0G6AEKFF1XS5QV0WS0X1HF err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:13:40 DEBUG1: outsiders=1, minTime=1527948000000, c.MinTime=1527955200000, maxTime=1527955200000, c.MaxTime=1527958080000
level=warn ts=2018-06-05T19:13:41.097309259Z caller=index_issue.go:60 msg="detected issue" id=01CF0Q21PK9DHW4FK6RP77BX22 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:13:47 DEBUG1: outsiders=1, minTime=1527955200000, c.MinTime=1527962400000, maxTime=1527962400000, c.MaxTime=1527965280000
level=warn ts=2018-06-05T19:13:48.162951326Z caller=index_issue.go:60 msg="detected issue" id=01CF0XXRYK87TG8K9JGM1VNV1C err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:13:53 DEBUG1: outsiders=1, minTime=1527962400000, c.MinTime=1527969600000, maxTime=1527969600000, c.MaxTime=1527972480000
level=warn ts=2018-06-05T19:13:53.832931786Z caller=index_issue.go:60 msg="detected issue" id=01CF14SG6K43J0TEF1QTJVKJ9M err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:13:59 DEBUG1: outsiders=1, minTime=1527969600000, c.MinTime=1527976800000, maxTime=1527976800000, c.MaxTime=1527979680000
level=warn ts=2018-06-05T19:13:59.644003904Z caller=index_issue.go:60 msg="detected issue" id=01CF1BN7EK9AABME7YYJ9XQP05 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:14:05 DEBUG1: outsiders=1, minTime=1527976800000, c.MinTime=1527984000000, maxTime=1527984000000, c.MaxTime=1527986880000
level=warn ts=2018-06-05T19:14:05.58646566Z caller=index_issue.go:60 msg="detected issue" id=01CF1JGYPKJ5Q4397CD6ZF0CFE err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:14:10 DEBUG1: outsiders=1, minTime=1527984000000, c.MinTime=1527991200000, maxTime=1527991200000, c.MaxTime=1527994080000
level=warn ts=2018-06-05T19:14:11.102943109Z caller=index_issue.go:60 msg="detected issue" id=01CF1SCNYKVFGSPDZW26T06EHC err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:14:17 DEBUG1: outsiders=1, minTime=1527991200000, c.MinTime=1527998400000, maxTime=1527998400000, c.MaxTime=1528001280000
level=warn ts=2018-06-05T19:14:18.006573875Z caller=index_issue.go:60 msg="detected issue" id=01CF208D6KV5JV8NN008WWPKA1 err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue
2018/06/05 22:14:23 DEBUG1: outsiders=1, minTime=1527998400000, c.MinTime=1528005600000, maxTime=1528005600000, c.MaxTime=1528008480000
level=warn ts=2018-06-05T19:14:24.005909162Z caller=index_issue.go:60 msg="detected issue" id=01CF2744HF9KHY57XYCCXM22CF err="No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 1. Complete: 0" issue=index_issue

As we can see that "outsiders" are before minTime.

povilasv picture povilasv on 5 Jun 2018

@povilasv I'm not sure what you mean by the outsiders are before minTime. You seem be in the exact same situation I'm in: the outsider's minTime (c.MinTime) is exactly equal to the block's maxTime (maxTime). So all the outsiders "overflow" the block at the end, not at the start.

To make things easier, I've been using this script to inspect Prometheus blocks locally, rather than using thanos bucket verify to check the blocks after they've been uploaded. It gives me this kind of output on affected blocks.

Interestingly, out of the four Prometheus instances that I run (all identical, based on the prom/prometheus:v2.2.1 Docker image), only one is affected by this issue, but not on every block:

$ ./chunks /var/lib/prometheus/data/01C*
block=01CD222J966Z2JJMS1AZ8JNTBF, MinTime=2018-05-07 00:00:00 +0000 UTC, MaxTime=2018-05-09 06:00:00 +0000 UTC, compaction=4
block=01CD7VF55R54PV4DEHGGC2KZ2H, MinTime=2018-05-09 06:00:00 +0000 UTC, MaxTime=2018-05-11 12:00:00 +0000 UTC, compaction=4
block=01CDDMVSD5B82B27A8XNARER90, MinTime=2018-05-11 12:00:00 +0000 UTC, MaxTime=2018-05-13 18:00:00 +0000 UTC, compaction=4
block=01CDKE8D2PSZFFJ8GRX47DE12D, MinTime=2018-05-13 18:00:00 +0000 UTC, MaxTime=2018-05-16 00:00:00 +0000 UTC, compaction=4
block=01CDS7N2T3XFSME66KD1AMH6PW, MinTime=2018-05-16 00:00:00 +0000 UTC, MaxTime=2018-05-18 06:00:00 +0000 UTC, compaction=4
block=01CDZ11MMPDGRFMQCMS4RXFBGK, MinTime=2018-05-18 06:00:00 +0000 UTC, MaxTime=2018-05-20 12:00:00 +0000 UTC, compaction=4
block=01CE4TEA4E80PPRJQ0GHP1TADE, MinTime=2018-05-20 12:00:00 +0000 UTC, MaxTime=2018-05-22 18:00:00 +0000 UTC, compaction=4
block=01CEAKTWDT2W08HY4PFHMJTYAV, MinTime=2018-05-22 18:00:00 +0000 UTC, MaxTime=2018-05-25 00:00:00 +0000 UTC, compaction=4
block=01CEGD7FBRP4SXHT39XMTBGET5, MinTime=2018-05-25 00:00:00 +0000 UTC, MaxTime=2018-05-27 06:00:00 +0000 UTC, compaction=4
block=01CEP6M3153AGS6XZM6Q9P1APV, MinTime=2018-05-27 06:00:00 +0000 UTC, MaxTime=2018-05-29 12:00:00 +0000 UTC, compaction=4
block=01CEW00QHRRQ52S6YC9QKH9M00, MinTime=2018-05-29 12:00:00 +0000 UTC, MaxTime=2018-05-31 18:00:00 +0000 UTC, compaction=4
posting=11265764, MinTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 18:39:40 +0000 UTC
posting=11266807, MinTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 18:39:40 +0000 UTC
posting=11267482, MinTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 18:39:40 +0000 UTC
posting=11268158, MinTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 18:39:40 +0000 UTC
posting=11268834, MinTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 18:39:40 +0000 UTC
posting=11270881, MinTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 18:39:40 +0000 UTC
posting=11271865, MinTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 18:39:40 +0000 UTC
posting=11273787, MinTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 18:39:40 +0000 UTC
posting=11304482, MinTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 18:39:40 +0000 UTC
posting=11310999, MinTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 18:39:40 +0000 UTC
posting=11317304, MinTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 18:39:40 +0000 UTC
posting=12321976, MinTime=2018-05-31 18:00:00 +0000 UTC, maxTime=2018-05-31 18:39:40 +0000 UTC
block=01CF1SDBE6J6EMHNK799TP4ZFX, MinTime=2018-05-31 18:00:00 +0000 UTC, MaxTime=2018-06-03 00:00:00 +0000 UTC, compaction=4
posting=11658250, MinTime=2018-06-03 00:00:00 +0000 UTC, maxTime=2018-06-03 00:39:40 +0000 UTC
posting=11659307, MinTime=2018-06-03 00:00:00 +0000 UTC, maxTime=2018-06-03 00:39:40 +0000 UTC
posting=11659989, MinTime=2018-06-03 00:00:00 +0000 UTC, maxTime=2018-06-03 00:39:40 +0000 UTC
posting=11660671, MinTime=2018-06-03 00:00:00 +0000 UTC, maxTime=2018-06-03 00:39:40 +0000 UTC
posting=11661354, MinTime=2018-06-03 00:00:00 +0000 UTC, maxTime=2018-06-03 00:39:40 +0000 UTC
posting=11663421, MinTime=2018-06-03 00:00:00 +0000 UTC, maxTime=2018-06-03 00:39:40 +0000 UTC
posting=11664414, MinTime=2018-06-03 00:00:00 +0000 UTC, maxTime=2018-06-03 00:39:40 +0000 UTC
posting=11666356, MinTime=2018-06-03 00:00:00 +0000 UTC, maxTime=2018-06-03 00:39:40 +0000 UTC
posting=11698438, MinTime=2018-06-03 00:00:00 +0000 UTC, maxTime=2018-06-03 00:39:40 +0000 UTC
posting=11705086, MinTime=2018-06-03 00:00:00 +0000 UTC, maxTime=2018-06-03 00:39:40 +0000 UTC
posting=11711510, MinTime=2018-06-03 00:00:00 +0000 UTC, maxTime=2018-06-03 00:39:40 +0000 UTC
posting=12735981, MinTime=2018-06-03 00:00:00 +0000 UTC, maxTime=2018-06-03 00:39:40 +0000 UTC
block=01CF7JSYPJWXJ0F3HAZZWGYRPG, MinTime=2018-06-03 00:00:00 +0000 UTC, MaxTime=2018-06-05 06:00:00 +0000 UTC, compaction=4
posting=11349917, MinTime=2018-06-05 06:00:00 +0000 UTC, maxTime=2018-06-05 06:39:40 +0000 UTC
posting=11350973, MinTime=2018-06-05 06:00:00 +0000 UTC, maxTime=2018-06-05 06:39:40 +0000 UTC
posting=11351656, MinTime=2018-06-05 06:00:00 +0000 UTC, maxTime=2018-06-05 06:39:40 +0000 UTC
posting=11352339, MinTime=2018-06-05 06:00:00 +0000 UTC, maxTime=2018-06-05 06:39:40 +0000 UTC
posting=11353023, MinTime=2018-06-05 06:00:00 +0000 UTC, maxTime=2018-06-05 06:39:40 +0000 UTC
posting=11355086, MinTime=2018-06-05 06:00:00 +0000 UTC, maxTime=2018-06-05 06:39:40 +0000 UTC
posting=11356084, MinTime=2018-06-05 06:00:00 +0000 UTC, maxTime=2018-06-05 06:39:40 +0000 UTC
posting=11358021, MinTime=2018-06-05 06:00:00 +0000 UTC, maxTime=2018-06-05 06:39:40 +0000 UTC
posting=11391043, MinTime=2018-06-05 06:00:00 +0000 UTC, maxTime=2018-06-05 06:39:40 +0000 UTC
posting=11397659, MinTime=2018-06-05 06:00:00 +0000 UTC, maxTime=2018-06-05 06:39:40 +0000 UTC
posting=11404046, MinTime=2018-06-05 06:00:00 +0000 UTC, maxTime=2018-06-05 06:39:40 +0000 UTC
posting=12413590, MinTime=2018-06-05 06:00:00 +0000 UTC, maxTime=2018-06-05 06:39:40 +0000 UTC
block=01CF9GJVFAS4AJF7M9CJ9QV10E, MinTime=2018-06-06 00:00:00 +0000 UTC, MaxTime=2018-06-06 02:00:00 +0000 UTC, compaction=1
block=01CF9GK7ENZF10H6GARMXS7XPQ, MinTime=2018-06-05 06:00:00 +0000 UTC, MaxTime=2018-06-06 00:00:00 +0000 UTC, compaction=3
block=01CF9QEJMQ35ZB60DK72KHBD4N, MinTime=2018-06-06 02:00:00 +0000 UTC, MaxTime=2018-06-06 04:00:00 +0000 UTC, compaction=1

So again, I'm not sure if this is a Prometheus issue (meaning it should never produce blocks with chunks that stick out at the end), or if it's a Thanos issue (in the sense that it should not error out on blocks with that particular type of outsiders, but just treat them like any other block).

BenoitKnecht picture BenoitKnecht on 6 Jun 2018
👍1

@BenoitKnecht did you check the Prometheus local blocks? (before upload to object storage)

if yes -> well this is certainly TSDB (prometheus) issue if that is the case, since these blocks have not been yet touched by Thanos.

bwplotka picture bwplotka on 6 Jun 2018

I'm suffering from the same issue, logs:

level=info ts=2018-06-10T15:30:00.971577754Z caller=compact.go:264 msg="starting compact node"
level=info ts=2018-06-10T15:30:00.971848237Z caller=compact.go:152 msg="start sync of metas"
level=debug ts=2018-06-10T15:30:01.16760429Z caller=compact.go:165 msg="download meta" block=01CEWBM60NRAF8SZSWYTC5TAHK
level=debug ts=2018-06-10T15:30:01.194339535Z caller=compact.go:165 msg="download meta" block=01CEWCPEM86SE64J7M48YPG8SV
level=debug ts=2018-06-10T15:30:01.241614966Z caller=compact.go:165 msg="download meta" block=01CEY1MS2ZSXTA78W85R60DJQM
level=debug ts=2018-06-10T15:30:01.274153301Z caller=compact.go:165 msg="download meta" block=01CEY3EJPQX40NCY52XQ45TEE1
level=debug ts=2018-06-10T15:30:01.293018625Z caller=compact.go:165 msg="download meta" block=01CF1FRBEX4R9HDQYM9AGM8XTB
level=debug ts=2018-06-10T15:30:01.416705535Z caller=compact.go:165 msg="download meta" block=01CF1G0VC0YP7GQKMZGMSYJ46R
level=debug ts=2018-06-10T15:30:01.428553142Z caller=compact.go:165 msg="download meta" block=01CF1GGXXWPZVR04YZP57N9ST7
level=debug ts=2018-06-10T15:30:01.449371692Z caller=compact.go:165 msg="download meta" block=01CF1GZ20VQ2RYH4V8KHJ75W4J
level=debug ts=2018-06-10T15:30:01.479952082Z caller=compact.go:165 msg="download meta" block=01CF6M5B7E22MZ7PJMCBSNN9RD
level=debug ts=2018-06-10T15:30:01.50509985Z caller=compact.go:165 msg="download meta" block=01CF6M6Z8W8P8D9CMAQPK02T8W
level=debug ts=2018-06-10T15:30:01.529175788Z caller=compact.go:165 msg="download meta" block=01CF6M8JW87GNXJG54V38DCAHC
level=debug ts=2018-06-10T15:30:01.538592614Z caller=compact.go:165 msg="download meta" block=01CF6MB0G5734FYNBDK85BCX11
level=debug ts=2018-06-10T15:30:01.566367749Z caller=compact.go:165 msg="download meta" block=01CF6MEAT3TGPT13TD7G9ZMNJ0
level=debug ts=2018-06-10T15:30:01.585283355Z caller=compact.go:165 msg="download meta" block=01CF6MP5EFQY6VJMSS9VBVQQ4N
level=debug ts=2018-06-10T15:30:01.610238641Z caller=compact.go:165 msg="download meta" block=01CF6N578EXZXRY2FY8P34K9FB
level=debug ts=2018-06-10T15:30:01.642939675Z caller=compact.go:165 msg="download meta" block=01CF6NJBMY84TZENSCW5RR3TCC
level=debug ts=2018-06-10T15:30:01.683478842Z caller=compact.go:165 msg="download meta" block=01CF96EE1RDKZHEVZ0069QN67B
level=debug ts=2018-06-10T15:30:01.705450866Z caller=compact.go:165 msg="download meta" block=01CF96GD1V0GJK1ET1QKZ7E7FV
level=debug ts=2018-06-10T15:30:01.720084748Z caller=compact.go:165 msg="download meta" block=01CF96J7GJTV72KPK843GBCGTE
level=debug ts=2018-06-10T15:30:01.744881313Z caller=compact.go:165 msg="download meta" block=01CF96KV88NCJY4VV9HGVSQ46M
level=debug ts=2018-06-10T15:30:01.768252972Z caller=compact.go:165 msg="download meta" block=01CF96NQ1XX5AAN43QA42G83HQ
level=debug ts=2018-06-10T15:30:01.778128854Z caller=compact.go:165 msg="download meta" block=01CF96QMF4WW3RYH43YPZG25G7
level=debug ts=2018-06-10T15:30:01.83051566Z caller=compact.go:165 msg="download meta" block=01CFBRWV1B87H2SK9Q5MJAPC74
level=debug ts=2018-06-10T15:30:01.857459618Z caller=compact.go:165 msg="download meta" block=01CFBRYPERSX2MZRTXTA3PJ4TD
level=debug ts=2018-06-10T15:30:01.882939594Z caller=compact.go:165 msg="download meta" block=01CFBS0MPFBB1HWNJAMC6X2QYW
level=debug ts=2018-06-10T15:30:01.908027145Z caller=compact.go:165 msg="download meta" block=01CFBS2E9HACEX18YDGFQ90HFB
level=debug ts=2018-06-10T15:30:01.917668477Z caller=compact.go:165 msg="download meta" block=01CFBS48QG0ADM7VE2WMPBY1XT
level=debug ts=2018-06-10T15:30:01.948793312Z caller=compact.go:165 msg="download meta" block=01CFBS64YK030W4ZZ411YX8S0J
level=debug ts=2018-06-10T15:30:01.970793196Z caller=compact.go:165 msg="download meta" block=01CFC4W6YNVFNVBZSPGKQMJZPC
level=debug ts=2018-06-10T15:30:02.025167331Z caller=compact.go:165 msg="download meta" block=01CFC4Y6YYDBF8YMEHSYNARHSG
level=debug ts=2018-06-10T15:30:02.061091831Z caller=compact.go:165 msg="download meta" block=01CFD0A5GVBYH21PP0A8VN7G18
level=debug ts=2018-06-10T15:30:02.102365727Z caller=compact.go:165 msg="download meta" block=01CFD0BSZTEQGBBRF3H0BVYJN9
level=debug ts=2018-06-10T15:30:02.22250147Z caller=compact.go:165 msg="download meta" block=01CFDVWCTJXRSGMTK60BFKBSSB
level=debug ts=2018-06-10T15:30:02.258879018Z caller=compact.go:165 msg="download meta" block=01CFDVYC66KWF49X0QKXMBPYC6
level=debug ts=2018-06-10T15:30:02.291347849Z caller=compact.go:165 msg="download meta" block=01CFEQDP28SRBGV3KVC32738B4
level=debug ts=2018-06-10T15:30:02.333481284Z caller=compact.go:165 msg="download meta" block=01CFEQFN0EGW2NK6PZNMY7YZWY
level=debug ts=2018-06-10T15:30:02.379332137Z caller=compact.go:165 msg="download meta" block=01CFFJNCQWZ466CN06KEHEA9CS
level=debug ts=2018-06-10T15:30:02.418125378Z caller=compact.go:165 msg="download meta" block=01CFFJQ0ZRCP242XR5HQ0GYXTR
level=debug ts=2018-06-10T15:30:02.442441762Z caller=compact.go:165 msg="download meta" block=01CFGE53GNMJEGPM1QF27YCDAP
level=debug ts=2018-06-10T15:30:02.466082742Z caller=compact.go:165 msg="download meta" block=01CFGE72VQJM07CK4VSFYFMDSP
level=debug ts=2018-06-10T15:30:02.484716718Z caller=compact.go:165 msg="download meta" block=01CFH9R407M4RGDHAYEPQVXF9G
level=debug ts=2018-06-10T15:30:02.507876374Z caller=compact.go:165 msg="download meta" block=01CFH9T4E2498EKNEPPBGJS211
level=debug ts=2018-06-10T15:30:02.539581855Z caller=compact.go:165 msg="download meta" block=01CFJ5083EA0N1R2Z7Z963FWHV
level=debug ts=2018-06-10T15:30:02.572463107Z caller=compact.go:165 msg="download meta" block=01CFJ51X4CAYHDQD2AEH2X3JFE
level=debug ts=2018-06-10T15:30:02.60155112Z caller=compact.go:165 msg="download meta" block=01CFK0GQ7YKMN3QMDK51VS6Z2M
level=debug ts=2018-06-10T15:30:02.626621866Z caller=compact.go:165 msg="download meta" block=01CFK0JKZX2ZP064TWHPX58479
level=debug ts=2018-06-10T15:30:02.647190853Z caller=compact.go:165 msg="download meta" block=01CFKW2QXQ9E7R6AQAQ9VZ37EY
level=debug ts=2018-06-10T15:30:02.676151973Z caller=compact.go:165 msg="download meta" block=01CFKW4KM77DFNXYJ5PV8TCHTP
level=debug ts=2018-06-10T15:30:02.704317781Z caller=compact.go:165 msg="download meta" block=01CFMNMKZVY8N8VGVAVEWY9E7H
level=debug ts=2018-06-10T15:30:02.727665182Z caller=compact.go:165 msg="download meta" block=01CFMNMKZWP98QXMWAM64ZS94Q
level=debug ts=2018-06-10T15:30:02.760041659Z caller=compact.go:165 msg="download meta" block=01CFMQN7BEYC1KVNBKFCZAGE06
level=debug ts=2018-06-10T15:30:02.77714674Z caller=compact.go:165 msg="download meta" block=01CFMQPV49DN867N8GV7AB3SJC
level=debug ts=2018-06-10T15:30:02.807106415Z caller=compact.go:165 msg="download meta" block=01CFMWGB7V7PFMEY0VMZEJKHM3
level=debug ts=2018-06-10T15:30:02.831981756Z caller=compact.go:165 msg="download meta" block=01CFMWGB7WZJWG5B2GT3PAJ4VW
level=debug ts=2018-06-10T15:30:02.855537517Z caller=compact.go:165 msg="download meta" block=01CFN3C2FTS24465TX4CCNG3HV
level=debug ts=2018-06-10T15:30:02.864736141Z caller=compact.go:165 msg="download meta" block=01CFN3C2FZ9KDCW0QR0NH6RG5Z
level=info ts=2018-06-10T15:30:02.953035824Z caller=compact.go:158 msg="start of GC"
level=error ts=2018-06-10T15:30:19.93372924Z caller=main.go:147 msg="running command failed" err="compaction: invalid plan block /var/thanos/compact/compact/0@{prometheus=\"monitoring/k8s\",prometheus_replica=\"prometheus-k8s-0\"}/01CF6M8JW87GNXJG54V38DCAHC: open index file: try lock file: open /var/thanos/compact/compact/0@{prometheus=\"monitoring/k8s\",prometheus_replica=\"prometheus-k8s-0\"}/01CF6M8JW87GNXJG54V38DCAHC/index: no such file or directory"
felipejfc picture felipejfc on 10 Jun 2018

@Bplotka I think I've pinpointed the issue in prometheus/tsdb.

Nevertheless, since Prometheus can sometimes produce blocks with outsider chunks, Thanos should probably handle that situation gracefully (either by fixing the block, or just leaving them alone, I don't think those chunks hurt beyond using up some space).

(@felipejfc your issue seems different, something to do with a missing file; you should probably open a separate issue.)

BenoitKnecht picture BenoitKnecht on 12 Jun 2018

Wow @BenoitKnecht thanks! Wonder why some people are not having this, while you have it so often :thinking: We have like 3 envs with couple of monthos of data and we never experienced it.

EDIT: just checked our deployment and my compactor is stating same 0.o

level=error name=thanos-compactor ts=2018-06-04T13:23:08.827109642Z caller=compact.go:194 msg="critical error detected; halting" err="compaction: invalid plan block /compactor-data/compact/0@{cluster=\"h-te1\",environment=\"testing\",monitor_namespace=\"default\",replica=\"thanos-mon-1\"}/01CDQ2Z34FBEYZR0XH1RWC8EWQ: No chunks are out of order, but found some outsider blocks. (Blocks that outside of block time range): 290. Complete: 0"

I guess I was just lucky.

What would be the correct way or repairing this? Just removing the outsiders, since there is no use of them?

@BenoitKnecht thanks for looking into it!

bwplotka picture bwplotka on 12 Jun 2018

@BenoitKnecht can you join slack, so we can discuss this issue more synchronously? (:

bwplotka picture bwplotka on 12 Jun 2018

Additionally it "always" means that this chunk is in both neighbouring blocks?

bwplotka picture bwplotka on 12 Jun 2018

Thanks of @BenoitKnecht we found a root cause and fix is in progress

bwplotka picture bwplotka on 12 Jun 2018
🎉1

Thanks all for helping with this issue!

Thanos now handles these blocks gracefully (it repairs them in place). The TSDB it not yet fixed (since it is not straightforward), but when the issue occurs, Thanos handles it well now.

Feel free to use master-2018-06-15-5b66b72 docker tag or above. New release candidate will produce soon.

Thanks to @BenoitKnecht who figured the root cause and @clmssz for reporting it! Nice work!

bwplotka picture bwplotka on 15 Jun 2018
🎉2
Was this page helpful?
0 / 5 - 0 ratings

Related issues

MrD2 picture MrD2  路  3Comments
sepich picture sepich  路  4Comments
wiardvanrij picture wiardvanrij  路  3Comments
paulcdejean picture paulcdejean  路  4Comments
bwplotka picture bwplotka  路  4Comments