Bug 1748073 - Kubelet metrics returned HTTP status 500 Internal Server Error
Summary: Kubelet metrics returned HTTP status 500 Internal Server Error
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: OpenShift Container Platform
Classification: Red Hat
Component: Node
Version: 4.2.0
Hardware: Unspecified
OS: Unspecified
medium
medium
Target Milestone: ---
: 4.4.0
Assignee: Ryan Phillips
QA Contact: Sunil Choudhary
URL:
Whiteboard:
: 1749149 1749690 1750963 1759260 1774091 (view as bug list)
Depends On:
Blocks: 1779285 1781258 1781281 1781285
TreeView+ depends on / blocked
 
Reported: 2019-09-02 16:23 UTC by Florin Peter
Modified: 2023-09-07 20:31 UTC (History)
12 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Cause: Sometimes the Kubelet metrics endpoint would return a 500 status code. Consequence: This would not allow prometheus to monitor the kubelet endpoint and node for metrics. Fix: Dead containers could be mixed into the metrics stream causing duplicate metrics to be injected. These duplicate metrics would cause a 500. Result: Metrics will be reported correctly from the Kubelet.
Clone Of:
: 1779285 1781258 (view as bug list)
Environment:
Last Closed: 2020-05-04 11:13:32 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github openshift origin pull 24251 0 'None' closed Bug 1748073: UPSTREAM: 85852: kubelet: CAdvisor sometimes injects old Pod metrics from an old namespaces 2021-01-05 16:47:28 UTC
Github openshift origin pull 24262 0 'None' closed Bug 1748073: disable kubelet_container_log_filesystem_used_bytes due to duplicate log metrics 2021-01-05 16:47:28 UTC
Github openshift origin pull 24265 0 'None' closed Bug 1748073: UPSTREAM: 86009: kubelet: guarantee at most only one cinfo per containerID 2021-01-05 16:47:30 UTC
Red Hat Product Errata RHBA-2020:0581 0 None None None 2020-05-04 11:14:08 UTC

Description Florin Peter 2019-09-02 16:23:49 UTC 
Description of problem:
Kubelet /metrics server returned HTTP status 500 Internal Server Error maybe a dupe of 1712645.

Version-Release number of selected component (if applicable):
4.2.0-0.nightly-2019-08-27-072819

How reproducible:
not sure right now

Steps to Reproduce:
1.
2.
3.

