'Error on ingesting out-of-order samples' in 0.18.0

[RichiH]

As per IRC/mailing list:

After upgrading to 0.18.0, I am seeing tons of

WARN[194663] Error on ingesting out-of-order samples       numDropped=1967 source=scrape.go:459
WARN[194693] Error on ingesting out-of-order samples       numDropped=4573 source=scrape.go:459
WARN[194694] Error on ingesting out-of-order samples       numDropped=1184 source=scrape.go:459
WARN[194723] Error on ingesting out-of-order samples       numDropped=1967 source=scrape.go:459
WARN[194753] Error on ingesting out-of-order samples       numDropped=4573 source=scrape.go:459
WARN[194754] Error on ingesting out-of-order samples       numDropped=1184 source=scrape.go:459
WARN[194783] Error on ingesting out-of-order samples       numDropped=1967 source=scrape.go:459
WARN[194813] Error on ingesting out-of-order samples       numDropped=4573 source=scrape.go:459
WARN[194814] Error on ingesting out-of-order samples       numDropped=1184 source=scrape.go:459
WARN[194843] Error on ingesting out-of-order samples       numDropped=1967 source=scrape.go:459

From the ML, several others are seeing the same.

[RichiH]

@jrv suggested trying https://gist.github.com/juliusv/dab35d4b17caf1937ff080238f1e7f20 which I will do now.

[RichiH]

As a somewhat unexpected update:

All those messages came from three machines, all of them running CatOS (properly firewalled, for a specific historical reason, and I would have killed them ages ago). Gut feeling is that the messages are valid and 0.18.0 simply exposes things that 0.17.0 gracefully ignored.

[RichiH]

As another update: I removed the patch and the CatOS machines and am running with vanilla 0.18.0 from source again. Will continue to monitor the situation.

[RichiH]

I re-enabled the machines to play with the situation a bit and I think that it would be an acceptable trade-off to print the instance and/or the job name along with numDropped. That way, users have something to dog down with while STDOUT/STDERR is not flooded with crap.

[juliusv]

Could you share some of the log excerpts generated by https://gist.github.com/juliusv/dab35d4b17caf1937ff080238f1e7f20? I'm interested in the other fields also, not just what the metrics were...

[beorn7]

Or we re-introduce the detailed logging, but on DEBUG level.

[RichiH]

[beorn7]

Sure, that's what I meant.

[juliusv]

Got a private look at @RichiH's log excerpts. The problem is that samples are coming in with the same timestamp, but different value. So in that case, Prometheus is doing the right thing, but the "out of order" error message is a bit misleading. Should we have a separate error code for "hey, you can't change the value of an existing sample"?

[fabxc]

To clarify, this actually is from two targets being relabeled into the same
thing?

On Mon, Apr 25, 2016 at 1:01 PM Julius Volz notifications@github.com
wrote:

Got a private look at @RichiH https://github.com/RichiH's log excerpts.
The problem is that samples are coming in with the same timestamp, but
different value. So in that case, Prometheus is doing the right thing, but
the "out of order" error message is a bit misleading. Should we have a
separate error code for "hey, you can't change the value of an existing
sample"?

—
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub
#1585 (comment)

[RichiH]

No, it's old machines answering to one query twice and apparently doing it live, so they produce different values every time.

I can't say anything about the others seeing this effect, though.

[juliusv]

I would bet that it's the same issue for the other people. In 0.17.0, we just didn't check the sample value equality yet, only if the timestamps are the same:

0.17.0:

https://github.com/prometheus/prometheus/blob/0.17.0/storage/local/storage.go#L595-L606

Compare to 0.18.0:

https://github.com/prometheus/prometheus/blob/0.18.0/storage/local/storage.go#L607-L619

[beorn7]

OK, improved logging merged.
For investigation, you can now switch to debug log level.

The duplicate metrics from node exporter apparently only happen with a pretty old version.

I think this can be closed.

[spinus]

Is it possible to know which samples are meant to be overridden (or which set of labels cause the problem)?

[RichiH]

Switch to debug level. Richard Sent by mobile; excuse my brevity.

[spinus]

ah, sure, I should tried that before asking. Thank you @RichiH.

[lock]

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.