<p dir="auto">This test has failed twice in the last couple days, both times with the same issue ("Number of replicas has changed: expected 3, got 4"). I've copied the logs from today's failure below:</p>
<div class="snippet-clipboard-content notranslate position-relative overflow-auto" data-snippet-clipboard-copy-content="07:30:37 Horizontal pod autoscaling 
07:30:37   [Skipped][Autoscaling Suite] should scale from 1 pod to 3 pods and from 3 to 5 (scale resource: CPU)
07:30:37   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/horizontal_pod_autoscaling.go:47
07:30:37 [BeforeEach] Horizontal pod autoscaling
07:30:37   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework.go:51
07:30:37 STEP: Creating a kubernetes client
07:30:37 &gt;&gt;&gt; testContext.KubeConfig: /var/lib/jenkins/jobs/kubernetes-e2e-gce-autoscaling/workspace/.kube/config
07:30:37 STEP: Building a namespace api object
07:30:37 Oct 30 07:30:37.281: INFO: Waiting up to 2m0s for service account default to be provisioned in ns e2e-tests-horizontal-pod-autoscaling-rb5j0
07:30:37 Oct 30 07:30:37.283: INFO: Get service account default in ns e2e-tests-horizontal-pod-autoscaling-rb5j0 failed, ignoring for 2s: serviceaccounts &quot;default&quot; not found
07:30:39 Oct 30 07:30:39.287: INFO: Service account default in ns e2e-tests-horizontal-pod-autoscaling-rb5j0 with secrets found. (2.006387709s)
07:30:39 STEP: Waiting for a default service account to be provisioned in namespace
07:30:39 Oct 30 07:30:39.287: INFO: Waiting up to 2m0s for service account default to be provisioned in ns e2e-tests-horizontal-pod-autoscaling-rb5j0
07:30:39 Oct 30 07:30:39.289: INFO: Service account default in ns e2e-tests-horizontal-pod-autoscaling-rb5j0 with secrets found. (2.097824ms)
07:30:39 [It] [Skipped][Autoscaling Suite] should scale from 1 pod to 3 pods and from 3 to 5 (scale resource: CPU)
07:30:39   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/horizontal_pod_autoscaling.go:47
07:30:39 STEP: Running consuming RC rc with 1 replicas
07:30:39 STEP: creating replication controller rc in namespace e2e-tests-horizontal-pod-autoscaling-rb5j0
07:30:39 Oct 30 07:30:39.310: INFO: Created replication controller with name: rc, namespace: e2e-tests-horizontal-pod-autoscaling-rb5j0, replica count: 1
07:30:49 Oct 30 07:30:49.310: INFO: rc Pods: 1 out of 1 created, 1 running, 0 pending, 0 waiting, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
07:30:59 Oct 30 07:30:59.311: INFO: RC rc: consume 250 millicores in total
07:30:59 Oct 30 07:30:59.311: INFO: RC rc: consume 250 millicores in total
07:30:59 Oct 30 07:30:59.311: INFO: RC rc: consume 0 MB in total
07:30:59 Oct 30 07:30:59.311: INFO: RC rc: consume 0 MB in total
07:30:59 Oct 30 07:30:59.364: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:30:59 Oct 30 07:30:59.364: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:30:59 Oct 30 07:30:59.428: INFO: Replication Controller current replicas number 1 waiting to be 3
07:31:19 Oct 30 07:31:19.435: INFO: Replication Controller current replicas number 1 waiting to be 3
07:31:29 Oct 30 07:31:29.365: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:31:29 Oct 30 07:31:29.365: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:31:39 Oct 30 07:31:39.442: INFO: Replication Controller current replicas number 1 waiting to be 3
07:31:59 Oct 30 07:31:59.365: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:31:59 Oct 30 07:31:59.365: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:31:59 Oct 30 07:31:59.448: INFO: Replication Controller current replicas number 1 waiting to be 3
07:32:19 Oct 30 07:32:19.458: INFO: Replication Controller current replicas number 1 waiting to be 3
07:32:29 Oct 30 07:32:29.365: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:32:29 Oct 30 07:32:29.365: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:32:39 Oct 30 07:32:39.464: INFO: Replication Controller current replicas number 1 waiting to be 3
07:32:59 Oct 30 07:32:59.365: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:32:59 Oct 30 07:32:59.365: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:32:59 Oct 30 07:32:59.470: INFO: Replication Controller current replicas number 1 waiting to be 3
07:33:19 Oct 30 07:33:19.478: INFO: Replication Controller current replicas number 1 waiting to be 3
07:33:29 Oct 30 07:33:29.366: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:33:29 Oct 30 07:33:29.366: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:33:39 Oct 30 07:33:39.485: INFO: Replication Controller current replicas number 1 waiting to be 3
07:33:59 Oct 30 07:33:59.366: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:33:59 Oct 30 07:33:59.366: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:33:59 Oct 30 07:33:59.491: INFO: Replication Controller current replicas number 1 waiting to be 3
07:34:19 Oct 30 07:34:19.498: INFO: Replication Controller current replicas number 1 waiting to be 3
07:34:29 Oct 30 07:34:29.366: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:34:29 Oct 30 07:34:29.367: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:34:39 Oct 30 07:34:39.529: INFO: Replication Controller current replicas number 1 waiting to be 3
07:34:59 Oct 30 07:34:59.367: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:34:59 Oct 30 07:34:59.367: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:34:59 Oct 30 07:34:59.535: INFO: Replication Controller current replicas number 1 waiting to be 3
07:35:19 Oct 30 07:35:19.539: INFO: Replication Controller current replicas number is equal to desired replicas number: 3
07:35:19 Oct 30 07:35:19.542: INFO: Number of replicas is as expected
07:35:29 Oct 30 07:35:29.367: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:35:29 Oct 30 07:35:29.368: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:35:29 Oct 30 07:35:29.546: INFO: Number of replicas is as expected
07:35:39 Oct 30 07:35:39.551: INFO: Number of replicas is as expected
07:35:49 Oct 30 07:35:49.607: INFO: Number of replicas is as expected
07:35:59 Oct 30 07:35:59.368: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:35:59 Oct 30 07:35:59.368: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:35:59 Oct 30 07:35:59.611: INFO: Number of replicas is as expected
07:36:09 Oct 30 07:36:09.615: INFO: Number of replicas is as expected
07:36:19 Oct 30 07:36:19.620: INFO: Number of replicas is as expected
07:36:29 Oct 30 07:36:29.368: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:36:29 Oct 30 07:36:29.368: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:36:29 Oct 30 07:36:29.630: INFO: Number of replicas is as expected
07:36:39 Oct 30 07:36:39.635: INFO: Number of replicas is as expected
07:36:49 Oct 30 07:36:49.639: INFO: Number of replicas is as expected
07:36:59 Oct 30 07:36:59.369: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:36:59 Oct 30 07:36:59.369: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:36:59 Oct 30 07:36:59.643: INFO: Number of replicas is as expected
07:37:09 Oct 30 07:37:09.658: INFO: Number of replicas is as expected
07:37:19 Oct 30 07:37:19.662: INFO: Number of replicas is as expected
07:37:29 Oct 30 07:37:29.369: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:37:29 Oct 30 07:37:29.369: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:37:29 Oct 30 07:37:29.666: INFO: Number of replicas is as expected
07:37:39 Oct 30 07:37:39.671: INFO: Number of replicas is as expected
07:37:49 Oct 30 07:37:49.675: INFO: Number of replicas is as expected
07:37:59 Oct 30 07:37:59.369: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:37:59 Oct 30 07:37:59.369: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:37:59 Oct 30 07:37:59.679: INFO: Number of replicas is as expected
07:38:09 Oct 30 07:38:09.684: INFO: Number of replicas is as expected
07:38:19 STEP: Removing consuming RC rc
07:38:29 STEP: deleting replication controller rc in namespace e2e-tests-horizontal-pod-autoscaling-rb5j0
07:38:31 Oct 30 07:38:31.838: INFO: Deleting RC rc took: 2.026864587s
07:38:31 Oct 30 07:38:31.840: INFO: Terminating RC rc pods took: 2.284225ms
07:38:31 [AfterEach] Horizontal pod autoscaling
07:38:31   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework.go:52
07:38:31 STEP: Collecting events from namespace &quot;e2e-tests-horizontal-pod-autoscaling-rb5j0&quot;.
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {scheduler } Scheduled: Successfully assigned rc-cguak to e2e-autoscaling-minion-l9vl
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Pulled: Container image &quot;beta.gcr.io/google_containers/pause:2.0&quot; already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Created: Created with docker id b571732a7ad9
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Started: Started with docker id b571732a7ad9
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Pulled: Container image &quot;gcr.io/google_containers/resource_consumer:beta&quot; already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Created: Created with docker id a3d5cc9dda0c
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Started: Started with docker id a3d5cc9dda0c
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Killing: Killing with docker id a3d5cc9dda0c
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Killing: Killing with docker id b571732a7ad9
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {scheduler } Scheduled: Successfully assigned rc-dhyz5 to e2e-autoscaling-minion-yyc1
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Pulled: Container image &quot;beta.gcr.io/google_containers/pause:2.0&quot; already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Created: Created with docker id 591b71d72206
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Started: Started with docker id 591b71d72206
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Pulled: Container image &quot;gcr.io/google_containers/resource_consumer:beta&quot; already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Created: Created with docker id 7cc04c2d2f5d
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Started: Started with docker id 7cc04c2d2f5d
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Killing: Killing with docker id 7cc04c2d2f5d
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Killing: Killing with docker id 591b71d72206
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {scheduler } Scheduled: Successfully assigned rc-hiu3s to e2e-autoscaling-minion-yyc1
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Pulled: Container image &quot;beta.gcr.io/google_containers/pause:2.0&quot; already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Created: Created with docker id 25719910c6f6
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Started: Started with docker id 25719910c6f6
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Pulled: Container image &quot;gcr.io/google_containers/resource_consumer:beta&quot; already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Created: Created with docker id f3724e91d71c
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Started: Started with docker id f3724e91d71c
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Killing: Killing with docker id f3724e91d71c
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Killing: Killing with docker id 25719910c6f6
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {scheduler } Scheduled: Successfully assigned rc-lrer9 to e2e-autoscaling-minion-y3ln
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Pulled: Container image &quot;beta.gcr.io/google_containers/pause:2.0&quot; already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Created: Created with docker id 8d3e1606b211
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Started: Started with docker id 8d3e1606b211
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Pulled: Container image &quot;gcr.io/google_containers/resource_consumer:beta&quot; already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Created: Created with docker id 253fa7198af6
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Started: Started with docker id 253fa7198af6
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Killing: Killing with docker id 253fa7198af6
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Killing: Killing with docker id 8d3e1606b211
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {replication-controller } SuccessfulCreate: Created pod: rc-cguak
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {horizontal-pod-autoscaler } FailedGetMetrics: failed to get CPU consumption and request: failed to unmarshall heapster response: invalid character 'h' in literal true (expecting 'r')
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {horizontal-pod-autoscaler } FailedComputeReplicas: failed to get cpu utilization: failed to get CPU consumption and request: failed to unmarshall heapster response: invalid character 'h' in literal true (expecting 'r')
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {horizontal-pod-autoscaler } SuccessfulRescale: New size: 3
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {replication-controller } SuccessfulCreate: Created pod: rc-hiu3s
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {replication-controller } SuccessfulCreate: Created pod: rc-lrer9
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {horizontal-pod-autoscaler } FailedGetMetrics: failed to get CPU consumption and request: metrics obtained for 1/3 of pods
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {horizontal-pod-autoscaler } FailedComputeReplicas: failed to get cpu utilization: failed to get CPU consumption and request: metrics obtained for 1/3 of pods
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {horizontal-pod-autoscaler } SuccessfulRescale: New size: 4
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {replication-controller } SuccessfulCreate: Created pod: rc-dhyz5
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {service-controller } DeletingLoadBalancer: Deleting load balancer
07:38:32 Oct 30 07:38:32.171: INFO: POD                                                NODE                         PHASE    GRACE  CONDITIONS
07:38:32 Oct 30 07:38:32.171: INFO: elasticsearch-logging-v1-n6tk3                     e2e-autoscaling-minion-l9vl  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:06:37 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: elasticsearch-logging-v1-vc5vd                     e2e-autoscaling-minion-y3ln  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:25:58 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: fluentd-elasticsearch-e2e-autoscaling-minion-l9vl  e2e-autoscaling-minion-l9vl  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:06:38 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: fluentd-elasticsearch-e2e-autoscaling-minion-y3ln  e2e-autoscaling-minion-y3ln  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:13:31 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: fluentd-elasticsearch-e2e-autoscaling-minion-yyc1  e2e-autoscaling-minion-yyc1  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:06:22 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: heapster-v10-9wlhh                                 e2e-autoscaling-minion-l9vl  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:07:41 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: kibana-logging-v1-uoh4w                            e2e-autoscaling-minion-yyc1  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:25:59 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: kube-dns-v9-pce8u                                  e2e-autoscaling-minion-y3ln  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:25:18 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: kube-ui-v3-xdgv3                                   e2e-autoscaling-minion-l9vl  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:06:02 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: monitoring-influxdb-grafana-v2-8xsqx               e2e-autoscaling-minion-yyc1  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:25:31 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: 
07:38:32 Oct 30 07:38:32.171: INFO: Waiting up to 1m0s for all nodes to be ready
07:38:32 Oct 30 07:38:32.175: INFO: Node e2e-autoscaling-minion-l9vl condition 1/2: type: Ready, status: True, reason: &quot;KubeletReady&quot;, message: &quot;kubelet is posting ready status&quot;, last transition time: 2015-10-30 06:05:52 -0700 PDT
07:38:32 Oct 30 07:38:32.175: INFO: Successfully found node e2e-autoscaling-minion-l9vl readiness to be true
07:38:32 Oct 30 07:38:32.175: INFO: Node e2e-autoscaling-minion-y3ln condition 1/2: type: Ready, status: True, reason: &quot;KubeletReady&quot;, message: &quot;kubelet is posting ready status&quot;, last transition time: 2015-10-30 06:13:08 -0700 PDT
07:38:32 Oct 30 07:38:32.175: INFO: Successfully found node e2e-autoscaling-minion-y3ln readiness to be true
07:38:32 Oct 30 07:38:32.175: INFO: Node e2e-autoscaling-minion-yyc1 condition 1/2: type: Ready, status: True, reason: &quot;KubeletReady&quot;, message: &quot;kubelet is posting ready status&quot;, last transition time: 2015-10-30 06:05:59 -0700 PDT
07:38:32 Oct 30 07:38:32.175: INFO: Successfully found node e2e-autoscaling-minion-yyc1 readiness to be true
07:38:32 STEP: Destroying namespace &quot;e2e-tests-horizontal-pod-autoscaling-rb5j0&quot; for this suite.
07:38:37 
07:38:37 • Failure [479.957 seconds]
07:38:37 Horizontal pod autoscaling
07:38:37 /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/horizontal_pod_autoscaling.go:58
07:38:37   [Skipped][Autoscaling Suite] should scale from 1 pod to 3 pods and from 3 to 5 (scale resource: CPU) [It]
07:38:37   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/horizontal_pod_autoscaling.go:47
07:38:37 
07:38:37   Oct 30 07:38:19.688: Number of replicas has changed: expected 3, got 4
07:38:37 
07:38:37   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/autoscaling_utils.go:238"><pre class="notranslate"><code class="notranslate">07:30:37 Horizontal pod autoscaling 
07:30:37   [Skipped][Autoscaling Suite] should scale from 1 pod to 3 pods and from 3 to 5 (scale resource: CPU)
07:30:37   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/horizontal_pod_autoscaling.go:47
07:30:37 [BeforeEach] Horizontal pod autoscaling
07:30:37   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework.go:51
07:30:37 STEP: Creating a kubernetes client
07:30:37 &gt;&gt;&gt; testContext.KubeConfig: /var/lib/jenkins/jobs/kubernetes-e2e-gce-autoscaling/workspace/.kube/config
07:30:37 STEP: Building a namespace api object
07:30:37 Oct 30 07:30:37.281: INFO: Waiting up to 2m0s for service account default to be provisioned in ns e2e-tests-horizontal-pod-autoscaling-rb5j0
07:30:37 Oct 30 07:30:37.283: INFO: Get service account default in ns e2e-tests-horizontal-pod-autoscaling-rb5j0 failed, ignoring for 2s: serviceaccounts "default" not found
07:30:39 Oct 30 07:30:39.287: INFO: Service account default in ns e2e-tests-horizontal-pod-autoscaling-rb5j0 with secrets found. (2.006387709s)
07:30:39 STEP: Waiting for a default service account to be provisioned in namespace
07:30:39 Oct 30 07:30:39.287: INFO: Waiting up to 2m0s for service account default to be provisioned in ns e2e-tests-horizontal-pod-autoscaling-rb5j0
07:30:39 Oct 30 07:30:39.289: INFO: Service account default in ns e2e-tests-horizontal-pod-autoscaling-rb5j0 with secrets found. (2.097824ms)
07:30:39 [It] [Skipped][Autoscaling Suite] should scale from 1 pod to 3 pods and from 3 to 5 (scale resource: CPU)
07:30:39   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/horizontal_pod_autoscaling.go:47
07:30:39 STEP: Running consuming RC rc with 1 replicas
07:30:39 STEP: creating replication controller rc in namespace e2e-tests-horizontal-pod-autoscaling-rb5j0
07:30:39 Oct 30 07:30:39.310: INFO: Created replication controller with name: rc, namespace: e2e-tests-horizontal-pod-autoscaling-rb5j0, replica count: 1
07:30:49 Oct 30 07:30:49.310: INFO: rc Pods: 1 out of 1 created, 1 running, 0 pending, 0 waiting, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
07:30:59 Oct 30 07:30:59.311: INFO: RC rc: consume 250 millicores in total
07:30:59 Oct 30 07:30:59.311: INFO: RC rc: consume 250 millicores in total
07:30:59 Oct 30 07:30:59.311: INFO: RC rc: consume 0 MB in total
07:30:59 Oct 30 07:30:59.311: INFO: RC rc: consume 0 MB in total
07:30:59 Oct 30 07:30:59.364: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:30:59 Oct 30 07:30:59.364: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:30:59 Oct 30 07:30:59.428: INFO: Replication Controller current replicas number 1 waiting to be 3
07:31:19 Oct 30 07:31:19.435: INFO: Replication Controller current replicas number 1 waiting to be 3
07:31:29 Oct 30 07:31:29.365: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:31:29 Oct 30 07:31:29.365: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:31:39 Oct 30 07:31:39.442: INFO: Replication Controller current replicas number 1 waiting to be 3
07:31:59 Oct 30 07:31:59.365: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:31:59 Oct 30 07:31:59.365: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:31:59 Oct 30 07:31:59.448: INFO: Replication Controller current replicas number 1 waiting to be 3
07:32:19 Oct 30 07:32:19.458: INFO: Replication Controller current replicas number 1 waiting to be 3
07:32:29 Oct 30 07:32:29.365: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:32:29 Oct 30 07:32:29.365: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:32:39 Oct 30 07:32:39.464: INFO: Replication Controller current replicas number 1 waiting to be 3
07:32:59 Oct 30 07:32:59.365: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:32:59 Oct 30 07:32:59.365: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:32:59 Oct 30 07:32:59.470: INFO: Replication Controller current replicas number 1 waiting to be 3
07:33:19 Oct 30 07:33:19.478: INFO: Replication Controller current replicas number 1 waiting to be 3
07:33:29 Oct 30 07:33:29.366: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:33:29 Oct 30 07:33:29.366: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:33:39 Oct 30 07:33:39.485: INFO: Replication Controller current replicas number 1 waiting to be 3
07:33:59 Oct 30 07:33:59.366: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:33:59 Oct 30 07:33:59.366: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:33:59 Oct 30 07:33:59.491: INFO: Replication Controller current replicas number 1 waiting to be 3
07:34:19 Oct 30 07:34:19.498: INFO: Replication Controller current replicas number 1 waiting to be 3
07:34:29 Oct 30 07:34:29.366: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:34:29 Oct 30 07:34:29.367: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:34:39 Oct 30 07:34:39.529: INFO: Replication Controller current replicas number 1 waiting to be 3
07:34:59 Oct 30 07:34:59.367: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:34:59 Oct 30 07:34:59.367: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:34:59 Oct 30 07:34:59.535: INFO: Replication Controller current replicas number 1 waiting to be 3
07:35:19 Oct 30 07:35:19.539: INFO: Replication Controller current replicas number is equal to desired replicas number: 3
07:35:19 Oct 30 07:35:19.542: INFO: Number of replicas is as expected
07:35:29 Oct 30 07:35:29.367: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:35:29 Oct 30 07:35:29.368: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:35:29 Oct 30 07:35:29.546: INFO: Number of replicas is as expected
07:35:39 Oct 30 07:35:39.551: INFO: Number of replicas is as expected
07:35:49 Oct 30 07:35:49.607: INFO: Number of replicas is as expected
07:35:59 Oct 30 07:35:59.368: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:35:59 Oct 30 07:35:59.368: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:35:59 Oct 30 07:35:59.611: INFO: Number of replicas is as expected
07:36:09 Oct 30 07:36:09.615: INFO: Number of replicas is as expected
07:36:19 Oct 30 07:36:19.620: INFO: Number of replicas is as expected
07:36:29 Oct 30 07:36:29.368: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:36:29 Oct 30 07:36:29.368: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:36:29 Oct 30 07:36:29.630: INFO: Number of replicas is as expected
07:36:39 Oct 30 07:36:39.635: INFO: Number of replicas is as expected
07:36:49 Oct 30 07:36:49.639: INFO: Number of replicas is as expected
07:36:59 Oct 30 07:36:59.369: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:36:59 Oct 30 07:36:59.369: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:36:59 Oct 30 07:36:59.643: INFO: Number of replicas is as expected
07:37:09 Oct 30 07:37:09.658: INFO: Number of replicas is as expected
07:37:19 Oct 30 07:37:19.662: INFO: Number of replicas is as expected
07:37:29 Oct 30 07:37:29.369: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:37:29 Oct 30 07:37:29.369: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:37:29 Oct 30 07:37:29.666: INFO: Number of replicas is as expected
07:37:39 Oct 30 07:37:39.671: INFO: Number of replicas is as expected
07:37:49 Oct 30 07:37:49.675: INFO: Number of replicas is as expected
07:37:59 Oct 30 07:37:59.369: INFO: RC rc: sending 2 requests to consume 100 millicores each and 1 request to consume 50 millicores
07:37:59 Oct 30 07:37:59.369: INFO: RC rc: sending 0 requests to consume 100 MB each and 1 request to consume 0 MB
07:37:59 Oct 30 07:37:59.679: INFO: Number of replicas is as expected
07:38:09 Oct 30 07:38:09.684: INFO: Number of replicas is as expected
07:38:19 STEP: Removing consuming RC rc
07:38:29 STEP: deleting replication controller rc in namespace e2e-tests-horizontal-pod-autoscaling-rb5j0
07:38:31 Oct 30 07:38:31.838: INFO: Deleting RC rc took: 2.026864587s
07:38:31 Oct 30 07:38:31.840: INFO: Terminating RC rc pods took: 2.284225ms
07:38:31 [AfterEach] Horizontal pod autoscaling
07:38:31   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework.go:52
07:38:31 STEP: Collecting events from namespace "e2e-tests-horizontal-pod-autoscaling-rb5j0".
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {scheduler } Scheduled: Successfully assigned rc-cguak to e2e-autoscaling-minion-l9vl
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Pulled: Container image "beta.gcr.io/google_containers/pause:2.0" already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Created: Created with docker id b571732a7ad9
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Started: Started with docker id b571732a7ad9
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Pulled: Container image "gcr.io/google_containers/resource_consumer:beta" already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Created: Created with docker id a3d5cc9dda0c
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Started: Started with docker id a3d5cc9dda0c
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Killing: Killing with docker id a3d5cc9dda0c
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-cguak: {kubelet e2e-autoscaling-minion-l9vl} Killing: Killing with docker id b571732a7ad9
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {scheduler } Scheduled: Successfully assigned rc-dhyz5 to e2e-autoscaling-minion-yyc1
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Pulled: Container image "beta.gcr.io/google_containers/pause:2.0" already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Created: Created with docker id 591b71d72206
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Started: Started with docker id 591b71d72206
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Pulled: Container image "gcr.io/google_containers/resource_consumer:beta" already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Created: Created with docker id 7cc04c2d2f5d
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Started: Started with docker id 7cc04c2d2f5d
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Killing: Killing with docker id 7cc04c2d2f5d
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-dhyz5: {kubelet e2e-autoscaling-minion-yyc1} Killing: Killing with docker id 591b71d72206
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {scheduler } Scheduled: Successfully assigned rc-hiu3s to e2e-autoscaling-minion-yyc1
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Pulled: Container image "beta.gcr.io/google_containers/pause:2.0" already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Created: Created with docker id 25719910c6f6
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Started: Started with docker id 25719910c6f6
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Pulled: Container image "gcr.io/google_containers/resource_consumer:beta" already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Created: Created with docker id f3724e91d71c
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Started: Started with docker id f3724e91d71c
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Killing: Killing with docker id f3724e91d71c
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-hiu3s: {kubelet e2e-autoscaling-minion-yyc1} Killing: Killing with docker id 25719910c6f6
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {scheduler } Scheduled: Successfully assigned rc-lrer9 to e2e-autoscaling-minion-y3ln
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Pulled: Container image "beta.gcr.io/google_containers/pause:2.0" already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Created: Created with docker id 8d3e1606b211
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Started: Started with docker id 8d3e1606b211
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Pulled: Container image "gcr.io/google_containers/resource_consumer:beta" already present on machine
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Created: Created with docker id 253fa7198af6
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Started: Started with docker id 253fa7198af6
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Killing: Killing with docker id 253fa7198af6
07:38:32 Oct 30 07:38:32.114: INFO: event for rc-lrer9: {kubelet e2e-autoscaling-minion-y3ln} Killing: Killing with docker id 8d3e1606b211
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {replication-controller } SuccessfulCreate: Created pod: rc-cguak
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {horizontal-pod-autoscaler } FailedGetMetrics: failed to get CPU consumption and request: failed to unmarshall heapster response: invalid character 'h' in literal true (expecting 'r')
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {horizontal-pod-autoscaler } FailedComputeReplicas: failed to get cpu utilization: failed to get CPU consumption and request: failed to unmarshall heapster response: invalid character 'h' in literal true (expecting 'r')
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {horizontal-pod-autoscaler } SuccessfulRescale: New size: 3
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {replication-controller } SuccessfulCreate: Created pod: rc-hiu3s
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {replication-controller } SuccessfulCreate: Created pod: rc-lrer9
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {horizontal-pod-autoscaler } FailedGetMetrics: failed to get CPU consumption and request: metrics obtained for 1/3 of pods
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {horizontal-pod-autoscaler } FailedComputeReplicas: failed to get cpu utilization: failed to get CPU consumption and request: metrics obtained for 1/3 of pods
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {horizontal-pod-autoscaler } SuccessfulRescale: New size: 4
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {replication-controller } SuccessfulCreate: Created pod: rc-dhyz5
07:38:32 Oct 30 07:38:32.114: INFO: event for rc: {service-controller } DeletingLoadBalancer: Deleting load balancer
07:38:32 Oct 30 07:38:32.171: INFO: POD                                                NODE                         PHASE    GRACE  CONDITIONS
07:38:32 Oct 30 07:38:32.171: INFO: elasticsearch-logging-v1-n6tk3                     e2e-autoscaling-minion-l9vl  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:06:37 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: elasticsearch-logging-v1-vc5vd                     e2e-autoscaling-minion-y3ln  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:25:58 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: fluentd-elasticsearch-e2e-autoscaling-minion-l9vl  e2e-autoscaling-minion-l9vl  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:06:38 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: fluentd-elasticsearch-e2e-autoscaling-minion-y3ln  e2e-autoscaling-minion-y3ln  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:13:31 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: fluentd-elasticsearch-e2e-autoscaling-minion-yyc1  e2e-autoscaling-minion-yyc1  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:06:22 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: heapster-v10-9wlhh                                 e2e-autoscaling-minion-l9vl  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:07:41 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: kibana-logging-v1-uoh4w                            e2e-autoscaling-minion-yyc1  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:25:59 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: kube-dns-v9-pce8u                                  e2e-autoscaling-minion-y3ln  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:25:18 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: kube-ui-v3-xdgv3                                   e2e-autoscaling-minion-l9vl  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:06:02 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: monitoring-influxdb-grafana-v2-8xsqx               e2e-autoscaling-minion-yyc1  Running         [{Ready True 0001-01-01 00:00:00 +0000 UTC 2015-10-30 06:25:31 -0700 PDT  }]
07:38:32 Oct 30 07:38:32.171: INFO: 
07:38:32 Oct 30 07:38:32.171: INFO: Waiting up to 1m0s for all nodes to be ready
07:38:32 Oct 30 07:38:32.175: INFO: Node e2e-autoscaling-minion-l9vl condition 1/2: type: Ready, status: True, reason: "KubeletReady", message: "kubelet is posting ready status", last transition time: 2015-10-30 06:05:52 -0700 PDT
07:38:32 Oct 30 07:38:32.175: INFO: Successfully found node e2e-autoscaling-minion-l9vl readiness to be true
07:38:32 Oct 30 07:38:32.175: INFO: Node e2e-autoscaling-minion-y3ln condition 1/2: type: Ready, status: True, reason: "KubeletReady", message: "kubelet is posting ready status", last transition time: 2015-10-30 06:13:08 -0700 PDT
07:38:32 Oct 30 07:38:32.175: INFO: Successfully found node e2e-autoscaling-minion-y3ln readiness to be true
07:38:32 Oct 30 07:38:32.175: INFO: Node e2e-autoscaling-minion-yyc1 condition 1/2: type: Ready, status: True, reason: "KubeletReady", message: "kubelet is posting ready status", last transition time: 2015-10-30 06:05:59 -0700 PDT
07:38:32 Oct 30 07:38:32.175: INFO: Successfully found node e2e-autoscaling-minion-yyc1 readiness to be true
07:38:32 STEP: Destroying namespace "e2e-tests-horizontal-pod-autoscaling-rb5j0" for this suite.
07:38:37 
07:38:37 • Failure [479.957 seconds]
07:38:37 Horizontal pod autoscaling
07:38:37 /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/horizontal_pod_autoscaling.go:58
07:38:37   [Skipped][Autoscaling Suite] should scale from 1 pod to 3 pods and from 3 to 5 (scale resource: CPU) [It]
07:38:37   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/horizontal_pod_autoscaling.go:47
07:38:37 
07:38:37   Oct 30 07:38:19.688: Number of replicas has changed: expected 3, got 4
07:38:37 
07:38:37   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/autoscaling_utils.go:238
</code></pre></div>
<p dir="auto">Instead of consuming 250 milli-cores, recourse consumer consumes nearly 400 milli-cores. This causes flakiness of autoscaling e2e tests:<br>
<a href="http://kubekins.dls.corp.google.com/job/kubernetes-e2e-gce-autoscaling/1521/" rel="nofollow">http://kubekins.dls.corp.google.com/job/kubernetes-e2e-gce-autoscaling/1521/</a></p>
<p dir="auto"><strong>Horizontal pod autoscaling [Skipped][Autoscaling Suite] should scale from 1 pod to 3 pods and from 3 to 5 (scale resource: CPU)</strong><br>
/go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/horizontal_pod_autoscaling.go:47<br>
Oct 28 03:27:29.523: Number of replicas has changed: expected 3, got 4</p>
<p dir="auto">Logs from controller-manager:</p>
<div class="snippet-clipboard-content notranslate position-relative overflow-auto" data-snippet-clipboard-copy-content="I1028 10:27:25.876466       6 metrics_client.go:135] Sum of cpu requested: {1.500 DecimalSI}
I1028 10:27:25.878913       6 metrics_client.go:172] Metrics available: {
  &quot;items&quot;: [
   {
    &quot;metrics&quot;: [
     {
      &quot;timestamp&quot;: &quot;2015-10-28T10:25:00Z&quot;,
      &quot;value&quot;: 0
     },
     {
      &quot;timestamp&quot;: &quot;2015-10-28T10:24:00Z&quot;,
      &quot;value&quot;: 180
     }
    ],
    &quot;latestTimestamp&quot;: &quot;2015-10-28T10:25:00Z&quot;
   },
   {
    &quot;metrics&quot;: [
     {
      &quot;timestamp&quot;: &quot;2015-10-28T10:25:00Z&quot;,
      &quot;value&quot;: 227
     }
    ],
    &quot;latestTimestamp&quot;: &quot;2015-10-28T10:25:00Z&quot;
   },
   {
    &quot;metrics&quot;: [
     {
      &quot;timestamp&quot;: &quot;2015-10-28T10:25:00Z&quot;,
      &quot;value&quot;: 122
     },
     {
      &quot;timestamp&quot;: &quot;2015-10-28T10:24:00Z&quot;,
      &quot;value&quot;: 80
     }
    ],
    &quot;latestTimestamp&quot;: &quot;2015-10-28T10:25:00Z&quot;
   }
  ]
 }
