This job view page is being replaced by Spyglass soon. Check out the new job view.
PRaramase: Add staging directory for kms
ResultABORTED
Tests 0 failed / 67 succeeded
Started2022-09-22 19:00
Elapsed57m20s
Revision116d6aefc12b88de470df06432c90e2c76850b49
Refs 111980

No Test Failures!


Show 67 Passed Tests

Error lines from build-log.txt

... skipping 723 lines ...
Looking for address 'e2e-111980-95a39-master-ip'
Looking for address 'e2e-111980-95a39-master-internal-ip'
Using master: e2e-111980-95a39-master (external IP: 34.75.230.220; 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-06_e2e-111980-95a39" set.
User "k8s-infra-e2e-boskos-scale-06_e2e-111980-95a39" set.
Context "k8s-infra-e2e-boskos-scale-06_e2e-111980-95a39" created.
Switched to context "k8s-infra-e2e-boskos-scale-06_e2e-111980-95a39".
... skipping 227 lines ...
e2e-111980-95a39-minion-group-zr9q   Ready                         <none>   55s   v1.26.0-alpha.1.74+c79617d877e650
e2e-111980-95a39-minion-group-zslk   Ready                         <none>   57s   v1.26.0-alpha.1.74+c79617d877e650
e2e-111980-95a39-minion-heapster     Ready                         <none>   78s   v1.26.0-alpha.1.74+c79617d877e650
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://34.75.230.220
GLBCDefaultBackend is running at https://34.75.230.220/api/v1/namespaces/kube-system/services/default-http-backend:http/proxy
CoreDNS is running at https://34.75.230.220/api/v1/namespaces/kube-system/services/kube-dns:dns/proxy
Metrics-server is running at https://34.75.230.220/api/v1/namespaces/kube-system/services/https:metrics-server:/proxy
... skipping 59 lines ...
2022/09/22 19:26:40 process.go:153: Running: /home/prow/go/src/k8s.io/perf-tests/run-e2e.sh cluster-loader2 --nodes=100 --provider=gce --experimental-gcp-snapshot-prometheus-disk=true --experimental-prometheus-disk-snapshot-name=pull-kubernetes-e2e-gce-100-performance-1573024000039194624 --experimental-prometheus-snapshot-to-report-dir=true --prometheus-scrape-kubelets=true --prometheus-scrape-node-exporter --report-dir=/logs/artifacts --testconfig=testing/load/config.yaml --testconfig=testing/huge-service/config.yaml --testoverrides=./testing/experiments/enable_restart_count_check.yaml --testoverrides=./testing/experiments/use_simple_latency_query.yaml --testoverrides=./testing/overrides/load_throughput.yaml
TOOL_NAME: cluster-loader2
k8s.io/perf-tests git log:
964ccc47d59c35296e44e8a12079df1ece47d12b - Tue Sep 20 08:15:20 2022 (Merge pull request #2064 from oprinmarius/patch/azure-disk)
349be8a8c2c040a684deee24a99e3ba4ec27b468 - Fri Sep 9 09:27:22 2022 (Merge pull request #2139 from Argh4k/apiserver-calls)
f2db8e258d4e34a29c79c53a409c26b8ac302a64 - Thu Sep 8 13:01:44 2022 (Merge pull request #2140 from dlapcevic/new-dns-client-1)
1bdbd6df74b1bb0bb39762a96ff9a6f41b53f471 - Thu Sep 8 12:10:22 2022 (Add DNS lookup error percentage threshold instead of error count)
5985db0548d268abc4cd733006f0d743fbb5baaa - Wed Sep 7 13:38:21 2022 (Add dashboards for calls made from apiserver)
19e50ee9b6e2dacbdaad9ab12e4b2270f2cbc80e - Thu Sep 1 18:33:07 2022 (Merge pull request #2138 from tosi3k/gci-driver-adc)
e058a80f38dedb901ff996d8771446cbabf70be7 - Thu Sep 1 13:29:07 2022 (Fall back to using ADC when setting up GCE PD CSI driver in CL2)
f77b43a9b2cc79d59d5ac1cb8f77f41edda4dc86 - Wed Aug 31 13:27:00 2022 (Merge pull request #2113 from jupblb/b235038746)
2ccc73a91a2a54c42cf50d88e3fe6b4e24f757d4 - Thu Aug 4 14:53:56 2022 (Add documentation about adding new clusterloader2 test)
483fe918a398c30962c414ddd22750b82a6597bd - Wed Aug 31 06:51:02 2022 (Merge pull request #2132 from mborsz/startup-delete)
... skipping 1021 lines ...
I0922 19:34:11.488577  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(small-deployment-243): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:34:12.328113  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(small-deployment-89): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:34:12.975575  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(small-deployment-138): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:34:12.999737  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(small-deployment-275): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:34:13.426401  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(small-deployment-10): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:34:13.537917  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(small-deployment-244): Pods: 5 out of 5 created, 5 running (5 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:34:13.598908  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 2, deleted 0, timeout: 0, failed: 0
I0922 19:34:13.598939  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=40.00746586s, operationTimeout=15m0s, ratio=0.04
I0922 19:34:13.598956  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 2/2 StatefulSets are running with all pods
I0922 19:34:13.598915  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 1, deleted 0, timeout: 0, failed: 0
I0922 19:34:13.598968  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=5.001982264s, operationTimeout=15m0s, ratio=0.01
I0922 19:34:13.598976  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 1/1 DaemonSets are running with all pods
I0922 19:34:13.601042  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 3, deleted 0, timeout: 0, failed: 0
I0922 19:34:13.601066  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=10.012124955s, operationTimeout=15m0s, ratio=0.01
I0922 19:34:13.601077  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 3/3 Jobs are running with all pods
I0922 19:34:13.819018  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 323, deleted 0, timeout: 0, failed: 0
I0922 19:34:13.819043  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=10.014522601s, operationTimeout=15m0s, ratio=0.01
I0922 19:34:13.819055  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 323/323 Deployments are running with all pods
I0922 19:34:13.819071  100239 simple_test_executor.go:171] Step "[step: 07] Waiting for 'create objects' to be completed" ended
I0922 19:34:13.819085  100239 simple_test_executor.go:149] Step "[step: 08] Creating scheduler throughput measurements" started
I0922 19:34:13.819177  100239 wait_for_controlled_pods.go:216] WaitForControlledPodsRunning: starting wait for controlled pods measurement...
I0922 19:34:13.819301  100239 pod_startup_latency.go:132] PodStartupLatency: labelSelector(group = scheduler-throughput): starting pod startup latency measurement...
... skipping 4 lines ...
I0922 19:34:13.965383  100239 simple_test_executor.go:171] Step "[step: 09] create scheduler throughput pods" ended
I0922 19:34:13.965414  100239 simple_test_executor.go:149] Step "[step: 10] Waiting for scheduler throughput pods to be created" started
I0922 19:34:13.965450  100239 wait_for_controlled_pods.go:247] WaitForControlledPodsRunning: waiting for controlled pods measurement...
I0922 19:34:18.973344  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-2), controlledBy(scheduler-throughput-deployment-0): Pods: 577 out of 1000 created, 431 running (431 updated), 141 pending scheduled, 5 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:34:23.988786  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-2), controlledBy(scheduler-throughput-deployment-0): Pods: 1000 out of 1000 created, 916 running (916 updated), 84 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:34:29.005007  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-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 
I0922 19:34:29.005064  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 1, deleted 0, timeout: 0, failed: 0
I0922 19:34:29.005074  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=15.039966153s, operationTimeout=20m0s, ratio=0.01
I0922 19:34:29.005088  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 1/1 Deployments are running with all pods
I0922 19:34:29.005118  100239 simple_test_executor.go:171] Step "[step: 10] Waiting for scheduler throughput pods to be created" ended
I0922 19:34:29.005135  100239 simple_test_executor.go:149] Step "[step: 11] Collecting scheduler throughput measurements" started
I0922 19:34:29.005182  100239 scheduling_throughput.go:154] SchedulingThroughput: gathering data
I0922 19:34:29.005219  100239 pod_startup_latency.go:226] PodStartupLatency: labelSelector(group = scheduler-throughput): gathering pod startup latency measurement...
... skipping 33 lines ...
I0922 19:34:29.436820  100239 simple_test_executor.go:149] Step "[step: 13] Waiting for scheduler throughput pods to be deleted" started
I0922 19:34:29.436845  100239 wait_for_controlled_pods.go:247] WaitForControlledPodsRunning: waiting for controlled pods measurement...
I0922 19:34:29.437030  100239 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-0qigs3-2), controlledBy(scheduler-throughput-deployment-0): starting with timeout: 19m59.999980813s
I0922 19:34:34.446464  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-2), controlledBy(scheduler-throughput-deployment-0): Pods: 457 out of 0 created, 457 running (457 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 96 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:34:39.447742  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-2), controlledBy(scheduler-throughput-deployment-0): Pods: 0 out of 0 created, 0 running (0 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 48 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:34:44.448715  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-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 
I0922 19:34:44.448777  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 0, deleted 1, timeout: 0, failed: 0
I0922 19:34:44.448808  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=15.011727235s, operationTimeout=20m0s, ratio=0.01
I0922 19:34:44.448828  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 0/0 Deployments are running with all pods
I0922 19:34:44.448853  100239 simple_test_executor.go:171] Step "[step: 13] Waiting for scheduler throughput pods to be deleted" ended
I0922 19:34:44.448873  100239 simple_test_executor.go:149] Step "[step: 14] Starting latency pod measurements" started
I0922 19:34:44.448939  100239 wait_for_controlled_pods.go:216] WaitForControlledPodsRunning: starting wait for controlled pods measurement...
I0922 19:34:44.449032  100239 pod_startup_latency.go:132] PodStartupLatency: labelSelector(group = latency): starting pod startup latency measurement...
... skipping 999 lines ...
I0922 19:36:28.681366  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-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 
I0922 19:36:28.885807  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-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 
I0922 19:36:29.082137  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-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 
I0922 19:36:29.284477  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-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 
I0922 19:36:29.485585  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-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 
I0922 19:36:29.686012  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-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 
I0922 19:36:30.084397  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 500, deleted 0, timeout: 0, failed: 0
I0922 19:36:30.084447  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=5.001376811s, operationTimeout=15m0s, ratio=0.01
I0922 19:36:30.084465  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 500/500 Deployments are running with all pods
I0922 19:36:30.084494  100239 simple_test_executor.go:171] Step "[step: 16] Waiting for latency pods to be running" ended
I0922 19:36:30.084519  100239 simple_test_executor.go:149] Step "[step: 17] Deleting latency pods" started
I0922 19:36:30.125880  100239 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(latency-deployment-0): starting with timeout: 14m59.999966983s
I0922 19:36:30.225569  100239 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(latency-deployment-1): starting with timeout: 14m59.999978674s
... skipping 495 lines ...
I0922 19:37:19.825752  100239 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(latency-deployment-497): starting with timeout: 14m59.999982738s
I0922 19:37:19.926509  100239 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(latency-deployment-498): starting with timeout: 14m59.999981681s
I0922 19:37:20.030265  100239 simple_test_executor.go:171] Step "[step: 17] Deleting latency pods" ended
I0922 19:37:20.030295  100239 simple_test_executor.go:149] Step "[step: 18] Waiting for latency pods to be deleted" started
I0922 19:37:20.030326  100239 wait_for_controlled_pods.go:247] WaitForControlledPodsRunning: waiting for controlled pods measurement...
I0922 19:37:20.030396  100239 wait_for_pods.go:61] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(latency-deployment-499): starting with timeout: 14m59.999979521s
I0922 19:37:25.082803  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 0, deleted 500, timeout: 0, failed: 0
I0922 19:37:25.082845  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=5.004728356s, operationTimeout=15m0s, ratio=0.01
I0922 19:37:25.082863  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 0/0 Deployments are running with all pods
I0922 19:37:25.082894  100239 simple_test_executor.go:171] Step "[step: 18] Waiting for latency pods to be deleted" ended
I0922 19:37:25.082916  100239 simple_test_executor.go:149] Step "[step: 19] Collecting pod startup latency" started
I0922 19:37:25.082960  100239 pod_startup_latency.go:226] PodStartupLatency: labelSelector(group = latency): gathering pod startup latency measurement...
I0922 19:37:25.632931  100239 phase_latency.go:141] PodStartupLatency: 100 worst create_to_schedule latencies: [{test-0qigs3-1/latency-deployment-227-556fcbdf6f-8cn9c 0s} {test-0qigs3-1/latency-deployment-303-6b6788b47-bdzzh 0s} {test-0qigs3-1/latency-deployment-368-5f65f9ddb5-9l6qq 0s} {test-0qigs3-1/latency-deployment-397-78ffc76bb9-7jhgg 0s} {test-0qigs3-1/latency-deployment-439-6bfd7f845f-rs6wm 0s} {test-0qigs3-1/latency-deployment-40-5dcfcd6bc9-96d8n 0s} {test-0qigs3-1/latency-deployment-65-d8c5c776c-mp57r 0s} {test-0qigs3-1/latency-deployment-129-c8fcfbc9-qw6gv 0s} {test-0qigs3-1/latency-deployment-226-598b5bbd55-275hs 0s} {test-0qigs3-1/latency-deployment-28-7896c7dfff-h5j4w 0s} {test-0qigs3-1/latency-deployment-215-6cb8bfd959-trrhn 0s} {test-0qigs3-1/latency-deployment-296-5d5cdf864f-tcjs8 0s} {test-0qigs3-1/latency-deployment-113-65fc576965-5zmxn 0s} {test-0qigs3-1/latency-deployment-275-84f94d5987-kb8c8 0s} {test-0qigs3-1/latency-deployment-181-578fcc79b7-9qk47 0s} {test-0qigs3-1/latency-deployment-364-8bfc5f569-8vc9s 0s} {test-0qigs3-1/latency-deployment-333-967847f45-bm2p5 0s} {test-0qigs3-1/latency-deployment-395-868fc8cd5c-gzhdp 0s} {test-0qigs3-1/latency-deployment-450-9559454df-slbgc 0s} {test-0qigs3-1/latency-deployment-469-768b4b488f-xwbvp 0s} {test-0qigs3-1/latency-deployment-38-5f67cdd979-cnwps 0s} {test-0qigs3-1/latency-deployment-306-79f76dbb5c-4b88l 0s} {test-0qigs3-1/latency-deployment-388-dfc79d7d5-58lfv 0s} {test-0qigs3-1/latency-deployment-411-db8977467-ngx8r 0s} {test-0qigs3-1/latency-deployment-358-699f7c89cf-pd4lt 0s} {test-0qigs3-1/latency-deployment-206-6d87964f75-2hml5 0s} {test-0qigs3-1/latency-deployment-267-7f764db757-kjjlk 0s} {test-0qigs3-1/latency-deployment-271-577b94fb75-lvqks 0s} {test-0qigs3-1/latency-deployment-435-5986bf55f9-pbv6q 0s} {test-0qigs3-1/latency-deployment-140-5dffc8f57c-f7v26 0s} {test-0qigs3-1/latency-deployment-191-76c5869c57-jppkm 0s} {test-0qigs3-1/latency-deployment-426-85bdcd66c9-msv6x 0s} {test-0qigs3-1/latency-deployment-104-79f6c6c7d9-nv7xb 0s} {test-0qigs3-1/latency-deployment-328-5889db7dbf-7gjlj 0s} {test-0qigs3-1/latency-deployment-444-56866586c9-6c8tt 0s} {test-0qigs3-1/latency-deployment-234-6496fc7865-x87tn 0s} {test-0qigs3-1/latency-deployment-255-6775847487-j9k7t 0s} {test-0qigs3-1/latency-deployment-441-56bf78f845-frnpc 0s} {test-0qigs3-1/latency-deployment-478-7dcdcf6dcc-qcj7g 0s} {test-0qigs3-1/latency-deployment-332-9665db559-7zwxs 0s} {test-0qigs3-1/latency-deployment-99-d577f4455-d49b2 0s} {test-0qigs3-1/latency-deployment-151-bd4f9965c-n8827 0s} {test-0qigs3-1/latency-deployment-169-cc9bd4847-t8j7j 0s} {test-0qigs3-1/latency-deployment-268-7f5466b4ff-v4kbk 0s} {test-0qigs3-1/latency-deployment-451-748f8459d7-v9pps 0s} {test-0qigs3-1/latency-deployment-75-578fd9967-lg7zz 0s} {test-0qigs3-1/latency-deployment-183-5dd87-ht9wr 0s} {test-0qigs3-1/latency-deployment-272-76dcf759c7-wfv7j 0s} {test-0qigs3-1/latency-deployment-378-5cbbd777c9-kw6jv 0s} {test-0qigs3-1/latency-deployment-122-59fc8d78cc-6vct5 0s} {test-0qigs3-1/latency-deployment-345-546b758f4c-v5qwh 0s} {test-0qigs3-1/latency-deployment-365-54c54cfdd7-d7h82 0s} {test-0qigs3-1/latency-deployment-330-6d8cdc8c5-bsfgv 0s} {test-0qigs3-1/latency-deployment-337-fc7dbbdb5-v2lml 0s} {test-0qigs3-1/latency-deployment-443-745b7c7f77-b866z 0s} {test-0qigs3-1/latency-deployment-108-7f79745b85-bkk47 0s} {test-0qigs3-1/latency-deployment-173-7cbb5794f7-tndsc 0s} {test-0qigs3-1/latency-deployment-219-876989bd7-r79qw 0s} {test-0qigs3-1/latency-deployment-245-5c7bcc46f7-pskmq 0s} {test-0qigs3-1/latency-deployment-371-7b49647bbf-9lbdz 0s} {test-0qigs3-1/latency-deployment-389-65c995dfdc-xpzf2 0s} {test-0qigs3-1/latency-deployment-393-6d477b86b9-sksgp 0s} {test-0qigs3-1/latency-deployment-483-8548c4d689-r5x4z 0s} {test-0qigs3-1/latency-deployment-5-55cbdf5677-r9b26 0s} {test-0qigs3-1/latency-deployment-10-76bb5ff6f5-j5twl 0s} {test-0qigs3-1/latency-deployment-73-5df47f4967-h4ljk 0s} {test-0qigs3-1/latency-deployment-157-59b9f4df57-s4fj7 0s} {test-0qigs3-1/latency-deployment-495-865c9c5d4c-npjzv 0s} {test-0qigs3-1/latency-deployment-467-7799f765df-kqx5k 0s} {test-0qigs3-1/latency-deployment-70-58dbb7f68c-n9fhj 0s} {test-0qigs3-1/latency-deployment-185-7c6b7f794c-bmsmt 0s} {test-0qigs3-1/latency-deployment-340-685f54f9b9-mzbnh 0s} {test-0qigs3-1/latency-deployment-367-6df78fcc4c-qdvrf 0s} {test-0qigs3-1/latency-deployment-290-85899c589-4p5s9 0s} {test-0qigs3-1/latency-deployment-16-74948f8bff-jvhqs 0s} {test-0qigs3-1/latency-deployment-111-d8644d6c7-tv5xb 0s} {test-0qigs3-1/latency-deployment-179-54c46c7c4f-6z928 0s} {test-0qigs3-1/latency-deployment-237-69bf47ffdc-tjcd7 0s} {test-0qigs3-1/latency-deployment-372-f7f5c4d79-qhgjm 0s} {test-0qigs3-1/latency-deployment-408-5fcf8fdb55-6kc7c 0s} {test-0qigs3-1/latency-deployment-54-84b4656855-wbjvh 0s} {test-0qigs3-1/latency-deployment-95-798c75b86c-vdvjs 0s} {test-0qigs3-1/latency-deployment-136-6b9ff86c5f-kbcvj 0s} {test-0qigs3-1/latency-deployment-299-5f68c854f5-w4rx4 0s} {test-0qigs3-1/latency-deployment-120-544bb9cc89-gkpb6 0s} {test-0qigs3-1/latency-deployment-487-fd999dc8f-lfbs2 0s} {test-0qigs3-1/latency-deployment-491-595775595f-bm9nj 0s} {test-0qigs3-1/latency-deployment-400-5ccfc6c967-rftxd 0s} {test-0qigs3-1/latency-deployment-425-68bdbb58fc-4tfnw 0s} {test-0qigs3-1/latency-deployment-282-dbcd5fd47-kjsgt 0s} {test-0qigs3-1/latency-deployment-375-645f496c85-bszbp 0s} {test-0qigs3-1/latency-deployment-32-58d9b6d67f-brr2z 0s} {test-0qigs3-1/latency-deployment-107-764b45957f-k6rkm 0s} {test-0qigs3-1/latency-deployment-336-6b7bf59b79-wv5nf 1s} {test-0qigs3-1/latency-deployment-351-67b7b96fbf-tb6dm 1s} {test-0qigs3-1/latency-deployment-331-6d9c9c987c-f4tnb 1s} {test-0qigs3-1/latency-deployment-341-6dd66887dc-zmvfb 1s} {test-0qigs3-1/latency-deployment-7-f5f9cb5df-d8s7k 1s} {test-0qigs3-1/latency-deployment-17-6cbbb587c5-lj9dd 1s} {test-0qigs3-1/latency-deployment-22-78b6cdd9cf-kwbj2 1s}]
... skipping 603 lines ...
I0922 19:38:06.851499  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(small-deployment-223): Pods: 4 out of 4 created, 4 running (4 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:38:06.932991  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(small-deployment-273): Pods: 3 out of 3 created, 3 running (3 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:38:07.117329  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(small-deployment-235): Pods: 2 out of 2 created, 2 running (2 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:38:07.332729  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(small-deployment-169): Pods: 7 out of 7 created, 7 running (7 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:38:07.486114  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(small-deployment-199): Pods: 6 out of 6 created, 6 running (6 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:38:07.607155  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(small-deployment-253): Pods: 3 out of 3 created, 3 running (3 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:38:07.648913  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 3, deleted 0, timeout: 0, failed: 0
I0922 19:38:07.648947  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=5.004075965s, operationTimeout=15m0s, ratio=0.01
I0922 19:38:07.648968  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 3/3 Jobs are running with all pods
I0922 19:38:07.811216  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 323, deleted 0, timeout: 0, failed: 0
I0922 19:38:07.811250  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=10.00180948s, operationTimeout=15m0s, ratio=0.01
I0922 19:38:07.811268  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 323/323 Deployments are running with all pods
I0922 19:38:09.739351  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(daemonset-0): Pods: 97 out of 100 created, 91 running (67 updated), 6 pending scheduled, 0 not scheduled, 0 inactive, 2 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:38:10.789337  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(medium-statefulset-0): Pods: 44 out of 44 created, 40 running (40 updated), 4 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
W0922 19:38:14.744600  100239 wait_for_pods.go:104] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(daemonset-0): 18 pods disappeared: daemonset-0-785z6, daemonset-0-v7cg6, daemonset-0-ncqvh, daemonset-0-t5frs, daemonset-0-7j4lk, daemonset-0-vzsjz, daemonset-0-744td, daemonset-0-9cp5n, daemonset-0-t9d4h, daemonset-0-fztjk, daemonset-0-qfnbk, daemonset-0-mmn5h, daemonset-0-qkjmn, daemonset-0-4kml5, daemonset-0-fpfl4, daemonset-0-gsl4p, daemonset-0-mfm8c, daemonset-0-ps4xn
I0922 19:38:14.744639  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(daemonset-0): Pods: 97 out of 100 created, 90 running (85 updated), 7 pending scheduled, 0 not scheduled, 0 inactive, 3 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:38:15.791346  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(medium-statefulset-0): Pods: 44 out of 44 created, 41 running (41 updated), 3 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:38:19.746562  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-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 
I0922 19:38:19.746622  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 1, deleted 0, timeout: 0, failed: 0
I0922 19:38:19.746633  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=30.122691974s, operationTimeout=15m0s, ratio=0.03
I0922 19:38:19.746647  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 1/1 DaemonSets are running with all pods
I0922 19:38:20.793030  100239 wait_for_pods.go:111] WaitForControlledPodsRunning: namespace(test-0qigs3-1), controlledBy(medium-statefulset-0): Pods: 44 out of 44 created, 44 running (44 updated), 0 pending scheduled, 0 not scheduled, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0922 19:38:20.793097  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 2, deleted 0, timeout: 0, failed: 0
I0922 19:38:20.793114  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=30.010672494s, operationTimeout=15m0s, ratio=0.03
I0922 19:38:20.793133  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 2/2 StatefulSets are running with all pods
I0922 19:38:20.793160  100239 simple_test_executor.go:171] Step "[step: 22] Waiting for 'scale and update objects' to be completed" ended
I0922 19:38:20.793190  100239 simple_test_executor.go:149] Step "[step: 23] Starting measurement for 'delete objects'" started
I0922 19:38:20.793251  100239 wait_for_controlled_pods.go:213] WaitForControlledPodsRunning: wait for controlled pods measurement already running
I0922 19:38:20.793253  100239 wait_for_controlled_pods.go:213] WaitForControlledPodsRunning: wait for controlled pods measurement already running
... skipping 333 lines ...
I0922 19:41:53.463214  100239 simple_test_executor.go:171] Step "[step: 24] delete objects" ended
I0922 19:41:53.463253  100239 simple_test_executor.go:149] Step "[step: 25] Waiting for 'delete objects' to be completed" started
I0922 19:41:53.463368  100239 wait_for_controlled_pods.go:247] WaitForControlledPodsRunning: waiting for controlled pods measurement...
I0922 19:41:53.463406  100239 wait_for_controlled_pods.go:247] WaitForControlledPodsRunning: waiting for controlled pods measurement...
I0922 19:41:53.463368  100239 wait_for_controlled_pods.go:247] WaitForControlledPodsRunning: waiting for controlled pods measurement...
I0922 19:41:53.463548  100239 wait_for_controlled_pods.go:247] WaitForControlledPodsRunning: waiting for controlled pods measurement...
I0922 19:41:58.502340  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 0, deleted 3, timeout: 0, failed: 0
I0922 19:41:58.502384  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=5.000865731s, operationTimeout=15m0s, ratio=0.01
I0922 19:41:58.502401  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 0/0 Jobs are running with all pods
I0922 19:41:58.503506  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 0, deleted 2, timeout: 0, failed: 0
I0922 19:41:58.503530  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=5.000968197s, operationTimeout=15m0s, ratio=0.01
I0922 19:41:58.503546  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 0/0 StatefulSets are running with all pods
I0922 19:41:58.503531  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 0, deleted 1, timeout: 0, failed: 0
I0922 19:41:58.503563  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=5.000830064s, operationTimeout=15m0s, ratio=0.01
I0922 19:41:58.503571  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 0/0 DaemonSets are running with all pods
I0922 19:41:58.503785  100239 wait_for_controlled_pods.go:320] WaitForControlledPodsRunning: running 0, deleted 323, timeout: 0, failed: 0
I0922 19:41:58.503809  100239 wait_for_controlled_pods.go:325] WaitForControlledPodsRunning: maxDuration=5.001253725s, operationTimeout=15m0s, ratio=0.01
I0922 19:41:58.503826  100239 wait_for_controlled_pods.go:339] WaitForControlledPodsRunning: 0/0 Deployments are running with all pods
I0922 19:41:58.513860  100239 wait_for_pvcs.go:78] WaitForBoundPVCs: labelSelector(group = load): PVCs: 0 out of 0 created, 0 bound, 0 pending, 0 lost
I0922 19:41:58.513900  100239 simple_test_executor.go:171] Step "[step: 25] Waiting for 'delete objects' to be completed" ended
I0922 19:41:58.513928  100239 simple_test_executor.go:149] Step "[step: 26] delete objects configmaps and secrets" started
I0922 19:42:30.795049  100239 simple_test_executor.go:171] Step "[step: 26] delete objects configmaps and secrets" ended
... skipping 187 lines ...