W1017 19:31:29.265] **************************************************************************
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
**************************************************************************
I1017 19:31:29.265] Args: --job=chewong-e2e-ccm --service-account=/etc/service-account/service-account.json --upload=gs://kubernetes-jenkins/logs --job=chewong-e2e-ccm --repo=k8s.io/kubernetes=release-1.16 --repo=k8s.io/cloud-provider-azure=master:c470e6f36d76e5a565478fcba22118c06bc1548f,248:84546d4184c381a062c9b0a29a987390dc47f2ce --root=/go/src --service-account=/etc/service-account/service-account.json --timeout=450 --upload=gs://kubernetes-upstream/pr-logs --scenario=kubernetes_e2e -- --gce-ssh= --test=true --up=true --down=true --deployment=acsengine --build=quick --provider=skeleton --ginkgo-parallel=30 --test-ccm=True --acsengine-agentpoolcount=1 '--acsengine-admin-username=$AZURE_SSH_USER' '--acsengine-creds=$AZURE_CREDENTIALS' --acsengine-orchestratorRelease=1.16 --acsengine-mastervmsize=Standard_DS2_v2 --acsengine-agentvmsize=Standard_D4s_v3 --acsengine-hyperkube=True --acsengine-ccm=True --acsengine-location=eastus2 '--acsengine-public-key=$AZURE_SSH_PUBLIC_KEY_FILE' --acsengine-template-url=https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json --acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz --timeout=420m
I1017 19:31:29.265] Bootstrap chewong-e2e-ccm...
I1017 19:31:29.269] Builder: a2358d18-f114-11e9-b3d3-b20db476995a
I1017 19:31:29.269] Image: chewong/kubekins-e2e:v20191017-test-3
I1017 19:31:29.269] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184914779353911296
I1017 19:31:29.269] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W1017 19:31:29.787] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I1017 19:31:29.821] process 217 exited with code 0 after 0.0m
I1017 19:31:29.821] Call:  gcloud config get-value account
I1017 19:31:30.058] process 229 exited with code 0 after 0.0m
I1017 19:31:30.059] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
I1017 19:31:30.059] Root: /go/src
I1017 19:31:30.059] cd to /go/src
I1017 19:31:30.059] Checkout: /go/src/k8s.io/kubernetes release-1.16 to /go/src/k8s.io/kubernetes
I1017 19:31:30.060] Call:  git init k8s.io/kubernetes
I1017 19:31:30.064] Initialized empty Git repository in /go/src/k8s.io/kubernetes/.git/
I1017 19:31:30.065] process 241 exited with code 0 after 0.0m
I1017 19:31:30.065] Call:  git config --local user.name 'K8S Bootstrap'
I1017 19:31:30.067] process 242 exited with code 0 after 0.0m
I1017 19:31:30.067] Call:  git config --local user.email k8s_bootstrap@localhost
I1017 19:31:30.070] process 243 exited with code 0 after 0.0m
I1017 19:31:30.070] Call:  git fetch --quiet --tags https://github.com/kubernetes/kubernetes release-1.16
I1017 19:32:22.367] process 244 exited with code 0 after 0.9m
I1017 19:32:22.367] Call:  git checkout -B test FETCH_HEAD
W1017 19:32:24.476] Switched to a new branch 'test'
I1017 19:32:24.487] process 259 exited with code 0 after 0.0m
I1017 19:32:24.487] Call:  git show -s --format=format:%ct HEAD
I1017 19:32:24.491] process 260 exited with code 0 after 0.0m
I1017 19:32:24.491] Checkout: /go/src/k8s.io/cloud-provider-azure master:c470e6f36d76e5a565478fcba22118c06bc1548f,248:84546d4184c381a062c9b0a29a987390dc47f2ce to /go/src/k8s.io/cloud-provider-azure
I1017 19:32:24.491] Call:  git init k8s.io/cloud-provider-azure
I1017 19:32:24.495] Initialized empty Git repository in /go/src/k8s.io/cloud-provider-azure/.git/
I1017 19:32:24.495] process 261 exited with code 0 after 0.0m
I1017 19:32:24.495] Call:  git config --local user.name 'K8S Bootstrap'
I1017 19:32:24.497] process 262 exited with code 0 after 0.0m
I1017 19:32:24.498] Call:  git config --local user.email k8s_bootstrap@localhost
I1017 19:32:24.500] process 263 exited with code 0 after 0.0m
I1017 19:32:24.500] Call:  git fetch --quiet --tags https://github.com/kubernetes/cloud-provider-azure master +refs/pull/248/head:refs/pr/248
I1017 19:32:26.043] process 264 exited with code 0 after 0.0m
I1017 19:32:26.044] Call:  git checkout -B test c470e6f36d76e5a565478fcba22118c06bc1548f
W1017 19:32:26.464] Switched to a new branch 'test'
I1017 19:32:26.467] process 276 exited with code 0 after 0.0m
I1017 19:32:26.467] Call:  git show -s --format=format:%ct HEAD
I1017 19:32:26.470] process 277 exited with code 0 after 0.0m
I1017 19:32:26.470] Call:  git merge --no-ff -m 'Merge +refs/pull/248/head:refs/pr/248' 84546d4184c381a062c9b0a29a987390dc47f2ce
I1017 19:32:26.950] Merge made by the 'recursive' strategy.
I1017 19:32:26.951]  hack/log-dump.sh | 171 +++++++++++++++++++++++++++++++++++++++++++++++++++++++
I1017 19:32:26.952]  1 file changed, 171 insertions(+)
I1017 19:32:26.952]  create mode 100755 hack/log-dump.sh
I1017 19:32:26.952] process 278 exited with code 0 after 0.0m
I1017 19:32:26.952] Configure environment...
I1017 19:32:26.953] Call:  git show -s --format=format:%ct HEAD
I1017 19:32:26.956] process 280 exited with code 0 after 0.0m
I1017 19:32:26.956] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W1017 19:32:27.627] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I1017 19:32:27.735] process 281 exited with code 0 after 0.0m
I1017 19:32:27.735] Call:  gcloud config get-value account
I1017 19:32:27.967] process 293 exited with code 0 after 0.0m
I1017 19:32:27.968] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
I1017 19:32:27.968] 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
'
I1017 19:32:28.313] process 305 exited with code 0 after 0.0m
I1017 19:32:28.314] Start 1184914779353911296 at v1.16.3-beta.0.11+0d9472c2ffccc1...
I1017 19:32:28.316] Call:  gsutil -q -h Content-Type:application/json cp /tmp/gsutil_ccY5Jd gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184914779353911296/started.json
I1017 19:32:29.793] process 338 exited with code 0 after 0.0m
I1017 19:32:29.794] Call:  gsutil -q -h Content-Type:text/plain -h 'x-goog-meta-link: gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184914779353911296' cp /tmp/gsutil_ZCXF5G gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/1184914779353911296.txt
I1017 19:32:31.148] process 516 exited with code 0 after 0.0m
I1017 19:32:31.149] Call:  /workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py --gce-ssh= --test=true --up=true --down=true --deployment=acsengine --build=quick --provider=skeleton --ginkgo-parallel=30 --test-ccm=True --acsengine-agentpoolcount=1 --acsengine-admin-username=azureuser --acsengine-creds=/etc/azure-cred/credentials --acsengine-orchestratorRelease=1.16 --acsengine-mastervmsize=Standard_DS2_v2 --acsengine-agentvmsize=Standard_D4s_v3 --acsengine-hyperkube=True --acsengine-ccm=True --acsengine-location=eastus2 --acsengine-public-key=/etc/ssh-key-secret/ssh-public --acsengine-template-url=https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json --acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz --timeout=420m
W1017 19:32:31.187] starts with local mode
W1017 19:32:31.187] Environment:
W1017 19:32:31.188] ARTIFACTS=/workspace/_artifacts
W1017 19:32:31.188] AWS_SSH_PRIVATE_KEY_FILE=/root/.ssh/kube_aws_rsa
W1017 19:32:31.188] AWS_SSH_PUBLIC_KEY_FILE=/root/.ssh/kube_aws_rsa.pub
W1017 19:32:31.188] AZURE_CREDENTIALS=/etc/azure-cred/credentials
W1017 19:32:31.188] AZURE_SSH_PRIVATE_KEY_FILE=/etc/ssh-key-secret/ssh-private
W1017 19:32:31.188] AZURE_SSH_PUBLIC_KEY_FILE=/etc/ssh-key-secret/ssh-public
W1017 19:32:31.188] AZURE_SSH_USER=azureuser
W1017 19:32:31.189] AZ_STORAGE_CONTAINER_NAME=mystoragecontainer
W1017 19:32:31.189] BAZEL_REMOTE_CACHE_ENABLED=false
W1017 19:32:31.189] BAZEL_VERSION=0.23.2
W1017 19:32:31.189] BOOTSTRAP_MIGRATION=yes
W1017 19:32:31.189] BUILD_ID=1184914779353911296
W1017 19:32:31.189] BUILD_NUMBER=1184914779353911296
W1017 19:32:31.189] CLOUDSDK_COMPONENT_MANAGER_DISABLE_UPDATE_CHECK=true
W1017 19:32:31.190] CLOUDSDK_CONFIG=/go/src/k8s.io/kubernetes/.config/gcloud
W1017 19:32:31.190] CLOUDSDK_CORE_DISABLE_PROMPTS=1
W1017 19:32:31.190] CLOUDSDK_EXPERIMENTAL_FAST_COMPONENT_UPDATE=false
W1017 19:32:31.190] CLOUD_CONFIG=random
W1017 19:32:31.190] DECK_PORT=tcp://10.0.160.83:80
W1017 19:32:31.190] DECK_PORT_80_TCP=tcp://10.0.160.83:80
W1017 19:32:31.191] DECK_PORT_80_TCP_ADDR=10.0.160.83
W1017 19:32:31.191] DECK_PORT_80_TCP_PORT=80
W1017 19:32:31.191] DECK_PORT_80_TCP_PROTO=tcp
W1017 19:32:31.191] DECK_SERVICE_HOST=10.0.160.83
W1017 19:32:31.191] DECK_SERVICE_PORT=80
W1017 19:32:31.191] DOCKER_IN_DOCKER_ENABLED=true
W1017 19:32:31.191] DOCKER_IN_DOCKER_IPV6_ENABLED=false
W1017 19:32:31.192] GCS_ARTIFACTS_DIR=gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184914779353911296/artifacts
W1017 19:32:31.192] GOOGLE_APPLICATION_CREDENTIALS=/etc/service-account/service-account.json
W1017 19:32:31.192] GOPATH=/go
W1017 19:32:31.192] GO_TARBALL=go1.12.10.linux-amd64.tar.gz
W1017 19:32:31.192] HOME=/workspace
W1017 19:32:31.193] HOOK_PORT=tcp://10.0.144.133:8888
W1017 19:32:31.194] HOOK_PORT_8888_TCP=tcp://10.0.144.133:8888
W1017 19:32:31.196] HOOK_PORT_8888_TCP_ADDR=10.0.144.133
W1017 19:32:31.196] HOOK_PORT_8888_TCP_PORT=8888
W1017 19:32:31.196] HOOK_PORT_8888_TCP_PROTO=tcp
W1017 19:32:31.196] HOOK_SERVICE_HOST=10.0.144.133
W1017 19:32:31.196] HOOK_SERVICE_PORT=8888
W1017 19:32:31.196] HOSTNAME=a2358d18-f114-11e9-b3d3-b20db476995a
W1017 19:32:31.196] IMAGE=chewong/kubekins-e2e:v20191017-test-3
W1017 19:32:31.197] INSTANCE_PREFIX=bootstrap-e2e
W1017 19:32:31.197] JENKINS_GCE_SSH_PRIVATE_KEY_FILE=/etc/ssh-key-secret/ssh-private
W1017 19:32:31.197] JENKINS_GCE_SSH_PUBLIC_KEY_FILE=/etc/ssh-key-secret/ssh-public
W1017 19:32:31.197] JOB_NAME=chewong-e2e-ccm
W1017 19:32:31.198] JOB_SPEC={"type":"presubmit","job":"chewong-e2e-ccm","buildid":"1184914779353911296","prowjobid":"a2358d18-f114-11e9-b3d3-b20db476995a","refs":{"org":"Azure","repo":"kubernetes","repo_link":"https://github.com/Azure/kubernetes","base_ref":"master","base_sha":"37fca51d74a81df3b6c8b6df5b644e333acd7274","base_link":"https://github.com/Azure/kubernetes/commit/37fca51d74a81df3b6c8b6df5b644e333acd7274","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"}]}}
W1017 19:32:31.198] JOB_TYPE=presubmit
W1017 19:32:31.198] KUBERNETES_PORT=tcp://10.0.0.1:443
W1017 19:32:31.198] KUBERNETES_PORT_443_TCP=tcp://10.0.0.1:443
W1017 19:32:31.198] KUBERNETES_PORT_443_TCP_ADDR=10.0.0.1
W1017 19:32:31.198] KUBERNETES_PORT_443_TCP_PORT=443
W1017 19:32:31.198] KUBERNETES_PORT_443_TCP_PROTO=tcp
W1017 19:32:31.199] KUBERNETES_SERVICE_HOST=10.0.0.1
W1017 19:32:31.199] KUBERNETES_SERVICE_PORT=443
W1017 19:32:31.199] KUBERNETES_SERVICE_PORT_HTTPS=443
W1017 19:32:31.199] KUBETEST_IN_DOCKER=true
W1017 19:32:31.199] KUBETEST_MANUAL_DUMP=y
W1017 19:32:31.199] KUBE_AWS_INSTANCE_PREFIX=bootstrap-e2e
W1017 19:32:31.199] KUBE_GCE_INSTANCE_PREFIX=bootstrap-e2e
W1017 19:32:31.199] KUBE_VERBOSE=0
W1017 19:32:31.199] NODE_NAME=a2358d18-f114-11e9-b3d3-b20db476995a
W1017 19:32:31.200] 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
W1017 19:32:31.200] PROW_JOB_ID=a2358d18-f114-11e9-b3d3-b20db476995a
W1017 19:32:31.200] PULL_BASE_REF=master
W1017 19:32:31.200] PULL_BASE_SHA=37fca51d74a81df3b6c8b6df5b644e333acd7274
W1017 19:32:31.200] PULL_NUMBER=113
W1017 19:32:31.200] PULL_PULL_SHA=879465972041635fd7bc8269da49153b67e63822
W1017 19:32:31.200] PULL_REFS=master:37fca51d74a81df3b6c8b6df5b644e333acd7274,113:879465972041635fd7bc8269da49153b67e63822
W1017 19:32:31.201] PWD=/workspace
W1017 19:32:31.201] REGISTRY=k8sprowinternal.azurecr.io
W1017 19:32:31.201] REPO_NAME=kubernetes
W1017 19:32:31.201] REPO_OWNER=Azure
W1017 19:32:31.201] SHLVL=2
W1017 19:32:31.201] SOURCE_DATE_EPOCH=1571316399
W1017 19:32:31.201] TERM=xterm
W1017 19:32:31.201] TIDE_PORT=tcp://10.0.180.53:80
W1017 19:32:31.201] TIDE_PORT_80_TCP=tcp://10.0.180.53:80
W1017 19:32:31.201] TIDE_PORT_80_TCP_ADDR=10.0.180.53
W1017 19:32:31.201] TIDE_PORT_80_TCP_PORT=80
W1017 19:32:31.202] TIDE_PORT_80_TCP_PROTO=tcp
W1017 19:32:31.202] TIDE_SERVICE_HOST=10.0.180.53
W1017 19:32:31.202] TIDE_SERVICE_PORT=80
W1017 19:32:31.202] USER=prow
W1017 19:32:31.202] WORKSPACE=/workspace
W1017 19:32:31.202] _=./test-infra/jenkins/bootstrap.py
W1017 19:32:31.203] Run: ('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=quick', '--up', '--down', '--test', '--deployment=acsengine', '--provider=skeleton', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--ginkgo-parallel=30', '--test-ccm=True', '--acsengine-agentpoolcount=1', '--acsengine-admin-username=azureuser', '--acsengine-creds=/etc/azure-cred/credentials', '--acsengine-orchestratorRelease=1.16', '--acsengine-mastervmsize=Standard_DS2_v2', '--acsengine-agentvmsize=Standard_D4s_v3', '--acsengine-hyperkube=True', '--acsengine-ccm=True', '--acsengine-location=eastus2', '--acsengine-public-key=/etc/ssh-key-secret/ssh-public', '--acsengine-template-url=https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json', '--acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz', '--timeout=420m')
W1017 19:32:31.204] 2019/10/17 19:32:31 main.go:332: Limiting testing to 7h0m0s
W1017 19:32:31.205] 2019/10/17 19:32:31 azure.go:232: Reading credentials file /etc/azure-cred/credentials
W1017 19:32:31.205] 2019/10/17 19:32:31 process.go:153: Running: make -C /go/src/k8s.io/kubernetes quick-release
I1017 19:32:31.305] make: Entering directory '/go/src/k8s.io/kubernetes'
I1017 19:32:31.305] +++ [1017 19:32:31] Verifying Prerequisites....
I1017 19:32:31.499] +++ [1017 19:32:31] Building Docker image kube-build:build-fd56beb493-5-v1.12.10-1
I1017 19:35:18.322] +++ [1017 19:35:18] Creating data container kube-build-data-fd56beb493-5-v1.12.10-1
I1017 19:35:48.651] +++ [1017 19:35:48] Syncing sources to container
I1017 19:35:55.620] +++ [1017 19:35:55] Running build command...
I1017 19:36:03.943] +++ [1017 19:36:03] Building go targets for linux/amd64:
I1017 19:36:03.944]     ./vendor/k8s.io/code-generator/cmd/deepcopy-gen
I1017 19:36:11.818] +++ [1017 19:36:11] Building go targets for linux/amd64:
I1017 19:36:11.819]     ./vendor/k8s.io/code-generator/cmd/defaulter-gen
I1017 19:36:17.903] +++ [1017 19:36:17] Building go targets for linux/amd64:
I1017 19:36:17.903]     ./vendor/k8s.io/code-generator/cmd/conversion-gen
I1017 19:36:28.254] +++ [1017 19:36:28] Building go targets for linux/amd64:
I1017 19:36:28.254]     ./vendor/k8s.io/kube-openapi/cmd/openapi-gen
I1017 19:36:40.282] +++ [1017 19:36:40] Building go targets for linux/amd64:
I1017 19:36:40.282]     ./vendor/github.com/go-bindata/go-bindata/go-bindata
I1017 19:36:41.522] +++ [1017 19:36:41] Building go targets for linux/amd64:
I1017 19:36:41.522]     cmd/kube-proxy
I1017 19:36:41.522]     cmd/kube-apiserver
I1017 19:36:41.522]     cmd/kube-controller-manager
I1017 19:36:41.522]     cmd/kubelet
I1017 19:36:41.522]     cmd/kubeadm
I1017 19:36:41.522]     cmd/hyperkube
I1017 19:36:41.523]     cmd/kube-scheduler
I1017 19:36:41.523]     vendor/k8s.io/apiextensions-apiserver
I1017 19:36:41.523]     cluster/gce/gci/mounter
I1017 19:40:05.581] +++ [1017 19:40:05] Building go targets for linux/amd64:
I1017 19:40:05.581]     cmd/kube-proxy
I1017 19:40:05.581]     cmd/kubeadm
I1017 19:40:05.581]     cmd/kubelet
I1017 19:40:19.702] +++ [1017 19:40:19] Building go targets for linux/amd64:
I1017 19:40:19.702]     cmd/kubectl
I1017 19:40:36.285] +++ [1017 19:40:36] Building go targets for linux/amd64:
I1017 19:40:36.285]     cmd/gendocs
I1017 19:40:36.286]     cmd/genkubedocs
I1017 19:40:36.286]     cmd/genman
I1017 19:40:36.286]     cmd/genyaml
I1017 19:40:36.286]     cmd/genswaggertypedocs
I1017 19:40:36.286]     cmd/linkcheck
I1017 19:40:36.286]     vendor/github.com/onsi/ginkgo/ginkgo
I1017 19:40:36.286]     test/e2e/e2e.test
I1017 19:40:36.287]     cluster/images/conformance/go-runner
I1017 19:42:55.292] +++ [1017 19:42:55] Building go targets for linux/amd64:
I1017 19:42:55.293]     cmd/kubemark
I1017 19:42:55.293]     vendor/github.com/onsi/ginkgo/ginkgo
I1017 19:42:55.293]     test/e2e_node/e2e_node.test
I1017 19:44:08.212] +++ [1017 19:44:08] Syncing out of container
I1017 19:44:49.081] +++ [1017 19:44:49] Building tarball: src
I1017 19:44:49.081] +++ [1017 19:44:49] Building tarball: manifests
I1017 19:44:49.082] +++ [1017 19:44:49] Starting tarball: client linux-amd64
I1017 19:44:49.084] +++ [1017 19:44:49] Waiting on tarballs
I1017 19:44:55.106] +++ [1017 19:44:55] Building tarball: node linux-amd64
I1017 19:44:55.108] +++ [1017 19:44:55] Building images: linux-amd64
I1017 19:44:55.731] +++ [1017 19:44:55] Starting docker build for image: kube-apiserver-amd64
I1017 19:44:55.733] +++ [1017 19:44:55] Starting docker build for image: kube-controller-manager-amd64
I1017 19:44:55.736] +++ [1017 19:44:55] Starting docker build for image: kube-scheduler-amd64
I1017 19:44:55.739] +++ [1017 19:44:55] Starting docker build for image: kube-proxy-amd64
I1017 19:44:55.743] +++ [1017 19:44:55] Building hyperkube image for arch: amd64
I1017 19:44:55.744] +++ [1017 19:44:55] Building conformance image for arch: amd64
I1017 19:45:45.341] +++ [1017 19:45:45] Deleting docker image k8s.gcr.io/kube-controller-manager-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1
I1017 19:45:52.397] +++ [1017 19:45:52] Deleting docker image k8s.gcr.io/kube-scheduler-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1
I1017 19:45:52.598] +++ [1017 19:45:52] Deleting docker image k8s.gcr.io/kube-apiserver-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1
I1017 19:46:03.045] +++ [1017 19:46:03] Deleting docker image k8s.gcr.io/kube-proxy-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1
I1017 19:46:33.815] +++ [1017 19:46:33] Deleting hyperkube image k8s.gcr.io/hyperkube-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1
I1017 19:47:04.507] +++ [1017 19:47:04] Deleting conformance image k8s.gcr.io/conformance-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1
I1017 19:47:04.738] +++ [1017 19:47:04] Docker builds done
I1017 19:47:04.744] +++ [1017 19:47:04] Building tarball: server linux-amd64
I1017 19:48:31.364] +++ [1017 19:48:31] Building tarball: final
I1017 19:48:31.718] +++ [1017 19:48:31] Starting tarball: test linux-amd64
I1017 19:48:31.718] +++ [1017 19:48:31] Waiting on test tarballs
I1017 19:49:24.874] +++ [1017 19:49:24] Building tarball: test portable
I1017 19:49:24.956] +++ [1017 19:49:24] Building tarball: test mondo (deprecated by KEP sig-testing/20190118-breaking-apart-the-kubernetes-test-tarball)
I1017 19:50:18.890] make: Leaving directory '/go/src/k8s.io/kubernetes'
W1017 19:50:18.990] 2019/10/17 19:50:18 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes quick-release' finished in 17m47.684836147s
W1017 19:50:18.990] 2019/10/17 19:50:18 util.go:277: Flushing memory.
W1017 19:50:25.789] 2019/10/17 19:50:25 azure.go:654: CWD /go/src/k8s.io/kubernetes
W1017 19:50:25.789] 2019/10/17 19:50:25 azure.go:673: Attempting Docker login with azure cred.
W1017 19:50:27.092] 2019/10/17 19:50:27 azure.go:682: Docker login success.
W1017 19:50:27.092] 2019/10/17 19:50:27 azure.go:697: Building ccm.
W1017 19:50:27.092] 2019/10/17 19:50:27 azure.go:699: projectPath /go/src/k8s.io/cloud-provider-azure
W1017 19:50:27.092] 2019/10/17 19:50:27 process.go:153: Running: docker build -t k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184914779353911296-5cf936a8 .
I1017 19:50:29.230] Sending build context to Docker daemon  67.18MB

