W1211 19:47:32.621] **************************************************************************
bootstrap.py is deprecated!
test-infra oncall does not support any job still using bootstrap.py.
Please migrate your job to podutils!
https://github.com/kubernetes/test-infra/blob/master/prow/pod-utilities.md
**************************************************************************
I1211 19:47:32.621] Args: --job=chewong-kubernetes-azure-disk-csi-driver-e2e --service-account=/etc/service-account/service-account.json --upload=gs://kubernetes-jenkins/logs --job=chewong-kubernetes-azure-disk-csi-driver-e2e --root=/go/src --service-account=/etc/service-account/service-account.json --repo=k8s.io/kubernetes=master:5e0f36705ef785a80955bd2b6412d9d227ff60da,85958:64bdba3457e8c2c32bb9b4ca1c94907edf5da3ad --upload=gs://kubernetes-upstream/pr-logs --timeout=460 --scenario=kubernetes_e2e -- --gce-ssh= --test=true --up=true --down=true --deployment=acsengine --build=quick --provider=azure --ginkgo-parallel=1 --acsengine-agentpoolcount=2 --acsengine-admin-username=azureuser '--acsengine-creds=$AZURE_CREDENTIALS' --acsengine-orchestratorRelease=1.17 --acsengine-mastervmsize=Standard_DS4_v2 --acsengine-agentvmsize=Standard_D4s_v3 --acsengine-ccm=True --aksengine-cnm=True --aksengine-deploy-custom-k8s=True --acsengine-location=westus2 '--acsengine-public-key=$AZURE_SSH_PUBLIC_KEY_FILE' --acsengine-template-url=https://gist.githubusercontent.com/chewong/7a3cc2b7c8d7af920941a8f3532291df/raw/ac446674cf47f8e463235e6a0b9e6f4548f71d51/linux-ccm.json --acsengine-download-url=https://chuwon.blob.core.windows.net/aks-engine/aks-engine-master-linux-amd64.tar.gz '--test_args=--ginkgo.flakeAttempts=2 --ginkgo.focus=disk.csi.azure.com' --timeout=420m
I1211 19:47:32.621] Bootstrap chewong-kubernetes-azure-disk-csi-driver-e2e...
I1211 19:47:32.624] Builder: fbdcc93a-1c4e-11ea-918b-16773c0c7aed
I1211 19:47:32.625] Image: gcr.io/k8s-testimages/kubekins-e2e:v20191211-04e540b-master
I1211 19:47:32.625] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/85958/chewong-kubernetes-azure-disk-csi-driver-e2e/1204850138439225344
I1211 19:47:32.625] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W1211 19:47:33.148] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I1211 19:47:33.177] process 212 exited with code 0 after 0.0m
I1211 19:47:33.177] Call:  gcloud config get-value account
I1211 19:47:33.408] process 225 exited with code 0 after 0.0m
I1211 19:47:33.408] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
I1211 19:47:33.409] Root: /go/src
I1211 19:47:33.409] cd to /go/src
I1211 19:47:33.409] Checkout: /go/src/k8s.io/kubernetes master:5e0f36705ef785a80955bd2b6412d9d227ff60da,85958:64bdba3457e8c2c32bb9b4ca1c94907edf5da3ad to /go/src/k8s.io/kubernetes
I1211 19:47:33.409] Call:  git init k8s.io/kubernetes
I1211 19:47:33.413] Initialized empty Git repository in /go/src/k8s.io/kubernetes/.git/
I1211 19:47:33.414] process 238 exited with code 0 after 0.0m
I1211 19:47:33.414] Call:  git config --local user.name 'K8S Bootstrap'
I1211 19:47:33.416] process 239 exited with code 0 after 0.0m
I1211 19:47:33.417] Call:  git config --local user.email k8s_bootstrap@localhost
I1211 19:47:33.419] process 240 exited with code 0 after 0.0m
I1211 19:47:33.419] Call:  git fetch --quiet --tags https://github.com/kubernetes/kubernetes master +refs/pull/85958/head:refs/pr/85958
I1211 19:48:43.225] process 241 exited with code 0 after 1.2m
I1211 19:48:43.225] Call:  git checkout -B test 5e0f36705ef785a80955bd2b6412d9d227ff60da
W1211 19:48:45.663] Switched to a new branch 'test'
I1211 19:48:45.672] process 252 exited with code 0 after 0.0m
I1211 19:48:45.672] Call:  git show -s --format=format:%ct HEAD
I1211 19:48:45.675] process 253 exited with code 0 after 0.0m
I1211 19:48:45.675] Call:  git merge --no-ff -m 'Merge +refs/pull/85958/head:refs/pr/85958' 64bdba3457e8c2c32bb9b4ca1c94907edf5da3ad
I1211 19:48:46.433] Merge made by the 'recursive' strategy.
I1211 19:48:46.435]  test/e2e/storage/csi_volumes.go |  1 +
I1211 19:48:46.436]  test/e2e/storage/drivers/csi.go | 90 +++++++++++++++++++++++++++++++++++++++++
I1211 19:48:46.436]  2 files changed, 91 insertions(+)
I1211 19:48:46.436] process 254 exited with code 0 after 0.0m
I1211 19:48:46.436] Configure environment...
I1211 19:48:46.437] Call:  git show -s --format=format:%ct HEAD
I1211 19:48:46.440] process 296 exited with code 0 after 0.0m
I1211 19:48:46.440] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W1211 19:48:47.171] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I1211 19:48:47.277] process 297 exited with code 0 after 0.0m
I1211 19:48:47.278] Call:  gcloud config get-value account
I1211 19:48:47.509] process 310 exited with code 0 after 0.0m
I1211 19:48:47.510] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
I1211 19:48:47.510] Call:  bash -c '
set -o errexit
set -o nounset
export KUBE_ROOT=.
source hack/lib/version.sh
kube::version::get_version_vars
echo $KUBE_GIT_VERSION
'
I1211 19:48:47.760] process 323 exited with code 0 after 0.0m
I1211 19:48:47.760] Start 1204850138439225344 at v1.18.0-alpha.0.1654+eb1a8668a7258f...
I1211 19:48:47.762] Call:  gsutil -q -h Content-Type:application/json cp /tmp/gsutil_TDBAiz gs://kubernetes-upstream/pr-logs/pull/85958/chewong-kubernetes-azure-disk-csi-driver-e2e/1204850138439225344/started.json
I1211 19:48:49.151] process 356 exited with code 0 after 0.0m
I1211 19:48:49.151] Call:  gsutil -q -h Content-Type:text/plain -h 'x-goog-meta-link: gs://kubernetes-upstream/pr-logs/pull/85958/chewong-kubernetes-azure-disk-csi-driver-e2e/1204850138439225344' cp /tmp/gsutil_wlptfa gs://kubernetes-upstream/pr-logs/directory/chewong-kubernetes-azure-disk-csi-driver-e2e/1204850138439225344.txt
I1211 19:48:50.437] process 537 exited with code 0 after 0.0m
I1211 19:48:50.438] Call:  /workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py --gce-ssh= --test=true --up=true --down=true --deployment=acsengine --build=quick --provider=azure --ginkgo-parallel=1 --acsengine-agentpoolcount=2 --acsengine-admin-username=azureuser --acsengine-creds=/etc/azure-cred/credentials --acsengine-orchestratorRelease=1.17 --acsengine-mastervmsize=Standard_DS4_v2 --acsengine-agentvmsize=Standard_D4s_v3 --acsengine-ccm=True --aksengine-cnm=True --aksengine-deploy-custom-k8s=True --acsengine-location=westus2 --acsengine-public-key=/etc/azure-ssh/azure-ssh-pub --acsengine-template-url=https://gist.githubusercontent.com/chewong/7a3cc2b7c8d7af920941a8f3532291df/raw/ac446674cf47f8e463235e6a0b9e6f4548f71d51/linux-ccm.json --acsengine-download-url=https://chuwon.blob.core.windows.net/aks-engine/aks-engine-master-linux-amd64.tar.gz '--test_args=--ginkgo.flakeAttempts=2 --ginkgo.focus=disk.csi.azure.com' --timeout=420m
W1211 19:48:50.474] starts with local mode
W1211 19:48:50.474] Environment:
W1211 19:48:50.474] ARTIFACTS=/workspace/_artifacts
W1211 19:48:50.474] AWS_SSH_PRIVATE_KEY_FILE=/root/.ssh/kube_aws_rsa
W1211 19:48:50.475] AWS_SSH_PUBLIC_KEY_FILE=/root/.ssh/kube_aws_rsa.pub
W1211 19:48:50.475] AZURE_CREDENTIALS=/etc/azure-cred/credentials
W1211 19:48:50.475] AZURE_SSH_PUBLIC_KEY_FILE=/etc/azure-ssh/azure-ssh-pub
W1211 19:48:50.475] AZ_STORAGE_CONTAINER_NAME=mystoragecontainer
W1211 19:48:50.475] BAZEL_REMOTE_CACHE_ENABLED=false
W1211 19:48:50.475] BAZEL_VERSION=0.23.2
W1211 19:48:50.475] BOOTSTRAP_MIGRATION=yes
W1211 19:48:50.475] BUILD_ID=1204850138439225344
W1211 19:48:50.476] BUILD_NUMBER=1204850138439225344
W1211 19:48:50.476] CLOUDSDK_COMPONENT_MANAGER_DISABLE_UPDATE_CHECK=true
W1211 19:48:50.476] CLOUDSDK_CONFIG=/go/src/k8s.io/kubernetes/.config/gcloud
W1211 19:48:50.476] CLOUDSDK_CORE_DISABLE_PROMPTS=1
W1211 19:48:50.476] CLOUDSDK_EXPERIMENTAL_FAST_COMPONENT_UPDATE=false
W1211 19:48:50.476] CLOUD_CONFIG=random
W1211 19:48:50.477] DECK_PORT=tcp://10.0.160.83:80
W1211 19:48:50.477] DECK_PORT_80_TCP=tcp://10.0.160.83:80
W1211 19:48:50.477] DECK_PORT_80_TCP_ADDR=10.0.160.83
W1211 19:48:50.477] DECK_PORT_80_TCP_PORT=80
W1211 19:48:50.477] DECK_PORT_80_TCP_PROTO=tcp
W1211 19:48:50.477] DECK_SERVICE_HOST=10.0.160.83
W1211 19:48:50.477] DECK_SERVICE_PORT=80
W1211 19:48:50.478] DOCKER_IN_DOCKER_ENABLED=true
W1211 19:48:50.478] DOCKER_IN_DOCKER_IPV6_ENABLED=false
W1211 19:48:50.478] GCS_ARTIFACTS_DIR=gs://kubernetes-upstream/pr-logs/pull/85958/chewong-kubernetes-azure-disk-csi-driver-e2e/1204850138439225344/artifacts
W1211 19:48:50.478] GOOGLE_APPLICATION_CREDENTIALS=/etc/service-account/service-account.json
W1211 19:48:50.478] GOPATH=/go
W1211 19:48:50.479] GO_TARBALL=go1.13.4.linux-amd64.tar.gz
W1211 19:48:50.479] HOME=/workspace
W1211 19:48:50.479] HOOK_PORT=tcp://10.0.144.133:8888
W1211 19:48:50.479] HOOK_PORT_8888_TCP=tcp://10.0.144.133:8888
W1211 19:48:50.479] HOOK_PORT_8888_TCP_ADDR=10.0.144.133
W1211 19:48:50.479] HOOK_PORT_8888_TCP_PORT=8888
W1211 19:48:50.479] HOOK_PORT_8888_TCP_PROTO=tcp
W1211 19:48:50.479] HOOK_SERVICE_HOST=10.0.144.133
W1211 19:48:50.480] HOOK_SERVICE_PORT=8888
W1211 19:48:50.480] HOSTNAME=fbdcc93a-1c4e-11ea-918b-16773c0c7aed
W1211 19:48:50.480] IMAGE=gcr.io/k8s-testimages/kubekins-e2e:v20191211-04e540b-master
W1211 19:48:50.480] INSTANCE_PREFIX=bootstrap-e2e
W1211 19:48:50.480] JENKINS_GCE_SSH_PRIVATE_KEY_FILE=/root/.ssh/google_compute_engine
W1211 19:48:50.480] JENKINS_GCE_SSH_PUBLIC_KEY_FILE=/root/.ssh/google_compute_engine.pub
W1211 19:48:50.480] JOB_NAME=chewong-kubernetes-azure-disk-csi-driver-e2e
W1211 19:48:50.481] JOB_SPEC={"type":"presubmit","job":"chewong-kubernetes-azure-disk-csi-driver-e2e","buildid":"1204850138439225344","prowjobid":"fbdcc93a-1c4e-11ea-918b-16773c0c7aed","refs":{"org":"Azure","repo":"kubernetes","repo_link":"https://github.com/Azure/kubernetes","base_ref":"master","base_sha":"5e0f36705ef785a80955bd2b6412d9d227ff60da","base_link":"https://github.com/Azure/kubernetes/commit/5e0f36705ef785a80955bd2b6412d9d227ff60da","pulls":[{"number":113,"author":"chewong","sha":"879465972041635fd7bc8269da49153b67e63822","link":"https://github.com/Azure/kubernetes/pull/113","commit_link":"https://github.com/Azure/kubernetes/pull/113/commits/879465972041635fd7bc8269da49153b67e63822","author_link":"https://github.com/chewong"}]}}
W1211 19:48:50.481] JOB_TYPE=presubmit
W1211 19:48:50.481] KUBERNETES_CONFORMANCE_PROVIDER=azure
W1211 19:48:50.481] KUBERNETES_PORT=tcp://10.0.0.1:443
W1211 19:48:50.482] KUBERNETES_PORT_443_TCP=tcp://10.0.0.1:443
W1211 19:48:50.482] KUBERNETES_PORT_443_TCP_ADDR=10.0.0.1
W1211 19:48:50.482] KUBERNETES_PORT_443_TCP_PORT=443
W1211 19:48:50.482] KUBERNETES_PORT_443_TCP_PROTO=tcp
W1211 19:48:50.482] KUBERNETES_SERVICE_HOST=10.0.0.1
W1211 19:48:50.482] KUBERNETES_SERVICE_PORT=443
W1211 19:48:50.482] KUBERNETES_SERVICE_PORT_HTTPS=443
W1211 19:48:50.482] KUBETEST_IN_DOCKER=true
W1211 19:48:50.483] KUBETEST_MANUAL_DUMP=y
W1211 19:48:50.483] KUBE_AWS_INSTANCE_PREFIX=bootstrap-e2e
W1211 19:48:50.483] KUBE_GCE_INSTANCE_PREFIX=bootstrap-e2e
W1211 19:48:50.483] KUBE_VERBOSE=0
W1211 19:48:50.483] NODE_NAME=fbdcc93a-1c4e-11ea-918b-16773c0c7aed
W1211 19:48:50.483] PATH=/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
W1211 19:48:50.483] PROW_JOB_ID=fbdcc93a-1c4e-11ea-918b-16773c0c7aed
W1211 19:48:50.483] PULL_BASE_REF=master
W1211 19:48:50.484] PULL_BASE_SHA=5e0f36705ef785a80955bd2b6412d9d227ff60da
W1211 19:48:50.484] PULL_NUMBER=113
W1211 19:48:50.484] PULL_PULL_SHA=879465972041635fd7bc8269da49153b67e63822
W1211 19:48:50.484] PULL_REFS=master:5e0f36705ef785a80955bd2b6412d9d227ff60da,113:879465972041635fd7bc8269da49153b67e63822
W1211 19:48:50.484] PWD=/workspace
W1211 19:48:50.484] REGISTRY=k8sprowinternal.azurecr.io
W1211 19:48:50.484] REPO_NAME=kubernetes
W1211 19:48:50.484] REPO_OWNER=Azure
W1211 19:48:50.485] SHLVL=2
W1211 19:48:50.485] SOURCE_DATE_EPOCH=1576088263
W1211 19:48:50.485] TERM=xterm
W1211 19:48:50.485] TIDE_PORT=tcp://10.0.180.53:80
W1211 19:48:50.485] TIDE_PORT_80_TCP=tcp://10.0.180.53:80
W1211 19:48:50.485] TIDE_PORT_80_TCP_ADDR=10.0.180.53
W1211 19:48:50.485] TIDE_PORT_80_TCP_PORT=80
W1211 19:48:50.486] TIDE_PORT_80_TCP_PROTO=tcp
W1211 19:48:50.486] TIDE_SERVICE_HOST=10.0.180.53
W1211 19:48:50.486] TIDE_SERVICE_PORT=80
W1211 19:48:50.486] WORKSPACE=/workspace
W1211 19:48:50.486] _=./test-infra/jenkins/bootstrap.py
W1211 19:48:50.487] Run: ('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=quick', '--up', '--down', '--test', '--deployment=acsengine', '--provider=azure', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--ginkgo-parallel=1', '--acsengine-agentpoolcount=2', '--acsengine-admin-username=azureuser', '--acsengine-creds=/etc/azure-cred/credentials', '--acsengine-orchestratorRelease=1.17', '--acsengine-mastervmsize=Standard_DS4_v2', '--acsengine-agentvmsize=Standard_D4s_v3', '--acsengine-ccm=True', '--aksengine-cnm=True', '--aksengine-deploy-custom-k8s=True', '--acsengine-location=westus2', '--acsengine-public-key=/etc/azure-ssh/azure-ssh-pub', '--acsengine-template-url=https://gist.githubusercontent.com/chewong/7a3cc2b7c8d7af920941a8f3532291df/raw/ac446674cf47f8e463235e6a0b9e6f4548f71d51/linux-ccm.json', '--acsengine-download-url=https://chuwon.blob.core.windows.net/aks-engine/aks-engine-master-linux-amd64.tar.gz', '--test_args=--ginkgo.flakeAttempts=2 --ginkgo.focus=disk.csi.azure.com', '--timeout=420m')
W1211 19:48:50.512] 2019/12/11 19:48:50 main.go:332: Limiting testing to 7h0m0s
W1211 19:48:50.512] 2019/12/11 19:48:50 azure.go:274: Reading credentials file /etc/azure-cred/credentials
W1211 19:48:50.512] 2019/12/11 19:48:50 azure.go:823: CWD /go/src/k8s.io/kubernetes
W1211 19:48:50.512] 2019/12/11 19:48:50 azure.go:842: Attempting Docker login with azure cred.
W1211 19:48:50.677] 2019/12/11 19:48:50 azure.go:851: Docker login success.
W1211 19:48:50.678] 2019/12/11 19:48:50 process.go:153: Running: make -C /go/src/k8s.io/kubernetes quick-release
I1211 19:48:50.778] make: Entering directory '/go/src/k8s.io/kubernetes'
I1211 19:48:50.779] +++ [1211 19:48:50] Verifying Prerequisites....
I1211 19:48:51.066] +++ [1211 19:48:51] Building Docker image kube-build:build-eca70c456c-5-v1.13.4-1
I1211 19:52:48.586] +++ [1211 19:52:48] Creating data container kube-build-data-eca70c456c-5-v1.13.4-1
I1211 19:53:39.253] +++ [1211 19:53:39] Syncing sources to container
I1211 19:53:50.858] +++ [1211 19:53:50] Running build command...
I1211 19:54:00.127] +++ [1211 19:54:00] Building go targets for linux/amd64:
I1211 19:54:00.127]     ./vendor/k8s.io/code-generator/cmd/deepcopy-gen
I1211 19:54:08.277] +++ [1211 19:54:08] Building go targets for linux/amd64:
I1211 19:54:08.277]     ./vendor/k8s.io/code-generator/cmd/defaulter-gen
I1211 19:54:14.922] +++ [1211 19:54:14] Building go targets for linux/amd64:
I1211 19:54:14.922]     ./vendor/k8s.io/code-generator/cmd/conversion-gen
I1211 19:54:25.894] +++ [1211 19:54:25] Building go targets for linux/amd64:
I1211 19:54:25.894]     ./vendor/k8s.io/kube-openapi/cmd/openapi-gen
I1211 19:54:38.743] +++ [1211 19:54:38] Building go targets for linux/amd64:
I1211 19:54:38.743]     ./vendor/github.com/go-bindata/go-bindata/go-bindata
I1211 19:54:40.468] +++ [1211 19:54:40] Building go targets for linux/amd64:
I1211 19:54:40.468]     cmd/kube-proxy
I1211 19:54:40.468]     cmd/kube-apiserver
I1211 19:54:40.468]     cmd/kube-controller-manager
I1211 19:54:40.468]     cmd/kubelet
I1211 19:54:40.468]     cmd/kubeadm
I1211 19:54:40.469]     cmd/kube-scheduler
I1211 19:54:40.469]     vendor/k8s.io/apiextensions-apiserver
I1211 19:54:40.469]     cluster/gce/gci/mounter
I1211 19:59:46.984] +++ [1211 19:59:46] Building go targets for linux/amd64:
I1211 19:59:46.984]     cmd/kube-proxy
I1211 19:59:46.984]     cmd/kubeadm
I1211 19:59:46.985]     cmd/kubelet
I1211 19:59:59.595] +++ [1211 19:59:59] Building go targets for linux/amd64:
I1211 19:59:59.596]     cmd/kubectl
I1211 20:00:21.359] +++ [1211 20:00:21] Building go targets for linux/amd64:
I1211 20:00:21.359]     cmd/gendocs
I1211 20:00:21.359]     cmd/genkubedocs
I1211 20:00:21.360]     cmd/genman
I1211 20:00:21.360]     cmd/genyaml
I1211 20:00:21.360]     cmd/genswaggertypedocs
I1211 20:00:21.360]     cmd/linkcheck
I1211 20:00:21.360]     vendor/github.com/onsi/ginkgo/ginkgo
I1211 20:00:21.361]     test/e2e/e2e.test
I1211 20:00:21.361]     cluster/images/conformance/go-runner
I1211 20:03:47.972] +++ [1211 20:03:47] Building go targets for linux/amd64:
I1211 20:03:47.972]     cmd/kubemark
I1211 20:03:47.972]     vendor/github.com/onsi/ginkgo/ginkgo
I1211 20:03:47.972]     test/e2e_node/e2e_node.test
I1211 20:05:06.780] +++ [1211 20:05:06] Syncing out of container
I1211 20:05:58.057] +++ [1211 20:05:58] Building tarball: manifests
I1211 20:05:58.058] +++ [1211 20:05:58] Building tarball: src
I1211 20:05:58.060] +++ [1211 20:05:58] Starting tarball: client linux-amd64
I1211 20:05:58.063] +++ [1211 20:05:58] Waiting on tarballs
I1211 20:06:04.683] +++ [1211 20:06:04] Building tarball: node linux-amd64
I1211 20:06:04.683] +++ [1211 20:06:04] Building images: linux-amd64
I1211 20:06:05.155] +++ [1211 20:06:05] Starting docker build for image: kube-apiserver-amd64
I1211 20:06:05.160] +++ [1211 20:06:05] Starting docker build for image: kube-controller-manager-amd64
I1211 20:06:05.167] +++ [1211 20:06:05] Starting docker build for image: kube-scheduler-amd64
I1211 20:06:05.171] +++ [1211 20:06:05] Starting docker build for image: kube-proxy-amd64
I1211 20:06:05.184] +++ [1211 20:06:05] Building conformance image for arch: amd64
I1211 20:06:05.203] +++ [1211 20:06:05] Building hyperkube image for arch: amd64
I1211 20:07:07.115] +++ [1211 20:07:07] Tagging docker image k8s.gcr.io/kube-scheduler-amd64:v1.18.0-alpha.0.1654_eb1a8668a7258f as k8sprowinternal.azurecr.io/kube-scheduler-amd64:azure-e2e-1204850138439225344
I1211 20:07:07.138] +++ [1211 20:07:07] Tagging docker image k8s.gcr.io/kube-apiserver-amd64:v1.18.0-alpha.0.1654_eb1a8668a7258f as k8sprowinternal.azurecr.io/kube-apiserver-amd64:azure-e2e-1204850138439225344
I1211 20:07:07.141] +++ [1211 20:07:07] Tagging docker image k8s.gcr.io/kube-controller-manager-amd64:v1.18.0-alpha.0.1654_eb1a8668a7258f as k8sprowinternal.azurecr.io/kube-controller-manager-amd64:azure-e2e-1204850138439225344
I1211 20:07:27.178] +++ [1211 20:07:27] Tagging docker image k8s.gcr.io/kube-proxy-amd64:v1.18.0-alpha.0.1654_eb1a8668a7258f as k8sprowinternal.azurecr.io/kube-proxy-amd64:azure-e2e-1204850138439225344
I1211 20:07:27.435] +++ [1211 20:07:27] Deleting docker image k8s.gcr.io/kube-scheduler-amd64:v1.18.0-alpha.0.1654_eb1a8668a7258f
I1211 20:07:27.790] +++ [1211 20:07:27] Deleting docker image k8s.gcr.io/kube-apiserver-amd64:v1.18.0-alpha.0.1654_eb1a8668a7258f
I1211 20:07:27.842] +++ [1211 20:07:27] Deleting docker image k8s.gcr.io/kube-controller-manager-amd64:v1.18.0-alpha.0.1654_eb1a8668a7258f
I1211 20:08:04.667] +++ [1211 20:08:04] Deleting docker image k8s.gcr.io/kube-proxy-amd64:v1.18.0-alpha.0.1654_eb1a8668a7258f
I1211 20:08:30.135] +++ [1211 20:08:30] Deleting hyperkube image k8s.gcr.io/hyperkube-amd64:v1.18.0-alpha.0.1654_eb1a8668a7258f
I1211 20:09:06.550] +++ [1211 20:09:06] Deleting conformance image k8s.gcr.io/conformance-amd64:v1.18.0-alpha.0.1654_eb1a8668a7258f
I1211 20:09:06.919] +++ [1211 20:09:06] Docker builds done
I1211 20:09:06.923] +++ [1211 20:09:06] Building tarball: server linux-amd64
I1211 20:10:21.313] +++ [1211 20:10:21] Building tarball: final
I1211 20:10:21.600] +++ [1211 20:10:21] Starting tarball: test linux-amd64
I1211 20:10:21.600] +++ [1211 20:10:21] Waiting on test tarballs
I1211 20:11:09.279] +++ [1211 20:11:09] Building tarball: test portable
I1211 20:11:09.355] make: Leaving directory '/go/src/k8s.io/kubernetes'
W1211 20:11:09.455] 2019/12/11 20:11:09 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes quick-release' finished in 22m18.677376763s
W1211 20:11:09.456] 2019/12/11 20:11:09 azure.go:856: Pushing docker image k8sprowinternal.azurecr.io/kube-apiserver-amd64:azure-e2e-1204850138439225344
W1211 20:11:23.677] 2019/12/11 20:11:23 azure.go:856: Pushing docker image k8sprowinternal.azurecr.io/kube-controller-manager-amd64:azure-e2e-1204850138439225344
W1211 20:11:32.600] 2019/12/11 20:11:32 azure.go:856: Pushing docker image k8sprowinternal.azurecr.io/kube-proxy-amd64:azure-e2e-1204850138439225344
W1211 20:11:36.838] 2019/12/11 20:11:36 azure.go:856: Pushing docker image k8sprowinternal.azurecr.io/kube-scheduler-amd64:azure-e2e-1204850138439225344
W1211 20:11:41.732] 2019/12/11 20:11:41 azure.go:1125: Renaming /go/src/k8s.io/kubernetes/_output/release-tars/kubernetes-node-linux-amd64.tar.gz to /go/src/k8s.io/kubernetes/_output/release-tars/kubernetes-node-linux-amd64-1204850138439225344.tar.gz
W1211 20:11:44.104] 2019/12/11 20:11:44 azure.go:951: Uploaded /go/src/k8s.io/kubernetes/_output/release-tars/kubernetes-node-linux-amd64-1204850138439225344.tar.gz to https://upstreamprowstorageacct.blob.core.windows.net/mystoragecontainer/kubernetes-node-linux-amd64-1204850138439225344.tar.gz
W1211 20:11:44.105] 2019/12/11 20:11:44 util.go:265: Flushing memory.
W1211 20:11:47.215] 2019/12/11 20:11:47 azure.go:1137: Deleting resource group: kubetest-40e75f62-1c4f-11ea-9bd8-02420587b4c3.
W1211 20:11:47.394] 2019/12/11 20:11:47 azure.go:870: Building cloud controller manager and cloud node manager.
W1211 20:11:47.395] 2019/12/11 20:11:47 util.go:56: Warning: Couldn't find directory src/sigs.k8s.io/cloud-provider-azure under any of GOPATH /go, defaulting to /go/src/k8s.io/cloud-provider-azure
W1211 20:11:47.395] 2019/12/11 20:11:47 process.go:153: Running: make -C /go/src/k8s.io/cloud-provider-azure image push
W1211 20:11:47.396] make: *** /go/src/k8s.io/cloud-provider-azure: No such file or directory.  Stop.
W1211 20:11:47.396] 2019/12/11 20:11:47 process.go:155: Step 'make -C /go/src/k8s.io/cloud-provider-azure image push' finished in 1.590213ms
W1211 20:11:47.396] 2019/12/11 20:11:47 util.go:56: Warning: Couldn't find directory src/sigs.k8s.io/cloud-provider-azure under any of GOPATH /go, defaulting to /go/src/k8s.io/cloud-provider-azure
W1211 20:11:47.397] 2019/12/11 20:11:47 azure.go:1137: Deleting resource group: kubetest-40e75f62-1c4f-11ea-9bd8-02420587b4c3.
W1211 20:11:47.407] 2019/12/11 20:11:47 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml.
W1211 20:11:47.408] 2019/12/11 20:11:47 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"
W1211 20:11:48.657] 2019/12/11 20:11:48 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 1.249866606s
W1211 20:11:48.658] 2019/12/11 20:11:48 main.go:319: Something went wrong: starting e2e cluster: error building Azure cloud components: error during make -C /go/src/k8s.io/cloud-provider-azure image push: exit status 2
W1211 20:11:48.662] Traceback (most recent call last):
W1211 20:11:48.665]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in <module>
W1211 20:11:48.665]     main(parse_args())
W1211 20:11:48.665]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main
W1211 20:11:48.665]     mode.start(runner_args)
W1211 20:11:48.666]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start
W1211 20:11:48.666]     check_env(env, self.command, *args)
W1211 20:11:48.666]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env
W1211 20:11:48.667]     subprocess.check_call(cmd, env=env)
W1211 20:11:48.667]   File "/usr/lib/python2.7/subprocess.py", line 190, in check_call
W1211 20:11:48.667]     raise CalledProcessError(retcode, cmd)
W1211 20:11:48.668] subprocess.CalledProcessError: Command '('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=quick', '--up', '--down', '--test', '--deployment=acsengine', '--provider=azure', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--ginkgo-parallel=1', '--acsengine-agentpoolcount=2', '--acsengine-admin-username=azureuser', '--acsengine-creds=/etc/azure-cred/credentials', '--acsengine-orchestratorRelease=1.17', '--acsengine-mastervmsize=Standard_DS4_v2', '--acsengine-agentvmsize=Standard_D4s_v3', '--acsengine-ccm=True', '--aksengine-cnm=True', '--aksengine-deploy-custom-k8s=True', '--acsengine-location=westus2', '--acsengine-public-key=/etc/azure-ssh/azure-ssh-pub', '--acsengine-template-url=https://gist.githubusercontent.com/chewong/7a3cc2b7c8d7af920941a8f3532291df/raw/ac446674cf47f8e463235e6a0b9e6f4548f71d51/linux-ccm.json', '--acsengine-download-url=https://chuwon.blob.core.windows.net/aks-engine/aks-engine-master-linux-amd64.tar.gz', '--test_args=--ginkgo.flakeAttempts=2 --ginkgo.focus=disk.csi.azure.com', '--timeout=420m')' returned non-zero exit status 1
E1211 20:11:48.673] Command failed
I1211 20:11:48.673] process 718 exited with code 1 after 23.0m
E1211 20:11:48.673] FAIL: chewong-kubernetes-azure-disk-csi-driver-e2e
I1211 20:11:48.673] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W1211 20:11:49.327] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I1211 20:11:49.359] process 24133 exited with code 0 after 0.0m
I1211 20:11:49.360] Call:  gcloud config get-value account
I1211 20:11:49.596] process 24146 exited with code 0 after 0.0m
I1211 20:11:49.597] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
I1211 20:11:49.597] Upload result and artifacts...
I1211 20:11:49.597] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/85958/chewong-kubernetes-azure-disk-csi-driver-e2e/1204850138439225344
I1211 20:11:49.597] Call:  gsutil ls gs://kubernetes-upstream/pr-logs/pull/85958/chewong-kubernetes-azure-disk-csi-driver-e2e/1204850138439225344/artifacts
W1211 20:11:50.524] CommandException: One or more URLs matched no objects.
E1211 20:11:50.596] Command failed
I1211 20:11:50.596] process 24159 exited with code 1 after 0.0m
W1211 20:11:50.596] Remote dir gs://kubernetes-upstream/pr-logs/pull/85958/chewong-kubernetes-azure-disk-csi-driver-e2e/1204850138439225344/artifacts not exist yet
I1211 20:11:50.596] Call:  gsutil -m -q -o GSUtil:use_magicfile=True cp -r -c -z log,txt,xml /workspace/_artifacts gs://kubernetes-upstream/pr-logs/pull/85958/chewong-kubernetes-azure-disk-csi-driver-e2e/1204850138439225344/artifacts
I1211 20:11:52.062] process 24304 exited with code 0 after 0.0m
I1211 20:11:52.063] Call:  git rev-parse HEAD
I1211 20:11:52.065] process 24831 exited with code 0 after 0.0m
I1211 20:11:52.066] Call:  git rev-parse HEAD
I1211 20:11:52.072] process 24832 exited with code 0 after 0.0m
I1211 20:11:52.072] Call:  gsutil stat gs://kubernetes-upstream/pr-logs/directory/chewong-kubernetes-azure-disk-csi-driver-e2e/jobResultsCache.json
I1211 20:11:52.831] process 24833 exited with code 0 after 0.0m
I1211 20:11:52.831] Call:  gsutil -q cat 'gs://kubernetes-upstream/pr-logs/directory/chewong-kubernetes-azure-disk-csi-driver-e2e/jobResultsCache.json#1576093224700904'
I1211 20:11:53.966] process 24978 exited with code 0 after 0.0m
I1211 20:11:53.967] Call:  gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1576093224700904 cp /tmp/gsutil_ayRUqi gs://kubernetes-upstream/pr-logs/directory/chewong-kubernetes-azure-disk-csi-driver-e2e/jobResultsCache.json
I1211 20:11:55.145] process 25125 exited with code 0 after 0.0m
I1211 20:11:55.145] Call:  gsutil stat gs://kubernetes-upstream/pr-logs/pull/85958/chewong-kubernetes-azure-disk-csi-driver-e2e/jobResultsCache.json
I1211 20:11:56.040] process 25306 exited with code 0 after 0.0m
I1211 20:11:56.041] Call:  gsutil -q cat 'gs://kubernetes-upstream/pr-logs/pull/85958/chewong-kubernetes-azure-disk-csi-driver-e2e/jobResultsCache.json#1576093227585058'
I1211 20:11:57.146] process 25451 exited with code 0 after 0.0m
I1211 20:11:57.147] Call:  gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1576093227585058 cp /tmp/gsutil_GFfMl3 gs://kubernetes-upstream/pr-logs/pull/85958/chewong-kubernetes-azure-disk-csi-driver-e2e/jobResultsCache.json
I1211 20:11:58.324] process 25598 exited with code 0 after 0.0m
I1211 20:11:58.325] Call:  gsutil -q -h Content-Type:application/json cp /tmp/gsutil_xySIKx gs://kubernetes-upstream/pr-logs/pull/85958/chewong-kubernetes-azure-disk-csi-driver-e2e/1204850138439225344/finished.json
I1211 20:11:59.662] process 25779 exited with code 0 after 0.0m
I1211 20:11:59.662] Call:  gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_L0V4J3 gs://kubernetes-upstream/pr-logs/pull/85958/chewong-kubernetes-azure-disk-csi-driver-e2e/latest-build.txt
I1211 20:12:00.926] process 25960 exited with code 0 after 0.0m
I1211 20:12:00.927] Call:  gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_wz3IM2 gs://kubernetes-upstream/pr-logs/directory/chewong-kubernetes-azure-disk-csi-driver-e2e/latest-build.txt
I1211 20:12:02.043] process 26141 exited with code 0 after 0.0m