Actual results:
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: I0902 16:11:38.009572    1360 server.go:828] GET /metrics: (3.528117ms) 500
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: goroutine 2333794 [running]:
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: github.com/openshift/origin/vendor/k8s.io/apiserver/pkg/server/httplog.(*respLogger).recordStatus(0xc001ff6fc0, 0x1f4)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /builddir/build/BUILD/openshift-git-0.b985ea3/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/apiserver/pkg/server/httplog/httplog.go:204 +0xc8
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: github.com/openshift/origin/vendor/k8s.io/apiserver/pkg/server/httplog.(*respLogger).WriteHeader(0xc001ff6fc0, 0x1f4)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /builddir/build/BUILD/openshift-git-0.b985ea3/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/apiserver/pkg/server/httplog/httplog.go:183 +0x35
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus.(*responseWriterDelegator).WriteHeader(0xc001f471a0, 0x1f4)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /builddir/build/BUILD/openshift-git-0.b985ea3/_output/local/go/src/github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus/http.go:317 +0x45
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: net/http.Error(0x944a860, 0xc001f471a0, 0xc000c5a600, 0x180, 0x1f4)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /usr/lib/golang/src/net/http/server.go:2007 +0x213
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus.httpError(0x944a860, 0xc001f471a0, 0x93b2320, 0xc00117ae40)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /builddir/build/BUILD/openshift-git-0.b985ea3/_output/local/go/src/github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus/http.go:499 +0xf3
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus.UninstrumentedHandler.func1(0x944a860, 0xc001f471a0, 0xc0016b4900)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /builddir/build/BUILD/openshift-git-0.b985ea3/_output/local/go/src/github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus/http.go:66 +0x4e5
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: net/http.HandlerFunc.ServeHTTP(0x619f220, 0x944a860, 0xc001f471a0, 0xc0016b4900)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /usr/lib/golang/src/net/http/server.go:1995 +0x44
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus.InstrumentHandlerFuncWithOpts.func1(0x9456ce0, 0xc001ff6fc0, 0xc0016b4900)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /builddir/build/BUILD/openshift-git-0.b985ea3/_output/local/go/src/github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus/http.go:260 +0x232
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: net/http.HandlerFunc.ServeHTTP(0xc0007b9c70, 0x9456ce0, 0xc001ff6fc0, 0xc0016b4900)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /usr/lib/golang/src/net/http/server.go:1995 +0x44
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: github.com/openshift/origin/vendor/github.com/emicklei/go-restful.(*Container).HandleWithFilter.func1.1(0xc001f47110, 0xc0037fec60)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /builddir/build/BUILD/openshift-git-0.b985ea3/_output/local/go/src/github.com/openshift/origin/vendor/github.com/emicklei/go-restful/container.go:311 +0x4a
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: github.com/openshift/origin/vendor/github.com/emicklei/go-restful.(*FilterChain).ProcessFilter(0xc001f470b0, 0xc001f47110, 0xc0037fec60)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /builddir/build/BUILD/openshift-git-0.b985ea3/_output/local/go/src/github.com/openshift/origin/vendor/github.com/emicklei/go-restful/filter.go:21 +0x84
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/server.(*Server).InstallAuthFilter.func1(0xc001f47110, 0xc0037fec60, 0xc001f470b0)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /builddir/build/BUILD/openshift-git-0.b985ea3/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/server/server.go:277 +0x52f
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: github.com/openshift/origin/vendor/github.com/emicklei/go-restful.(*FilterChain).ProcessFilter(0xc001f470b0, 0xc001f47110, 0xc0037fec60)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /builddir/build/BUILD/openshift-git-0.b985ea3/_output/local/go/src/github.com/openshift/origin/vendor/github.com/emicklei/go-restful/filter.go:19 +0x5e
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: github.com/openshift/origin/vendor/github.com/emicklei/go-restful.(*Container).HandleWithFilter.func1(0x9456ce0, 0xc001ff6fc0, 0xc0016b4900)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /builddir/build/BUILD/openshift-git-0.b985ea3/_output/local/go/src/github.com/openshift/origin/vendor/github.com/emicklei/go-restful/container.go:313 +0x285
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: net/http.HandlerFunc.ServeHTTP(0xc000a34640, 0x9456ce0, 0xc001ff6fc0, 0xc0016b4900)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /usr/lib/golang/src/net/http/server.go:1995 +0x44
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: net/http.(*ServeMux).ServeHTTP(0xc000776680, 0x9456ce0, 0xc001ff6fc0, 0xc0016b4900)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /usr/lib/golang/src/net/http/server.go:2375 +0x1d6
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: github.com/openshift/origin/vendor/github.com/emicklei/go-restful.(*Container).ServeHTTP(0xc0009717a0, 0x9456ce0, 0xc001ff6fc0, 0xc0016b4900)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /builddir/build/BUILD/openshift-git-0.b985ea3/_output/local/go/src/github.com/openshift/origin/vendor/github.com/emicklei/go-restful/container.go:292 +0x4d
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/server.(*Server).ServeHTTP(0xc0007b8fa0, 0x9456ce0, 0xc001ff6fc0, 0xc0016b4900)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /builddir/build/BUILD/openshift-git-0.b985ea3/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/server/server.go:827 +0x107
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: net/http.serverHandler.ServeHTTP(0xc000ebcc30, 0x945d3a0, 0xc000f3ad20, 0xc0016b4900)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /usr/lib/golang/src/net/http/server.go:2774 +0xa8
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: net/http.(*conn).serve(0xc003d88140, 0x94a21a0, 0xc001c296c0)
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /usr/lib/golang/src/net/http/server.go:1878 +0x851
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: created by net/http.(*Server).Serve
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]:         /usr/lib/golang/src/net/http/server.go:2884 +0x2f4
Sep 02 16:11:38 t420-cqp8f-worker-s2large4-eu-de-01-dtns2 hyperkube[1360]: logging error output: "An error has occurred while serving metrics:\n\ncollected metric \"kubelet_container_log_filesystem_used_bytes\" { label:<name:\"container\" value:\"fluentd\" > label:<name:\"namespace\" value:\"mcs-logging\" > label:<name:\"pod\" value:\"fluentd-qfchr\" > label:<name:\"uid\" value:\"e0cd033b-cb3d-11e9-8239-fa163e4547b3\" > gauge:<value:4096 > } was collected before with the same name and label values\n"

