Thanos compactor backlog

[BouchaaraAdil]

Thanos, Prometheus and Golang version used:

• thanos: 0.34.1
• kube-prometheus-stack-48.6.0: prometheus-v2.45.0

  Anything else we need to know:

  2024-03-19 00:50:47.693 
  caller=compact.go:1466 level=info msg="start of GC"
  2024-03-19 00:50:47.688 
  caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=7m48.994184246s duration_ms=468994 cached=26009 returned=25127 partial=0
  2024-03-19 00:50:38.477 
  caller=fetcher.go:820 level=debug msg="removed replica label" label=prometheus_replica count=18838
  2024-03-19 00:50:34.009 
  caller=fetcher.go:407 level=debug component=block.BaseFetcher msg="fetching meta data" concurrency=100
  2024-03-19 00:50:34.002 
  caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=7m48.930507728s duration_ms=468930 cached=26009 returned=26009 partial=0
  2024-03-19 00:42:58.691 
  caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=6m3.515992146s duration_ms=363515 cached=26009 returned=25127 partial=0
  2024-03-19 00:42:49.595 
  caller=fetcher.go:820 level=debug msg="removed replica label" label=prometheus_replica count=18838
  2024-03-19 00:42:45.071 
  caller=fetcher.go:407 level=debug component=block.BaseFetcher msg="fetching meta data" concurrency=100
  2024-03-19 00:42:45.065 
  caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=6m4.828559979s duration_ms=364828 cached=26009 returned=26009 partial=0
  2024-03-19 00:36:55.168 
  caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=7m57.780002178s duration_ms=477780 cached=26009 returned=25127 partial=0
  2024-03-19 00:36:44.681 
  caller=fetcher.go:820 level=debug msg="removed replica label" label=prometheus_replica count=18838
  2024-03-19 00:36:40.236 
  caller=fetcher.go:407 level=debug component=block.BaseFetcher msg="fetching meta data" concurrency=100
  2024-03-19 00:36:40.230 component=block.BaseFetcher msg="successfully synchronized block metadata" duration=7m42.841847446s duration_ms=462841 cached=26009 returned=26009 partial=0
  2024-03-19 00:28:57.388 
  caller=compact.go:1461 level=info msg="start sync of metas"
  2024-03-19 00:28:57.388 
  caller=tls_config.go:277 level=info service=http/server component=compact msg="TLS is disabled." http2=false address=[::]:10902
  2024-03-19 00:28:57.388 
  caller=tls_config.go:274 level=info service=http/server component=compact msg="Listening on" address=[::]:10902
  2024-03-19 00:28:57.388 
  caller=fetcher.go:407 level=debug component=block.BaseFetcher msg="fetching meta data" concurrency=100
  2024-03-19 00:28:57.388 
  aller=http.go:73 level=info service=http/server component=compact msg="listening for requests and metrics" address=0.0.0.0:10902
  2024-03-19 00:28:57.388 
  aller=intrumentation.go:75 level=info msg="changing probe status" status=healthy
  2024-03-19 00:28:57.388 
  caller=intrumentation.go:56 level=info msg="changing probe status" status=ready
  2024-03-19 00:28:57.388 
  caller=compact.go:679 level=info msg="starting compact node"
  2024-03-19 00:28:57.387 
  caller=compact.go:405 level=info msg="retention policy of 5 min aggregated samples is enabled" duration=8760h0m0s
  2024-03-19 00:28:57.387 
  caller=compact.go:398 level=info msg="retention policy of raw samples is enabled" duration=4320h0m0s
  2024-03-19 00:28:57.387 
  caller=compact.go:256 level=info msg="vertical compaction is enabled" compact.enable-vertical-compaction=true
  2024-03-19 00:28:57.387 
  caller=compact.go:251 level=info msg="deduplication.replica-label specified, enabling vertical compaction" dedupReplicaLabels=prometheus_replica
  2024-03-19 00:28:57.386 
  caller=factory.go:53 level=info msg="loading bucket configuration"
  2024-03-19 00:28:57.386 
  caller=main.go:67 level=debug msg="maxprocs: Updating GOMAXPROCS=[20]: determined from CPU quota"

