Bug 1733830
| Summary: | many "Error on ingesting results from rule evaluation with different value but same timestamp" msg in prometheus-k8s pod logs | ||||||
|---|---|---|---|---|---|---|---|
| Product: | OpenShift Container Platform | Reporter: | Junqi Zhao <juzhao> | ||||
| Component: | Monitoring | Assignee: | Lili Cosic <lcosic> | ||||
| Status: | CLOSED ERRATA | QA Contact: | Viacheslav <mviaches> | ||||
| Severity: | low | Docs Contact: | |||||
| Priority: | low | ||||||
| Version: | 4.2.0 | CC: | alegrand, anpicker, erooth, lcosic, mloibl, pkrupa, surbania | ||||
| Target Milestone: | --- | Keywords: | Regression | ||||
| Target Release: | 4.2.0 | ||||||
| Hardware: | Unspecified | ||||||
| OS: | Unspecified | ||||||
| Whiteboard: | |||||||
| Fixed In Version: | Doc Type: | If docs needed, set a value | |||||
| Doc Text: | Story Points: | --- | |||||
| Clone Of: | Environment: | ||||||
| Last Closed: | 2019-10-16 06:33:51 UTC | Type: | Bug | ||||
| Regression: | --- | Mount Type: | --- | ||||
| Documentation: | --- | CRM: | |||||
| Verified Versions: | Category: | --- | |||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||
| Embargoed: | |||||||
| Attachments: |
|
||||||
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 |
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: