Instant queries and Rate behavior

[Peter Zaitsev]

Hi,

I'm trying to create dashboard which shows the current CPU usage per CPU core and I'm finding strange behavior what rate() seems to report some strange looking numbers.

I'm running Prometheus 1.8.2 if it matters

I run  "stress -c 4"   which ensures 4 CPU cores on this system are 100% saturated

However if I run this query in the Prometheus console:

(sum by (cpu) ( (clamp_max(rate(node_cpu{instance="rocky",mode!="idle",mode!="iowait"}[5s]),1)) ))

I get:

{cpu="cpu19"}

0.6187579999999475

which is some  60%

as I increase the value for 5s it increases too 

(sum by (cpu) ( (clamp_max(rate(node_cpu{instance="rocky",mode!="idle",mode!="iowait"}[10s]),1)) ))

{cpu="cpu19"}

0.7256014474634671

(sum by (cpu) ( (clamp_max(rate(node_cpu{instance="rocky",mode!="idle",mode!="iowait"}[60s]),1)) ))

{cpu="cpu19"}

0.9608500000000001

Note, what these date does NOT match  if I click "Graph" on Prometheus which  is very close to 1 at all time, whatever number of seconds I use 

What is going on here. Is this expected ? 

[Björn Rabenstein]

What’s your scrape interval? ([5s] is quite short for a rate but it might make sense in high-scrape frequency scenarios. But then you might also be able to sample inaccuracies of the CPU metric.)

What happens if you leave out the clamp_max?

At a first glance, I’d say that you are just running into inaccuracies here, and due to the clamp_max, you are throwing away the ones that shoot above 1, so you get a value too low as the final result.

However, all of that doesn’t explain why the “Graph” view doesn’t show the same…

​

--
You received this message because you are subscribed to the Google Groups "Prometheus Developers" group.
To unsubscribe from this group and stop receiving emails from it, send an email to prometheus-developers+unsub...@googlegroups.com.
To post to this group, send email to prometheus-developers@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/prometheus-developers/eea86bb0-8f46-4020-8802-daa49dee1fad%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

Björn Rabenstein, Engineer
http://soundcloud.com/brabenstein

SoundCloud Ltd. | Rheinsberger Str. 76/77, 10115 Berlin, Germany
Managing Director: Alexander Ljung | Incorporated in England & Wales with Company No. 6343600 | Local Branch Office | AG Charlottenburg  | HRB 110657B

[Peter Zaitsev]

Hi Bjorn,

Thank you for response! 

The scrape interval is 1 sec 

Here is result without clamp_max:

(sum by (cpu) ( (rate(node_cpu{instance="rocky",mode!="idle",mode!="iowait"}[5s])) ))

{cpu="cpu15"}

0.7352559999995604

10s

{cpu="cpu15"}

0.7848360000004554

30s

{cpu="cpu15"}

0.9428344197534526

Here is graph example as you see clamp_max avoids value over 100% which happen due to jitter but does not explain this

I wonder how does rate() works with very last interval - if we are looking back for 5 sec and for example data only available for 3 will   "missing data" be considered as null and ignored or will it be considered as zero ? 

There is more weirdness with instant queries:

Running this query:

time()-node_time{instance="rocky"}

I get values of 1 and 3 on refreshes with 2 being most frequent.  If I graph it however I get:

note there are only were rare spikes to 1 sec   and the very last interval is strangely spiking 

I almost always see this.  So is there something special in how last interval is evaluated ? 

To unsubscribe from this group and stop receiving emails from it, send an email to prometheus-developers+unsubscri...@googlegroups.com.

To post to this group, send email to prometheus-developers@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/prometheus-developers/eea86bb0-8f46-4020-8802-daa49dee1fad%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

Björn Rabenstein, Engineer
http://soundcloud.com/brabenstein

SoundCloud Ltd. | Rheinsberger Str. 76/77, 10115 Berlin, Germany
Managing Director: Alexander Ljung | Incorporated in England & Wales with Company No. 6343600 | Local Branch Office | AG Charlottenburg  | HRB 110657B

--

Peter Zaitsev, CEO, Percona
Tel: +1 888 401 3401 ext 7360   Skype:  peter_zaitsev

[Ben Kochie]

One question about your node_cpu metrics, what version of the exporter are you using?  Do you have any VMs running?

We recently fixed[0] an issue in master where there was some over-counting of CPU when there are VMs (guest time) leading to > 100% reporting.

