Too much memory used and bad query performance

[jackpgao]

We have 3119 target from Prometheus, each has 3600 metric, scrape_interval is 60sec.

4 Mimir node, config as below.

The Mimir use too much memory, and the query performance is bad.

blocks_storage:
    backend: s3
    s3:
        access_key_id: mimir
        bucket_name: mimir-blocks
        endpoint: xx:9000
        insecure: true
        secret_access_key: '********'
    tsdb:
        block_ranges_period:
            - 10m0s
        dir: /data1/mimir/ingester
limits:
    ingestion_burst_size: 20000000
    ingestion_rate: 1e+06
    max_global_series_per_metric: 200000000
    max_global_series_per_user: 1500000000
    max_label_names_per_series: 30000000
memberlist:
    join_members:
        - xx
        - xx
        - xx
        - xxx
server:
    log_level: debug
target: all,alertmanager,overrides-exporter

We use a Nginx as load balance before the 4 node Mimir, and the nginx log show that the /api/v1/push only use about 10-20 ms, but the /prometheus/api/v1/query_range from Grafana is more than 5 sec.

Update

block_ranges_period seted to 10m is used to reduce the meomory usage, thus cause too many block, may affect the query formance.

level=debug ts=2022-05-16T11:41:36.23584015Z caller=blocks_consistency_checker.go:64 msg="block skipped from consistency check because it was uploaded recently" block=01G368PXHY7JNPC51DVMFGD90C uploadedAt="2022-05-16 19:08:25 +0800 CST"
level=debug ts=2022-05-16T11:41:36.235862534Z caller=blocks_consistency_checker.go:64 msg="block skipped from consistency check because it was uploaded recently" block=01G36997ECF1N1AWK4GJ6QWJNZ uploadedAt="2022-05-16 19:18:38 +0800 CST"
level=debug ts=2022-05-16T11:41:36.235877533Z caller=blocks_consistency_checker.go:64 msg="block skipped from consistency check because it was uploaded recently" block=01G368PXDYYRGGKNTP6YQN2JZ5 uploadedAt="2022-05-16 19:08:48 +0800 CST"
level=debug ts=2022-05-16T11:41:36.430411487Z caller=bucket.go:1123 org_id=sce msg="stats query processed" stats="&{blocksQueried:22 postingsTouched:9 postingsTouchedSizeSum:4637878 postingsToFetch:0 postingsFetched:1 postingsFetchedSizeSum:26848 postingsFetchCount:1 postingsFetchDurationSum:145498470 cachedPostingsCompressions:1 cachedPostingsCompressionErrors:0 cachedPostingsOriginalSizeSum:26848 cachedPostingsCompressedSizeSum:326 cachedPostingsCompressionTimeSum:128913 cachedPostingsDecompressions:27 cachedPostingsDecompressionErrors:0 cachedPostingsDecompressionTimeSum:19768102 seriesTouched:17 seriesTouchedSizeSum:646 seriesFetched:1 seriesFetchedSizeSum:65536 seriesFetchCount:1 seriesFetchDurationSum:39790817 seriesHashCacheRequests:0 seriesHashCacheHits:0 chunksTouched:17 chunksTouchedSizeSum:1141 chunksFetched:17 chunksFetchedSizeSum:272000 chunksFetchCount:17 chunksFetchDurationSum:23973197921 getAllDuration:2599273642 mergedSeriesCount:1 mergedChunksCount:14 mergeDuration:135168}" err=null
level=debug ts=2022-05-16T11:41:36.430534026Z caller=grpc_logging.go:58 duration=2.600109464s method=/gatewaypb.StoreGateway/Series msg="gRPC (success)"
ts=2022-05-16T11:41:36.430710526Z caller=spanlogger.go:80 org_id=sce level=debug msg="received series from store-gateway" instance=10.182.1.93:9095 fetchedseries=1 fetchedchunkbytes=1188 fetchedchunks=14 requestedblocks="01G36997BX3P02NNF06YZKV75S 01G3684KFY78MRMPK72M168XJV 01G362ZT5YNT2Y2YM2TG3121P7 01G367J9V8BZFWPDNGE7MPVB6F 01G3644E0CT7XDD94F0FVKKR8P 01G35YZMKYEKVZPKBKCKRFJ9Y8 01G3618VVWGVTJK12WCFQVWS7F 01G36591XYEYEHGRKNBQE8WFVZ 01G364PQVYVHJVNW5ZVXFSY9VY 01G3684KJCG6B0AAC0169TB0HJ 01G361V65YWX347VYTRFX7Z011 01G368PXHY7JNPC51DVMFGD90C 01G36048EDAQSXMDTYAMH9ZS5S 01G360PJCDK3GRS2EMEZQSHPGJ 01G3644E79JTT0KN7FPHWSFJY3 01G36591SX2ESYFB08QWZQDR5R 01G364PQYDPY7B4FR8WRBQT0Q8 01G366DNSZ0815ZEC29PA1YHEE 01G35YZM3WDA5PS3M8PREHS61N 01G366ZZR1H9HX5J8781FVVJQG 01G3618W7Y0PCFAAP7BNSEZQP6 01G3684KS8RC7H99Q5HJY9PDH6" queriedblocks="01G35YZMKYEKVZPKBKCKRFJ9Y8 01G35YZM3WDA5PS3M8PREHS61N 01G36048EDAQSXMDTYAMH9ZS5S 01G360PJCDK3GRS2EMEZQSHPGJ 01G3618VVWGVTJK12WCFQVWS7F 01G3618W7Y0PCFAAP7BNSEZQP6 01G361V65YWX347VYTRFX7Z011 01G362ZT5YNT2Y2YM2TG3121P7 01G3644E0CT7XDD94F0FVKKR8P 01G3644E79JTT0KN7FPHWSFJY3 01G364PQVYVHJVNW5ZVXFSY9VY 01G364PQYDPY7B4FR8WRBQT0Q8 01G36591XYEYEHGRKNBQE8WFVZ 01G36591SX2ESYFB08QWZQDR5R 01G366DNSZ0815ZEC29PA1YHEE 01G366ZZR1H9HX5J8781FVVJQG 01G367J9V8BZFWPDNGE7MPVB6F 01G3684KS8RC7H99Q5HJY9PDH6 01G3684KJCG6B0AAC0169TB0HJ 01G3684KFY78MRMPK72M168XJV 01G368PXHY7JNPC51DVMFGD90C 01G36997BX3P02NNF06YZKV75S"
ts=2022-05-16T11:41:36.430784607Z caller=spanlogger.go:80 org_id=sce method=blocksStoreQuerier.selectSorted level=debug msg="received series from all store-gateways" queriedblocks="01G36048FZYQEXGC8C7G9Z23RH 01G360PJ9XBDPFJTFTTZ57NZJF 01G3618WADYF2SHJKH3A7WHQ6Y 01G362DG7YQF09EF9SW0CJKJEC 01G362DGD80KRWMP11PWHN9TH9 01G363J43YMFXBPS6AQ5PZQD36 01G363J3ZXZWZCBT0W6C571HYV 01G3644DXXKF98JHXSR0XNG4ZQ 01G3644E1YN2ZNPE1TPJMS53NF 01G364PR58NWWVAQCXD1CX5QDP 01G3659238R1VAMYGSHK2RVBNW 01G365VBQXY7M0HXXC2V9BE5R0 01G365VC18E9NAFBWABGYTSYRG 01G366DNNYSHTBBE4RR27C8H3Q 01G366DNRCZP6RKWYJDAH05SJ0 01G366DNZ86E4HVKEJW2EYXTNR 01G367J9MCWQA61YAF379RHHTV 01G368PXGC5W3VN496GB7BPEKX 01G36997N80X49PN3NRNWAHFPQ 01G360TJNEMMXPBKMPEN7VBZ2M 01G35YZMFY8KBT1WZSZTS4FP5W 01G35ZHYGDCQGBJ59E75BZBFVC 01G3618WBYMDQHR35Y47QME6ZR 01G361V69Y0RXYNY8CEDJ6RHQB 01G361V6F8GEF4BW7S4SRW0SQY 01G362ZT1XRMP47DXV7GGQ1D8E 01G364PQZYCDPGY6S3J2CEAZJS 01G36591WCAWD8BWN1K8GZ0V7H 01G365VBVYDGJ1F4GZBEMBXVNP 01G366ZZPC2H0P82DFCFP6VDXK 01G368PXQ83CNQBMQ5ZGG4R562 01G36997FYC1SKNDVSN3TN8VWG 01G35W6BJ8EBATNYHR2JN9D2Z7 01G35YZMJDJGR0SMKSY13KFZTQ 01G35ZHY1W44Q6ZCVNM1ZATWYN 01G35ZHYHY4Z37Y4SQHT9EH963 01G35ZHYDX4Z6M3NG1TWPKBXZS 01G36047ZW87A22CYEWXD8S88V 01G36048BYZDP4VPR6WAJ4FDFD 01G360PJDZTNTG2EN01E674VJN 01G360PHXWPKM1CW34T4MKJDZD 01G361V68C8PSXSCEZTXXPRSA9 01G362DG6DKX781WF206110A8E 01G362DG3YYN5B7M82BFKEXJY8 01G362ZT4DFM0DCRA8B1PTDBAR 01G362ZTB8JNVG4JX0VA3VB088 01G363J499TCCEC52NBNN4XH8Y 01G363J42D9GEH792B5TVSEKJY 01G365VBTC561JMWZ3Y289GPJ7 01G366ZZX8VG2HA05ZRKTNMP8N 01G366ZZKYBC6MEEF865F53ZCW 01G367J9NYEB2K913Y3BNYX2MW 01G367J9HYY12ZACNR2BC75CF7 01G3684KKYFHZYX7XA35YA0NFS 01G368PXDYYRGGKNTP6YQN2JZ5 01G36997ECF1N1AWK4GJ6QWJNZ 01G35YZMKYEKVZPKBKCKRFJ9Y8 01G35YZM3WDA5PS3M8PREHS61N 01G36048EDAQSXMDTYAMH9ZS5S 01G360PJCDK3GRS2EMEZQSHPGJ 01G3618VVWGVTJK12WCFQVWS7F 01G3618W7Y0PCFAAP7BNSEZQP6 01G361V65YWX347VYTRFX7Z011 01G362ZT5YNT2Y2YM2TG3121P7 01G3644E0CT7XDD94F0FVKKR8P 01G3644E79JTT0KN7FPHWSFJY3 01G364PQVYVHJVNW5ZVXFSY9VY 01G364PQYDPY7B4FR8WRBQT0Q8 01G36591XYEYEHGRKNBQE8WFVZ 01G36591SX2ESYFB08QWZQDR5R 01G366DNSZ0815ZEC29PA1YHEE 01G366ZZR1H9HX5J8781FVVJQG 01G367J9V8BZFWPDNGE7MPVB6F 01G3684KS8RC7H99Q5HJY9PDH6 01G3684KJCG6B0AAC0169TB0HJ 01G3684KFY78MRMPK72M168XJV 01G368PXHY7JNPC51DVMFGD90C 01G36997BX3P02NNF06YZKV75S"

