Kube-state-metrics: error while sending encoded metrics: write: broken pipe

[olivierboudet]

Is this a BUG REPORT or FEATURE REQUEST?:
/kind bug

What happened:

Some metrics are not collected. The following error happen for each scraping interval :
E1001 07:14:23.558510 1 main.go:52] [error while sending encoded metrics: write tcp 10.8.13.78:8080->10.8.0.27:51354: write: broken pipe]

What you expected to happen:

No error at all and all metrics collected.

How to reproduce it (as minimally and precisely as possible):

This is my deployment configuration :

spec:
  replicas: 1
  selector:
    matchLabels:
      app: prometheus
      component: kube-state-metrics
  strategy:
    rollingUpdate:
      maxSurge: 1
      maxUnavailable: 1
    type: RollingUpdate
  template:
    metadata:
      creationTimestamp: null
      labels:
        app: prometheus
        component: kube-state-metrics
    spec:
      containers:
      - args:
        - --v=4
        image: quay.io/coreos/kube-state-metrics:v1.4.0
        imagePullPolicy: IfNotPresent
        name: prometheus-kube-state-metrics
        ports:
        - containerPort: 8080
          name: metrics
          protocol: TCP
        resources:
          limits:
            cpu: 10m
            memory: 128Mi
          requests:
            cpu: 10m
            memory: 16Mi
        terminationMessagePath: /dev/termination-log
        terminationMessagePolicy: File
      dnsPolicy: ClusterFirst
      restartPolicy: Always
      schedulerName: default-scheduler
      securityContext: {}
      serviceAccount: prometheus-kube-state-metrics
      serviceAccountName: prometheus-kube-state-metrics
      terminationGracePeriodSeconds: 30

Anything else we need to know?:

This is the log with command line argument --v=4 :

