This job view page is being replaced by Spyglass soon. Check out the new job view.
PRaojea: cluster: fix metrics-server deployment on CI jobs
ResultABORTED
Tests 0 failed / 45 succeeded
Started2021-07-21 22:21
Elapsed54m28s
Revision3c3b0a1174dd5e5eb0ff6418cf5b64517fa80536
Refs 103713
job-versionv1.23.0-alpha.0.8+11eec279439f96
kubetest-version
revisionv1.23.0-alpha.0.8+11eec279439f96

No Test Failures!


Show 45 Passed Tests

Error lines from build-log.txt

... skipping 681 lines ...
Looking for address 'e2e-103713-95a39-master-ip'
Looking for address 'e2e-103713-95a39-master-internal-ip'
Using master: e2e-103713-95a39-master (external IP: 34.74.223.185; internal IP: 10.40.0.2)
Waiting up to 300 seconds for cluster initialization.

  This will continually check to see if the API for kubernetes is reachable.
  This may time out if there was some uncaught error during start up.

Kubernetes cluster created.
Cluster "k8s-infra-e2e-boskos-scale-04_e2e-103713-95a39" set.
User "k8s-infra-e2e-boskos-scale-04_e2e-103713-95a39" set.
Context "k8s-infra-e2e-boskos-scale-04_e2e-103713-95a39" created.
Switched to context "k8s-infra-e2e-boskos-scale-04_e2e-103713-95a39".
... skipping 227 lines ...
e2e-103713-95a39-minion-group-xm77   Ready                         <none>   51s   v1.23.0-alpha.0.8+11eec279439f96
e2e-103713-95a39-minion-group-z8v9   Ready                         <none>   57s   v1.23.0-alpha.0.8+11eec279439f96
e2e-103713-95a39-minion-group-zkm9   Ready                         <none>   52s   v1.23.0-alpha.0.8+11eec279439f96
Warning: v1 ComponentStatus is deprecated in v1.19+
Validate output:
Warning: v1 ComponentStatus is deprecated in v1.19+
NAME                 STATUS    MESSAGE                         ERROR
etcd-0               Healthy   {"health":"true","reason":""}   
scheduler            Healthy   ok                              
etcd-1               Healthy   {"health":"true","reason":""}   
controller-manager   Healthy   ok                              
Cluster validation encountered some problems, but cluster should be in working order
...ignoring non-fatal errors in validate-cluster
Done, listing cluster services:

Kubernetes control plane is running at https://34.74.223.185
GLBCDefaultBackend is running at https://34.74.223.185/api/v1/namespaces/kube-system/services/default-http-backend:http/proxy
CoreDNS is running at https://34.74.223.185/api/v1/namespaces/kube-system/services/kube-dns:dns/proxy
Metrics-server is running at https://34.74.223.185/api/v1/namespaces/kube-system/services/https:metrics-server:/proxy
... skipping 348 lines ...
I0721 22:50:01.518865  105557 util.go:85] Not enough active targets (0), expected at least (3), waiting for more to become active...
I0721 22:50:01.756329  105557 util.go:85] Not enough active targets (0), expected at least (6), waiting for more to become active...
I0721 22:50:16.515957  105557 util.go:85] Not enough active targets (0), expected at least (3), waiting for more to become active...
I0721 22:50:16.755901  105557 util.go:85] Not enough active targets (0), expected at least (6), waiting for more to become active...
I0721 22:50:31.517779  105557 util.go:85] Not enough active targets (0), expected at least (3), waiting for more to become active...
I0721 22:50:31.756575  105557 util.go:85] Not enough active targets (0), expected at least (6), waiting for more to become active...
E0721 22:50:31.803106  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 22:50:46.517037  105557 util.go:85] Not enough active targets (0), expected at least (3), waiting for more to become active...
I0721 22:50:46.755255  105557 util.go:85] Not enough active targets (0), expected at least (6), waiting for more to become active...
I0721 22:51:01.521626  105557 util.go:93] 1/3 targets are ready, example not ready target: {map[container:dns endpoint:metrics instance:10.64.45.3:8080 job:dns namespace:probes pod:dns-854b7dccbf-fbrh9 service:dns] unknown}
I0721 22:51:01.762592  105557 util.go:93] 3/6 targets are ready, example not ready target: {map[container:ping-server endpoint:metrics instance:10.64.59.3:8080 job:ping-server namespace:probes pod:ping-server-596b77b4cb-t72sj service:ping-server] unknown}
I0721 22:51:16.518218  105557 util.go:96] All 3 expected targets are ready
I0721 22:51:16.518287  105557 prometheus_measurement.go:75] SLOMeasurement has started
... skipping 28 lines ...
I0721 22:51:30.614688  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-272)
I0721 22:51:31.681950  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-269)
I0721 22:51:31.812226  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-142)
I0721 22:51:32.182967  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-73)
I0721 22:51:32.362174  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-224)
I0721 22:51:32.372239  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-28)
E0721 22:51:32.375900  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 22:51:32.667576  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-227): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:51:32.667747  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-227)
I0721 22:51:32.852185  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-123): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:51:32.852363  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-123)
I0721 22:51:32.894293  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-193): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:51:32.894559  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-193)
... skipping 411 lines ...
I0721 22:52:32.248431  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-98): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:52:32.248511  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-98)
I0721 22:52:32.248669  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-22)
I0721 22:52:32.413149  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-187): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:52:32.413284  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-187)
I0721 22:52:32.902467  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-125)
E0721 22:52:32.959712  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 22:52:33.086603  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-259)
I0721 22:52:33.207037  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-49): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:52:33.207135  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-49)
I0721 22:52:33.480946  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-23): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:52:33.481068  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-23)
I0721 22:52:33.626081  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-165): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
... skipping 362 lines ...
I0721 22:53:33.299896  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-82)
I0721 22:53:33.487755  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=medium-deployment-19): Pods: 30 out of 30 created, 30 running (30 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:53:33.487885  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=medium-deployment-19)
I0721 22:53:33.522726  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-208)
I0721 22:53:33.525641  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=big-job-0): Pods: 250 out of 250 created, 250 running (250 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:53:33.525862  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=big-job-0)
E0721 22:53:33.546485  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 22:53:33.656991  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-112): Pods: 5 out of 5 created, 4 running (4 updated), 1 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:53:33.658166  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=medium-deployment-2): Pods: 30 out of 30 created, 27 running (27 updated), 3 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:53:33.686886  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-291): Pods: 5 out of 5 created, 4 running (4 updated), 1 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:53:34.053734  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-107): Pods: 5 out of 5 created, 4 running (4 updated), 1 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:53:34.101635  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-188)
I0721 22:53:34.275101  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-6): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
... skipping 308 lines ...
I0721 22:54:18.862091  105557 phase_latency.go:146] PodStartupLatency: perc50: 0s, perc90: 0s, perc99: 0s; threshold 1h0m0s
I0721 22:54:18.862214  105557 simple_test_executor.go:173] Step "[step: 12] Collecting scheduler throughput measurements" ended
I0721 22:54:18.862237  105557 simple_test_executor.go:145] Step "[step: 13] delete scheduler throughput pods" started
I0721 22:54:18.901866  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-2), labelSelector(name=scheduler-throughput-deployment-0)
I0721 22:54:23.955226  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-2), labelSelector(name=scheduler-throughput-deployment-0): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:54:23.955411  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-2), labelSelector(name=scheduler-throughput-deployment-0)
E0721 22:54:34.111246  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 22:54:48.902279  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-3), labelSelector(name=scheduler-throughput-deployment-0)
I0721 22:54:53.953204  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-3), labelSelector(name=scheduler-throughput-deployment-0): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:54:53.953387  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-3), labelSelector(name=scheduler-throughput-deployment-0)
I0721 22:55:18.902315  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-4), labelSelector(name=scheduler-throughput-deployment-0)
I0721 22:55:23.953333  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-4), labelSelector(name=scheduler-throughput-deployment-0): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:55:23.953523  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-4), labelSelector(name=scheduler-throughput-deployment-0)
E0721 22:55:34.664182  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 22:55:48.902643  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-5), labelSelector(name=scheduler-throughput-deployment-0)
I0721 22:55:53.953736  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-5), labelSelector(name=scheduler-throughput-deployment-0): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:55:53.953923  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-5), labelSelector(name=scheduler-throughput-deployment-0)
I0721 22:56:18.914879  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-6), labelSelector(name=scheduler-throughput-deployment-0)
I0721 22:56:24.015323  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-6), labelSelector(name=scheduler-throughput-deployment-0): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:56:24.015581  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-6), labelSelector(name=scheduler-throughput-deployment-0)
E0721 22:56:35.203344  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 22:56:48.903414  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-7), labelSelector(name=scheduler-throughput-deployment-0)
I0721 22:56:53.955224  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-7), labelSelector(name=scheduler-throughput-deployment-0): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:56:53.955395  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-7), labelSelector(name=scheduler-throughput-deployment-0)
I0721 22:57:18.904046  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-8), labelSelector(name=scheduler-throughput-deployment-0)
I0721 22:57:24.005102  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-8), labelSelector(name=scheduler-throughput-deployment-0): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:57:24.005255  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-8), labelSelector(name=scheduler-throughput-deployment-0)
E0721 22:57:35.763660  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 22:57:48.903689  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-9), labelSelector(name=scheduler-throughput-deployment-0)
I0721 22:57:54.004306  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-9), labelSelector(name=scheduler-throughput-deployment-0): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:57:54.004513  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-9), labelSelector(name=scheduler-throughput-deployment-0)
I0721 22:58:18.903771  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-10), labelSelector(name=scheduler-throughput-deployment-0)
I0721 22:58:23.954990  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-10), labelSelector(name=scheduler-throughput-deployment-0): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:58:23.955178  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-10), labelSelector(name=scheduler-throughput-deployment-0)
E0721 22:58:36.304044  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 22:58:48.915179  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-11), labelSelector(name=scheduler-throughput-deployment-0)
I0721 22:58:53.966793  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-11), labelSelector(name=scheduler-throughput-deployment-0): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:58:53.966959  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-11), labelSelector(name=scheduler-throughput-deployment-0)
I0721 22:59:18.870410  105557 simple_test_executor.go:173] Step "[step: 13] delete scheduler throughput pods" ended
I0721 22:59:18.870501  105557 simple_test_executor.go:145] Step "[step: 14] Waiting for scheduler throughput pods to be deleted" started
I0721 22:59:18.870547  105557 wait_for_controlled_pods.go:200] WaitForControlledPodsRunning: waiting for controlled pods measurement...
... skipping 142 lines ...
I0721 22:59:36.548810  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-60)
I0721 22:59:36.582471  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-35): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:59:36.582560  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-35)
I0721 22:59:36.750041  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-61)
I0721 22:59:36.784157  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-36): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:59:36.784253  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-36)
E0721 22:59:36.842484  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 22:59:36.949625  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-62)
I0721 22:59:36.997920  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-37): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:59:36.998017  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-37)
I0721 22:59:37.150170  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-63)
I0721 22:59:37.185313  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-38): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 22:59:37.185407  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-38)
... skipping 894 lines ...
I0721 23:00:37.130634  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-362)
I0721 23:00:37.167029  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-337): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:00:37.167149  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-337)
I0721 23:00:37.332174  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-363)
I0721 23:00:37.367375  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-338): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:00:37.367487  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-338)
E0721 23:00:37.397234  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 23:00:37.530741  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-364)
I0721 23:00:37.567581  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-339): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:00:37.567692  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-339)
I0721 23:00:37.730834  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-365)
I0721 23:00:37.768567  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-340): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:00:37.768683  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-340)
... skipping 820 lines ...
I0721 23:01:37.582254  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-137)
I0721 23:01:37.614220  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-112): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:01:37.614347  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-112)
I0721 23:01:37.782821  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-138)
I0721 23:01:37.815491  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-113): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:01:37.815581  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-113)
E0721 23:01:37.955906  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 23:01:37.982957  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-139)
I0721 23:01:38.015650  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-114): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:01:38.015801  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-114)
I0721 23:01:38.184262  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-140)
I0721 23:01:38.216636  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-115): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:01:38.216763  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-115)
... skipping 894 lines ...
I0721 23:02:38.155520  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-439)
I0721 23:02:38.192689  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-414): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:02:38.192853  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-414)
I0721 23:02:38.356561  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-440)
I0721 23:02:38.394447  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-415): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:02:38.394544  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-415)
E0721 23:02:38.501038  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 23:02:38.558684  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-441)
I0721 23:02:38.593781  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-416): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:02:38.593991  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-416)
I0721 23:02:38.757861  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-442)
I0721 23:02:38.795505  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-417): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:02:38.795690  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=latency-deployment-417)
... skipping 1067 lines ...
I0721 23:03:38.247336  105557 wait_for_controlled_pods.go:267] WaitForControlledPodsRunning: running 3, deleted 0, timeout: 0, unknown: 0
I0721 23:03:38.247385  105557 wait_for_controlled_pods.go:281] WaitForControlledPodsRunning: 3/3 Jobs are running with all pods
I0721 23:03:38.309795  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-296): Pods: 6 out of 6 created, 6 running (6 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:03:38.309966  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-296)
I0721 23:03:38.526001  105557 wait_for_controlled_pods.go:267] WaitForControlledPodsRunning: running 323, deleted 0, timeout: 0, unknown: 0
I0721 23:03:38.526049  105557 wait_for_controlled_pods.go:281] WaitForControlledPodsRunning: 323/323 Deployments are running with all pods
E0721 23:03:39.057638  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 23:03:39.517042  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(group=load,name=small-statefulset-0): Pods: 7 out of 7 created, 5 running (5 updated), 2 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:03:39.892004  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(group=load,name=medium-statefulset-0): Pods: 41 out of 41 created, 41 running (41 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:03:39.892202  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(group=load,name=medium-statefulset-0)
E0721 23:03:41.536031  105557 wait_for_pods.go:88] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=daemonset-0): 27 pods disappeared: daemonset-0-qxtmn, daemonset-0-4sgvc, daemonset-0-xkq2q, daemonset-0-p95vm, daemonset-0-x7g64, daemonset-0-7d4jk, daemonset-0-p2cvc, daemonset-0-p459g, daemonset-0-z87qq, daemonset-0-7jgb6, daemonset-0-lknnx, daemonset-0-p8shd, daemonset-0-vnnm5, daemonset-0-2ptvf, daemonset-0-tlgdc, daemonset-0-8zvs9, daemonset-0-bnzx4, daemonset-0-jtp7k, daemonset-0-c4cgr, daemonset-0-v42cx, daemonset-0-rtbqd, daemonset-0-vdrsj, daemonset-0-5qhj8, daemonset-0-8vrh9, daemonset-0-bgkck, daemonset-0-f7mwx, daemonset-0-wlth7
E0721 23:03:41.536084  105557 wait_for_pods.go:92] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=daemonset-0): 27 pods appeared: daemonset-0-cprvf, daemonset-0-g2p2m, daemonset-0-9m7hr, daemonset-0-9l7hz, daemonset-0-zwkl8, daemonset-0-qdx7d, daemonset-0-9jg5r, daemonset-0-6pklv, daemonset-0-g2gch, daemonset-0-dxchl, daemonset-0-fdtmv, daemonset-0-qg28j, daemonset-0-sgr2l, daemonset-0-4x7w7, daemonset-0-zsvns, daemonset-0-fqwxm, daemonset-0-65fnk, daemonset-0-wcx99, daemonset-0-cqmnr, daemonset-0-ptfkn, daemonset-0-5dfdv, daemonset-0-cdfmz, daemonset-0-4dzpk, daemonset-0-97d7s, daemonset-0-9fp4w, daemonset-0-hjfh4, daemonset-0-27sjk
I0721 23:03:41.536106  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=daemonset-0): Pods: 100 out of 100 created, 90 running (58 updated), 10 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
... skipping 330 lines ...
I0721 23:04:38.979848  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-183)
I0721 23:04:39.412939  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=medium-deployment-21): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:04:39.413134  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=medium-deployment-21)
I0721 23:04:39.430485  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=medium-deployment-19): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:04:39.430641  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=medium-deployment-19)
I0721 23:04:39.526340  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-106)
E0721 23:04:39.625944  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 23:04:40.252888  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-182): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:04:40.253100  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-182)
I0721 23:04:40.324700  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-271)
I0721 23:04:40.718894  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=medium-deployment-2)
I0721 23:04:41.019775  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=medium-deployment-10)
I0721 23:04:41.094112  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-131)
... skipping 418 lines ...
I0721 23:05:39.665607  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-178): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:05:39.665839  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-178)
I0721 23:05:39.930803  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-249)
I0721 23:05:40.120362  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-125)
I0721 23:05:40.170504  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-21): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:05:40.170685  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-21)
E0721 23:05:40.200513  105557 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I0721 23:05:40.358065  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-93): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:05:40.358226  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-93)
I0721 23:05:40.836606  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-288)
I0721 23:05:41.848929  105557 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-273)
I0721 23:05:41.992376  105557 wait_for_pods.go:94] WaitForControlledPodsRunning: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-55): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0721 23:05:41.992583  105557 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-2pz5tf-1), labelSelector(name=small-deployment-55)
... skipping 482 lines ...
load pubkey "/workspace/.ssh/google_compute_engine": invalid format
scp: /var/log/cluster-autoscaler.log*: No such file or directory
scp: /var/log/fluentd.log*: No such file or directory
scp: /var/log/kubelet.cov*: No such file or directory
scp: /var/log/cl2-**: No such file or directory
scp: /var/log/startupscript.log*: No such file or directory
ERROR: (gcloud.compute.scp) [/usr/bin/scp] exited with return code [1].
Dumping logs from nodes to GCS directly at 'gs://sig-scalability-logs/pull-kubernetes-e2e-gce-100-performance/1417972645273538560' using logexporter
Detecting nodes in the cluster
namespace/logexporter created
secret/google-service-account created
daemonset.apps/logexporter created
Listing marker files (gs://sig-scalability-logs/pull-kubernetes-e2e-gce-100-performance/1417972645273538560/logexported-nodes-registry) for successful nodes...
... skipping 376 lines ...