This job view page is being replaced by Spyglass soon. Check out the new job view.
PRwzshiming: Graceful Node Shutdown Based On Pod Priority
ResultABORTED
Tests 0 failed / 45 succeeded
Started2021-11-01 13:28
Elapsed54m42s
Revision8a7c93b7ee69954d7c8954f5a678dc9954d6bc92
Refs 102915
job-versionv1.23.0-alpha.3.695+50ff2725223361
kubetest-version
revisionv1.23.0-alpha.3.695+50ff2725223361

No Test Failures!


Show 45 Passed Tests

Error lines from build-log.txt

... skipping 705 lines ...
Looking for address 'e2e-102915-95a39-master-ip'
Looking for address 'e2e-102915-95a39-master-internal-ip'
Using master: e2e-102915-95a39-master (external IP: 35.231.63.86; 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-13_e2e-102915-95a39" set.
User "k8s-infra-e2e-boskos-scale-13_e2e-102915-95a39" set.
Context "k8s-infra-e2e-boskos-scale-13_e2e-102915-95a39" created.
Switched to context "k8s-infra-e2e-boskos-scale-13_e2e-102915-95a39".
... skipping 227 lines ...
e2e-102915-95a39-minion-group-xv3z   Ready                         <none>   52s   v1.23.0-alpha.3.695+50ff2725223361
e2e-102915-95a39-minion-group-zjjs   Ready                         <none>   53s   v1.23.0-alpha.3.695+50ff2725223361
e2e-102915-95a39-minion-heapster     Ready                         <none>   76s   v1.23.0-alpha.3.695+50ff2725223361
Warning: v1 ComponentStatus is deprecated in v1.19+
Validate output:
Warning: v1 ComponentStatus is deprecated in v1.19+
NAME                 STATUS    MESSAGE                         ERROR
etcd-1               Healthy   {"health":"true","reason":""}   
etcd-0               Healthy   {"health":"true","reason":""}   
scheduler            Healthy   ok                              
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://35.231.63.86
GLBCDefaultBackend is running at https://35.231.63.86/api/v1/namespaces/kube-system/services/default-http-backend:http/proxy
CoreDNS is running at https://35.231.63.86/api/v1/namespaces/kube-system/services/kube-dns:dns/proxy
Metrics-server is running at https://35.231.63.86/api/v1/namespaces/kube-system/services/https:metrics-server:/proxy
... skipping 352 lines ...
I1101 13:55:28.118140   84426 util.go:101] 2/3 targets are ready, example not ready target: {map[container:dns endpoint:metrics instance:10.64.35.3:8080 job:dns namespace:probes pod:dns-7c5f768667-rjs4q service:dns] unknown}
I1101 13:55:28.307277   84426 util.go:104] All 6 expected targets are ready
I1101 13:55:43.118971   84426 util.go:104] All 3 expected targets are ready
I1101 13:55:43.119023   84426 prometheus_measurement.go:75] SLOMeasurement has started
I1101 13:55:43.119037   84426 simple_test_executor.go:173] Step "[step: 01] starting measurements" ended
I1101 13:55:43.119053   84426 simple_test_executor.go:145] Step "[step: 02] Creating k8s services" started
E1101 13:55:43.421460   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 13:55:48.740650   84426 simple_test_executor.go:173] Step "[step: 02] Creating k8s services" ended
I1101 13:55:48.740679   84426 simple_test_executor.go:145] Step "[step: 03] Creating PriorityClass for DaemonSets" started
I1101 13:55:48.775391   84426 simple_test_executor.go:173] Step "[step: 03] Creating PriorityClass for DaemonSets" ended
I1101 13:55:48.775415   84426 simple_test_executor.go:145] Step "[step: 04] create objects configmaps and secrets" started
I1101 13:55:53.271514   84426 simple_test_executor.go:173] Step "[step: 04] create objects configmaps and secrets" ended
I1101 13:55:53.271543   84426 simple_test_executor.go:145] Step "[step: 05] Starting measurement for 'create objects'" started
... skipping 310 lines ...
I1101 13:56:42.972486   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-199)
I1101 13:56:43.105792   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-281)
I1101 13:56:43.594484   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-170): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 13:56:43.594601   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-170)
I1101 13:56:43.596458   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=medium-deployment-5)
I1101 13:56:43.727980   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-112)
E1101 13:56:43.969365   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 13:56:44.081443   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=medium-deployment-1): Pods: 30 out of 30 created, 30 running (30 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 13:56:44.081547   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=medium-deployment-1)
I1101 13:56:44.818767   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-9): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 13:56:44.818895   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-9)
I1101 13:56:45.032622   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-50)
I1101 13:56:45.072991   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-113): 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 406 lines ...
I1101 13:57:44.311338   84426 reflector.go:175] Starting reflector <unspecified> (0s) from pkg/mod/k8s.io/client-go@v0.18.0/tools/cache/reflector.go:125
I1101 13:57:44.411680   84426 reflector.go:181] Stopping reflector <unspecified> (0s) from pkg/mod/k8s.io/client-go@v0.18.0/tools/cache/reflector.go:125
I1101 13:57:44.412024   84426 reflector.go:175] Starting reflector <unspecified> (0s) from pkg/mod/k8s.io/client-go@v0.18.0/tools/cache/reflector.go:125
I1101 13:57:44.509664   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-147): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 13:57:44.509785   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-147)
I1101 13:57:44.512049   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=daemonset-0)
E1101 13:57:44.521687   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 13:57:44.752435   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-119)
I1101 13:57:44.967805   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-179)
I1101 13:57:45.020722   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=medium-deployment-11)
I1101 13:57:45.244410   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(group=load,name=small-statefulset-0): Pods: 5 out of 5 created, 0 running (0 updated), 5 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 13:57:45.447788   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-94)
I1101 13:57:45.515940   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-139): 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 448 lines ...
I1101 13:58:40.539104   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-7), labelSelector(name=scheduler-throughput-deployment-0)
I1101 13:58:40.540188   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-11), labelSelector(name=scheduler-throughput-deployment-0)
I1101 13:58:40.540368   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-8), labelSelector(name=scheduler-throughput-deployment-0)
I1101 13:58:40.541994   84426 simple_test_executor.go:173] Step "[step: 10] create scheduler throughput pods" ended
I1101 13:58:40.542024   84426 simple_test_executor.go:145] Step "[step: 11] Waiting for scheduler throughput pods to be created" started
I1101 13:58:40.542052   84426 wait_for_controlled_pods.go:200] WaitForControlledPodsRunning: waiting for controlled pods measurement...
E1101 13:58:45.090402   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 13:58:45.546927   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-2), labelSelector(name=scheduler-throughput-deployment-0): Pods: 100 out of 100 created, 100 running (100 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 13:58:45.547072   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-2), labelSelector(name=scheduler-throughput-deployment-0)
I1101 13:58:45.548926   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-10), labelSelector(name=scheduler-throughput-deployment-0): Pods: 100 out of 100 created, 99 running (99 updated), 1 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 13:58:45.639664   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-7), labelSelector(name=scheduler-throughput-deployment-0): Pods: 3 out of 100 created, 0 running (0 updated), 3 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 13:58:45.639683   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-9), labelSelector(name=scheduler-throughput-deployment-0): Pods: 48 out of 100 created, 1 running (1 updated), 46 pending scheduled, 1 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 13:58:45.639670   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-5), labelSelector(name=scheduler-throughput-deployment-0): Pods: 31 out of 100 created, 1 running (1 updated), 30 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
... skipping 68 lines ...
I1101 13:58:56.068770   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-2), labelSelector(name=scheduler-throughput-deployment-0)
I1101 13:59:01.169851   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-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 
I1101 13:59:01.169987   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-2), labelSelector(name=scheduler-throughput-deployment-0)
I1101 13:59:26.070265   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-3), labelSelector(name=scheduler-throughput-deployment-0)
I1101 13:59:31.121658   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-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 
I1101 13:59:31.121820   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-3), labelSelector(name=scheduler-throughput-deployment-0)
E1101 13:59:45.634462   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 13:59:56.070827   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-4), labelSelector(name=scheduler-throughput-deployment-0)
I1101 14:00:01.122524   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-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 
I1101 14:00:01.122706   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-4), labelSelector(name=scheduler-throughput-deployment-0)
I1101 14:00:26.071170   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-5), labelSelector(name=scheduler-throughput-deployment-0)
I1101 14:00:31.122630   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-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 
I1101 14:00:31.122796   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-5), labelSelector(name=scheduler-throughput-deployment-0)
E1101 14:00:46.175901   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 14:00:56.071192   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-6), labelSelector(name=scheduler-throughput-deployment-0)
I1101 14:01:01.122452   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-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 
I1101 14:01:01.122621   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-6), labelSelector(name=scheduler-throughput-deployment-0)
I1101 14:01:26.071848   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-7), labelSelector(name=scheduler-throughput-deployment-0)
I1101 14:01:31.123581   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-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 
I1101 14:01:31.123734   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-7), labelSelector(name=scheduler-throughput-deployment-0)
E1101 14:01:46.719141   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 14:01:56.073649   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-8), labelSelector(name=scheduler-throughput-deployment-0)
I1101 14:02:01.124586   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-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 
I1101 14:02:01.124765   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-8), labelSelector(name=scheduler-throughput-deployment-0)
I1101 14:02:26.074084   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-9), labelSelector(name=scheduler-throughput-deployment-0)
I1101 14:02:31.125112   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-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 
I1101 14:02:31.125290   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-9), labelSelector(name=scheduler-throughput-deployment-0)
E1101 14:02:47.263925   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 14:02:56.074252   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-10), labelSelector(name=scheduler-throughput-deployment-0)
I1101 14:03:01.175933   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-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 
I1101 14:03:01.176088   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-10), labelSelector(name=scheduler-throughput-deployment-0)
I1101 14:03:26.075104   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-11), labelSelector(name=scheduler-throughput-deployment-0)
I1101 14:03:31.126193   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-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 
I1101 14:03:31.126298   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-11), labelSelector(name=scheduler-throughput-deployment-0)
E1101 14:03:47.796527   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 14:03:56.042411   84426 simple_test_executor.go:173] Step "[step: 13] delete scheduler throughput pods" ended
I1101 14:03:56.042448   84426 simple_test_executor.go:145] Step "[step: 14] Waiting for scheduler throughput pods to be deleted" started
I1101 14:03:56.042543   84426 wait_for_controlled_pods.go:200] WaitForControlledPodsRunning: waiting for controlled pods measurement...
I1101 14:04:01.094199   84426 wait_for_controlled_pods.go:267] WaitForControlledPodsRunning: running 0, deleted 10, timeout: 0, unknown: 0
I1101 14:04:01.094242   84426 wait_for_controlled_pods.go:281] WaitForControlledPodsRunning: 0/0 Deployments are running with all pods
I1101 14:04:01.094258   84426 simple_test_executor.go:173] Step "[step: 14] Waiting for scheduler throughput pods to be deleted" ended
... skipping 652 lines ...
I1101 14:04:47.974252   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-231)
I1101 14:04:48.014316   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-206): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:04:48.014411   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-206)
I1101 14:04:48.175092   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-232)
I1101 14:04:48.215006   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-207): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:04:48.215102   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-207)
E1101 14:04:48.326285   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 14:04:48.375630   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-233)
I1101 14:04:48.414880   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-208): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:04:48.414977   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-208)
I1101 14:04:48.575832   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-234)
I1101 14:04:48.615156   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-209): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:04:48.615271   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-209)
... skipping 855 lines ...
I1101 14:05:47.768912   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-3)
I1101 14:05:47.969534   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-4)
I1101 14:05:48.170299   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-5)
I1101 14:05:48.371267   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-6)
I1101 14:05:48.572546   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-7)
I1101 14:05:48.773545   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-8)
E1101 14:05:48.861398   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 14:05:48.973890   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-9)
I1101 14:05:49.174954   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-10)
I1101 14:05:49.375488   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-11)
I1101 14:05:49.578346   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-12)
I1101 14:05:49.776074   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-13)
I1101 14:05:49.975915   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-14)
... skipping 862 lines ...
I1101 14:06:49.146952   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-309)
I1101 14:06:49.183751   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-284): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:06:49.183850   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-284)
I1101 14:06:49.348571   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-310)
I1101 14:06:49.386123   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-285): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:06:49.386196   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-285)
E1101 14:06:49.399239   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 14:06:49.550089   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-311)
I1101 14:06:49.587390   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-286): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:06:49.587488   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-286)
I1101 14:06:49.749181   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-312)
I1101 14:06:49.786820   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-287): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:06:49.786935   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=latency-deployment-287)
... skipping 934 lines ...
I1101 14:07:49.562896   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-206): Pods: 2 out of 2 created, 2 running (2 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:07:49.562977   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-206)
I1101 14:07:49.681966   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-25)
I1101 14:07:49.778637   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=medium-deployment-20)
I1101 14:07:49.839032   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-122)
I1101 14:07:49.907941   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-117)
E1101 14:07:49.955362   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 14:07:50.019865   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-210)
I1101 14:07:50.034957   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-102)
I1101 14:07:50.035332   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-97): Pods: 7 out of 7 created, 7 running (7 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:07:50.035511   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-97)
I1101 14:07:50.121366   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-105)
I1101 14:07:50.187975   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-46): Pods: 4 out of 4 created, 4 running (4 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
... skipping 692 lines ...
I1101 14:08:49.910419   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-199): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:08:49.910602   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-199)
I1101 14:08:49.951079   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-60)
I1101 14:08:50.024861   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-260)
I1101 14:08:50.205765   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-268): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:08:50.205907   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-268)
E1101 14:08:50.480954   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 14:08:51.193860   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-281)
I1101 14:08:51.351651   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-204): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:08:51.351772   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-204)
I1101 14:08:51.398459   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-121): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:08:51.398567   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-121)
I1101 14:08:51.626994   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=medium-deployment-3)
... skipping 260 lines ...
I1101 14:09:48.885400   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=big-deployment-0)
I1101 14:09:49.246792   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=medium-deployment-12)
I1101 14:09:49.380365   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-208): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:09:49.380481   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-208)
I1101 14:09:49.969580   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-22)
I1101 14:09:50.971110   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-34)
E1101 14:09:51.060657   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 14:09:51.321161   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-167)
I1101 14:09:51.531543   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-105)
I1101 14:09:51.886651   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-144)
I1101 14:09:52.291996   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-133)
I1101 14:09:53.065432   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-282)
I1101 14:09:53.069550   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-53)
... skipping 234 lines ...
I1101 14:10:50.594643   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-90)
I1101 14:10:51.035392   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-29): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:10:51.035532   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-29)
I1101 14:10:51.391413   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-152): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:10:51.391559   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-152)
I1101 14:10:51.579650   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-56)
E1101 14:10:51.610949   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 14:10:51.643405   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-102)
I1101 14:10:51.729131   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-187): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:10:51.729258   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-187)
I1101 14:10:52.207477   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-14): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:10:52.207614   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-14)
I1101 14:10:52.473303   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-43)
... skipping 287 lines ...
I1101 14:11:50.608992   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-5)
I1101 14:11:50.872097   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-218)
I1101 14:11:51.120653   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-291): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:11:51.120769   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-291)
I1101 14:11:51.233378   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-9): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:11:51.233522   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-9)
E1101 14:11:52.139986   84426 etcd_metrics.go:147] EtcdMetrics: failed to collect etcd database size
I1101 14:11:52.440597   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-119)
I1101 14:11:52.701833   84426 reflector.go:175] Starting reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-270)
I1101 14:11:53.327855   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(group=load,name=small-statefulset-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 
I1101 14:11:53.327980   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(group=load,name=small-statefulset-0)
I1101 14:11:53.783379   84426 wait_for_pods.go:96] WaitForControlledPodsRunning: namespace(test-e8n6he-1), labelSelector(name=small-deployment-239): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1101 14:11:53.783517   84426 reflector.go:181] Stopping reflector *v1.Pod (0s) from *v1.PodStore: namespace(test-e8n6he-1), labelSelector(name=small-deployment-239)
... skipping 337 lines ...
Specify --start=59318 in the next get-serial-port-output invocation to get only the new output starting from here.
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/1455164504546480128' 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/1455164504546480128/logexported-nodes-registry) for successful nodes...
... skipping 373 lines ...