[yeya24]

@BouchaaraAdil Have you checked your compactor metrics? Is it in halt status?

thanos_compact_halted you can find it via this metric.

https://thanos.io/tip/operating/compactor-backlog.md/#make-sure-compactors-are-running

[BouchaaraAdil]

@yeya24 yes i already did the value is: 0

logs are mostly like:

caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=7m8.010456222s duration_ms=428010 cached=24894 returned=24894 partial=0    
caller=fetcher.go:820 level=debug msg="removed replica label" label=prometheus_replica count=18750  
caller=fetcher.go:407 level=debug component=block.BaseFetcher msg="fetching meta data" concurrency=60   
caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=7m8.234159055s duration_ms=428234 cached=24894 returned=24894 partial=0    
caller=blocks_cleaner.go:58 level=info msg="cleaning of blocks marked for deletion done"    
caller=blocks_cleaner.go:44 level=info msg="started cleaning of blocks marked for deletion" 
caller=clean.go:61 level=info msg="cleaning of aborted partial uploads done"    
caller=clean.go:34 level=info msg="started cleaning of aborted partial uploads" 
caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=8m35.588933685s duration_ms=515588 cached=24894 returned=24894 partial=0   
caller=fetcher.go:820 level=debug msg="removed replica label" label=prometheus_replica count=18750  
caller=fetcher.go:407 level=debug component=block.BaseFetcher msg="fetching meta data" concurrency=60   
caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=8m35.392333486s duration_ms=515392 cached=24894 returned=24894 partial=0   
caller=blocks_cleaner.go:58 level=info msg="cleaning of blocks marked for deletion done"    caller=blocks_cleaner.go:44 level=info msg="started cleaning of blocks marked for deletion" 
caller=clean.go:61 level=info msg="cleaning of aborted partial uploads done"    
caller=clean.go:34 level=info msg="started cleaning of aborted partial uploads" 
caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=8m11.753199423s duration_ms=491753 cached=24894 returned=24894 partial=0   
caller=fetcher.go:820 level=debug msg="removed replica label" label=prometheus_replica count=18750  
caller=fetcher.go:407 level=debug component=block.BaseFetcher msg="fetching meta data" concurrency=60   
caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=8m11.674345163s duration_ms=491674 cached=24894 returned=24894 partial=0   
caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=7m35.466654203s duration_ms=455466 cached=24894 returned=24894 partial=0   
caller=fetcher.go:820 level=debug msg="removed replica label" label=prometheus_replica count=18750  
caller=fetcher.go:407 level=debug component=block.BaseFetcher msg="fetching meta data" concurrency=60   
caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=7m35.686672464s duration_ms=455686 cached=24894 returned=24894 partial=0   
caller=blocks_cleaner.go:58 level=info msg="cleaning of blocks marked for deletion done"    
caller=blocks_cleaner.go:44 level=info msg="started cleaning of blocks marked for deletion" 
caller=clean.go:61 level=info msg="cleaning of aborted partial uploads done"    
caller=clean.go:34 level=info msg="started cleaning of aborted partial uploads" 
caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=6m37.443088828s duration_ms=397443 cached=24894 returned=24894 partial=0   
caller=fetcher.go:820 level=debug msg="removed replica label" label=prometheus_replica count=18750  
caller=fetcher.go:407 level=debug component=block.BaseFetcher msg="fetching meta data" concurrency=60   
caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=6m36.845099529s duration_ms=396845 cached=24894 returned=24894 partial=0   
caller=blocks_cleaner.go:58 level=info msg="cleaning of blocks marked for deletion done"    
caller=blocks_cleaner.go:44 level=info msg="started cleaning of blocks marked for deletion" 
caller=clean.go:61 level=info msg="cleaning of aborted partial uploads done"    
caller=clean.go:34 level=info msg="started cleaning of aborted partial uploads" 
caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=6m39.587074548s duration_ms=399587 cached=24894 returned=24894 partial=0   
caller=fetcher.go:820 level=debug msg="removed replica label" label=prometheus_replica count=18750  
caller=fetcher.go:407 level=debug component=block.BaseFetcher msg="fetching meta data" concurrency=60   
caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=6m40.384243402s duration_ms=400384 cached=24894 returned=24894 partial=0   
caller=fetcher.go:557 level=info component=block.BaseFetcher msg="successfully synchronized block metadata" duration=6m54.588252009s duration_ms=414588 cached=24894 returned=24791 partial=0   
caller=fetcher.go:820 level=debug msg="removed replica label" label=prometheus_replica count=18647  
caller=fetcher.go:867 level=debug msg="block is too fresh for now" block=01HSJP6XN8DPDBJ9XHZTTWDWRD 
caller=fetcher.go:867 level=debug msg="block is too fresh for now" block=01HSJP6XKT2BVBNEB3THRGR0WC 
caller=fetcher.go:867 level=debug msg="block is too fresh for now" block=01HSJP6X2G14XJ04WJ53CZXRKC 
caller=fetcher.go:867 level=debug msg="block is too fresh for now" block=01HSJP6WVZ01H29HPT1QGK07T5 