Expected results:
That the kubelet is not crashing 

Additional info:
Comment 1 Ryan Phillips 2019-09-03 18:32:04 UTC 
Can you run `oc get pods -n mcs-logging`? Thank you!
Comment 2 Florin Peter 2019-09-03 19:03:52 UTC 
Hey Ryan,

here is the output:

NAME            READY   STATUS    RESTARTS   AGE
fluentd-2whlb   1/1     Running   7          4d3h
fluentd-2xpsv   1/1     Running   7          4d3h
fluentd-9jq8t   1/1     Running   7          4d3h
fluentd-f25rn   1/1     Running   7          4d3h
fluentd-gmq9t   1/1     Running   7          4d3h
fluentd-qfchr   1/1     Running   7          4d3h
fluentd-rbkzz   1/1     Running   7          4d3h
fluentd-rhhqs   1/1     Running   7          4d3h
fluentd-xxqjv   1/1     Running   7          4d3h
Comment 3 Ryan Phillips 2019-09-04 13:31:16 UTC 
Pretty sure I found the problem. Waiting on an upstream review.

Upstream PR: https://github.com/kubernetes/kubernetes/pull/82294
Comment 4 Seth Jennings 2019-09-04 18:25:54 UTC 
Deferring to 4.3.  Will look to backport to 4.2.z.
Comment 5 Ryan Phillips 2019-09-05 14:00:58 UTC 
*** Bug 1749149 has been marked as a duplicate of this bug. ***
Comment 6 Seth Jennings 2019-09-06 13:27:22 UTC 
*** Bug 1749690 has been marked as a duplicate of this bug. ***
Comment 7 Ryan Phillips 2019-09-10 21:27:39 UTC 
*** Bug 1750963 has been marked as a duplicate of this bug. ***
Comment 8 Kevin Chung 2019-11-13 19:48:34 UTC 
I am also reporting this issue in my OCP 4.2 cluster, my operators are updated to 4.2.2 at the moment.  My Prometheus targets show the openshift-monitoring/kubelet/0 endpoints for /metrics are all down with a "server returned HTTP status 500 Internal Server Error".  When I dig in a little deeper, I also receive the same metrics error reported above.

Steps to reproduce:
# curl -k -H "Authorization: Bearer $(oc sa get-token prometheus-k8s -n openshift-monitoring)" https://<my-node-ip>:10250/metrics

Actual results:

An error has occurred while serving metrics:

collected metric "kubelet_container_log_filesystem_used_bytes" { label:<name:"container" value:"tuned" > label:<name:"namespace" value:"openshift-cluster-node-tuning-operator" > label:<name:"pod" value:"tuned-vpnfx" > label:<name:"uid" value:"8c78bf14-fbe6-11e9-a817-566f9e110060" > gauge:<value:36864 > } was collected before with the same name and label values
Comment 11 Ryan Phillips 2019-12-04 22:41:57 UTC 
Florin: What sort of platform is this on? Is chrony or ntp running on the nodes?
Comment 12 Ryan Phillips 2019-12-05 01:18:48 UTC 
Florin: Was this cluster ever suspended and resumed?

I have found some code in the kubelet that is sensitive to timestamp ordering with multiple containers within a pod.
Comment 13 Florin Peter 2019-12-06 00:58:32 UTC 
Ryan: The cluster was build on OpenStack and version 4.2.2

The errors started again to target some of our clusters and this brings also our masters to flapping around.
It could be that we faced some network issues that blocked to the communication between masters but we did not suspended and resumed the clusters.