I1001 07:11:16.958662       1 deployment.go:181] collected 53 deployments
I1001 07:11:14.958533       1 persistentvolumeclaim.go:126] collected 0 persistentvolumeclaims
I1001 07:11:21.957911       1 pod.go:282] collected 93 pods
E1001 07:11:28.157221       1 main.go:52] [error while sending encoded metrics: write tcp 10.8.13.78:8080->10.8.0.27:50328: write: broken pipe]
I1001 07:12:12.943334       1 persistentvolumeclaim.go:126] collected 22 persistentvolumeclaims
I1001 07:12:12.957211       1 daemonset.go:159] collected 4 daemonsets
I1001 07:12:12.957307       1 hpa.go:137] collected 0 hpas
I1001 07:12:12.957342       1 resourcequota.go:103] collected 0 resourcequotas
I1001 07:12:12.957951       1 job.go:181] collected 9 jobs
I1001 07:12:12.958132       1 node.go:206] collected 4 nodes
I1001 07:12:12.958169       1 replicationcontroller.go:143] collected 0 replicationcontrollers
I1001 07:12:12.959056       1 replicaset.go:135] collected 75 replicasets
I1001 07:12:13.359632       1 deployment.go:181] collected 53 deployments
I1001 07:12:13.359879       1 namespace.go:125] collected 9 namespaces
I1001 07:12:13.363003       1 statefulset.go:151] collected 17 statefulsets
I1001 07:12:13.558844       1 service.go:119] collected 92 services
I1001 07:12:13.559436       1 configmap.go:110] collected 44 configmaps
I1001 07:12:14.857507       1 cronjob.go:151] collected 2 cronjobs
I1001 07:12:14.858860       1 secret.go:128] collected 74 secrets
I1001 07:12:16.959586       1 pod.go:282] collected 93 pods
I1001 07:12:17.358140       1 endpoint.go:130] collected 94 endpoints
I1001 07:12:17.757231       1 persistentvolume.go:119] collected 22 persistentvolumes
I1001 07:12:18.057245       1 limitrange.go:101] collected 1 limitranges
E1001 07:12:24.158422       1 main.go:52] [error while sending encoded metrics: write tcp 10.8.13.78:8080->10.8.0.27:50658: write: broken pipe]
I1001 07:13:13.260075       1 endpoint.go:130] collected 94 endpoints
I1001 07:13:13.260158       1 limitrange.go:101] collected 1 limitranges
I1001 07:13:13.260315       1 cronjob.go:151] collected 2 cronjobs
I1001 07:13:13.657648       1 secret.go:128] collected 74 secrets
I1001 07:13:13.658485       1 persistentvolumeclaim.go:126] collected 22 persistentvolumeclaims
I1001 07:13:13.660651       1 hpa.go:137] collected 0 hpas
I1001 07:13:13.660694       1 resourcequota.go:103] collected 0 resourcequotas
I1001 07:13:14.057347       1 job.go:181] collected 9 jobs
I1001 07:13:14.058320       1 node.go:206] collected 4 nodes
I1001 07:13:14.060030       1 replicaset.go:135] collected 75 replicasets
I1001 07:13:14.060059       1 replicationcontroller.go:143] collected 0 replicationcontrollers
I1001 07:13:14.460392       1 statefulset.go:151] collected 17 statefulsets
I1001 07:13:14.857319       1 daemonset.go:159] collected 4 daemonsets
I1001 07:13:14.857414       1 namespace.go:125] collected 9 namespaces
I1001 07:13:14.857986       1 persistentvolume.go:119] collected 22 persistentvolumes
I1001 07:13:14.859108       1 deployment.go:181] collected 53 deployments
I1001 07:13:15.759209       1 configmap.go:110] collected 44 configmaps
I1001 07:13:15.760053       1 service.go:119] collected 92 services
I1001 07:13:17.759649       1 pod.go:282] collected 93 pods
E1001 07:13:23.957200       1 main.go:52] [error while sending encoded metrics: write tcp 10.8.13.78:8080->10.8.0.27:51026: write: broken pipe]
I1001 07:14:12.945895       1 persistentvolumeclaim.go:126] collected 22 persistentvolumeclaims
I1001 07:14:12.957150       1 hpa.go:137] collected 0 hpas
I1001 07:14:12.957223       1 resourcequota.go:103] collected 0 resourcequotas
I1001 07:14:12.958188       1 node.go:206] collected 4 nodes
I1001 07:14:12.958888       1 replicaset.go:135] collected 75 replicasets
I1001 07:14:12.958923       1 replicationcontroller.go:143] collected 0 replicationcontrollers
I1001 07:14:13.459363       1 job.go:181] collected 9 jobs
I1001 07:14:13.460220       1 statefulset.go:151] collected 17 statefulsets
I1001 07:14:13.460434       1 namespace.go:125] collected 9 namespaces
I1001 07:14:13.857340       1 daemonset.go:159] collected 4 daemonsets
I1001 07:14:14.457685       1 configmap.go:110] collected 44 configmaps
I1001 07:14:14.457702       1 persistentvolume.go:119] collected 22 persistentvolumes
I1001 07:14:14.459542       1 endpoint.go:130] collected 94 endpoints
I1001 07:14:14.459606       1 limitrange.go:101] collected 1 limitranges
I1001 07:14:14.757502       1 cronjob.go:151] collected 2 cronjobs
I1001 07:14:13.960645       1 service.go:119] collected 92 services
I1001 07:14:13.958269       1 deployment.go:181] collected 53 deployments
I1001 07:14:15.557780       1 secret.go:128] collected 74 secrets
I1001 07:14:17.458212       1 pod.go:282] collected 93 pods
E1001 07:14:23.558510       1 main.go:52] [error while sending encoded metrics: write tcp 10.8.13.78:8080->10.8.0.27:51354: write: broken pipe]
I1001 07:15:12.943546       1 configmap.go:110] collected 44 configmaps
I1001 07:15:12.943864       1 cronjob.go:151] collected 2 cronjobs
I1001 07:15:13.257172       1 secret.go:128] collected 74 secrets
I1001 07:15:13.358669       1 resourcequota.go:103] collected 0 resourcequotas
I1001 07:15:13.358978       1 job.go:181] collected 9 jobs
I1001 07:15:13.359382       1 persistentvolumeclaim.go:126] collected 22 persistentvolumeclaims
I1001 07:15:13.657335       1 daemonset.go:159] collected 4 daemonsets
I1001 07:15:13.657375       1 hpa.go:137] collected 0 hpas
I1001 07:15:13.657708       1 service.go:119] collected 92 services
I1001 07:15:14.159346       1 replicationcontroller.go:143] collected 0 replicationcontrollers
I1001 07:15:13.658273       1 statefulset.go:151] collected 17 statefulsets
I1001 07:15:13.658507       1 namespace.go:125] collected 9 namespaces
I1001 07:15:13.658937       1 persistentvolume.go:119] collected 22 persistentvolumes
I1001 07:15:13.659335       1 node.go:206] collected 4 nodes
I1001 07:15:13.659908       1 replicaset.go:135] collected 75 replicasets
I1001 07:15:14.158058       1 endpoint.go:130] collected 94 endpoints
I1001 07:15:14.158244       1 limitrange.go:101] collected 1 limitranges
I1001 07:15:15.159389       1 deployment.go:181] collected 53 deployments
I1001 07:15:17.058359       1 pod.go:282] collected 93 pods
E1001 07:15:23.357200       1 main.go:52] [error while sending encoded metrics: write tcp 10.8.13.78:8080->10.8.0.27:51682: write: broken pipe]
I1001 07:16:12.946221       1 service.go:119] collected 92 services
I1001 07:16:13.057191       1 limitrange.go:101] collected 1 limitranges
I1001 07:16:12.957515       1 configmap.go:110] collected 44 configmaps
I1001 07:16:13.157262       1 cronjob.go:151] collected 2 cronjobs
I1001 07:16:13.158252       1 secret.go:128] collected 74 secrets
I1001 07:16:13.957264       1 hpa.go:137] collected 0 hpas
I1001 07:16:13.957631       1 resourcequota.go:103] collected 0 resourcequotas
I1001 07:16:13.958618       1 job.go:181] collected 9 jobs
I1001 07:16:13.959588       1 persistentvolumeclaim.go:126] collected 22 persistentvolumeclaims
I1001 07:16:13.959899       1 daemonset.go:159] collected 4 daemonsets
I1001 07:16:13.959924       1 replicationcontroller.go:143] collected 0 replicationcontrollers
I1001 07:16:14.359188       1 deployment.go:181] collected 53 deployments
I1001 07:16:15.559565       1 statefulset.go:151] collected 17 statefulsets
I1001 07:16:15.559855       1 namespace.go:125] collected 9 namespaces
I1001 07:16:15.957343       1 persistentvolume.go:119] collected 22 persistentvolumes
I1001 07:16:16.057800       1 node.go:206] collected 4 nodes
I1001 07:16:16.460051       1 endpoint.go:130] collected 94 endpoints
I1001 07:16:16.460951       1 replicaset.go:135] collected 75 replicasets
I1001 07:16:18.359939       1 pod.go:282] collected 93 pods
E1001 07:16:26.257246       1 main.go:52] [error while sending encoded metrics: write tcp 10.8.13.78:8080->10.8.0.27:52000: write: broken pipe]