and the rate of compaction is very low, it starts only after recreating the compactor pod, when I removed the vertical compaction, the compaction rate was high and started to compact even fresher blocks of 2hours to 8,6 hours

[BouchaaraAdil]

@GiedriusS any idea on Error executing query: sum and count timestamps not aligned behaviour?

[BouchaaraAdil]

@yeya24 any updates?

[BouchaaraAdil]

@bwplotka any idea?

[navidshariaty]

I'm facing the same issue. I'm using Thanos (0.36.0), Prometheus (2.53.0), and a ceph cluster for object storage. I have an HA Prometheus scraping the same set of targets, and the compaction rate is very low on the Thanos compactor. The blocks are uploading successfully to block storage via Thanos sidecar. but I have issues with the compaction and downsampling process.

thanos compactor flags:

  - args:
    - compact
    - --data-dir=/var/thanos/compact
    - --log.level=info
    - --http-address=0.0.0.0:10902
    - --objstore.config-file=/etc/objectstore/monitoring-user-s3-creds.yaml
    - --retention.resolution-raw=14d
    - --retention.resolution-5m=30d
    - --retention.resolution-1h=180d
    - --delete-delay=0
    - --wait
    - --wait-interval=15m
    - --web.disable
    - --enable-auto-gomemlimit
    - --deduplication.replica-label=prometheus_replica
    - --deduplication.func=penalty
    - --block-files-concurrency=8
    - --compact.blocks-fetch-concurrency=8
    - --compact.concurrency=8
    - --downsample.concurrency=8

Thanos compactor resources:

resources:
  limits:
    cpu: "8"
    memory: 24Gi
  requests:
    cpu: "8"
    memory: 24Gi

And the Thanos compactor is not halting, but the thanos_compact_todo_downsample_blocks metric is always 0. The backlog is getting heavier. our 2h blocks of Prometheus are about 1G.

The thanos_compact_todo_compaction_blocks metric:

Thanos compact UI:

The vertical compaction is done but the compaction level is stuck on level 2. Also, there is no error or warning in the logs. verbosity is info, but as I checked in debug mode, there was nothing found related to this issue.

Also about the resource usage, I checked this from the node with top command and it does not use half of it's resources.

[navidshariaty]

@BouchaaraAdil could you fix the issue?

[BouchaaraAdil]

i fixed it by running multiple compactors per a list of cluster external label