compactor: File name is too long error

[mdferoz]

Thanos, Prometheus and Golang version used
-> prometheus instances run in kubernetes with thanos 0.3 side car and image tags used 2.7.1.

-> % thanos --version
type: S3
thanos, version 0.3.0 (branch: HEAD, revision: 837e967)
build user: root@986454de7a63
build date: 20190208-15:24:36
go version: go1.11.5

What happened
Running compact command fails against a known bucket containing our metrics data. The data itself is currently not huge, may be around 3GB so far. Thanos sidecar keep pushing the data in to our local s3 compatible storage and we were hoping to keep this data at lesser granularity for several years. Here is the command I used:

% thanos compact --log.level=info --data-dir=/tmp/ --objstore.config-file=thanos-s3-bucket.conf --retention.resolution-raw=0d --retention.resolution-5m=180d --retention.resolution-1h=1000d --wait

What you expected to happen
I was hoping the compact command will process the data :)
How to reproduce it (as minimally and precisely as possible):
Our data is collected by prometheus from a bunch of netdata agents but with limited metrics we have identified. This gets scraped every 15s at the moment and all targets are CentOS 6/7. I feel like that may not be as relevant, as this looks like something else while creating a directory locally.

Full logs to relevant components
level=info ts=2019-02-14T19:39:03.453025Z caller=factory.go:39 msg="loading bucket configuration"
level=info ts=2019-02-14T19:39:03.453635Z caller=compact.go:196 msg="retention policy of 5 min aggregated samples is enabled" duration=4320h0m0s
level=info ts=2019-02-14T19:39:03.453659Z caller=compact.go:199 msg="retention policy of 1 hour aggregated samples is enabled" duration=24000h0m0s
level=info ts=2019-02-14T19:39:03.453759Z caller=compact.go:281 msg="starting compact node"
level=info ts=2019-02-14T19:39:03.453862Z caller=compact.go:821 msg="start sync of metas"
level=info ts=2019-02-14T19:39:03.453839Z caller=main.go:308 msg="Listening for metrics" address=0.0.0.0:10902
level=info ts=2019-02-14T19:39:03.658623Z caller=compact.go:827 msg="start of GC"
level=error ts=2019-02-14T19:39:03.808235Z caller=compact.go:265 msg="retriable error" err="compaction failed: compaction: download block 01D3MZ4NWJ8Q5YGSCB5F3SCDFT: create dir: mkdir /tmp/compact/0@{prometheus="kube-monitoring/operator-prometheus-lsf",prometheus_replica="prometheus-operator-prometheus-lsf-0",region="sc",role="lsf-metrics"}/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT/01D3MZ4NWJ8Q5YGSCB5F3SCDFT: file name too long"
^Clevel=info ts=2019-02-14T19:39:08.503792Z caller=main.go:192 msg="caught signal. Exiting." signal=interrupt
level=info ts=2019-02-14T19:39:08.503963Z caller=main.go:184 msg=exiting

Anything else we need to know
Nope and thanks for looking in to this, I hope I didn't miss anything else to help you understand this issue.

[GiedriusS]

The newest versions have a newer minio-go which has some fixes WRT "retryable" error codes. Could you check them out and see if this is reproducible?

[bwplotka]

Hi We had a similar issue reported for 0.6.0 - #1491 looking for more data from the author on this, especially what object storage is used.

It looks super suspicious and actually might mean our object storage client we used (e.g minio-client) is not working properly for a certain case. @mdferoz have you managed to fix this / find the root cause?

[ingvarm-gr]