I1028 10:27:25.884889       6 horizontal.go:154] Successfull rescale of rc, old size: 3, new size: 4"><pre class="notranslate"><code class="notranslate">I1028 10:27:25.876466       6 metrics_client.go:135] Sum of cpu requested: {1.500 DecimalSI}
I1028 10:27:25.878913       6 metrics_client.go:172] Metrics available: {
  "items": [
   {
    "metrics": [
     {
      "timestamp": "2015-10-28T10:25:00Z",
      "value": 0
     },
     {
      "timestamp": "2015-10-28T10:24:00Z",
      "value": 180
     }
    ],
    "latestTimestamp": "2015-10-28T10:25:00Z"
   },
   {
    "metrics": [
     {
      "timestamp": "2015-10-28T10:25:00Z",
      "value": 227
     }
    ],
    "latestTimestamp": "2015-10-28T10:25:00Z"
   },
   {
    "metrics": [
     {
      "timestamp": "2015-10-28T10:25:00Z",
      "value": 122
     },
     {
      "timestamp": "2015-10-28T10:24:00Z",
      "value": 80
     }
    ],
    "latestTimestamp": "2015-10-28T10:25:00Z"
   }
  ]
 }
I1028 10:27:25.884889       6 horizontal.go:154] Successfull rescale of rc, old size: 3, new size: 4
</code></pre></div>