Looks like chrony is running:
ps xua | grep chrony
chrony     1023  0.0  0.0 121328  3248 ?        S    00:19   0:00 /usr/sbin/chronyd
root     123591  0.0  0.0  12764  1096 pts/0    S+   00:56   0:00 grep --color=auto chrony

Is there a workaround that we can use to stabilize the situation?

Here is the stackstrace from log
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: I1206 00:45:05.407884    2148 httplog.go:90] GET /metrics: (12.860388ms) 500
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: goroutine 1601 [running]:
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: github.com/openshift/origin/vendor/k8s.io/apiserver/pkg/server/httplog.(*respLogger).recordStatus(0xc002b8c8c0, 0x1f4)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /builddir/build/BUILD/openshift-git-0.7e13ab9/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/apiserver/pkg/server/httplog/httplog.go:217 +0xc8
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: github.com/openshift/origin/vendor/k8s.io/apiserver/pkg/server/httplog.(*respLogger).WriteHeader(0xc002b8c8c0, 0x1f4)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /builddir/build/BUILD/openshift-git-0.7e13ab9/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/apiserver/pkg/server/httplog/httplog.go:196 +0x35
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus.(*responseWriterDelegator).WriteHeader(0xc00394cff0, 0x1f4)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /builddir/build/BUILD/openshift-git-0.7e13ab9/_output/local/go/src/github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus/http.go:317 +0x45
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: net/http.Error(0x9464740, 0xc00394cff0, 0xc000a78680, 0x198, 0x1f4)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /usr/lib/golang/src/net/http/server.go:2007 +0x213
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus.httpError(0x9464740, 0xc00394cff0, 0x93cb1e0, 0xc00276c5c0)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /builddir/build/BUILD/openshift-git-0.7e13ab9/_output/local/go/src/github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus/http.go:499 +0xf3
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus.UninstrumentedHandler.func1(0x9464740, 0xc00394cff0, 0xc001639100)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /builddir/build/BUILD/openshift-git-0.7e13ab9/_output/local/go/src/github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus/http.go:66 +0x4e5
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: net/http.HandlerFunc.ServeHTTP(0x61c18c0, 0x9464740, 0xc00394cff0, 0xc001639100)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /usr/lib/golang/src/net/http/server.go:1995 +0x44
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus.InstrumentHandlerFuncWithOpts.func1(0x9470c40, 0xc002b8c8c0, 0xc001639100)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /builddir/build/BUILD/openshift-git-0.7e13ab9/_output/local/go/src/github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus/http.go:260 +0x232
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: net/http.HandlerFunc.ServeHTTP(0xc000509b30, 0x9470c40, 0xc002b8c8c0, 0xc001639100)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /usr/lib/golang/src/net/http/server.go:1995 +0x44
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: github.com/openshift/origin/vendor/github.com/emicklei/go-restful.(*Container).HandleWithFilter.func1.1(0xc002d62570, 0xc00278f860)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /builddir/build/BUILD/openshift-git-0.7e13ab9/_output/local/go/src/github.com/openshift/origin/vendor/github.com/emicklei/go-restful/container.go:311 +0x4a
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: github.com/openshift/origin/vendor/github.com/emicklei/go-restful.(*FilterChain).ProcessFilter(0xc002d62510, 0xc002d62570, 0xc00278f860)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /builddir/build/BUILD/openshift-git-0.7e13ab9/_output/local/go/src/github.com/openshift/origin/vendor/github.com/emicklei/go-restful/filter.go:21 +0x84
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/server.(*Server).InstallAuthFilter.func1(0xc002d62570, 0xc00278f860, 0xc002d62510)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /builddir/build/BUILD/openshift-git-0.7e13ab9/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/server/server.go:277 +0x52f
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: github.com/openshift/origin/vendor/github.com/emicklei/go-restful.(*FilterChain).ProcessFilter(0xc002d62510, 0xc002d62570, 0xc00278f860)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /builddir/build/BUILD/openshift-git-0.7e13ab9/_output/local/go/src/github.com/openshift/origin/vendor/github.com/emicklei/go-restful/filter.go:19 +0x5e
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: github.com/openshift/origin/vendor/github.com/emicklei/go-restful.(*Container).HandleWithFilter.func1(0x9470c40, 0xc002b8c8c0, 0xc001639100)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /builddir/build/BUILD/openshift-git-0.7e13ab9/_output/local/go/src/github.com/openshift/origin/vendor/github.com/emicklei/go-restful/container.go:313 +0x285
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: net/http.HandlerFunc.ServeHTTP(0xc00105b440, 0x9470c40, 0xc002b8c8c0, 0xc001639100)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /usr/lib/golang/src/net/http/server.go:1995 +0x44
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: net/http.(*ServeMux).ServeHTTP(0xc00060f2c0, 0x9470c40, 0xc002b8c8c0, 0xc001639100)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /usr/lib/golang/src/net/http/server.go:2375 +0x1d6
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: github.com/openshift/origin/vendor/github.com/emicklei/go-restful.(*Container).ServeHTTP(0xc000358e10, 0x9470c40, 0xc002b8c8c0, 0xc001639100)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /builddir/build/BUILD/openshift-git-0.7e13ab9/_output/local/go/src/github.com/openshift/origin/vendor/github.com/emicklei/go-restful/container.go:292 +0x4d
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: github.com/openshift/origin/vendor/k8s.io/apiserver/pkg/server/httplog.WithLogging.func1(0x94772c0, 0xc00177bb20, 0xc001639000)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /builddir/build/BUILD/openshift-git-0.7e13ab9/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/apiserver/pkg/server/httplog/httplog.go:89 +0x29c
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: net/http.HandlerFunc.ServeHTTP(0xc000fe1f60, 0x94772c0, 0xc00177bb20, 0xc001639000)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /usr/lib/golang/src/net/http/server.go:1995 +0x44
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/server.(*Server).ServeHTTP(0xc000509090, 0x94772c0, 0xc00177bb20, 0xc001639000)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /builddir/build/BUILD/openshift-git-0.7e13ab9/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/server/server.go:825 +0x101
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: net/http.serverHandler.ServeHTTP(0xc000f26f70, 0x94772c0, 0xc00177bb20, 0xc001639000)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /usr/lib/golang/src/net/http/server.go:2774 +0xa8
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: net/http.(*conn).serve(0xc000e9cc80, 0x94bb900, 0xc0011ad940)
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /usr/lib/golang/src/net/http/server.go:1878 +0x851
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: created by net/http.(*Server).Serve
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]:         /usr/lib/golang/src/net/http/server.go:2884 +0x2f4
Dec 06 00:45:05 p000-smq24-master-0.novalocal hyperkube[2148]: logging error output: "An error has occurred while serving metrics:\n\ncollected metric \"kubelet_container_log_filesystem_used_bytes\" { label:<name:\"container\" value:\"tuned\" > label:<name:\"namespace\" value:\"openshift-cluster-node-tuning-operator\" > label:<name:\"pod\" value:\"tuned-pf625\" > label:<name:\"uid\" value:\"8faa953a-17be-11ea-b588-fa163e803fbd\" > gauge:<value:12288 > } was collected before with the same name and label values\n"
Comment 14 Ryan Phillips 2019-12-06 23:45:43 UTC 
I have good news, and I thank you for your patience. I have an upstream PR fixing the issue [1] which has been approved and in the process of merging. The issue is the Kubelet stats system can inject stopped containers into the metrics stream.

I will backport this patch into our Openshift releases on Monday.

1. https://github.com/kubernetes/kubernetes/pull/86009
Comment 15 Florin Peter 2019-12-09 10:58:35 UTC 
Hey Ryan,

good work and thx for your effort!
Hope to see this getting soon backported to 4.2.
Comment 16 Ryan Phillips 2019-12-10 14:26:37 UTC 
*** Bug 1774091 has been marked as a duplicate of this bug. ***
Comment 17 Sam Batschelet 2019-12-10 15:33:47 UTC 
*** Bug 1759260 has been marked as a duplicate of this bug. ***
Comment 26 errata-xmlrpc 2020-05-04 11:13:32 UTC 
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-2020:0581
Note You need to log in before you can comment on or make changes to this bug.