This isn't in a release build yet, so the workaround would be to ignore guest modes from any node_cpu calculations.

[0]: https://github.com/prometheus/node_exporter/pull/744

To unsubscribe from this group and stop receiving emails from it, send an email to prometheus-developers+unsub...@googlegroups.com.

To post to this group, send email to prometheus-developers@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/prometheus-developers/CA%2BRUij23vdhcck7XdvSx01FBk2MbKe4vAV_rmBCasWftoxgNHw%40mail.gmail.com.

[Björn Rabenstein]

It looks indeed as if there is an issue with the time it takes for a
sample to become visible.

I have never run into those issues, but you are scraping quite
frequently with a perhaps relatively loaded Prometheus server, which
might make it more severe.

To rule out an issue of instant queries (for the console) vs. range
queries (for the graph), you can run queries in the console view with
an `offset 10m` modifier, see
https://prometheus.io/docs/prometheus/latest/querying/basics/#offset-modifier

If this is really about delayed recent samples, those offset queries
should have the same result as you see in the graph.

[Peter Zaitsev]

Hi Bjorn,

Thanks.   Indeed offset helps, and If I use this query the results are much more stable:

(sum by (cpu) ( (rate(node_cpu{instance="rocky",mode!="idle",mode!="iowait"}[5s] offset 1m)) ))  

{cpu="cpu0"}

0.9918175055789733

And indeed the "Console" output matches graph. 

Now I'm trying to understand if this is documented behavior ? Bug or what ?  

Am I correct in understanding what

1)  the "instant" query result should match the last data point of the "range" query when queried to the current time ?

2) The rate() for the query is considered from the current time, so if I have  [5s] interval when data from   current_time()-5sec to current_time() will be considered and value computed based on the data available in this interval, 

or is it suppose to be something else ? 

[Björn Rabenstein]

On 31 December 2017 at 04:20, Peter Zaitsev <p...@percona.com> wrote:
>
> Now I'm trying to understand if this is documented behavior ? Bug or what ?

I'd say it's mostly "by design". A scrape happens at a time t, with
that time assigned as a timestamp to all samples in the scrape. (This
has already a few implications, as the scrape takes a finite time. Is
t the beginning or the end of the scrape? The monitored target will in
general not take a real snapshot at t but collect metrics over a
finite timestamp again. However, the only thing relevant for the issue
at hand is that t is not in the future.) Now ingestion of all those
samples will take a finite time, from arrival of the samples at the
Prometheus server to visibility for queries. If you query for "now",
samples still being ingested, but with a timestamp in the past, will
not show up.

Compared to usual scrape intervals (15s to 60s) and the resulting
typical ranges used for rates, this delay hardly matters. However,
with high frequency scrapes, perhaps even combined with a heavily
loaded Prometheus server, you run into the problems you have observed
here. In general, the Prometheus collection model should be robust
against a lost or delayed scrape. But I assume, in your case, we are
getting into an area where the delay is comparable to a scrape
interval, which throws off the heuristic of determining the "end" of a
series within a range expression.

Prometheus 2 doesn't change anything in principle, but ingestion is
much more streamlined, so the delay is expected to be much shorter.

A real solution would be some kind of ingestion watermark that would
restrict the most recent timestamp for which queries can be issued
(essentially putting "now" a bit into the past). However, those
watermark approaches have some problematic implications.

Another solution might be to tie the range interpolation heuristics
(used for rate calculation) into staleness handling (essentially
making use of the knowledge that the series hasn't actually ended even
if the ingestion delay is approaching the scrape interval).

But perhaps it's really a non-issue in practice with Prometheus 2
because the ingestion delay will hardly ever get close to practically
relevant scrape intervals.

> Am I correct in understanding what
>
> 1) the "instant" query result should match the last data point of the "range" query when queried to the current time ?

If you are referring to "console" vs. "graph" view (or "query" vs.
"query_range" from the point of view of the API), then yes. The range
query is equivalent to issuing a series of instant queries.

> 2) The rate() for the query is considered from the current time, so if I have [5s] interval when data from current_time()-5sec to current_time() will be considered and value computed based on the data available in this interval,
> or is it suppose to be something else ?

The [5s] range for each rate calculation is taken from the time
reference of the query, i.e. it is between t and t-5s. t varies
depending on what the query is for. If you just run a console query,
it's "now". If you run a graph query with a certain resolution, it's
"now", "now" minus once the resolution, "now" minus twice the
resolution etc. And the `offset` modifier shifts t again.