Docker in Docker enabled, initializing...
================================================================================
Starting Docker: docker.
Waiting for docker to be ready, sleeping for 1 seconds.
================================================================================
Done setting up docker in docker.
Activated service account credentials for: [prow-build@k8s-infra-prow-build.iam.gserviceaccount.com]
+ WRAPPED_COMMAND_PID=167
+ wait 167
+ /workspace/scenarios/kubernetes_e2e.py --build=quick --cluster= --env=HEAPSTER_MACHINE_TYPE=e2-standard-8 '--env=KUBEMARK_APISERVER_TEST_ARGS=--max-requests-inflight=80 --max-mutating-requests-inflight=0 --profiling --contention-profiling' --extract=local --flush-mem-after-build=true --gcp-node-image=gci --gcp-nodes=100 --gcp-project-type=scalability-project --gcp-zone=us-east1-b --provider=gce --stage=gs://kubernetes-release-pull/ci/pull-kubernetes-e2e-gce-100-performance --tear-down-previous --env=CL2_ENABLE_DNS_PROGRAMMING=true --env=CL2_SCHEDULER_THROUGHPUT_THRESHOLD=0 --env=CL2_ENABLE_API_AVAILABILITY_MEASUREMENT=true --env=CL2_API_AVAILABILITY_PERCENTAGE_THRESHOLD=99.5 --test=false '--test-cmd=$GOPATH/src/k8s.io/perf-tests/run-e2e.sh' --test-cmd-args=cluster-loader2 --test-cmd-args=--nodes=100 --test-cmd-args=--provider=gce --test-cmd-args=--experimental-gcp-snapshot-prometheus-disk=true --test-cmd-args=--experimental-prometheus-disk-snapshot-name=pull-kubernetes-e2e-gce-100-performance-1617999810789380096 --test-cmd-args=--experimental-prometheus-snapshot-to-report-dir=true --test-cmd-args=--prometheus-scrape-kubelets=true --test-cmd-args=--prometheus-scrape-node-exporter --test-cmd-args=--report-dir=/logs/artifacts --test-cmd-args=--testconfig=testing/load/config.yaml --test-cmd-args=--testconfig=testing/huge-service/config.yaml --test-cmd-args=--testoverrides=./testing/experiments/enable_restart_count_check.yaml --test-cmd-args=--testoverrides=./testing/experiments/use_simple_latency_query.yaml --test-cmd-args=--testoverrides=./testing/overrides/load_throughput.yaml --test-cmd-name=ClusterLoaderV2 --timeout=100m --use-logexporter --logexporter-gcs-path=gs://sig-scalability-logs/pull-kubernetes-e2e-gce-100-performance/1617999810789380096
starts with local mode
Environment:
APISERVER_TEST_ARGS=--profiling --contention-profiling
API_SERVER_TEST_LOG_LEVEL=--v=3
ARTIFACTS=/logs/artifacts
AWS_ROLE_SESSION_NAME=2852be30-9c2f-11ed-8b47-ba63745bd213
BAZEL_REMOTE_CACHE_ENABLED=false
BAZEL_VERSION=3.4.1
BOSKOS_METRICS_PORT=tcp://10.35.242.179:9090
BOSKOS_METRICS_PORT_9090_TCP=tcp://10.35.242.179:9090
BOSKOS_METRICS_PORT_9090_TCP_ADDR=10.35.242.179
BOSKOS_METRICS_PORT_9090_TCP_PORT=9090
BOSKOS_METRICS_PORT_9090_TCP_PROTO=tcp
BOSKOS_METRICS_SERVICE_HOST=10.35.242.179
BOSKOS_METRICS_SERVICE_PORT=9090
BOSKOS_METRICS_SERVICE_PORT_METRICS=9090
BOSKOS_PORT=tcp://10.35.241.148:80
BOSKOS_PORT_80_TCP=tcp://10.35.241.148:80
BOSKOS_PORT_80_TCP_ADDR=10.35.241.148
BOSKOS_PORT_80_TCP_PORT=80
BOSKOS_PORT_80_TCP_PROTO=tcp
BOSKOS_SERVICE_HOST=10.35.241.148
BOSKOS_SERVICE_PORT=80
BOSKOS_SERVICE_PORT_DEFAULT=80
BUILD_ID=1617999810789380096
BUILD_NUMBER=1617999810789380096
CI=true
CL2_ALLOWED_SLOW_API_CALLS=1
CL2_API_AVAILABILITY_PERCENTAGE_THRESHOLD=99.5
CL2_ENABLE_API_AVAILABILITY_MEASUREMENT=true
CL2_ENABLE_DNS_PROGRAMMING=true
CL2_ENABLE_QUOTAS_USAGE_MEASUREMENT=true
CL2_SCHEDULER_THROUGHPUT_THRESHOLD=0
CL2_WAIT_FOR_CONTROLLED_PODS_USE_EXACT_OPERATION_TIMEOUT=true
CLOUDSDK_COMPONENT_MANAGER_DISABLE_UPDATE_CHECK=true
CLOUDSDK_CORE_DISABLE_PROMPTS=1
CLOUDSDK_EXPERIMENTAL_FAST_COMPONENT_UPDATE=false
CONTROLLER_MANAGER_TEST_ARGS=--profiling --contention-profiling --kube-api-qps=100 --kube-api-burst=100
CREATE_CUSTOM_NETWORK=true
DEPLOY_GCI_DRIVER=true
DOCKER_IN_DOCKER_ENABLED=true
DOCKER_IN_DOCKER_IPV6_ENABLED=false
DUMP_TO_GCS_ONLY=true
E2E_GOOGLE_APPLICATION_CREDENTIALS=/etc/service-account/service-account.json
ENABLE_PROMETHEUS_SERVER=true
ENTRYPOINT_OPTIONS={"timeout":7200000000000,"grace_period":900000000000,"artifact_dir":"/logs/artifacts","args":["runner.sh","/workspace/scenarios/kubernetes_e2e.py","--build=quick","--cluster=","--env=HEAPSTER_MACHINE_TYPE=e2-standard-8","--env=KUBEMARK_APISERVER_TEST_ARGS=--max-requests-inflight=80 --max-mutating-requests-inflight=0 --profiling --contention-profiling","--extract=local","--flush-mem-after-build=true","--gcp-node-image=gci","--gcp-nodes=100","--gcp-project-type=scalability-project","--gcp-zone=us-east1-b","--provider=gce","--stage=gs://kubernetes-release-pull/ci/pull-kubernetes-e2e-gce-100-performance","--tear-down-previous","--env=CL2_ENABLE_DNS_PROGRAMMING=true","--env=CL2_SCHEDULER_THROUGHPUT_THRESHOLD=0","--env=CL2_ENABLE_API_AVAILABILITY_MEASUREMENT=true","--env=CL2_API_AVAILABILITY_PERCENTAGE_THRESHOLD=99.5","--test=false","--test-cmd=$GOPATH/src/k8s.io/perf-tests/run-e2e.sh","--test-cmd-args=cluster-loader2","--test-cmd-args=--nodes=100","--test-cmd-args=--provider=gce","--test-cmd-args=--experimental-gcp-snapshot-prometheus-disk=true","--test-cmd-args=--experimental-prometheus-disk-snapshot-name=pull-kubernetes-e2e-gce-100-performance-1617999810789380096","--test-cmd-args=--experimental-prometheus-snapshot-to-report-dir=true","--test-cmd-args=--prometheus-scrape-kubelets=true","--test-cmd-args=--prometheus-scrape-node-exporter","--test-cmd-args=--report-dir=/logs/artifacts","--test-cmd-args=--testconfig=testing/load/config.yaml","--test-cmd-args=--testconfig=testing/huge-service/config.yaml","--test-cmd-args=--testoverrides=./testing/experiments/enable_restart_count_check.yaml","--test-cmd-args=--testoverrides=./testing/experiments/use_simple_latency_query.yaml","--test-cmd-args=--testoverrides=./testing/overrides/load_throughput.yaml","--test-cmd-name=ClusterLoaderV2","--timeout=100m","--use-logexporter","--logexporter-gcs-path=gs://sig-scalability-logs/pull-kubernetes-e2e-gce-100-performance/1617999810789380096"],"container_name":"test","process_log":"/logs/process-log.txt","marker_file":"/logs/marker-file.txt","metadata_file":"/logs/artifacts/metadata.json"}
ETCD_COMPACTION_INTERVAL_SEC=150
ETCD_EXTRA_ARGS=--enable-pprof
GCE_SSH_PRIVATE_KEY_FILE=/etc/ssh-key-secret/ssh-private
GCE_SSH_PUBLIC_KEY_FILE=/etc/ssh-key-secret/ssh-public
GOOGLE_APPLICATION_CREDENTIALS=/etc/service-account/service-account.json
GOOGLE_APPLICATION_CREDENTIALS_DEPRECATED=Migrate to workload identity, contact sig-testing
GOPATH=/home/prow/go
GOPROXY=https://proxy.golang.org
GO_TARBALL=go1.19.5.linux-amd64.tar.gz
HEAPSTER_MACHINE_TYPE=e2-standard-8
HOME=/workspace
HOSTNAME=2852be30-9c2f-11ed-8b47-ba63745bd213
IMAGE=gcr.io/k8s-staging-test-infra/kubekins-e2e:v20230124-157bf4e62c-master
INSTANCE_PREFIX=e2e-113896-95a39
JENKINS_GCE_SSH_PRIVATE_KEY_FILE=/workspace/.ssh/google_compute_engine
JENKINS_GCE_SSH_PUBLIC_KEY_FILE=/workspace/.ssh/google_compute_engine.pub
JOB_NAME=pull-kubernetes-e2e-gce-100-performance
JOB_SPEC={"type":"presubmit","job":"pull-kubernetes-e2e-gce-100-performance","buildid":"1617999810789380096","prowjobid":"2852be30-9c2f-11ed-8b47-ba63745bd213","refs":{"org":"kubernetes","repo":"kubernetes","repo_link":"https://github.com/kubernetes/kubernetes","base_ref":"master","base_sha":"14549722e416827bf598a36ff156fb6dd66e61c0","base_link":"https://github.com/kubernetes/kubernetes/commit/14549722e416827bf598a36ff156fb6dd66e61c0","pulls":[{"number":113896,"author":"nilekhc","sha":"114a0f8cbf32522e57ed6bce8777579fea4f72ef","title":"chore: improves tests","link":"https://github.com/kubernetes/kubernetes/pull/113896","commit_link":"https://github.com/kubernetes/kubernetes/pull/113896/commits/114a0f8cbf32522e57ed6bce8777579fea4f72ef","author_link":"https://github.com/nilekhc"}],"path_alias":"k8s.io/kubernetes"},"extra_refs":[{"org":"kubernetes","repo":"perf-tests","base_ref":"master","path_alias":"k8s.io/perf-tests"},{"org":"kubernetes","repo":"release","base_ref":"master","path_alias":"k8s.io/release"}],"decoration_config":{"timeout":"2h0m0s","grace_period":"15m0s","utility_images":{"clonerefs":"gcr.io/k8s-prow/clonerefs:v20230124-17d9ffa086","initupload":"gcr.io/k8s-prow/initupload:v20230124-17d9ffa086","entrypoint":"gcr.io/k8s-prow/entrypoint:v20230124-17d9ffa086","sidecar":"gcr.io/k8s-prow/sidecar:v20230124-17d9ffa086"},"resources":{"clonerefs":{"requests":{"cpu":"100m"}},"initupload":{"requests":{"cpu":"100m"}},"place_entrypoint":{"requests":{"cpu":"100m"}},"sidecar":{"requests":{"cpu":"100m"}}},"gcs_configuration":{"bucket":"kubernetes-jenkins","path_strategy":"legacy","default_org":"kubernetes","default_repo":"kubernetes"},"gcs_credentials_secret":"service-account"}}
JOB_TYPE=presubmit
KUBECTL_PRUNE_WHITELIST_OVERRIDE=core/v1/ConfigMap core/v1/Endpoints core/v1/Namespace core/v1/PersistentVolumeClaim core/v1/PersistentVolume core/v1/ReplicationController core/v1/Secret core/v1/Service batch/v1/Job batch/v1/CronJob apps/v1/DaemonSet apps/v1/Deployment apps/v1/ReplicaSet apps/v1/StatefulSet networking.k8s.io/v1/Ingress
KUBELET_TEST_ARGS=--enable-debugging-handlers --kube-api-qps=100 --kube-api-burst=100
KUBEMARK_APISERVER_TEST_ARGS=--max-requests-inflight=80 --max-mutating-requests-inflight=0 --profiling --contention-profiling
KUBEPROXY_TEST_ARGS=--profiling --metrics-bind-address=0.0.0.0 --feature-gates=MinimizeIPTablesRestore=true
KUBERNETES_PORT=tcp://10.35.240.1:443
KUBERNETES_PORT_443_TCP=tcp://10.35.240.1:443
KUBERNETES_PORT_443_TCP_ADDR=10.35.240.1
KUBERNETES_PORT_443_TCP_PORT=443
KUBERNETES_PORT_443_TCP_PROTO=tcp
KUBERNETES_SERVICE_HOST=10.35.240.1
KUBERNETES_SERVICE_PORT=443
KUBERNETES_SERVICE_PORT_HTTPS=443
KUBETEST_IN_DOCKER=true
KUBETEST_MANUAL_DUMP=y
KUBE_APISERVER_GODEBUG=gctrace=1
KUBE_AWS_INSTANCE_PREFIX=e2e-113896-95a39
KUBE_ENABLE_CLUSTER_UI=false
KUBE_GCE_ENABLE_IP_ALIASES=true
KUBE_GCE_INSTANCE_PREFIX=e2e-113896-95a39
KUBE_GCE_PRIVATE_CLUSTER=true
KUBE_MASTER_NODE_LABELS=node.kubernetes.io/node-exporter-ready=true
LOGROTATE_FILES_MAX_COUNT=1000
LOGROTATE_MAX_SIZE=5G
LOG_DUMP_EXPECTED_SUCCESS_PERCENTAGE=50
LOG_DUMP_EXTRA_FILES=cl2-*
LOG_DUMP_SAVE_SERVICES=containerd
LOG_DUMP_SCRIPT_PATH=/workspace/log-dump.sh
LOG_DUMP_SSH_TIMEOUT_SECONDS=3600
LOG_DUMP_SYSTEMD_JOURNAL=true
MASTER_MIN_CPU_ARCHITECTURE=Intel Skylake
NODE_DISK_SIZE=50GB
NODE_KUBELET_TEST_ARGS=--kube-reserved=cpu=1050m
NODE_SIZE=e2-medium
PATH=/home/prow/go/bin:/go/bin:/usr/local/go/bin:/google-cloud-sdk/bin:/workspace:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
PERF_TESTS_PRINT_COMMIT_HISTORY=true
PROMETHEUS_SCRAPE_ETCD=true
PROMETHEUS_SCRAPE_MASTER_KUBELETS=true
PROMETHEUS_STORAGE_CLASS_PROVISIONER=pd.csi.storage.gke.io
PROW_JOB_ID=2852be30-9c2f-11ed-8b47-ba63745bd213
PULL_BASE_REF=master
PULL_BASE_SHA=14549722e416827bf598a36ff156fb6dd66e61c0
PULL_NUMBER=113896
PULL_PULL_SHA=114a0f8cbf32522e57ed6bce8777579fea4f72ef
PULL_REFS=master:14549722e416827bf598a36ff156fb6dd66e61c0,113896:114a0f8cbf32522e57ed6bce8777579fea4f72ef
PWD=/home/prow/go/src/k8s.io/kubernetes
REGISTER_MASTER=true
REPO_NAME=kubernetes
REPO_OWNER=kubernetes
SCHEDULER_TEST_ARGS=--profiling --contention-profiling --kube-api-qps=100 --kube-api-burst=100
SHLVL=0
SOURCE_DATE_EPOCH=1674593754
TERM=xterm
TEST_CLUSTER_DELETE_COLLECTION_WORKERS=--delete-collection-workers=16
TEST_CLUSTER_LOG_LEVEL=--v=2
TEST_CLUSTER_RESYNC_PERIOD=--min-resync-period=12h
USER=prow
USE_TEST_INFRA_LOG_DUMPING=true
WORKSPACE=/workspace
_=/workspace/scenarios/kubernetes_e2e.py
Run: ('kubetest', '--dump=/logs/artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=quick', '--stage=gs://kubernetes-release-pull/ci/pull-kubernetes-e2e-gce-100-performance', '--up', '--down', '--provider=gce', '--cluster=e2e-113896-95a39', '--gcp-network=e2e-113896-95a39', '--extract=local', '--flush-mem-after-build=true', '--gcp-node-image=gci', '--gcp-nodes=100', '--gcp-project-type=scalability-project', '--gcp-zone=us-east1-b', '--test-cmd=$GOPATH/src/k8s.io/perf-tests/run-e2e.sh', '--test-cmd-args=cluster-loader2', '--test-cmd-args=--nodes=100', '--test-cmd-args=--provider=gce', '--test-cmd-args=--experimental-gcp-snapshot-prometheus-disk=true', '--test-cmd-args=--experimental-prometheus-disk-snapshot-name=pull-kubernetes-e2e-gce-100-performance-1617999810789380096', '--test-cmd-args=--experimental-prometheus-snapshot-to-report-dir=true', '--test-cmd-args=--prometheus-scrape-kubelets=true', '--test-cmd-args=--prometheus-scrape-node-exporter', '--test-cmd-args=--report-dir=/logs/artifacts', '--test-cmd-args=--testconfig=testing/load/config.yaml', '--test-cmd-args=--testconfig=testing/huge-service/config.yaml', '--test-cmd-args=--testoverrides=./testing/experiments/enable_restart_count_check.yaml', '--test-cmd-args=--testoverrides=./testing/experiments/use_simple_latency_query.yaml', '--test-cmd-args=--testoverrides=./testing/overrides/load_throughput.yaml', '--test-cmd-name=ClusterLoaderV2', '--timeout=100m', '--logexporter-gcs-path=gs://sig-scalability-logs/pull-kubernetes-e2e-gce-100-performance/1617999810789380096')
2023/01/24 21:42:43 Warning: Couldn't find directory src/sigs.k8s.io/cloud-provider-azure under any of GOPATH /home/prow/go, defaulting to /home/prow/go/src/k8s.io/cloud-provider-azure
2023/01/24 21:42:43 main.go:281: Running kubetest version: v20230124-157bf4e62c
2023/01/24 21:42:43 extract_k8s.go:118: Matched extraction strategy: ^(local)
2023/01/24 21:42:43 main.go:341: Limiting testing to 1h40m0s
2023/01/24 21:42:43 util.go:150: Please use kubetest --gcp-node-size=e2-medium (instead of deprecated NODE_SIZE=e2-medium)
2023/01/24 21:42:43 process.go:153: Running: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
Activated service account credentials for: [prow-build@k8s-infra-prow-build.iam.gserviceaccount.com]
2023/01/24 21:42:44 process.go:155: Step 'gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json' finished in 1.118318089s
2023/01/24 21:42:44 main.go:746: --gcp-project is missing, trying to fetch a project from boskos.
(for local runs please set --gcp-project to your dev project)
2023/01/24 21:42:44 main.go:758: provider gce, will acquire project type scalability-project from boskos
2023/01/24 21:42:44 process.go:153: Running: gcloud config set project k8s-infra-e2e-boskos-scale-22
WARNING: You do not appear to have access to project [k8s-infra-e2e-boskos-scale-22] or it does not exist.
Updated property [core/project].
2023/01/24 21:42:45 process.go:155: Step 'gcloud config set project k8s-infra-e2e-boskos-scale-22' finished in 1.000208024s
2023/01/24 21:42:45 main.go:797: Checking existing of GCP ssh keys...
2023/01/24 21:42:45 main.go:807: Checking presence of public key in k8s-infra-e2e-boskos-scale-22
2023/01/24 21:42:45 process.go:153: Running: gcloud compute --project=k8s-infra-e2e-boskos-scale-22 project-info describe
2023/01/24 21:42:47 process.go:155: Step 'gcloud compute --project=k8s-infra-e2e-boskos-scale-22 project-info describe' finished in 1.589822787s
2023/01/24 21:42:47 process.go:153: Running: make -C /home/prow/go/src/k8s.io/kubernetes quick-release
make: Entering directory '/home/prow/go/src/k8s.io/kubernetes'
+++ [0124 21:42:47] Verifying Prerequisites....
+++ [0124 21:42:47] Building Docker image kube-build:build-7a8b118a0c-5-v1.26.0-go1.19.5-bullseye.0