read dir: open /data/compact: no such file or directory

[Antiarchitect]

Thanos, Prometheus and Golang version used:

docker.io/bitnami/thanos:0.19.0-scratch-r0
quay.io/prometheus/prometheus:v2.24.0
Thanos Sidecar: thanosio/thanos:v0.19.0

Object Storage Provider:

Ceph RadosGW S3

What happened:

Strange warning in logs of compactor I cannot google anywhere:

2021-04-26T20:39:15.964628100Z level=warn ts=2021-04-26T20:39:15.964538873Z caller=compact.go:966 msg="failed deleting non-compaction group direc tories/files, some disk space usage might have leaked. Continuing" err="read dir: open /data/compact: no such file or directory" dir=/data/compact

What you expected to happen:
No warning

Anything else we need to know:
Thanos compactor has 150GB of space for /data directory

[wiardvanrij]

Hi,

Could you provide more information on when this is happening? I.e. does it run and is this an incidental error?
The bitnami helm chart sets a securityContext, have you tested that Thanos can access the /data directory? Have you seen data in the /data folder?

[Antiarchitect]

It seems it works normally and occasionally this warning appears:

level=info ts=2021-04-27T09:00:18.83617202Z caller=factory.go:46 msg="loading bucket configuration"
level=info ts=2021-04-27T09:00:18.839450444Z caller=compact.go:339 msg="retention policy of raw samples is enabled" duration=336h0m0s
level=info ts=2021-04-27T09:00:18.839508598Z caller=compact.go:342 msg="retention policy of 5 min aggregated samples is enabled" duration=336h0m0s
level=info ts=2021-04-27T09:00:18.839533574Z caller=compact.go:345 msg="retention policy of 1 hour aggregated samples is enabled" duration=336h0m0s
level=info ts=2021-04-27T09:00:18.840874486Z caller=compact.go:516 msg="starting compact node"
level=info ts=2021-04-27T09:00:18.840909124Z caller=intrumentation.go:48 msg="changing probe status" status=ready
level=info ts=2021-04-27T09:00:18.840998151Z caller=intrumentation.go:60 msg="changing probe status" status=healthy
level=info ts=2021-04-27T09:00:18.841041084Z caller=http.go:62 service=http/server component=compact msg="listening for requests and metrics" address=0.0.0.0:10902
level=info ts=2021-04-27T09:00:18.841041419Z caller=compact.go:941 msg="start sync of metas"
level=info ts=2021-04-27T09:00:19.175082829Z caller=fetcher.go:476 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=333.98549ms cached=315 returned=315 partial=0
level=info ts=2021-04-27T09:00:19.280150882Z caller=fetcher.go:476 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=89.794691ms cached=315 returned=315 partial=0
level=info ts=2021-04-27T09:00:19.654605015Z caller=fetcher.go:476 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=813.574729ms cached=315 returned=20 partial=0
level=info ts=2021-04-27T09:00:19.655510261Z caller=clean.go:33 msg="started cleaning of aborted partial uploads"
level=info ts=2021-04-27T09:00:19.655545669Z caller=clean.go:60 msg="cleaning of aborted partial uploads done"
level=info ts=2021-04-27T09:00:19.655564432Z caller=blocks_cleaner.go:43 msg="started cleaning of blocks marked for deletion"
level=info ts=2021-04-27T09:00:19.655699929Z caller=blocks_cleaner.go:57 msg="cleaning of blocks marked for deletion done"
level=info ts=2021-04-27T09:00:20.216921122Z caller=fetcher.go:476 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=561.339011ms cached=315 returned=20 partial=0
level=info ts=2021-04-27T09:00:20.217783674Z caller=compact.go:946 msg="start of GC"
level=info ts=2021-04-27T09:00:20.218011206Z caller=compact.go:969 msg="start of compactions"
level=info ts=2021-04-27T09:00:20.218410554Z caller=compact.go:1001 msg="compaction iterations done"
level=info ts=2021-04-27T09:00:20.21847889Z caller=compact.go:400 msg="downsampling was explicitly disabled"
level=info ts=2021-04-27T09:00:20.765653606Z caller=fetcher.go:476 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=547.153799ms cached=315 returned=20 partial=0
level=info ts=2021-04-27T09:00:20.76689107Z caller=retention.go:31 msg="start optional retention"
level=info ts=2021-04-27T09:00:20.766946241Z caller=retention.go:46 msg="optional retention apply done"
level=info ts=2021-04-27T09:00:21.329405105Z caller=fetcher.go:476 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=562.424378ms cached=315 returned=20 partial=0
level=info ts=2021-04-27T09:00:21.330174951Z caller=clean.go:33 msg="started cleaning of aborted partial uploads"
level=info ts=2021-04-27T09:00:21.330202094Z caller=clean.go:60 msg="cleaning of aborted partial uploads done"
level=info ts=2021-04-27T09:00:21.330214809Z caller=blocks_cleaner.go:43 msg="started cleaning of blocks marked for deletion"
level=info ts=2021-04-27T09:00:21.330307954Z caller=blocks_cleaner.go:57 msg="cleaning of blocks marked for deletion done"
level=info ts=2021-04-27T09:01:19.329899013Z caller=fetcher.go:476 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=139.398342ms cached=316 returned=316 partial=0
level=info ts=2021-04-27T09:02:19.314975966Z caller=fetcher.go:476 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=124.439139ms cached=317 returned=317 partial=0
level=info ts=2021-04-27T09:03:19.266523143Z caller=fetcher.go:476 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=76.013305ms cached=317 returned=317 partial=0
level=info ts=2021-04-27T09:04:19.274448952Z caller=fetcher.go:476 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=83.959527ms cached=317 returned=317 partial=0
level=info ts=2021-04-27T09:05:18.841137324Z caller=compact.go:941 msg="start sync of metas"
level=info ts=2021-04-27T09:05:19.258848764Z caller=fetcher.go:476 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=68.455173ms cached=317 returned=317 partial=0
level=info ts=2021-04-27T09:05:19.454744337Z caller=fetcher.go:476 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=613.540103ms cached=317 returned=20 partial=0
level=info ts=2021-04-27T09:05:19.455578266Z caller=clean.go:33 msg="started cleaning of aborted partial uploads"
level=info ts=2021-04-27T09:05:19.455607559Z caller=clean.go:60 msg="cleaning of aborted partial uploads done"
level=info ts=2021-04-27T09:05:19.455620815Z caller=blocks_cleaner.go:43 msg="started cleaning of blocks marked for deletion"
level=info ts=2021-04-27T09:05:19.45571072Z caller=blocks_cleaner.go:57 msg="cleaning of blocks marked for deletion done"
level=info ts=2021-04-27T09:05:20.009258674Z caller=fetcher.go:476 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=553.604809ms cached=317 returned=20 partial=0
level=info ts=2021-04-27T09:05:20.010349045Z caller=compact.go:946 msg="start of GC"
level=warn ts=2021-04-27T09:05:20.010595729Z caller=compact.go:966 msg="failed deleting non-compaction group directories/files, some disk space usage might have leaked. Continuing" err="read dir: open /data/compact: no such file or directory" dir=/data/compact
level=info ts=2021-04-27T09:05:20.01064756Z caller=compact.go:969 msg="start of compactions"
level=info ts=2021-04-27T09:05:20.01111113Z caller=compact.go:1001 msg="compaction iterations done"
level=info ts=2021-04-27T09:05:20.011205251Z caller=compact.go:400 msg="downsampling was explicitly disabled"
level=info ts=2021-04-27T09:05:20.560920892Z caller=fetcher.go:476 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=549.682164ms cached=317 returned=20 partial=0
level=info ts=2021-04-27T09:05:20.561950213Z caller=retention.go:31 msg="start optional retention"
level=info ts=2021-04-27T09:05:20.561985386Z caller=retention.go:46 msg="optional retention apply done"
level=info ts=2021-04-27T09:05:21.126980485Z caller=fetcher.go:476 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=564.977013ms cached=317 returned=20 partial=0
level=info ts=2021-04-27T09:05:21.12801984Z caller=clean.go:33 msg="started cleaning of aborted partial uploads"
level=info ts=2021-04-27T09:05:21.128055449Z caller=clean.go:60 msg="cleaning of aborted partial uploads done"
level=info ts=2021-04-27T09:05:21.128072695Z caller=blocks_cleaner.go:43 msg="started cleaning of blocks marked for deletion"
level=info ts=2021-04-27T09:05:21.128192624Z caller=blocks_cleaner.go:57 msg="cleaning of blocks marked for deletion done"

It's hard to attach to bitnami Thanos compactor container as it does not have a shell and allocated TTY.

[wiardvanrij]

Actually this is related to #3912 - basically the message is harmless and should be fixed.

Please use this image (if you want to use bitnami) : https://hub.docker.com/layers/bitnami/thanos/0.19.0/images/sha256-a192127a22c0867ee66b17f7a934b1f6469fc689f476478a9e41eafd366be218?context=explore

The -rc are release candidates.

[Antiarchitect]

Thank you! But I beleive -scratch-r0 - is some kind of other versioning system used by Bitnami as I often see this namings there