[pracucci]

I've converted the issue into a discussion. We can open an issue anytime if there will be any action item as result of this discussion.

[pracucci]

My hot take, given what you shared:

1. Capacity planning doc can give you some hints about what to expect with regards to resources utilization
2. I wouldn't touch advanced config options (e.g. do not change block_ranges_period)
3. Make sure you followed production tips and, in particular, all memcached-based caches are configured and -querier.query-store-after set (I can follow up on this if you need more help)
4. Make sure CPU is not throttled (e.g. you're setting CPU limits on Kubernetes)

[jackpgao]

Can not find the query-store-after in here https://grafana.com/docs/mimir/v2.0.x/operators-guide/architecture/components/querier/ or from the http://mimir:8080/config.
It seems many parameters is missed.

[jackpgao]

I trace a simple query as below, which shows the 7 block is scaned, and the total query time is about 1sec, much more than Prometheus.

Can anyone analyse the stats query processed?

level=debug ts=2022-05-17T09:23:04.457923135Z caller=grpc_logging.go:41 method=/cortex.Ingester/QueryExemplars duration=115.401µs msg="gRPC (success)"
ts=2022-05-17T09:23:04.459643516Z caller=spanlogger.go:80 org_id=bip method=querier.Select level=debug hint.func=rate start="2022-05-17 05:35:00 +0000 UTC" end="2022-05-17 06:44:30 +0000 UTC" step=30000 matchers="instance=~\"10.13.1.192:9100\",mode=\"idle\",__name__=\"node_cpu_seconds_total\""
ts=2022-05-17T09:23:04.460040553Z caller=spanlogger.go:80 org_id=bip method=Ingester.QueryStream level=debug msg="using queryStreamChunks"
ts=2022-05-17T09:23:04.460399436Z caller=spanlogger.go:80 org_id=bip method=Ingester.QueryStream level=debug series=7 samples=4779
level=debug ts=2022-05-17T09:23:04.460438535Z caller=grpc_logging.go:58 method=/cortex.Ingester/QueryStream duration=508.095µs msg="gRPC (success)"
level=info ts=2022-05-17T09:23:04.466318999Z caller=loader.go:138 msg="loaded bucket index" user=bip duration=6.6044ms


ts=2022-05-17T09:23:04.466377189Z caller=spanlogger.go:80 org_id=bip method=blocksStoreQuerier.selectSorted level=debug msg="found blocks to query" expected="
01G38KZ5M4PVYE5ZYDQV27C6S6 (min time: 2022-05-17 06:00:00 +0000 UTC max time: 2022-05-17 08:00:00 +0000 UTC, compactor shard: none),
01G38M7HK11SR92TAXT1FQZCJM (min time: 2022-05-17 06:00:00 +0000 UTC max time: 2022-05-17 08:00:00 +0000 UTC, compactor shard: none),
01G38GBJBG94KB9MJTR8V01N8Q (min time: 2022-05-17 04:00:00 +0000 UTC max time: 2022-05-17 06:00:00 +0000 UTC, compactor shard: none),
01G38KZ4SFE5NTWRP610154SKM (min time: 2022-05-17 06:00:00 +0000 UTC max time: 2022-05-17 08:00:00 +0000 UTC, compactor shard: none),
01G38KYKGF9VXY1T2HQA6DE1CK (min time: 2022-05-17 06:00:00 +0000 UTC max time: 2022-05-17 08:00:00 +0000 UTC, compactor shard: none),
01G38MDG99PBJAB0ANTSFZAYJH (min time: 2022-05-17 06:00:00 +0000 UTC max time: 2022-05-17 08:00:00 +0000 UTC, compactor shard: none),
01G38M7VWTXQSB2T6QN0H6KV4N (min time: 2022-05-17 06:00:00 +0000 UTC max time: 2022-05-17 08:00:00 +0000 UTC, compactor shard: none)"


ts=2022-05-17T09:23:04.466432726Z caller=spanlogger.go:80 org_id=bip method=blocksStoreQuerier.selectSorted level=debug msg="found store-gateway instances to query" numinstances=3 attempt=1
level=debug ts=2022-05-17T09:23:04.466872239Z caller=bucket.go:972 org_id=bip msg="Blocks source resolutions" blocks=2 MaximumResolution=0 mint=1652765700000 maxt=1652769870000 lset="{__org_id__=\"bip\"}" spans="Range: 1652760000000-1652774400000 Resolution: 0"


level=debug ts=2022-05-17T09:23:05.396181165Z caller=bucket.go:1123 org_id=bip msg="stats query processed" stats="&{
blocksQueried:2 postingsTouched:0 postingsTouchedSizeSum:0
postingsToFetch:0 postingsFetched:0 postingsFetchedSizeSum:0
postingsFetchCount:0 postingsFetchDurationSum:0 cachedPostingsCompressions:0
cachedPostingsCompressionErrors:0 cachedPostingsOriginalSizeSum:0
cachedPostingsCompressedSizeSum:0 cachedPostingsCompressionTimeSum:0
cachedPostingsDecompressions:2 cachedPostingsDecompressionErrors:0
cachedPostingsDecompressionTimeSum:2716 seriesTouched:24 seriesTouchedSizeSum:1697
seriesFetched:0 seriesFetchedSizeSum:0 seriesFetchCount:0 seriesFetchDurationSum:0
seriesHashCacheRequests:0 seriesHashCacheHits:0 chunksTouched:59
chunksTouchedSizeSum:35459 chunksFetched:59 chunksFetchedSizeSum:405148
chunksFetchCount:24 chunksFetchDurationSum:15453988040 getAllDuration:929129853
mergedSeriesCount:12 mergedChunksCount:59 mergeDuration:88337

}"err=null
level=debug ts=2022-05-17T09:23:05.396235967Z caller=grpc_logging.go:58 method=/gatewaypb.StoreGateway/Series duration=929.574238ms msg="gRPC (success)"