This job view page is being replaced by Spyglass soon. Check out the new job view.
PRmborsz: [WIP] no statefulsets
ResultABORTED
Tests 0 failed / 84 succeeded
Started2022-11-24 12:12
Elapsed40m1s
Revisiond690065358d248119a0dbdad60f93842d3c77196
Refs 2208

No Test Failures!


Show 84 Passed Tests

Error lines from build-log.txt

... skipping 410 lines ...
Looking for address 'e2e-2208-62db2-master-ip'
Looking for address 'e2e-2208-62db2-master-internal-ip'
Using master: e2e-2208-62db2-master (external IP: 34.75.162.54; 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-presubmit-scale-37_e2e-2208-62db2" set.
User "k8s-presubmit-scale-37_e2e-2208-62db2" set.
Context "k8s-presubmit-scale-37_e2e-2208-62db2" created.
Switched to context "k8s-presubmit-scale-37_e2e-2208-62db2".
... skipping 233 lines ...
e2e-2208-62db2-minion-group-zklq   Ready                         <none>   38s    v1.27.0-alpha.0.46+8f2371bcceff79
e2e-2208-62db2-minion-group-zn1r   Ready                         <none>   39s    v1.27.0-alpha.0.46+8f2371bcceff79
e2e-2208-62db2-minion-heapster     Ready                         <none>   61s    v1.27.0-alpha.0.46+8f2371bcceff79
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":""}   
controller-manager   Healthy   ok                              
scheduler            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.75.162.54
GLBCDefaultBackend is running at https://34.75.162.54/api/v1/namespaces/kube-system/services/default-http-backend:http/proxy
CoreDNS is running at https://34.75.162.54/api/v1/namespaces/kube-system/services/kube-dns:dns/proxy
Metrics-server is running at https://34.75.162.54/api/v1/namespaces/kube-system/services/https:metrics-server:/proxy
... skipping 1097 lines ...
I1124 12:28:46.634455   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(small-deployment-107): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:28:46.702016   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(medium-deployment-14): Pods: 30 out of 30 created, 30 running (30 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:28:46.758115   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(small-deployment-257): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:28:47.846771   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(small-deployment-21): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:28:48.442608   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(small-deployment-103): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:28:48.587882   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(small-deployment-55): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:28:48.634803   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 3, deleted 0, timeout: 0, failed: 0
I1124 12:28:48.634882   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=5.011456705s, operationTimeout=15m0s, ratio=0.01
I1124 12:28:48.634910   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 3/3 Jobs are running with all pods
I1124 12:28:48.635383   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 1, deleted 0, timeout: 0, failed: 0
I1124 12:28:48.635592   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=5.004269309s, operationTimeout=15m0s, ratio=0.01
I1124 12:28:48.635625   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 1/1 DaemonSets are running with all pods
I1124 12:28:48.635832   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 0, deleted 0, timeout: 0, failed: 0
I1124 12:28:48.635868   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=0s, operationTimeout=15m0s, ratio=0.00
I1124 12:28:48.636022   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 0/0 StatefulSets are running with all pods
I1124 12:28:48.846226   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 325, deleted 0, timeout: 0, failed: 0
I1124 12:28:48.846286   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=5.021189331s, operationTimeout=15m0s, ratio=0.01
I1124 12:28:48.846311   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 325/325 Deployments are running with all pods
I1124 12:28:48.846339   15949 simple_test_executor.go:171] Step "[step: 07] Waiting for 'create objects' to be completed" ended
I1124 12:28:48.846368   15949 simple_test_executor.go:149] Step "[step: 08] Creating scheduler throughput measurements" started
I1124 12:28:48.846509   15949 pod_startup_latency.go:132] PodStartupLatency: labelSelector(group = scheduler-throughput): starting pod startup latency measurement...
I1124 12:28:48.846581   15949 wait_for_controlled_pods.go:215] WaitForControlledPodsRunning: starting wait for controlled pods measurement...
... skipping 4 lines ...
I1124 12:28:48.992380   15949 simple_test_executor.go:171] Step "[step: 09] create scheduler throughput pods" ended
I1124 12:28:48.992761   15949 simple_test_executor.go:149] Step "[step: 10] Waiting for scheduler throughput pods to be created" started
I1124 12:28:48.993064   15949 wait_for_controlled_pods.go:246] WaitForControlledPodsRunning: waiting for controlled pods measurement...
I1124 12:28:54.006033   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-2), controlledBy(scheduler-throughput-deployment-0): Pods: 573 out of 1000 created, 386 running (386 updated), 185 pending scheduled, 2 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:28:59.041839   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-2), controlledBy(scheduler-throughput-deployment-0): Pods: 1000 out of 1000 created, 929 running (929 updated), 71 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:29:04.076001   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-2), controlledBy(scheduler-throughput-deployment-0): Pods: 1000 out of 1000 created, 1000 running (1000 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:29:04.076140   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 1, deleted 0, timeout: 0, failed: 0
I1124 12:29:04.076159   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=15.084845414s, operationTimeout=20m0s, ratio=0.01
I1124 12:29:04.076203   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 1/1 Deployments are running with all pods
I1124 12:29:04.076234   15949 simple_test_executor.go:171] Step "[step: 10] Waiting for scheduler throughput pods to be created" ended
I1124 12:29:04.076265   15949 simple_test_executor.go:149] Step "[step: 11] Collecting scheduler throughput measurements" started
I1124 12:29:04.076339   15949 scheduling_throughput.go:154] SchedulingThroughput: gathering data
I1124 12:29:04.076390   15949 pod_startup_latency.go:226] PodStartupLatency: labelSelector(group = scheduler-throughput): gathering pod startup latency measurement...
... skipping 33 lines ...
I1124 12:29:04.582461   15949 simple_test_executor.go:149] Step "[step: 13] Waiting for scheduler throughput pods to be deleted" started
I1124 12:29:04.582513   15949 wait_for_controlled_pods.go:246] WaitForControlledPodsRunning: waiting for controlled pods measurement...
I1124 12:29:04.582966   15949 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-enuk6k-2), controlledBy(scheduler-throughput-deployment-0): starting with timeout: 19m59.999955017s
I1124 12:29:09.601877   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-2), controlledBy(scheduler-throughput-deployment-0): Pods: 457 out of 0 created, 457 running (457 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 90 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:29:14.603243   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-2), controlledBy(scheduler-throughput-deployment-0): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 36 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:29:19.603593   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-2), controlledBy(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 
I1124 12:29:19.604287   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 0, deleted 1, timeout: 0, failed: 0
I1124 12:29:19.604478   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=15.021273169s, operationTimeout=20m0s, ratio=0.01
I1124 12:29:19.604518   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 0/0 Deployments are running with all pods
I1124 12:29:19.604559   15949 simple_test_executor.go:171] Step "[step: 13] Waiting for scheduler throughput pods to be deleted" ended
I1124 12:29:19.604593   15949 simple_test_executor.go:149] Step "[step: 14] Starting latency pod measurements" started
I1124 12:29:19.604726   15949 pod_startup_latency.go:132] PodStartupLatency: labelSelector(group = latency): starting pod startup latency measurement...
I1124 12:29:19.605186   15949 wait_for_controlled_pods.go:215] WaitForControlledPodsRunning: starting wait for controlled pods measurement...
... skipping 329 lines ...
I1124 12:29:55.042112   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-151): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:29:55.057715   15949 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-176): starting with timeout: 14m59.99996378s
I1124 12:29:55.241796   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-152): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:29:55.256568   15949 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-177): starting with timeout: 14m59.999967062s
I1124 12:29:55.448759   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-153): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:29:55.456217   15949 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-178): starting with timeout: 14m59.999972427s
error dialing prow@34.75.162.54:22: 'ssh: handshake failed: read tcp 10.60.8.145:50702->34.75.162.54:22: read: connection reset by peer', retrying
I1124 12:29:55.646432   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-154): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:29:55.656463   15949 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-179): starting with timeout: 14m59.999967568s
I1124 12:29:55.844214   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-155): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:29:55.857606   15949 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-180): starting with timeout: 14m59.99995703s
I1124 12:29:56.044002   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-156): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:29:56.058491   15949 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-181): starting with timeout: 14m59.999966224s
... skipping 658 lines ...
I1124 12:31:03.857795   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-494): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:31:04.057606   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-495): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:31:04.257940   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-496): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:31:04.462303   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-497): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:31:04.667956   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-498): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:31:04.861725   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-499): Pods: 1 out of 1 created, 1 running (1 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:31:05.380657   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 500, deleted 0, timeout: 0, failed: 0
I1124 12:31:05.380715   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=5.007803344s, operationTimeout=15m0s, ratio=0.01
I1124 12:31:05.380744   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 500/500 Deployments are running with all pods
I1124 12:31:05.381009   15949 simple_test_executor.go:171] Step "[step: 16] Waiting for latency pods to be running" ended
I1124 12:31:05.381338   15949 simple_test_executor.go:149] Step "[step: 17] Deleting latency pods" started
I1124 12:31:05.421299   15949 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-0): starting with timeout: 14m59.999946374s
I1124 12:31:05.521517   15949 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-1): starting with timeout: 14m59.999963184s
... skipping 495 lines ...
I1124 12:31:55.122899   15949 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-497): starting with timeout: 14m59.999964244s
I1124 12:31:55.221264   15949 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-498): starting with timeout: 14m59.999960178s
I1124 12:31:55.322418   15949 simple_test_executor.go:171] Step "[step: 17] Deleting latency pods" ended
I1124 12:31:55.322875   15949 simple_test_executor.go:149] Step "[step: 18] Waiting for latency pods to be deleted" started
I1124 12:31:55.323210   15949 wait_for_controlled_pods.go:246] WaitForControlledPodsRunning: waiting for controlled pods measurement...
I1124 12:31:55.322872   15949 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(latency-deployment-499): starting with timeout: 14m59.999948036s
I1124 12:32:00.378454   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 0, deleted 500, timeout: 0, failed: 0
I1124 12:32:00.378960   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=5.012004584s, operationTimeout=15m0s, ratio=0.01
I1124 12:32:00.378992   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 0/0 Deployments are running with all pods
I1124 12:32:00.379053   15949 simple_test_executor.go:171] Step "[step: 18] Waiting for latency pods to be deleted" ended
I1124 12:32:00.379080   15949 simple_test_executor.go:149] Step "[step: 19] Collecting pod startup latency" started
I1124 12:32:00.379133   15949 pod_startup_latency.go:226] PodStartupLatency: labelSelector(group = latency): gathering pod startup latency measurement...
I1124 12:32:01.062826   15949 phase_latency.go:141] PodStartupLatency: 100 worst schedule_to_run latencies: [{test-enuk6k-1/latency-deployment-267-658c49b79c-bwcls 1s} {test-enuk6k-1/latency-deployment-304-79cb45f44f-66fbd 1s} {test-enuk6k-1/latency-deployment-71-56846c6d7-kwdf7 1s} {test-enuk6k-1/latency-deployment-56-8d4c768d7-6kttj 1s} {test-enuk6k-1/latency-deployment-63-77bc4dc967-vtb6m 1s} {test-enuk6k-1/latency-deployment-97-545cc47887-qkh8c 1s} {test-enuk6k-1/latency-deployment-69-68995f7c9f-gbk4m 1s} {test-enuk6k-1/latency-deployment-348-65c6bd4f49-xsz2k 1s} {test-enuk6k-1/latency-deployment-342-d747b7969-9n6mn 1s} {test-enuk6k-1/latency-deployment-221-5674b9db85-w2pqk 1s} {test-enuk6k-1/latency-deployment-249-b4bb789bf-867tv 1s} {test-enuk6k-1/latency-deployment-367-564cbcc98c-htbr8 1s} {test-enuk6k-1/latency-deployment-104-874b5d545-hf6zx 1s} {test-enuk6k-1/latency-deployment-137-9b5ddc789-8dswq 1s} {test-enuk6k-1/latency-deployment-203-58cdc666b5-xddkf 1s} {test-enuk6k-1/latency-deployment-455-688bfbfbcf-66fjj 1s} {test-enuk6k-1/latency-deployment-235-546789fb59-44x2g 1s} {test-enuk6k-1/latency-deployment-241-86465f5c97-4c89p 1s} {test-enuk6k-1/latency-deployment-295-58c794f695-85qdb 1s} {test-enuk6k-1/latency-deployment-247-6dc56454f-ttg8j 1s} {test-enuk6k-1/latency-deployment-173-6f74865fbf-2c4kw 1s} {test-enuk6k-1/latency-deployment-360-54bf874f97-f2kxb 1s} {test-enuk6k-1/latency-deployment-442-574d85ff4c-pgzhv 1s} {test-enuk6k-1/latency-deployment-479-768cf8b567-shtgd 1s} {test-enuk6k-1/latency-deployment-404-57fff9dd87-n2b56 1s} {test-enuk6k-1/latency-deployment-205-9bb76589c-q8t5j 1s} {test-enuk6k-1/latency-deployment-283-5ffd9cd79c-rnvdc 1s} {test-enuk6k-1/latency-deployment-312-7f9b59bfc9-slwjw 1s} {test-enuk6k-1/latency-deployment-407-b649cb997-4cww8 1s} {test-enuk6k-1/latency-deployment-426-5df9df6fcf-58s26 1s} {test-enuk6k-1/latency-deployment-480-6bb856b9f9-v5rv4 1s} {test-enuk6k-1/latency-deployment-14-8577448d87-8p9qc 1s} {test-enuk6k-1/latency-deployment-195-56c6fdd785-x57dm 1s} {test-enuk6k-1/latency-deployment-268-6d75dbf567-qb4kj 1s} {test-enuk6k-1/latency-deployment-289-7578bf5445-2r7c8 1s} {test-enuk6k-1/latency-deployment-319-6c78bcb66f-k92b9 1s} {test-enuk6k-1/latency-deployment-465-7bd646b4d9-mmr6s 1s} {test-enuk6k-1/latency-deployment-496-6bd4fdc86f-l8dkx 1s} {test-enuk6k-1/latency-deployment-20-857fcc5d8c-w8ncc 1s} {test-enuk6k-1/latency-deployment-157-596cf84d6f-2fdrt 1s} {test-enuk6k-1/latency-deployment-208-7c994ffcdc-zj7mv 1s} {test-enuk6k-1/latency-deployment-151-6775f4b54f-x7wnd 1s} {test-enuk6k-1/latency-deployment-182-5bdd56f88f-tg4tb 1s} {test-enuk6k-1/latency-deployment-495-5788dc8b99-g59hv 1s} {test-enuk6k-1/latency-deployment-338-f44c9d7bc-8pt5g 1s} {test-enuk6k-1/latency-deployment-445-5799bcdd7c-8vv8z 1s} {test-enuk6k-1/latency-deployment-477-5cb68dc95f-b4k47 1s} {test-enuk6k-1/latency-deployment-0-64c4b7bcf9-bhk8w 1s} {test-enuk6k-1/latency-deployment-163-687d84d77f-9m2k5 1s} {test-enuk6k-1/latency-deployment-231-5cc9dcf4cf-xswft 1s} {test-enuk6k-1/latency-deployment-52-5d97b5bb55-6576h 1s} {test-enuk6k-1/latency-deployment-162-6fd598d69-s96hl 1s} {test-enuk6k-1/latency-deployment-311-85fb4c4b6f-dkvc9 1s} {test-enuk6k-1/latency-deployment-435-7448d885dc-psxlc 1s} {test-enuk6k-1/latency-deployment-158-78d55f944c-z2mzw 1s} {test-enuk6k-1/latency-deployment-212-648556c585-765n2 1s} {test-enuk6k-1/latency-deployment-307-78d67b4c99-z985j 1s} {test-enuk6k-1/latency-deployment-26-69b66f8dc9-gpwjd 1s} {test-enuk6k-1/latency-deployment-222-767c47f75-gsw4h 1s} {test-enuk6k-1/latency-deployment-433-7579584c5f-92v4v 1s} {test-enuk6k-1/latency-deployment-378-6f7b684987-sxpf9 1s} {test-enuk6k-1/latency-deployment-398-985d766bc-pdrk2 1s} {test-enuk6k-1/latency-deployment-115-b5f7f4f45-nz8wt 1s} {test-enuk6k-1/latency-deployment-140-8454fd57c7-p8wfp 1s} {test-enuk6k-1/latency-deployment-302-ffd8bd5b9-4dgds 1s} {test-enuk6k-1/latency-deployment-13-f594dd687-mmg5g 1s} {test-enuk6k-1/latency-deployment-310-6874655447-x9c98 1s} {test-enuk6k-1/latency-deployment-386-fc6f7f585-6gv9x 1s} {test-enuk6k-1/latency-deployment-12-6b7647c479-txmvk 1s} {test-enuk6k-1/latency-deployment-191-77495cb46f-gb2c2 1s} {test-enuk6k-1/latency-deployment-349-5bc8959999-j2n42 1s} {test-enuk6k-1/latency-deployment-292-6fb7dc6cdf-6rmsc 1s} {test-enuk6k-1/latency-deployment-497-77d8b78cf9-qqp7v 1s} {test-enuk6k-1/latency-deployment-1-6779775c85-qtw8z 1s} {test-enuk6k-1/latency-deployment-47-545569bcb7-5wrz7 1s} {test-enuk6k-1/latency-deployment-285-9b75b8cbf-chldz 1s} {test-enuk6k-1/latency-deployment-170-6b5d45fb47-ghtb2 1s} {test-enuk6k-1/latency-deployment-389-74d587bdc9-cnjzb 1s} {test-enuk6k-1/latency-deployment-308-5d485658d5-b2vjj 1s} {test-enuk6k-1/latency-deployment-88-78bfbb578c-gxfpx 1s} {test-enuk6k-1/latency-deployment-223-66ff7578b5-xsp8n 1s} {test-enuk6k-1/latency-deployment-459-b895cb955-sn8tc 1s} {test-enuk6k-1/latency-deployment-131-6f54bb85-fw9jd 1s} {test-enuk6k-1/latency-deployment-270-77c49b4f89-5ctwr 1s} {test-enuk6k-1/latency-deployment-476-7d648bd7d9-n4gw4 1s} {test-enuk6k-1/latency-deployment-473-ff97b46dc-dc7qh 1s} {test-enuk6k-1/latency-deployment-488-6b4856dfcf-cv9gk 1s} {test-enuk6k-1/latency-deployment-80-7878757b47-8nr9s 1s} {test-enuk6k-1/latency-deployment-95-778c9fb86c-vhgcj 1s} {test-enuk6k-1/latency-deployment-254-57f84497c7-8j7vr 1s} {test-enuk6k-1/latency-deployment-364-775cf57b8f-hcnlj 1s} {test-enuk6k-1/latency-deployment-294-ff686499c-9mj6h 1s} {test-enuk6k-1/latency-deployment-298-59449f5d57-n7fhg 1s} {test-enuk6k-1/latency-deployment-375-786d4ffccc-xpvzl 2s} {test-enuk6k-1/latency-deployment-260-76589b78c9-ftwhp 2s} {test-enuk6k-1/latency-deployment-309-5b7bc584c9-pcd9j 2s} {test-enuk6k-1/latency-deployment-345-759995649f-r7dpq 2s} {test-enuk6k-1/latency-deployment-245-5456dd46c7-jfp2w 2s} {test-enuk6k-1/latency-deployment-320-5b68dfd757-9j8s7 2s} {test-enuk6k-1/latency-deployment-31-7548446687-zffkb 2s}]
... skipping 615 lines ...
I1124 12:32:42.644955   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(daemonset-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 
I1124 12:32:42.734987   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(small-deployment-280): Pods: 7 out of 7 created, 7 running (7 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:32:42.735658   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(small-deployment-16): Pods: 6 out of 6 created, 6 running (6 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:32:42.858479   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(small-deployment-281): Pods: 4 out of 4 created, 4 running (4 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:32:43.026462   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(small-deployment-122): Pods: 4 out of 4 created, 4 running (4 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:32:43.082412   15949 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(small-deployment-14): Pods: 7 out of 7 created, 7 running (7 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I1124 12:32:43.126072   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 3, deleted 0, timeout: 0, failed: 0
I1124 12:32:43.126130   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=5.006328965s, operationTimeout=15m0s, ratio=0.01
I1124 12:32:43.126159   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 3/3 Jobs are running with all pods
I1124 12:32:43.127274   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 0, deleted 0, timeout: 0, failed: 0
I1124 12:32:43.127311   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=0s, operationTimeout=15m0s, ratio=0.00
I1124 12:32:43.127606   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 1, deleted 0, timeout: 0, failed: 0
I1124 12:32:43.127631   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=30.19911949s, operationTimeout=15m0s, ratio=0.03
I1124 12:32:43.127649   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 1/1 DaemonSets are running with all pods
I1124 12:32:43.127917   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 0/0 StatefulSets are running with all pods
I1124 12:32:43.603573   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 325, deleted 0, timeout: 0, failed: 0
I1124 12:32:43.603627   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=5.017640548s, operationTimeout=15m0s, ratio=0.01
I1124 12:32:43.603657   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 325/325 Deployments are running with all pods
I1124 12:32:43.603695   15949 simple_test_executor.go:171] Step "[step: 22] Waiting for 'scale and update objects' to be completed" ended
I1124 12:32:43.603722   15949 simple_test_executor.go:149] Step "[step: 23] Starting measurement for 'delete objects'" started
I1124 12:32:43.603958   15949 wait_for_controlled_pods.go:212] WaitForControlledPodsRunning: wait for controlled pods measurement already running
I1124 12:32:43.604058   15949 wait_for_controlled_pods.go:212] WaitForControlledPodsRunning: wait for controlled pods measurement already running
... skipping 333 lines ...
I1124 12:36:17.354465   15949 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-enuk6k-1), controlledBy(small-deployment-125): starting with timeout: 14m59.999975714s
I1124 12:36:17.354485   15949 simple_test_executor.go:149] Step "[step: 25] Waiting for 'delete objects' to be completed" started
I1124 12:36:17.354529   15949 wait_for_controlled_pods.go:246] WaitForControlledPodsRunning: waiting for controlled pods measurement...
I1124 12:36:17.354580   15949 wait_for_controlled_pods.go:246] WaitForControlledPodsRunning: waiting for controlled pods measurement...
I1124 12:36:17.354815   15949 wait_for_controlled_pods.go:246] WaitForControlledPodsRunning: waiting for controlled pods measurement...
I1124 12:36:17.354870   15949 wait_for_controlled_pods.go:246] WaitForControlledPodsRunning: waiting for controlled pods measurement...
I1124 12:36:22.398514   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 0, deleted 3, timeout: 0, failed: 0
I1124 12:36:22.398892   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=5.001429141s, operationTimeout=15m0s, ratio=0.01
I1124 12:36:22.399248   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 0/0 Jobs are running with all pods
I1124 12:36:22.398514   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 0, deleted 0, timeout: 0, failed: 0
I1124 12:36:22.399443   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=0s, operationTimeout=15m0s, ratio=0.00
I1124 12:36:22.399521   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 0/0 StatefulSets are running with all pods
I1124 12:36:22.400920   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 0, deleted 325, timeout: 0, failed: 0
I1124 12:36:22.400955   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=5.00581763s, operationTimeout=15m0s, ratio=0.01
I1124 12:36:22.400974   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 0/0 Deployments are running with all pods
I1124 12:36:22.401010   15949 wait_for_controlled_pods.go:319] WaitForControlledPodsRunning: running 0, deleted 1, timeout: 0, failed: 0
I1124 12:36:22.401020   15949 wait_for_controlled_pods.go:324] WaitForControlledPodsRunning: maxDuration=5.00150918s, operationTimeout=15m0s, ratio=0.01
I1124 12:36:22.401036   15949 wait_for_controlled_pods.go:338] WaitForControlledPodsRunning: 0/0 DaemonSets are running with all pods
I1124 12:36:22.406127   15949 wait_for_pvcs.go:78] WaitForBoundPVCs: labelSelector(group = load): PVCs: 0 out of 0 created, 0 bound, 0 pending, 0 lost
I1124 12:36:22.406190   15949 simple_test_executor.go:171] Step "[step: 25] Waiting for 'delete objects' to be completed" ended
I1124 12:36:22.406224   15949 simple_test_executor.go:149] Step "[step: 26] delete objects configmaps and secrets" started
I1124 12:36:54.882923   15949 simple_test_executor.go:171] Step "[step: 26] delete objects configmaps and secrets" ended
... skipping 193 lines ...
I1124 12:37:04.419446   15949 ooms_tracker.go:230] ClusterOOMsTracker: gathering cluster OOMs tracking measurement
I1124 12:37:04.419589   15949 simple_test_executor.go:171] Step "[step: 29] gathering measurements" ended
I1124 12:37:04.419648   15949 simple_test_executor.go:80] Waiting for the chaos monkey subroutine to end...
I1124 12:37:04.419665   15949 simple_test_executor.go:82] Chaos monkey ended.
I1124 12:37:04.451836   15949 simple_test_executor.go:102] 
I1124 12:37:04.451883   15949 probes.go:151] Stopping DnsLookupLatency probe...
{"component":"entrypoint","file":"k8s.io/test-infra/prow/entrypoint/run.go:168","func":"k8s.io/test-infra/prow/entrypoint.Options.ExecuteProcess","level":"error","msg":"Entrypoint received interrupt: terminated","severity":"error","time":"2022-11-24T12:37:08Z"}
++ early_exit_handler
++ '[' -n 28 ']'