We use S3 object storage (sorry, I thought I'd put that in). Looking at the generated hostname, it seems as if the pathname contains the same timestamp repeated over and over again. I am in principle happy to bump a subset of compactors to v0.7.0 and see if it goes away. With the last error message, the constructed pathname is 4106 characters long (if we account for the ":" at the end), thus exceeding FILENAME_MAX by 10 bytes:

hostname$ kubectl logs -n NAMESPACE thanos-compactor-7f855dd997-ckhjk | awk '/file name too long/ { print $(NF-4) }' | wc
  1       1    4107

I'm happy to start digging through the code and see where that is being constructed.

[ingvarm-gr]

In terms of configuration:

spec:
  containers:
  - args:
    - compact
    - --log.level=debug
    - --data-dir=/local/state
    - --objstore.config-file=/config/bucket.yaml
    - --http-address=0.0.0.0:19191
    - --wait
    image: <internal repo, syncing to upstream>/improbable/thanos:v0.6.0
    imagePullPolicy: IfNotPresent
    name: thanos-compactor

I see that we should probably configure our repository to start mirroring thanosio/thanos in addition to / instead of improbable/thanos.

[ingvarm-gr]

If you want, I can try to generate a PR with some extra debugging of the directory name in various stages through the code path?

[ingvarm-gr]

I've now managed to catch this happening with some extra debugging enabled. The interesting debug logs is from two places in objstore.DownloadDir, one is right after the entry to the function (denoted caller=objstore.go:145) and the other is in the bkt.Iter loop a few lines down (denoted caller=objstore.go:152):

level=debug ts=2019-09-09T15:58:53.643925343Z caller=objstore.go:145 compactionGroup="0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}" msg="DownloadDir entered" src=01DFDXE9FF5VFXA4MRGZ4932EX dst="/local/state/compact/0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}/01DFDXE9FF5VFXA4MRGZ4932EX"
level=debug ts=2019-09-09T15:58:53.680970495Z caller=objstore.go:152 compactionGroup="0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}" msg="iteration function" name=01DFDXE9FF5VFXA4MRGZ4932EX/
level=debug ts=2019-09-09T15:58:53.681017126Z caller=objstore.go:145 compactionGroup="0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}" msg="DownloadDir entered" src=01DFDXE9FF5VFXA4MRGZ4932EX/ dst="/local/state/compact/0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX"
level=debug ts=2019-09-09T15:58:53.76472144Z caller=objstore.go:152 compactionGroup="0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}" msg="iteration function" name=01DFDXE9FF5VFXA4MRGZ4932EX/
level=debug ts=2019-09-09T15:58:53.764784984Z caller=objstore.go:145 compactionGroup="0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}" msg="DownloadDir entered" src=01DFDXE9FF5VFXA4MRGZ4932EX/ dst="/local/state/compact/0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX"
level=debug ts=2019-09-09T15:58:53.809286337Z caller=objstore.go:152 compactionGroup="0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}" msg="iteration function" name=01DFDXE9FF5VFXA4MRGZ4932EX/
level=debug ts=2019-09-09T15:58:53.809338947Z caller=objstore.go:145 compactionGroup="0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}" msg="DownloadDir entered" src=01DFDXE9FF5VFXA4MRGZ4932EX/ dst="/local/state/compact/0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX"
level=debug ts=2019-09-09T15:58:53.905969827Z caller=objstore.go:152 compactionGroup="0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}" msg="iteration function" name=01DFDXE9FF5VFXA4MRGZ4932EX/
level=debug ts=2019-09-09T15:58:53.906021906Z caller=objstore.go:145 compactionGroup="0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}" msg="DownloadDir entered" src=01DFDXE9FF5VFXA4MRGZ4932EX/ dst="/local/state/compact/0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX"
level=debug ts=2019-09-09T15:58:54.007003125Z caller=objstore.go:152 compactionGroup="0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}" msg="iteration function" name=01DFDXE9FF5VFXA4MRGZ4932EX/
level=debug ts=2019-09-09T15:58:54.007045632Z caller=objstore.go:145 compactionGroup="0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}" msg="DownloadDir entered" src=01DFDXE9FF5VFXA4MRGZ4932EX/ dst="/local/state/compact/0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX"
level=debug ts=2019-09-09T15:58:54.11842514Z caller=objstore.go:152 compactionGroup="0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}" msg="iteration function" name=01DFDXE9FF5VFXA4MRGZ4932EX/
...
level=error ts=2019-09-09T15:59:03.532032343Z caller=main.go:214 msg="running command failed" err="error executing compaction: compaction failed: compaction failed for group 0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}: download block 01DFDXE9FF5VFXA4MRGZ4932EX: create dir: mkdir /local/state/compact/0@{prometheus=\"NS/prometheus-NS\",prometheus_replica=\"prometheus-prometheus-NS-0\"}/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX/01DFDXE9FF5VFXA4MRGZ4932EX: file name too long"

It looks as if (somehow) under (some) conditions, the recursive call to bkt.Iter basically ends up fecthing the same thing over and over. Having looked at the S3 storage, I can see that (in s3browser), there's no infinite nesting.

[ingvarm-gr]

Looking even deeper, it looks as if minio, in some (all?) circumstances returns the "current directory", and a small patch that explictly logs this edge case and skips to the next item in the list does trigger the logging, and avoids the infinite recursion. A cleaner PR to follow, once we have had it running for a while.

[jimbobby5]

Raised PR for fix: #1544

[jimbobby5]

#1544 merged 🎉 so the next release of Thanos should have this fixed!

[GiedriusS]

🎉 closing this as fixed. Thanks for your contribution, @jimbobby5 !