Environment:

• Kubernetes version (use kubectl version):

Client Version: version.Info{Major:"1", Minor:"10", GitVersion:"v1.10.2", GitCommit:"81753b10df112992bf51bbc2c2f85208aad78335", GitTreeState:"clean", BuildDate:"2018-04-27T09:22:21Z", GoVersion:"go1.9.3", Compiler:"gc", Platform:"linux/amd64"}
Server Version: version.Info{Major:"1", Minor:"9+", GitVersion:"v1.9.7-gke.5", GitCommit:"9b635efce81582e1da13b35a7aa539c0ccb32987", GitTreeState:"clean", BuildDate:"2018-08-02T23:42:40Z", GoVersion:"go1.9.3b4", Compiler:"gc", Platform:"linux/amd64"}

• Kube-state-metrics image version : quay.io/coreos/kube-state-metrics:v1.4.0

[RRAlex]

I'm having the same issue on k8s 1.10.6 since I upgraded to v1.4.0.

If I try to reach :8080/metrics on kube-state-metrics, even from the pod itself, it freezes there for a very long time which I guess makes prometheus time out as I'm not getting the metrics anymore in there (getting context deadline exceeded in the target page on prometheus).

The request does seem to succeed, at least some times, after a very long delay (30+ seconds or more).

[mxinden]

@RRAlex are you seeing the same error message in the logs? (write tcp 10.8.13.78:8080->10.8.0.27:52000: write: broken pipe])

[RRAlex]

@mxinden Not recently, but 3 days ago, which is probably before I gave prometheus 45s for scraping:
2018-10-01T10:46:39-04:00 localhost docker/k8s_kube-state-metrics_kube-state-metrics-5b48c5b78c-blbct_kube-system_9a98a4b9-c586-11e8-995a-fa163e7471c5_0[1353]: E1001 14:46:39.349960 1 main.go:52] [error while sending encoded metrics: write tcp 10.1.192.52:8080->10.1.40.10:33084: write: broken pipe]

[mxinden]

@olivierboudet @RRAlex can you post your Prometheus scrape_timeout configuration here?

 # How long until a scrape request times out.
 [ scrape_timeout: <duration> | default = 10s ]

https://prometheus.io/docs/prometheus/latest/configuration/configuration/

It might be that Prometheus closes the connection.

In addition you can query Prometheus for the scrape_duration_seconds metric, which shows you if the given target exceeded the scrape request limit.

Let me know how it goes!

[olivierboudet]

@mxinden this is my prometheus configuration :

global:
      evaluation_interval: 1m
      scrape_interval: 1m
      scrape_timeout: 10s

By querying the scrape_duration_seconds metric, I can observe some values around 10s, I will try to extend the timeout.

Thanks.

[mxinden]

@olivierboudet sounds good. Let us know how it goes.

I am currently working on a performance optimization of kube-state-metrics (https://github.com/kubernetes/kube-state-metrics/pull/534) that improves those response times. Feel free to try it out (docker images referenced in the mentioned pull-request).

[mrsiano]

@mxinden @olivierboudet extend the timeout sound like a bad workaround, if there is a problem out there we should take care off it, as max said you can try the gzip image
https://quay.io/repository/mxinden/kube-state-metrics?tag=v1.4.0-gzip.3&tab=tags

@mxinden what about define an SLA for scrape_duration ?

[mrsiano]

@olivierboudet @RRAlex what scale are you guys using ?

[olivierboudet]

I tried with image 1.4.0-gzip.3 and 1.4.0-perf.8. There is no error anymore in logs but I am missing some metrics. For example, metrics kube_deployment_status_replicas_available does not exists for all my deployments.

[deimosfr]

I confirm what @olivierboudet says. It works fine for me on 1.4.0-gzip.3 too

[axdotl]

Same for me, 1.4.0-gzip.3 works good.

[mrsiano]

@deimosfr @axdotl @olivierboudet see also https://github.com/kubernetes/kube-state-metrics/pull/534#issuecomment-428531940

[olivierboudet]

I close this issue as I do not reproduce it with 1.5.0.beta.0