Bug: Native histogram operations like histogram_count emitting negative values

[rishabhkumar92]

What is the bug?

Hi Team,

We are seeing cases where histogram_count are giving negative values intermittently.

We also recently upgraded to 2.16.0 to see if that alleviates the issue as it includes fix related to aggr_over_time and counter reset detection but issue still persists.

How to reproduce it?

Start Mimir 2.16.0
One of rule is based on query avg_over_time(histogram_count(sum(rate(query:without_instance{bushido_mode="shogun",bushido_tier=~"production.*"}[5m])))[5m:]) which trigger alerts with a negative value

However, when we visualize the same query in a dashboard it shows expected values (non-negative), so it's only seen during rule evaluation.

What did you think would happen?

histogram_count should never emit negative values

What was your environment?

Kubernetes

Any additional context to share?

No response

[krajorama]

Hi,

not gonna lie, this sounds tough on account of only happening at rule evaluations.

• How often does this happen?

• Are there out of order samples? You can check cortex_ingester_tsdb_out_of_order_samples_appended_total metric.

• Let's try to narrow down which series have negative values. Since we don't know how many series have this problem, first I'd add a recording rule to just count how many series are affected:

  count(histogram_count(rate(query:without_instance{bushido_mode="shogun",bushido_tier=~"production.*"}[5m])) < 0)
  

  If it's not too bad, I'd record the labels of the affected series:

  histogram_count(rate(query:without_instance{bushido_mode="shogun",bushido_tier=~"production.*"}[5m])) < 0
  

• Maybe we can still see it outside rule eval, by adjusting the evaluation time. Take a note of the timestamp of the result sample in your recording rule. To get the raw evaluation time, you'll need to do an instant query on the recorded metric, use the format table and query the metric with a range vector selector, for example to get the raw samples from the last 1 minute: metric[1m]. In the result , use the Table view instead of Raw. See my screenshot:

  

  The times in the Time column are the real sample times. Can you see the negative value if you do the offending query as instant query at that time ? At that time meaning that the time selector in grafana has that time for the end.

[rishabhkumar92]

Can you see the negative value if you do the offending query as instant query at that time ? At that time meaning that the time selector in grafana has that time for the end.

No, that's why i was curious if it's related to any of extrapolation issue which is also being addressed here.

Also one other observation was around dropping avg_over_time which fixed this noise.

Let me add those recording rules anyways as suggested.

[krajorama]

No, that's why i was curious if it's related to any of extrapolation issue which is also being addressed prometheus/prometheus#16192.

We think it's not be related as extrapolating below zero happens before the rate is calculated , which means rate will think that there's a bigger increase in the series than actually possible. Thus rate gets higher , not lower.

Interesting that dropping avg_over_time() fixed the issue. The Prometheus code that we rely on here uses some optimizations around histogram_count() to not load the buckets themselves. We have had a few bugs related to this code in the past that caused memory corruption and led to panic in the code. Those bugs were non-deterministic which would explain why we cannot reproduce this problem easily. What's your setting for query_engine / -querier.query-engine ?

[krajorama]

By the way , how negative is the result on orders magnitude (-0.1 or -1000000) and how big is the expected error on orders of magnitude? Just to get of sense of the error and relative error.

[rishabhkumar92]

Those bugs were non-deterministic which would explain why we cannot reproduce this problem easily. What's your setting for query_engine / -querier.query-engine ?

We still use prometheus on query engine atm, we plan to switch to mimir in near term but want to address these functional issues first and then worry about query performance.

i also added recording rule to track negative results, so far haven't gotten any.

By the way , how negative is the result on orders magnitude (-0.1 or -1000000) and how big is the expected error on orders of magnitude? Just to get of sense of the error and relative error.

As far as this query goes avg_over_time(histogram_count(sum(rate(query:without_instance{bushido_mode="shogun",bushido_tier=~"production.*"}[5m])))[5m:]), it generally range from 2000 to 4000 but misfired data points were -1678.0952195889172 & -1674.4376774180341

In this case dropping avg_over_time helped and we haven't seen any misfire since past 4 days.

[rishabhkumar92]

@krajorama any further finding on avg_over_time usage? will you recommend switching to mimir query engine for this.