I1017 19:50:29.279] Step 1/7 : FROM golang:1.12.9-stretch AS build
I1017 19:50:30.221] 1.12.9-stretch: Pulling from library/golang
I1017 19:50:30.569] 092586df9206: Pulling fs layer
I1017 19:50:30.569] ef599477fae0: Pulling fs layer
I1017 19:50:30.570] 4530c6472b5d: Pulling fs layer
I1017 19:50:30.570] d34d61487075: Pulling fs layer
I1017 19:50:30.570] 89c6ec31b9e9: Pulling fs layer
I1017 19:50:30.570] e37857ebcafa: Pulling fs layer
I1017 19:50:30.570] b0e29f6c7f0a: Pulling fs layer
I1017 19:50:30.570] e37857ebcafa: Waiting
I1017 19:50:30.570] 89c6ec31b9e9: Waiting
I1017 19:50:30.570] b0e29f6c7f0a: Waiting
I1017 19:50:30.571] d34d61487075: Waiting
I1017 19:50:30.974] 4530c6472b5d: Verifying Checksum
I1017 19:50:30.974] 4530c6472b5d: Download complete
I1017 19:50:31.071] ef599477fae0: Verifying Checksum
I1017 19:50:31.072] ef599477fae0: Download complete
I1017 19:50:31.417] 092586df9206: Verifying Checksum
I1017 19:50:31.417] 092586df9206: Download complete
I1017 19:50:31.843] d34d61487075: Verifying Checksum
I1017 19:50:31.844] d34d61487075: Download complete
I1017 19:50:32.167] 89c6ec31b9e9: Verifying Checksum
I1017 19:50:32.168] 89c6ec31b9e9: Download complete
I1017 19:50:32.204] b0e29f6c7f0a: Download complete
I1017 19:50:33.253] e37857ebcafa: Verifying Checksum
I1017 19:50:33.253] e37857ebcafa: Download complete
I1017 19:50:34.700] 092586df9206: Pull complete
I1017 19:50:35.456] ef599477fae0: Pull complete
I1017 19:50:35.828] 4530c6472b5d: Pull complete
I1017 19:50:39.524] d34d61487075: Pull complete
I1017 19:50:42.959] 89c6ec31b9e9: Pull complete
I1017 19:50:50.509] e37857ebcafa: Pull complete
I1017 19:50:50.672] b0e29f6c7f0a: Pull complete
I1017 19:50:50.697] Digest: sha256:76b52857546f070cc3ac499accb27b8c411b10ff6d45c0b1da2a8aab7b61fe29
I1017 19:50:50.716] Status: Downloaded newer image for golang:1.12.9-stretch
I1017 19:50:50.716]  ---> 2c4a601e5da9
I1017 19:50:50.717] Step 2/7 : WORKDIR /go/src/k8s.io/cloud-provider-azure
I1017 19:51:02.644]  ---> Running in aa76419854d3
I1017 19:51:03.912] Removing intermediate container aa76419854d3
I1017 19:51:03.913]  ---> 0f29e5a0aad8
I1017 19:51:03.913] Step 3/7 : COPY . .
I1017 19:51:10.062]  ---> 1c6c98440d17
I1017 19:51:10.062] Step 4/7 : RUN make
I1017 19:51:10.283]  ---> Running in 8787f1848041
I1017 19:51:11.092] hack/pkg-config.sh > .pkg_config
I1017 19:51:11.117] go build -o bin/azure-cloud-controller-manager -ldflags '-s -w -X k8s.io/cloud-provider-azure/pkg/version.gitVersion=v0.3.0-11-gfe3b13bf4 -X k8s.io/cloud-provider-azure/pkg/version.gitCommit=fe3b13bf4e70c53da8e014490b97daeec1950fe1 -X k8s.io/cloud-provider-azure/pkg/version.buildDate=2019-10-17T19:51:11Z' ./cmd/cloud-controller-manager
I1017 19:51:54.434] go build -o bin/azure-cloud-node-manager -ldflags '-s -w -X k8s.io/cloud-provider-azure/pkg/version.gitVersion=v0.3.0-11-gfe3b13bf4 -X k8s.io/cloud-provider-azure/pkg/version.gitCommit=fe3b13bf4e70c53da8e014490b97daeec1950fe1 -X k8s.io/cloud-provider-azure/pkg/version.buildDate=2019-10-17T19:51:11Z' ./cmd/cloud-node-manager
I1017 19:52:16.691] Removing intermediate container 8787f1848041
I1017 19:52:16.691]  ---> 9baa8da9d942
I1017 19:52:16.692] Step 5/7 : FROM k8s.gcr.io/debian-base:v1.0.0
I1017 19:52:16.982] v1.0.0: Pulling from debian-base
I1017 19:52:17.097] Digest: sha256:3801f944c765dc1b54900826ca67b1380bb8c73b9caf4a2a27ce613b3ba3e742
I1017 19:52:18.645] Status: Downloaded newer image for k8s.gcr.io/debian-base:v1.0.0
I1017 19:52:18.646]  ---> 204e96332c91
I1017 19:52:18.646] Step 6/7 : COPY --from=build /go/src/k8s.io/cloud-provider-azure/bin/azure-cloud-controller-manager /usr/local/bin
I1017 19:52:20.929]  ---> c9410458621f
I1017 19:52:20.930] Step 7/7 : RUN ln -s /usr/local/bin/azure-cloud-controller-manager /usr/local/bin/cloud-controller-manager
I1017 19:52:21.079]  ---> Running in e1175a3ab6db
I1017 19:52:23.069] Removing intermediate container e1175a3ab6db
I1017 19:52:23.069]  ---> eb8f57e0ac3e
I1017 19:52:23.183] Successfully built eb8f57e0ac3e
I1017 19:52:23.561] Successfully tagged k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184914779353911296-5cf936a8
W1017 19:52:23.662] 2019/10/17 19:52:23 process.go:155: Step 'docker build -t k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184914779353911296-5cf936a8 .' finished in 1m56.473376497s
W1017 19:52:23.662] 2019/10/17 19:52:23 process.go:153: Running: docker push k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184914779353911296-5cf936a8
W1017 19:52:33.078] 2019/10/17 19:52:33 process.go:155: Step 'docker push k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184914779353911296-5cf936a8' finished in 9.512171506s
W1017 19:52:33.078] 2019/10/17 19:52:33 azure.go:686: Docker logout.
W1017 19:52:33.144] 2019/10/17 19:52:33 azure.go:716: Custom cloud controller manager URL: k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184914779353911296-5cf936a8 .
W1017 19:52:33.145] 2019/10/17 19:52:33 azure.go:654: CWD /go/src/k8s.io/kubernetes
W1017 19:52:33.145] 2019/10/17 19:52:33 azure.go:673: Attempting Docker login with azure cred.
W1017 19:52:34.466] 2019/10/17 19:52:34 azure.go:682: Docker login success.
W1017 19:52:34.467] 2019/10/17 19:52:34 azure.go:726: Building hyperkube.
W1017 19:52:34.467] 2019/10/17 19:52:34 process.go:153: Running: make -C /go/src/k8s.io/kubernetes WHAT=cmd/hyperkube
W1017 19:55:23.733] 2019/10/17 19:55:23 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes WHAT=cmd/hyperkube' finished in 2m49.266360752s
W1017 19:55:23.733] 2019/10/17 19:55:23 azure.go:733: Pushing hyperkube.
W1017 19:55:23.733] 2019/10/17 19:55:23 process.go:153: Running: make -C /go/src/k8s.io/kubernetes/cluster/images/hyperkube push HYPERKUBE_BIN=/go/src/k8s.io/kubernetes/_output/bin/hyperkube
I1017 19:55:23.834] make: Entering directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube'
I1017 19:55:23.834] cp -r ./* /tmp/hyperkubew1KShG
I1017 19:55:23.834] cp /go/src/k8s.io/kubernetes/_output/bin/hyperkube /tmp/hyperkubew1KShG
I1017 19:55:23.907] chmod a+rx /tmp/hyperkubew1KShG/hyperkube
I1017 19:55:23.909] cd /tmp/hyperkubew1KShG && sed -i.back "s|BASEIMAGE|k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1|g" Dockerfile
I1017 19:55:23.911] docker build --pull -t k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184914779353911296-a8e22860 /tmp/hyperkubew1KShG
I1017 19:55:25.121] Sending build context to Docker daemon  212.1MB

I1017 19:55:25.154] Step 1/2 : FROM k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1
I1017 19:55:25.434] 0.12.1: Pulling from debian-hyperkube-base-amd64
I1017 19:55:25.435] Digest: sha256:5d4ea2fb5fbe9a9a9da74f67cf2faefc881968bc39f2ac5d62d9167e575812a1
I1017 19:55:25.435] Status: Image is up to date for k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1
I1017 19:55:25.435]  ---> a46476511725
I1017 19:55:25.436] Step 2/2 : COPY hyperkube /hyperkube
I1017 19:55:50.102]  ---> 1d572cc802bc
I1017 19:55:50.128] Successfully built 1d572cc802bc
I1017 19:55:50.222] Successfully tagged k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184914779353911296-a8e22860
I1017 19:55:50.225] rm -rf "/tmp/hyperkubew1KShG"
I1017 19:55:50.253] docker push k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184914779353911296-a8e22860
I1017 19:55:50.316] The push refers to repository [k8sprowinternal.azurecr.io/hyperkube-amd64]
I1017 19:55:50.328] 2b96149ebb71: Preparing
I1017 19:55:50.328] 39b3ac6d96e9: Preparing
I1017 19:55:50.328] 7bbae4dddb88: Preparing
I1017 19:55:50.329] a00defcfe869: Preparing
I1017 19:55:50.329] 2ab0ae805c74: Preparing
I1017 19:55:50.329] 43a8fe7d2382: Preparing
I1017 19:55:50.329] 3f6a6f542637: Preparing
I1017 19:55:50.329] 5ba3be777c2d: Preparing
I1017 19:55:50.330] 43a8fe7d2382: Waiting
I1017 19:55:50.330] 3f6a6f542637: Waiting
I1017 19:55:50.330] 5ba3be777c2d: Waiting
I1017 19:55:50.501] 39b3ac6d96e9: Layer already exists
I1017 19:55:50.528] 2ab0ae805c74: Layer already exists
I1017 19:55:50.555] 7bbae4dddb88: Layer already exists
I1017 19:55:50.576] a00defcfe869: Layer already exists
I1017 19:55:50.600] 3f6a6f542637: Layer already exists
I1017 19:55:50.625] 43a8fe7d2382: Layer already exists
I1017 19:55:50.646] 5ba3be777c2d: Layer already exists
I1017 19:56:00.435] 2b96149ebb71: Pushed
I1017 19:56:01.084] azure-e2e-1184914779353911296-a8e22860: digest: sha256:4dea0c0304995e08f2e081363e1ee7cbd3bde4bad14625faea969693e78c8bfd size: 1998
I1017 19:56:01.098] docker rmi k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1184914779353911296-a8e22860 2>/dev/null || true
I1017 19:56:01.145] docker tag k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184914779353911296-a8e22860 k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1184914779353911296-a8e22860
I1017 19:56:01.211] docker push k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1184914779353911296-a8e22860
I1017 19:56:01.270] The push refers to repository [k8sprowinternal.azurecr.io/hyperkube]
I1017 19:56:01.282] 2b96149ebb71: Preparing
I1017 19:56:01.282] 39b3ac6d96e9: Preparing
I1017 19:56:01.282] 7bbae4dddb88: Preparing
I1017 19:56:01.282] a00defcfe869: Preparing
I1017 19:56:01.282] 2ab0ae805c74: Preparing
I1017 19:56:01.282] 43a8fe7d2382: Preparing
I1017 19:56:01.283] 3f6a6f542637: Preparing
I1017 19:56:01.283] 5ba3be777c2d: Preparing
I1017 19:56:01.283] 3f6a6f542637: Waiting
I1017 19:56:01.283] 43a8fe7d2382: Waiting
I1017 19:56:01.283] 5ba3be777c2d: Waiting
I1017 19:56:01.366] 2ab0ae805c74: Layer already exists
I1017 19:56:01.392] a00defcfe869: Layer already exists
I1017 19:56:01.426] 7bbae4dddb88: Layer already exists
I1017 19:56:01.445] 2b96149ebb71: Mounted from hyperkube-amd64
I1017 19:56:01.451] 39b3ac6d96e9: Layer already exists
I1017 19:56:01.463] 43a8fe7d2382: Layer already exists
I1017 19:56:01.497] 3f6a6f542637: Layer already exists
I1017 19:56:01.533] 5ba3be777c2d: Layer already exists
I1017 19:56:02.134] azure-e2e-1184914779353911296-a8e22860: digest: sha256:4dea0c0304995e08f2e081363e1ee7cbd3bde4bad14625faea969693e78c8bfd size: 1998
I1017 19:56:02.149] make: Leaving directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube'
W1017 19:56:02.249] 2019/10/17 19:56:02 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes/cluster/images/hyperkube push HYPERKUBE_BIN=/go/src/k8s.io/kubernetes/_output/bin/hyperkube' finished in 38.416320785s
W1017 19:56:02.250] 2019/10/17 19:56:02 azure.go:686: Docker logout.
W1017 19:56:02.250] 2019/10/17 19:56:02 azure.go:744: Custom hyperkube URL: k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184914779353911296-a8e22860 .
W1017 19:56:02.250] 2019/10/17 19:56:02 azure.go:787: downloading /workspace/aks252876717/kubernetes.json from https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json.
W1017 19:56:02.250] 2019/10/17 19:56:02 util.go:42: curl https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json
W1017 19:56:02.516] 2019/10/17 19:56:02 azure.go:529: downloading /workspace/aks-engine.tar.gz from https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz.
W1017 19:56:02.516] 2019/10/17 19:56:02 util.go:42: curl https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz
W1017 19:56:03.711] 2019/10/17 19:56:03 azure.go:556: Extracting tar file /workspace/aks-engine.tar.gz into directory /go/src/k8s.io/kubernetes .
W1017 19:56:03.711] 2019/10/17 19:56:03 process.go:153: Running: tar -xzf /workspace/aks-engine.tar.gz --strip 1
W1017 19:56:03.862] 2019/10/17 19:56:03 process.go:155: Step 'tar -xzf /workspace/aks-engine.tar.gz --strip 1' finished in 151.581325ms
W1017 19:56:03.863] 2019/10/17 19:56:03 process.go:153: Running: /go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks252876717/kubernetes.json --output-directory /workspace/aks252876717
I1017 19:56:04.066] INFO[0000] Generating assets into /workspace/aks252876717... 
W1017 19:56:15.197] 2019/10/17 19:56:15 process.go:155: Step '/go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks252876717/kubernetes.json --output-directory /workspace/aks252876717' finished in 11.334397642s
W1017 19:56:15.200] 2019/10/17 19:56:15 azure.go:627: Setting kubeconfig env variable: kubeconfig path: /workspace/aks252876717/kubeconfig/kubeconfig.eastus2.json.
W1017 19:56:15.200] 2019/10/17 19:56:15 azure.go:629: Creating resource group: kubetest-dc78b129-f114-11e9-9686-0242a3df36d0.
W1017 19:56:15.200] 2019/10/17 19:56:15 azure.go:631: Creating Azure resource group: kubetest-dc78b129-f114-11e9-9686-0242a3df36d0 for cluster deployment.
W1017 19:56:17.033] 2019/10/17 19:56:17 azure.go:636: Validating deployment ARM templates.
W1017 19:56:18.920] 2019/10/17 19:56:18 azure.go:642: Deploying cluster kubetest-dc78b129-f114-11e9-9686-0242a3df36d0 in resource group kubetest-dc78b129-f114-11e9-9686-0242a3df36d0.
W1017 20:06:26.627] 2019/10/17 20:06:26 process.go:153: Running: kubectl --match-server-version=false version
W1017 20:06:27.327] 2019/10/17 20:06:27 process.go:155: Step 'kubectl --match-server-version=false version' finished in 699.950834ms
W1017 20:06:27.327] 2019/10/17 20:06:27 process.go:153: Running: kubectl --match-server-version=false get nodes -oyaml
W1017 20:06:28.764] 2019/10/17 20:06:28 process.go:155: Step 'kubectl --match-server-version=false get nodes -oyaml' finished in 1.43662555s
W1017 20:06:28.764] 2019/10/17 20:06:28 azure.go:961: KUBE_TEST_REPO_LIST_DOWNLOAD_LOCATION not set. Using default test image repos.
W1017 20:06:28.764] 2019/10/17 20:06:28 azure.go:961: KUBE_TEST_REPO_LIST_DOWNLOAD_LOCATION not set. Using default test image repos.
W1017 20:06:28.764] 2019/10/17 20:06:28 process.go:153: Running: kubectl get nodes --no-headers
W1017 20:06:29.427] 2019/10/17 20:06:29 process.go:155: Step 'kubectl get nodes --no-headers' finished in 662.726051ms
W1017 20:06:29.427] 2019/10/17 20:06:29 e2e.go:462: Cluster nodes:
W1017 20:06:29.427] k8s-agentpool1-10563954-0   Ready   <none>   44s   v1.16.3-beta.0.11+0d9472c2ffccc1
W1017 20:06:29.427] k8s-master-10563954-0       Ready   <none>   44s   v1.16.3-beta.0.11+0d9472c2ffccc1
W1017 20:06:29.427] 2019/10/17 20:06:29 process.go:153: Running: kubectl --match-server-version=false version
W1017 20:06:29.832] 2019/10/17 20:06:29 process.go:155: Step 'kubectl --match-server-version=false version' finished in 405.608492ms
W1017 20:06:29.833] 2019/10/17 20:06:29 azure.go:915: Attempting to dump control-plane and node component logs to /workspace/_artifacts
W1017 20:06:29.834] 2019/10/17 20:06:29 process.go:153: Running: bash -c ./hack/log-dump.sh /workspace/_artifacts
W1017 20:06:29.836] ++ command -v kubectl
W1017 20:06:29.836] ++ [[ -z /etc/ssh-key-secret/ssh-private ]]
W1017 20:06:29.837] ++ [[ -z azureuser ]]
W1017 20:06:29.837] ++ master_logfiles=('kube-apiserver' 'kube-scheduler' 'kube-controller-manager' 'kube-addon-manager' 'cloud-controller-manager')
W1017 20:06:29.837] ++ readonly master_logfiles
W1017 20:06:29.837] ++ node_logfiles=('csi-azuredisk' 'csi-azurefile' 'kube-proxy')
W1017 20:06:29.838] ++ readonly node_logfiles
W1017 20:06:29.838] ++ systemd_services=('kubelet' 'docker' 'etcd')
W1017 20:06:29.838] ++ readonly systemd_services
W1017 20:06:29.838] ++ readonly report_dir=/workspace/_artifacts
W1017 20:06:29.838] ++ report_dir=/workspace/_artifacts
W1017 20:06:29.839] ++ main
W1017 20:06:29.839] ++ dump-masters
W1017 20:06:29.839] ++ master_names=($(kubectl get nodes -l kubernetes.io/role=master -ojsonpath={.items[*].metadata.name}))
W1017 20:06:29.839] +++ kubectl get nodes -l kubernetes.io/role=master '-ojsonpath={.items[*].metadata.name}'
W1017 20:06:30.482] ++ local -r master_names
W1017 20:06:30.482] ++ [[ 0 -eq 0 ]]
W1017 20:06:30.482] ++ echo 'No master found. Exiting...'
W1017 20:06:30.483] ++ exit 1
W1017 20:06:30.483] 2019/10/17 20:06:30 process.go:155: Step 'bash -c ./hack/log-dump.sh /workspace/_artifacts' finished in 649.973154ms
W1017 20:06:30.483] 2019/10/17 20:06:30 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml.
W1017 20:06:30.484] 2019/10/17 20:06:30 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"
I1017 20:06:30.584] No master found. Exiting...
W1017 20:06:30.647] 2019/10/17 20:06:30 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 153.425469ms
W1017 20:06:30.647] 2019/10/17 20:06:30 main.go:319: Something went wrong: encountered 1 errors: [error during bash -c ./hack/log-dump.sh /workspace/_artifacts: exit status 1]
W1017 20:06:30.647] Traceback (most recent call last):
W1017 20:06:30.647]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in <module>
W1017 20:06:30.648]     main(parse_args())
W1017 20:06:30.648]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main
W1017 20:06:30.648]     mode.start(runner_args)
W1017 20:06:30.648]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start
W1017 20:06:30.648]     check_env(env, self.command, *args)
W1017 20:06:30.648]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env
W1017 20:06:30.649]     subprocess.check_call(cmd, env=env)
W1017 20:06:30.649]   File "/usr/lib/python2.7/subprocess.py", line 186, in check_call
W1017 20:06:30.649]     raise CalledProcessError(retcode, cmd)
W1017 20:06:30.649] subprocess.CalledProcessError: Command '('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=quick', '--up', '--down', '--test', '--deployment=acsengine', '--provider=skeleton', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--ginkgo-parallel=30', '--test-ccm=True', '--acsengine-agentpoolcount=1', '--acsengine-admin-username=azureuser', '--acsengine-creds=/etc/azure-cred/credentials', '--acsengine-orchestratorRelease=1.16', '--acsengine-mastervmsize=Standard_DS2_v2', '--acsengine-agentvmsize=Standard_D4s_v3', '--acsengine-hyperkube=True', '--acsengine-ccm=True', '--acsengine-location=eastus2', '--acsengine-public-key=/etc/ssh-key-secret/ssh-public', '--acsengine-template-url=https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json', '--acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz', '--timeout=420m')' returned non-zero exit status 1
E1017 20:06:30.650] Command failed
I1017 20:06:30.650] process 694 exited with code 1 after 34.0m
E1017 20:06:30.650] FAIL: chewong-e2e-ccm
I1017 20:06:30.650] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W1017 20:06:31.475] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I1017 20:06:31.509] process 17827 exited with code 0 after 0.0m
I1017 20:06:31.509] Call:  gcloud config get-value account
I1017 20:06:31.766] process 17839 exited with code 0 after 0.0m
I1017 20:06:31.767] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
I1017 20:06:31.767] Upload result and artifacts...
I1017 20:06:31.767] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184914779353911296
I1017 20:06:31.767] Call:  gsutil ls gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184914779353911296/artifacts
W1017 20:06:33.029] CommandException: One or more URLs matched no objects.
E1017 20:06:33.109] Command failed
I1017 20:06:33.109] process 17851 exited with code 1 after 0.0m
W1017 20:06:33.110] Remote dir gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184914779353911296/artifacts not exist yet
I1017 20:06:33.110] Call:  gsutil -m -q -o GSUtil:use_magicfile=True cp -r -c -z log,txt,xml /workspace/_artifacts gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184914779353911296/artifacts
I1017 20:06:34.704] process 17993 exited with code 0 after 0.0m
I1017 20:06:34.705] Call:  git rev-parse HEAD
I1017 20:06:34.708] process 18520 exited with code 0 after 0.0m
I1017 20:06:34.708] Call:  git rev-parse HEAD
I1017 20:06:34.712] process 18521 exited with code 0 after 0.0m
I1017 20:06:34.712] Call:  gsutil stat gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json
I1017 20:06:35.661] process 18522 exited with code 0 after 0.0m
I1017 20:06:35.662] Call:  gsutil -q cat 'gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json#1571340090655229'
I1017 20:06:36.905] process 18664 exited with code 0 after 0.0m
I1017 20:06:36.907] Call:  gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1571340090655229 cp /tmp/gsutil_C1XNrC gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json
I1017 20:06:38.258] process 18808 exited with code 0 after 0.0m
I1017 20:06:38.259] Call:  gsutil stat gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json
I1017 20:06:39.220] process 18986 exited with code 0 after 0.0m
I1017 20:06:39.220] Call:  gsutil -q cat 'gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json#1571340094136336'
I1017 20:06:40.433] process 19128 exited with code 0 after 0.0m
I1017 20:06:40.434] Call:  gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1571340094136336 cp /tmp/gsutil_gvhNDw gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json
I1017 20:06:41.861] process 19272 exited with code 0 after 0.0m
I1017 20:06:41.861] Call:  gsutil -q -h Content-Type:application/json cp /tmp/gsutil_Hv7k4F gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184914779353911296/finished.json
I1017 20:06:43.212] process 19450 exited with code 0 after 0.0m
I1017 20:06:43.213] Call:  gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_vhg3bT gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/latest-build.txt
I1017 20:06:44.609] process 19628 exited with code 0 after 0.0m
I1017 20:06:44.610] Call:  gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_wyhEdT gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/latest-build.txt
I1017 20:06:45.894] process 19806 exited with code 0 after 0.0m