Created attachment 1594135 [details] "Error on ingesting results from rule evaluation with different value but same timestamp" msg Description of problem: See the attached log file, there are a lot of "Error on ingesting results from rule evaluation with different value but same timestamp" msg in prometheus-k8s pod logs It does not affect the prometheus function by far # oc -n openshift-monitoring logs -c prometheus prometheus-k8s-0 level=warn ts=2019-07-29T00:58:25.748Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-07-29T00:58:55.744Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=9 level=warn ts=2019-07-29T00:58:55.748Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-07-29T00:59:25.744Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=9 level=warn ts=2019-07-29T00:59:25.748Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-07-29T00:59:55.744Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=10 level=warn ts=2019-07-29T00:59:55.748Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-07-29T01:00:25.744Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=11 level=warn ts=2019-07-29T01:00:25.748Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 Version-Release number of selected component (if applicable): Always How reproducible: 4.2.0-0.nightly-2019-07-28-222114 Steps to Reproduce: 1. oc -n openshift-monitoring logs -c prometheus prometheus-k8s-0 2. 3. Actual results: "Error on ingesting results from rule evaluation with different value but same timestamp" msg Expected results: Should not have such error Additional info:
Simon, could you please take a look?
Sure I'll look into it.
I've enabled debug logging for Prometheus and can see the details about the offending rules. > level=debug ts=2019-07-30T07:59:55.749Z caller=manager.go:542 component="rule manager" group=k8s.rules msg="Rule evaluation result discarded" err="duplicate sample for timestamp" sample="{__name__=\"namespace:container_memory_usage_bytes:sum\", namespace=\"openshift-image-registry\"} => 24219648 @[1564473595729]" > level=debug ts=2019-07-30T07:59:55.749Z caller=manager.go:542 component="rule manager" group=k8s.rules msg="Rule evaluation result discarded" err="duplicate sample for timestamp" sample="{__name__=\"namespace:container_memory_usage_bytes:sum\", namespace=\"openshift-monitoring\"} => 2301251584 @[1564473595729]" > level=debug ts=2019-07-30T07:59:55.749Z caller=manager.go:542 component="rule manager" group=k8s.rules msg="Rule evaluation result discarded" err="duplicate sample for timestamp" sample="{__name__=\"namespace:container_memory_usage_bytes:sum\", namespace=\"openshift-marketplace\"} => 210898944 @[1564473595729]" > level=debug ts=2019-07-30T07:59:55.749Z caller=manager.go:542 component="rule manager" group=k8s.rules msg="Rule evaluation result discarded" err="duplicate sample for timestamp" sample="{__name__=\"namespace:container_memory_usage_bytes:sum\", namespace=\"openshift-cluster-node-tuning-operator\"} => 246198272 @[1564473595729]" > level=debug ts=2019-07-30T07:59:55.749Z caller=manager.go:542 component="rule manager" group=k8s.rules msg="Rule evaluation result discarded" err="duplicate sample for timestamp" sample="{__name__=\"namespace:container_memory_usage_bytes:sum\", namespace=\"openshift-machine-config-operator\"} => 204333056 @[1564473595729]" > level=warn ts=2019-07-30T07:59:55.749Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 There are indeed 2 recording rules that populate the same metric but with different label sets. It has been flagged upstream already: https://github.com/coreos/kube-prometheus/issues/134 I've created an issue in the kubernetes-mixin repository too: https://github.com/kubernetes-monitoring/kubernetes-mixin/issues/230
Fixed.
Filed after retest on latest night build 4.2.0-0.nightly-2019-08-20-043744 level=warn ts=2019-08-20T08:45:55.739Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=6 level=warn ts=2019-08-20T08:46:25.740Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=6 level=warn ts=2019-08-20T08:46:55.739Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:47:25.739Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:47:55.740Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:48:25.740Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:48:55.740Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:49:25.741Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:49:55.741Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:50:25.741Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:50:55.741Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:51:25.741Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:51:55.741Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:52:25.742Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:52:55.741Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:53:25.742Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:53:55.742Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:54:25.742Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:54:55.742Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:55:25.742Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:55:55.743Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:56:25.743Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:56:55.743Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=6 level=warn ts=2019-08-20T08:57:25.743Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=6 level=warn ts=2019-08-20T08:57:55.743Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=6 level=warn ts=2019-08-20T08:58:25.743Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=6 level=warn ts=2019-08-20T08:58:55.743Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:59:25.743Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T08:59:55.744Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T09:00:25.743Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T09:00:55.743Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T09:01:25.744Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T09:01:55.744Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T09:02:25.744Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T09:02:55.744Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5 level=warn ts=2019-08-20T09:03:25.744Z caller=manager.go:554 component="rule manager" group=k8s.rules msg="Error on ingesting results from rule evaluation with different value but same timestamp" numDropped=5
Simon: I brought over the changes you made in mixins that you mentioned above [1] to CMO[2] master so 4.2, so your fix should be in master - 4.2. [1]: https://github.com/kubernetes-monitoring/kubernetes-mixin/pull/232 [2]: https://github.com/openshift/cluster-monitoring-operator/pull/442/files#diff-1dca87d186c04a487d72e52ab0b4dde5L24-L30
@viacheslav, @junqi: do you mind to retest? This should be fixed, setting to MODIFIED.
(In reply to Sergiusz Urbaniak from comment #13) > @viacheslav, @junqi: do you mind to retest? This should be fixed, setting to > MODIFIED. tested with 4.2.0-0.nightly-2019-08-21-235427, still see the error
errors still present grouped near the bottom of log, was checked on 4.2.0-0.nightly-2019-08-22-04381
no such issue with 4.2.0-0.nightly-2019-09-08-180038
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHBA-2019:2922