W0702 07:00:00.774] bootstrap.py is deprecated!
Please migrate your job to podutils!
https://github.com/kubernetes/test-infra/blob/master/prow/pod-utilities.md
I0702 07:00:00.774] Args: --job=pull-kubernetes-e2e-aks-engine-azure --service-account=/etc/service-account/service-account.json --upload=gs://kubernetes-jenkins/logs --job=pull-kubernetes-e2e-aks-engine-azure --root=/go/src --service-account=/etc/service-account/service-account.json --repo=k8s.io/kubernetes --repo=github.com/Azure/kubernetes=master:6d8dd211111474f277ef8e390a3eeed2465fb9e0,112:e904c6df7f68d06ebbed624c501f74b72d5a6c96 --upload=gs://kubernetes-upstream/pr-logs --timeout=460 --scenario=kubernetes_e2e -- --gce-ssh= --test=true --up=true --down=true --deployment=acsengine --build=bazel --provider=skeleton --ginkgo-parallel=30 --acsengine-agentpoolcount=3 --acsengine-admin-username=azureuser '--acsengine-creds=$AZURE_CREDENTIALS' --acsengine-orchestratorRelease=1.15 --acsengine-mastervmsize=Standard_DS2_v2 --acsengine-agentvmsize=Standard_D4s_v3 --acsengine-hyperkube=True --acsengine-location=eastus2 '--acsengine-public-key=$AZURE_SSH_PUBLIC_KEY_FILE' --acsengine-template-url=https://raw.githubusercontent.com/Azure/aks-engine/master/examples/kubernetes.json --acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.36.1/aks-engine-v0.36.1-linux-amd64.tar.gz '--test_args= --ginkgo.skip=\[sig-node\]\sMount\spropagation|\[sig-network\]\sNetwork\sshould\sset\sTCP\sCLOSE_WAIT\stimeout|\[sig-storage\]\sPersistentVolumes-local\sStress\swith\slocal\svolume\sprovisioner\s\[Serial\]\sshould\suse\sbe\sable\sto\sprocess\smany\spods\sand\sreuse\slocal\svolumes|should\sunmount\sif\spod\sis\sgracefully\sdeleted\swhile\skubelet\sis\sdown\s\[Disruptive\]\[Slow\]|should\sunmount\sif\spod\sis\sforce\sdeleted\swhile\skubelet\sis\sdown\s\[Disruptive\]\[Slow\]|\[sig-network\]\sServices\sshould\sbe\sable\sto\screate\sa\sfunctioning\sNodePort\sservice|\[sig-scheduling\]\sSchedulerPredicates\s\[Serial\]\svalidates\sMaxPods\slimit\snumber\sof\spods\sthat\sare\sallowed\sto\srun\s\[Slow\]|\[sig-storage\]\sDynamic\sProvisioning\sDynamicProvisioner\sDefault\sshould\screate\sand\sdelete\sdefault\spersistent\svolumes\s\[Slow\]|\[sig-storage\]\sDynamic\sProvisioning\sDynamicProvisioner\sshould\sprovision\sstorage\swith\sdifferent\sparameters|\[sig-storage\]\sDynamic\sProvisioning\sDynamicProvisioner\sshould\stest\sthat\sdeleting\sa\sclaim\sbefore\sthe\svolume\sis\sprovisioned\sdeletes\sthe\svolume.|\[sig-apps\]\sStatefulSet\s\[k8s.io\]\sBasic\sStatefulSet\sfunctionality\s\[StatefulSetBasic\]\sshould\sadopt\smatching\sorphans\sand\srelease\snon-matching\spods|\[sig-apps\]\sStatefulSet\s\[k8s.io\]\sBasic\sStatefulSet\sfunctionality\s\[StatefulSetBasic\]\sshould\snot\sdeadlock\swhen\sa\spod.s\spredecessor\sfails|\[sig-apps\]\sStatefulSet\s\[k8s.io\]\sBasic\sStatefulSet\sfunctionality\s\[StatefulSetBasic\]\sshould\sperform\srolling\supdates\sand\sroll\sbacks\sof\stemplate\smodifications\swith\sPVCs|\[sig-apps\]\sStatefulSet\s\[k8s.io\]\sBasic\sStatefulSet\sfunctionality\s\[StatefulSetBasic\]\sshould\sprovide\sbasic\sidentity|\[sig-storage\]\sPersistentVolumes\sDefault\sStorageClass\spods\sthat\suse\smultiple\svolumes\sshould\sbe\sreschedulable|\[sig-storage\]\sPVC\sProtection|\[sig-storage\]\sDynamic\sProvisioning\s\[k8s.io\]\sGlusterDynamicProvisioner|\[sig-storage\]\sVolumes\sAzure\sDisk\sshould\sbe\smountable\s\[Slow\]|\[sig-apps\]\sNetwork\sPartition\s\[Disruptive\]\s\[Slow\]|\[sig-network\]\sDNS\sconfigMap|\[k8s.io\]\s\[sig-node\]\sKubelet\s\[Serial\]\s\[Slow\]\s\[k8s.io\]\s\[sig-node\]\sregular\sresource\susage\stracking\sresource\stracking\sfor\s0\spods\sper\snode|\[k8s.io\]\s\[sig-node\]\sKubelet\s\[Serial\]\s\[Slow\]\s\[k8s.io\]\s\[sig-node\]\sregular\sresource\susage\stracking\sresource\stracking\sfor\s100\spods\sper\snode|Horizontal\spod\sautoscaling\s\(scale\sresource:\sCPU\)|\[sig-storage\]\sDynamic\sProvisioning\sDynamicProvisioner\sExternal\sshould\slet\san\sexternal\sdynamic\sprovisioner\screate\sand\sdelete\spersistent\svolumes\s\[Slow\]|ESIPP|\[sig-network\]\sServices\sshould\spreserve\ssource\spod\sIP\sfor\straffic\sthru\sservice\scluster\sIP|In-tree\sVolumes|PersistentVolumes-local|CSI\sVolumes|should\swrite\sentries\sto\s/etc/hosts|\[Slow\]|\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\]|\[NodeFeature:.+\]' --timeout=420m
I0702 07:00:00.774] Bootstrap pull-kubernetes-e2e-aks-engine-azure...
I0702 07:00:00.778] Builder: e7ca7b3e-9c96-11e9-b3d3-b20db476995a
I0702 07:00:00.778] Image: gcr.io/k8s-testimages/kubekins-e2e:v20190522-9bf3ab0-master
I0702 07:00:00.778] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/Azure_kubernetes/112/pull-kubernetes-e2e-aks-engine-azure/1145950156466688000
I0702 07:00:00.778] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W0702 07:00:01.294] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I0702 07:00:01.339] process 214 exited with code 0 after 0.0m
I0702 07:00:01.340] Call:  gcloud config get-value account
I0702 07:00:01.570] process 226 exited with code 0 after 0.0m
I0702 07:00:01.570] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
I0702 07:00:01.571] Root: /go/src
I0702 07:00:01.571] cd to /go/src
I0702 07:00:01.571] Checkout: /go/src/k8s.io/kubernetes master to /go/src/k8s.io/kubernetes
I0702 07:00:01.571] Call:  git init k8s.io/kubernetes
I0702 07:00:01.575] Initialized empty Git repository in /go/src/k8s.io/kubernetes/.git/
I0702 07:00:01.575] process 238 exited with code 0 after 0.0m
I0702 07:00:01.575] Call:  git config --local user.name 'K8S Bootstrap'
I0702 07:00:01.578] process 239 exited with code 0 after 0.0m
I0702 07:00:01.578] Call:  git config --local user.email k8s_bootstrap@localhost
I0702 07:00:01.580] process 240 exited with code 0 after 0.0m
I0702 07:00:01.581] Call:  git fetch --quiet --tags https://github.com/kubernetes/kubernetes master
I0702 07:00:50.219] process 241 exited with code 0 after 0.8m
I0702 07:00:50.219] Call:  git checkout -B test FETCH_HEAD
W0702 07:00:52.127] Switched to a new branch 'test'
I0702 07:00:52.133] process 253 exited with code 0 after 0.0m
I0702 07:00:52.134] Call:  git show -s --format=format:%ct HEAD
I0702 07:00:52.180] process 254 exited with code 0 after 0.0m
I0702 07:00:52.180] Checkout: /go/src/github.com/Azure/kubernetes master:6d8dd211111474f277ef8e390a3eeed2465fb9e0,112:e904c6df7f68d06ebbed624c501f74b72d5a6c96 to /go/src/github.com/Azure/kubernetes
I0702 07:00:52.181] Call:  git init github.com/Azure/kubernetes
I0702 07:00:52.184] Initialized empty Git repository in /go/src/github.com/Azure/kubernetes/.git/
I0702 07:00:52.184] process 255 exited with code 0 after 0.0m
I0702 07:00:52.185] Call:  git config --local user.name 'K8S Bootstrap'
I0702 07:00:52.187] process 256 exited with code 0 after 0.0m
I0702 07:00:52.187] Call:  git config --local user.email k8s_bootstrap@localhost
I0702 07:00:52.190] process 257 exited with code 0 after 0.0m
I0702 07:00:52.190] Call:  git fetch --quiet --tags https://github.com/Azure/kubernetes master +refs/pull/112/head:refs/pr/112
I0702 07:01:40.515] process 258 exited with code 0 after 0.8m
I0702 07:01:40.515] Call:  git checkout -B test 6d8dd211111474f277ef8e390a3eeed2465fb9e0
W0702 07:01:42.396] Switched to a new branch 'test'
I0702 07:01:42.403] process 270 exited with code 0 after 0.0m
I0702 07:01:42.404] Call:  git show -s --format=format:%ct HEAD
I0702 07:01:42.449] process 271 exited with code 0 after 0.0m
I0702 07:01:42.449] Call:  git merge --no-ff -m 'Merge +refs/pull/112/head:refs/pr/112' e904c6df7f68d06ebbed624c501f74b72d5a6c96
W0702 07:01:43.096] warning: inexact rename detection was skipped due to too many files.
W0702 07:01:43.096] warning: you may want to set your merge.renamelimit variable to at least 3707 and retry the command.
I0702 07:01:43.291] Auto-merging README.md
I0702 07:01:43.292] Merge made by the 'recursive' strategy.
I0702 07:01:43.294]  README.md | 1 +
I0702 07:01:43.294]  1 file changed, 1 insertion(+)
I0702 07:01:43.296] process 272 exited with code 0 after 0.0m
I0702 07:01:43.296] Configure environment...
I0702 07:01:43.296] Call:  git show -s --format=format:%ct HEAD
I0702 07:01:43.342] process 274 exited with code 0 after 0.0m
I0702 07:01:43.343] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W0702 07:01:43.991] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I0702 07:01:44.101] process 275 exited with code 0 after 0.0m
I0702 07:01:44.101] Call:  gcloud config get-value account
I0702 07:01:44.331] process 287 exited with code 0 after 0.0m
I0702 07:01:44.332] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
I0702 07:01:44.332] 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
'
I0702 07:01:44.611] process 299 exited with code 0 after 0.0m
I0702 07:01:44.611] Start 1145950156466688000 at v1.16.0-alpha.0.1783+6d8dd211111474...
I0702 07:01:44.617] Call:  gsutil -q -h Content-Type:application/json cp /tmp/gsutil_YpCSiB gs://kubernetes-upstream/pr-logs/pull/Azure_kubernetes/112/pull-kubernetes-e2e-aks-engine-azure/1145950156466688000/started.json
I0702 07:01:46.268] process 332 exited with code 0 after 0.0m
I0702 07:01:46.269] Call:  gsutil -q -h Content-Type:text/plain -h 'x-goog-meta-link: gs://kubernetes-upstream/pr-logs/pull/Azure_kubernetes/112/pull-kubernetes-e2e-aks-engine-azure/1145950156466688000' cp /tmp/gsutil_iVG37i gs://kubernetes-upstream/pr-logs/directory/pull-kubernetes-e2e-aks-engine-azure/1145950156466688000.txt
I0702 07:01:47.560] process 510 exited with code 0 after 0.0m
I0702 07:01:47.561] Call:  /workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py --gce-ssh= --test=true --up=true --down=true --deployment=acsengine --build=bazel --provider=skeleton --ginkgo-parallel=30 --acsengine-agentpoolcount=3 --acsengine-admin-username=azureuser --acsengine-creds=/etc/azure-cred/credentials --acsengine-orchestratorRelease=1.15 --acsengine-mastervmsize=Standard_DS2_v2 --acsengine-agentvmsize=Standard_D4s_v3 --acsengine-hyperkube=True --acsengine-location=eastus2 --acsengine-public-key=/etc/azure-ssh/azure-ssh-pub --acsengine-template-url=https://raw.githubusercontent.com/Azure/aks-engine/master/examples/kubernetes.json --acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.36.1/aks-engine-v0.36.1-linux-amd64.tar.gz '--test_args= --ginkgo.skip=\[sig-node\]\sMount\spropagation|\[sig-network\]\sNetwork\sshould\sset\sTCP\sCLOSE_WAIT\stimeout|\[sig-storage\]\sPersistentVolumes-local\sStress\swith\slocal\svolume\sprovisioner\s\[Serial\]\sshould\suse\sbe\sable\sto\sprocess\smany\spods\sand\sreuse\slocal\svolumes|should\sunmount\sif\spod\sis\sgracefully\sdeleted\swhile\skubelet\sis\sdown\s\[Disruptive\]\[Slow\]|should\sunmount\sif\spod\sis\sforce\sdeleted\swhile\skubelet\sis\sdown\s\[Disruptive\]\[Slow\]|\[sig-network\]\sServices\sshould\sbe\sable\sto\screate\sa\sfunctioning\sNodePort\sservice|\[sig-scheduling\]\sSchedulerPredicates\s\[Serial\]\svalidates\sMaxPods\slimit\snumber\sof\spods\sthat\sare\sallowed\sto\srun\s\[Slow\]|\[sig-storage\]\sDynamic\sProvisioning\sDynamicProvisioner\sDefault\sshould\screate\sand\sdelete\sdefault\spersistent\svolumes\s\[Slow\]|\[sig-storage\]\sDynamic\sProvisioning\sDynamicProvisioner\sshould\sprovision\sstorage\swith\sdifferent\sparameters|\[sig-storage\]\sDynamic\sProvisioning\sDynamicProvisioner\sshould\stest\sthat\sdeleting\sa\sclaim\sbefore\sthe\svolume\sis\sprovisioned\sdeletes\sthe\svolume.|\[sig-apps\]\sStatefulSet\s\[k8s.io\]\sBasic\sStatefulSet\sfunctionality\s\[StatefulSetBasic\]\sshould\sadopt\smatching\sorphans\sand\srelease\snon-matching\spods|\[sig-apps\]\sStatefulSet\s\[k8s.io\]\sBasic\sStatefulSet\sfunctionality\s\[StatefulSetBasic\]\sshould\snot\sdeadlock\swhen\sa\spod.s\spredecessor\sfails|\[sig-apps\]\sStatefulSet\s\[k8s.io\]\sBasic\sStatefulSet\sfunctionality\s\[StatefulSetBasic\]\sshould\sperform\srolling\supdates\sand\sroll\sbacks\sof\stemplate\smodifications\swith\sPVCs|\[sig-apps\]\sStatefulSet\s\[k8s.io\]\sBasic\sStatefulSet\sfunctionality\s\[StatefulSetBasic\]\sshould\sprovide\sbasic\sidentity|\[sig-storage\]\sPersistentVolumes\sDefault\sStorageClass\spods\sthat\suse\smultiple\svolumes\sshould\sbe\sreschedulable|\[sig-storage\]\sPVC\sProtection|\[sig-storage\]\sDynamic\sProvisioning\s\[k8s.io\]\sGlusterDynamicProvisioner|\[sig-storage\]\sVolumes\sAzure\sDisk\sshould\sbe\smountable\s\[Slow\]|\[sig-apps\]\sNetwork\sPartition\s\[Disruptive\]\s\[Slow\]|\[sig-network\]\sDNS\sconfigMap|\[k8s.io\]\s\[sig-node\]\sKubelet\s\[Serial\]\s\[Slow\]\s\[k8s.io\]\s\[sig-node\]\sregular\sresource\susage\stracking\sresource\stracking\sfor\s0\spods\sper\snode|\[k8s.io\]\s\[sig-node\]\sKubelet\s\[Serial\]\s\[Slow\]\s\[k8s.io\]\s\[sig-node\]\sregular\sresource\susage\stracking\sresource\stracking\sfor\s100\spods\sper\snode|Horizontal\spod\sautoscaling\s\(scale\sresource:\sCPU\)|\[sig-storage\]\sDynamic\sProvisioning\sDynamicProvisioner\sExternal\sshould\slet\san\sexternal\sdynamic\sprovisioner\screate\sand\sdelete\spersistent\svolumes\s\[Slow\]|ESIPP|\[sig-network\]\sServices\sshould\spreserve\ssource\spod\sIP\sfor\straffic\sthru\sservice\scluster\sIP|In-tree\sVolumes|PersistentVolumes-local|CSI\sVolumes|should\swrite\sentries\sto\s/etc/hosts|\[Slow\]|\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\]|\[NodeFeature:.+\]' --timeout=420m
W0702 07:01:47.597] starts with local mode
W0702 07:01:47.598] Environment:
W0702 07:01:47.598] ARTIFACTS=/workspace/_artifacts
W0702 07:01:47.598] AWS_SSH_PRIVATE_KEY_FILE=/root/.ssh/kube_aws_rsa
W0702 07:01:47.598] AWS_SSH_PUBLIC_KEY_FILE=/root/.ssh/kube_aws_rsa.pub
W0702 07:01:47.599] AZURE_CREDENTIALS=/etc/azure-cred/credentials
W0702 07:01:47.599] AZURE_SSH_PUBLIC_KEY_FILE=/etc/azure-ssh/azure-ssh-pub
W0702 07:01:47.599] AZ_STORAGE_CONTAINER_NAME=mystoragecontainer
W0702 07:01:47.599] BAZEL_REMOTE_CACHE_ENABLED=false
W0702 07:01:47.599] BAZEL_VERSION=0.23.2
W0702 07:01:47.599] BOOTSTRAP_MIGRATION=yes
W0702 07:01:47.599] BUILD_ID=1145950156466688000
W0702 07:01:47.599] BUILD_NUMBER=1145950156466688000
W0702 07:01:47.600] CLOUDSDK_COMPONENT_MANAGER_DISABLE_UPDATE_CHECK=true
W0702 07:01:47.600] CLOUDSDK_CONFIG=/go/src/k8s.io/kubernetes/.config/gcloud
W0702 07:01:47.600] CLOUDSDK_CORE_DISABLE_PROMPTS=1
W0702 07:01:47.600] CLOUDSDK_EXPERIMENTAL_FAST_COMPONENT_UPDATE=false
W0702 07:01:47.600] CLOUD_CONFIG=random
W0702 07:01:47.600] DECK_PORT=tcp://10.0.160.83:80
W0702 07:01:47.600] DECK_PORT_80_TCP=tcp://10.0.160.83:80
W0702 07:01:47.600] DECK_PORT_80_TCP_ADDR=10.0.160.83
W0702 07:01:47.601] DECK_PORT_80_TCP_PORT=80
W0702 07:01:47.601] DECK_PORT_80_TCP_PROTO=tcp
W0702 07:01:47.601] DECK_SERVICE_HOST=10.0.160.83
W0702 07:01:47.601] DECK_SERVICE_PORT=80
W0702 07:01:47.601] DOCKER_IN_DOCKER_ENABLED=true
W0702 07:01:47.601] DOCKER_IN_DOCKER_IPV6_ENABLED=false
W0702 07:01:47.601] GCS_ARTIFACTS_DIR=gs://kubernetes-upstream/pr-logs/pull/Azure_kubernetes/112/pull-kubernetes-e2e-aks-engine-azure/1145950156466688000/artifacts
W0702 07:01:47.602] GOOGLE_APPLICATION_CREDENTIALS=/etc/service-account/service-account.json
W0702 07:01:47.602] GOPATH=/go
W0702 07:01:47.602] GO_TARBALL=go1.12.1.linux-amd64.tar.gz
W0702 07:01:47.602] HOME=/workspace
W0702 07:01:47.602] HOOK_PORT=tcp://10.0.144.133:8888
W0702 07:01:47.602] HOOK_PORT_8888_TCP=tcp://10.0.144.133:8888
W0702 07:01:47.602] HOOK_PORT_8888_TCP_ADDR=10.0.144.133
W0702 07:01:47.603] HOOK_PORT_8888_TCP_PORT=8888
W0702 07:01:47.603] HOOK_PORT_8888_TCP_PROTO=tcp
W0702 07:01:47.603] HOOK_SERVICE_HOST=10.0.144.133
W0702 07:01:47.603] HOOK_SERVICE_PORT=8888
W0702 07:01:47.603] HOSTNAME=e7ca7b3e-9c96-11e9-b3d3-b20db476995a
W0702 07:01:47.603] IMAGE=gcr.io/k8s-testimages/kubekins-e2e:v20190522-9bf3ab0-master
W0702 07:01:47.603] INSTANCE_PREFIX=bootstrap-e2e
W0702 07:01:47.603] JENKINS_GCE_SSH_PRIVATE_KEY_FILE=/root/.ssh/google_compute_engine
W0702 07:01:47.604] JENKINS_GCE_SSH_PUBLIC_KEY_FILE=/root/.ssh/google_compute_engine.pub
W0702 07:01:47.604] JOB_NAME=pull-kubernetes-e2e-aks-engine-azure
W0702 07:01:47.604] JOB_SPEC={"type":"presubmit","job":"pull-kubernetes-e2e-aks-engine-azure","buildid":"1145950156466688000","prowjobid":"e7ca7b3e-9c96-11e9-b3d3-b20db476995a","refs":{"org":"Azure","repo":"kubernetes","repo_link":"https://github.com/Azure/kubernetes","base_ref":"master","base_sha":"6d8dd211111474f277ef8e390a3eeed2465fb9e0","base_link":"https://github.com/Azure/kubernetes/commit/6d8dd211111474f277ef8e390a3eeed2465fb9e0","pulls":[{"number":112,"author":"ritazh","sha":"e904c6df7f68d06ebbed624c501f74b72d5a6c96","link":"https://github.com/Azure/kubernetes/pull/112","commit_link":"https://github.com/Azure/kubernetes/pull/112/commits/e904c6df7f68d06ebbed624c501f74b72d5a6c96","author_link":"https://github.com/ritazh"}]}}
W0702 07:01:47.604] JOB_TYPE=presubmit
W0702 07:01:47.605] KUBERNETES_PORT=tcp://10.0.0.1:443
W0702 07:01:47.605] KUBERNETES_PORT_443_TCP=tcp://10.0.0.1:443
W0702 07:01:47.605] KUBERNETES_PORT_443_TCP_ADDR=10.0.0.1
W0702 07:01:47.605] KUBERNETES_PORT_443_TCP_PORT=443
W0702 07:01:47.605] KUBERNETES_PORT_443_TCP_PROTO=tcp
W0702 07:01:47.605] KUBERNETES_SERVICE_HOST=10.0.0.1
W0702 07:01:47.605] KUBERNETES_SERVICE_PORT=443
W0702 07:01:47.606] KUBERNETES_SERVICE_PORT_HTTPS=443
W0702 07:01:47.606] KUBETEST_IN_DOCKER=true
W0702 07:01:47.606] KUBETEST_MANUAL_DUMP=y
W0702 07:01:47.606] KUBE_AWS_INSTANCE_PREFIX=bootstrap-e2e
W0702 07:01:47.606] KUBE_GCE_INSTANCE_PREFIX=bootstrap-e2e
W0702 07:01:47.606] KUBE_VERBOSE=0
W0702 07:01:47.607] NODE_NAME=e7ca7b3e-9c96-11e9-b3d3-b20db476995a
W0702 07:01:47.607] 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
W0702 07:01:47.607] PROW_JOB_ID=e7ca7b3e-9c96-11e9-b3d3-b20db476995a
W0702 07:01:47.607] PULL_BASE_REF=master
W0702 07:01:47.607] PULL_BASE_SHA=6d8dd211111474f277ef8e390a3eeed2465fb9e0
W0702 07:01:47.607] PULL_NUMBER=112
W0702 07:01:47.607] PULL_PULL_SHA=e904c6df7f68d06ebbed624c501f74b72d5a6c96
W0702 07:01:47.608] PULL_REFS=master:6d8dd211111474f277ef8e390a3eeed2465fb9e0,112:e904c6df7f68d06ebbed624c501f74b72d5a6c96
W0702 07:01:47.608] PWD=/workspace
W0702 07:01:47.608] REGISTRY=k8sprowinternal.azurecr.io
W0702 07:01:47.608] REPO_NAME=kubernetes
W0702 07:01:47.608] REPO_OWNER=Azure
W0702 07:01:47.608] SHLVL=2
W0702 07:01:47.608] SOURCE_DATE_EPOCH=1562042014
W0702 07:01:47.608] TERM=xterm
W0702 07:01:47.609] TIDE_PORT=tcp://10.0.180.53:80
W0702 07:01:47.609] TIDE_PORT_80_TCP=tcp://10.0.180.53:80
W0702 07:01:47.609] TIDE_PORT_80_TCP_ADDR=10.0.180.53
W0702 07:01:47.609] TIDE_PORT_80_TCP_PORT=80
W0702 07:01:47.609] TIDE_PORT_80_TCP_PROTO=tcp
W0702 07:01:47.609] TIDE_SERVICE_HOST=10.0.180.53
W0702 07:01:47.609] TIDE_SERVICE_PORT=80
W0702 07:01:47.610] WORKSPACE=/workspace
W0702 07:01:47.610] _=./test-infra/jenkins/bootstrap.py
W0702 07:01:47.612] Run: ('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=bazel', '--up', '--down', '--test', '--deployment=acsengine', '--provider=skeleton', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--ginkgo-parallel=30', '--acsengine-agentpoolcount=3', '--acsengine-admin-username=azureuser', '--acsengine-creds=/etc/azure-cred/credentials', '--acsengine-orchestratorRelease=1.15', '--acsengine-mastervmsize=Standard_DS2_v2', '--acsengine-agentvmsize=Standard_D4s_v3', '--acsengine-hyperkube=True', '--acsengine-location=eastus2', '--acsengine-public-key=/etc/azure-ssh/azure-ssh-pub', '--acsengine-template-url=https://raw.githubusercontent.com/Azure/aks-engine/master/examples/kubernetes.json', '--acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.36.1/aks-engine-v0.36.1-linux-amd64.tar.gz', '--test_args= --ginkgo.skip=\\[sig-node\\]\\sMount\\spropagation|\\[sig-network\\]\\sNetwork\\sshould\\sset\\sTCP\\sCLOSE_WAIT\\stimeout|\\[sig-storage\\]\\sPersistentVolumes-local\\sStress\\swith\\slocal\\svolume\\sprovisioner\\s\\[Serial\\]\\sshould\\suse\\sbe\\sable\\sto\\sprocess\\smany\\spods\\sand\\sreuse\\slocal\\svolumes|should\\sunmount\\sif\\spod\\sis\\sgracefully\\sdeleted\\swhile\\skubelet\\sis\\sdown\\s\\[Disruptive\\]\\[Slow\\]|should\\sunmount\\sif\\spod\\sis\\sforce\\sdeleted\\swhile\\skubelet\\sis\\sdown\\s\\[Disruptive\\]\\[Slow\\]|\\[sig-network\\]\\sServices\\sshould\\sbe\\sable\\sto\\screate\\sa\\sfunctioning\\sNodePort\\sservice|\\[sig-scheduling\\]\\sSchedulerPredicates\\s\\[Serial\\]\\svalidates\\sMaxPods\\slimit\\snumber\\sof\\spods\\sthat\\sare\\sallowed\\sto\\srun\\s\\[Slow\\]|\\[sig-storage\\]\\sDynamic\\sProvisioning\\sDynamicProvisioner\\sDefault\\sshould\\screate\\sand\\sdelete\\sdefault\\spersistent\\svolumes\\s\\[Slow\\]|\\[sig-storage\\]\\sDynamic\\sProvisioning\\sDynamicProvisioner\\sshould\\sprovision\\sstorage\\swith\\sdifferent\\sparameters|\\[sig-storage\\]\\sDynamic\\sProvisioning\\sDynamicProvisioner\\sshould\\stest\\sthat\\sdeleting\\sa\\sclaim\\sbefore\\sthe\\svolume\\sis\\sprovisioned\\sdeletes\\sthe\\svolume.|\\[sig-apps\\]\\sStatefulSet\\s\\[k8s.io\\]\\sBasic\\sStatefulSet\\sfunctionality\\s\\[StatefulSetBasic\\]\\sshould\\sadopt\\smatching\\sorphans\\sand\\srelease\\snon-matching\\spods|\\[sig-apps\\]\\sStatefulSet\\s\\[k8s.io\\]\\sBasic\\sStatefulSet\\sfunctionality\\s\\[StatefulSetBasic\\]\\sshould\\snot\\sdeadlock\\swhen\\sa\\spod.s\\spredecessor\\sfails|\\[sig-apps\\]\\sStatefulSet\\s\\[k8s.io\\]\\sBasic\\sStatefulSet\\sfunctionality\\s\\[StatefulSetBasic\\]\\sshould\\sperform\\srolling\\supdates\\sand\\sroll\\sbacks\\sof\\stemplate\\smodifications\\swith\\sPVCs|\\[sig-apps\\]\\sStatefulSet\\s\\[k8s.io\\]\\sBasic\\sStatefulSet\\sfunctionality\\s\\[StatefulSetBasic\\]\\sshould\\sprovide\\sbasic\\sidentity|\\[sig-storage\\]\\sPersistentVolumes\\sDefault\\sStorageClass\\spods\\sthat\\suse\\smultiple\\svolumes\\sshould\\sbe\\sreschedulable|\\[sig-storage\\]\\sPVC\\sProtection|\\[sig-storage\\]\\sDynamic\\sProvisioning\\s\\[k8s.io\\]\\sGlusterDynamicProvisioner|\\[sig-storage\\]\\sVolumes\\sAzure\\sDisk\\sshould\\sbe\\smountable\\s\\[Slow\\]|\\[sig-apps\\]\\sNetwork\\sPartition\\s\\[Disruptive\\]\\s\\[Slow\\]|\\[sig-network\\]\\sDNS\\sconfigMap|\\[k8s.io\\]\\s\\[sig-node\\]\\sKubelet\\s\\[Serial\\]\\s\\[Slow\\]\\s\\[k8s.io\\]\\s\\[sig-node\\]\\sregular\\sresource\\susage\\stracking\\sresource\\stracking\\sfor\\s0\\spods\\sper\\snode|\\[k8s.io\\]\\s\\[sig-node\\]\\sKubelet\\s\\[Serial\\]\\s\\[Slow\\]\\s\\[k8s.io\\]\\s\\[sig-node\\]\\sregular\\sresource\\susage\\stracking\\sresource\\stracking\\sfor\\s100\\spods\\sper\\snode|Horizontal\\spod\\sautoscaling\\s\\(scale\\sresource:\\sCPU\\)|\\[sig-storage\\]\\sDynamic\\sProvisioning\\sDynamicProvisioner\\sExternal\\sshould\\slet\\san\\sexternal\\sdynamic\\sprovisioner\\screate\\sand\\sdelete\\spersistent\\svolumes\\s\\[Slow\\]|ESIPP|\\[sig-network\\]\\sServices\\sshould\\spreserve\\ssource\\spod\\sIP\\sfor\\straffic\\sthru\\sservice\\scluster\\sIP|In-tree\\sVolumes|PersistentVolumes-local|CSI\\sVolumes|should\\swrite\\sentries\\sto\\s/etc/hosts|\\[Slow\\]|\\[Serial\\]|\\[Disruptive\\]|\\[Flaky\\]|\\[Feature:.+\\]|\\[NodeFeature:.+\\]', '--timeout=420m')
W0702 07:01:48.695] 2019/07/02 07:01:48 main.go:327: Limiting testing to 7h0m0s
W0702 07:01:48.695] 2019/07/02 07:01:48 azure.go:112: Reading credentials file /etc/azure-cred/credentials
W0702 07:01:48.703] 2019/07/02 07:01:48 process.go:153: Running: make -C /go/src/k8s.io/kubernetes bazel-release
I0702 07:01:48.804] make: Entering directory '/go/src/k8s.io/kubernetes'
W0702 07:01:49.090] Extracting Bazel installation...
W0702 07:02:00.240] Starting local Bazel server and connecting to it...
W0702 07:02:01.927] Loading: 
W0702 07:02:01.931] Loading: 0 packages loaded
W0702 07:02:02.933] Loading: 0 packages loaded
W0702 07:02:04.612] Loading: 0 packages loaded
W0702 07:02:05.934] Loading: 0 packages loaded
W0702 07:02:07.951] Loading: 0 packages loaded
W0702 07:02:09.936] Loading: 0 packages loaded
W0702 07:02:09.936]     currently loading: build/release-tars
W0702 07:02:11.157] Loading: 0 packages loaded
W0702 07:02:11.158]     currently loading: build/release-tars
W0702 07:02:11.490] Analyzing: target //build/release-tars:release-tars (1 packages loaded, 0 targets configured)
W0702 07:02:12.946] Analyzing: target //build/release-tars:release-tars (277 packages loaded, 1238 targets configured)
W0702 07:02:14.646] Analyzing: target //build/release-tars:release-tars (981 packages loaded, 4685 targets configured)
W0702 07:02:16.575] Analyzing: target //build/release-tars:release-tars (1883 packages loaded, 11667 targets configured)
W0702 07:02:18.812] Analyzing: target //build/release-tars:release-tars (2592 packages loaded, 21455 targets configured)
W0702 07:02:21.369] Analyzing: target //build/release-tars:release-tars (2911 packages loaded, 25337 targets configured)
W0702 07:02:24.692] Analyzing: target //build/release-tars:release-tars (2940 packages loaded, 26986 targets configured)
W0702 07:02:25.957] INFO: SHA256 (https://codeload.github.com/golang/tools/zip/bf090417da8b6150dcfe96795325f5aa78fff718) = 11629171a39a1cb4d426760005be6f7cb9b4182e4cb2756b7f1c5c2b6ae869fe
W0702 07:02:26.487] DEBUG: Rule 'org_golang_x_tools' modified arguments {"sha256": "11629171a39a1cb4d426760005be6f7cb9b4182e4cb2756b7f1c5c2b6ae869fe"}
W0702 07:02:28.198] Analyzing: target //build/release-tars:release-tars (2955 packages loaded, 32489 targets configured)
W0702 07:02:32.777] Analyzing: target //build/release-tars:release-tars (2956 packages loaded, 34739 targets configured)
W0702 07:02:46.082] INFO: Analysed target //build/release-tars:release-tars (2956 packages loaded, 41291 targets configured).
W0702 07:02:46.084] Building: checking cached actions
W0702 07:02:46.085] INFO: Found 1 target...
W0702 07:02:46.255] [0 / 8] [-----] Writing file build/release-tars/kubernetes-manifests.args
W0702 07:02:52.931] [119 / 1,975] GoCompile vendor/golang.org/x/text/encoding/internal/identifier/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/golang.org/x/text/encoding/internal/identifier.a; 0s linux-sandbox ... (8 actions, 7 running)
W0702 07:03:01.058] [143 / 2,046] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 8s linux-sandbox ... (8 actions running)
W0702 07:03:10.576] [184 / 2,230] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 17s linux-sandbox ... (8 actions running)
W0702 07:03:21.768] [264 / 2,529] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 28s linux-sandbox ... (8 actions running)
W0702 07:03:33.796] [337 / 2,830] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 40s linux-sandbox ... (8 actions, 7 running)
W0702 07:03:47.809] [404 / 2,951] GoCompile staging/src/k8s.io/client-go/util/jsonpath/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/client-go/util/jsonpath.a; 2s linux-sandbox ... (8 actions running)
W0702 07:04:03.794] [535 / 2,951] GoCompile vendor/google.golang.org/api/compute/v0.beta/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/google.golang.org/api/compute/v0.beta.a; 4s linux-sandbox ... (8 actions running)
W0702 07:04:22.097] [702 / 2,951] GoCompile vendor/gonum.org/v1/gonum/graph/formats/dot/internal/parser/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/gonum.org/v1/gonum/graph/formats/dot/internal/parser.a; 2s linux-sandbox ... (8 actions running)
W0702 07:04:43.625] [855 / 2,951] GoCompile staging/src/k8s.io/apiserver/pkg/util/wsstream/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/apiserver/pkg/util/wsstream.a; 1s linux-sandbox ... (8 actions, 7 running)
W0702 07:05:07.999] [1,009 / 2,951] GoCompile vendor/github.com/vmware/govmomi/vim25/types/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/vmware/govmomi/vim25/types.a; 9s linux-sandbox ... (8 actions, 7 running)
W0702 07:05:35.969] [1,231 / 2,951] GoCompile staging/src/k8s.io/apiserver/pkg/storage/etcd3/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/apiserver/pkg/storage/etcd3.a; 0s linux-sandbox ... (8 actions, 7 running)
W0702 07:06:08.311] [1,384 / 2,951] GoCompile staging/src/k8s.io/apiextensions-apiserver/pkg/apiserver/conversion/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/apiextensions-apiserver/pkg/apiserver/conversion.a; 1s linux-sandbox ... (8 actions running)
W0702 07:06:45.412] [1,567 / 2,951] GoCompile staging/src/k8s.io/apiextensions-apiserver/pkg/registry/customresourcedefinition/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/apiextensions-apiserver/pkg/registry/customresourcedefinition.a; 3s linux-sandbox ... (8 actions running)
W0702 07:07:28.488] [1,833 / 2,951] GoCompile vendor/github.com/godbus/dbus/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/godbus/dbus.a; 3s linux-sandbox ... (8 actions, 7 running)
W0702 07:08:17.672] [2,072 / 3,023] GoCompile pkg/proxy/iptables/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/pkg/proxy/iptables.a; 2s linux-sandbox ... (8 actions, 7 running)
W0702 07:08:57.461] Slow read: a 44509864-byte read from /workspace/.cache/bazel/_bazel_root/48d5366022b4e3197674c8d6e2bee219/execroot/io_k8s_kubernetes/bazel-out/k8-fastbuild/bin/cmd/kube-scheduler/linux_amd64_pure_stripped/kube-scheduler took 11725 ms.
W0702 07:09:14.566] [2,304 / 3,462] GoLink cmd/cloud-controller-manager/linux_amd64_pure_stripped/cloud-controller-manager; 53s linux-sandbox ... (8 actions running)
W0702 07:10:19.508] [2,961 / 4,269] GoCompile vendor/github.com/vmware/govmomi/list/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/vmware/govmomi/list.a; 0s linux-sandbox ... (8 actions, 7 running)
W0702 07:11:35.622] [3,536 / 4,375] GoCompile staging/src/k8s.io/apiextensions-apiserver/pkg/generated/openapi/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/apiextensions-apiserver/pkg/generated/openapi.a; 9s linux-sandbox ... (8 actions, 7 running)
W0702 07:13:01.711] [4,064 / 4,398] GoCompile pkg/controller/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/pkg/controller.a; 0s linux-sandbox ... (8 actions, 7 running)
W0702 07:14:40.979] [4,456 / 4,530] GoLink cmd/hyperkube/hyperkube; 43s linux-sandbox ... (8 actions, 7 running)
W0702 07:16:27.694] Slow read: a 592-byte read from /go/src/k8s.io/kubernetes/vendor/github.com/coreos/etcd/pkg/httputil/httputil.go took 5092 ms.
W0702 07:16:27.705] Slow read: a 1102064-byte read from /workspace/.cache/bazel/_bazel_root/48d5366022b4e3197674c8d6e2bee219/execroot/io_k8s_kubernetes/bazel-out/k8-fastbuild/bin/cmd/kubeadm/app/cmd/phases/join/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/cmd/kubeadm/app/cmd/phases/join.a took 5103 ms.
W0702 07:16:34.907] [4,743 / 4,804] GoCompile test/e2e/generated/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/test/e2e/generated.a; 4s linux-sandbox ... (8 actions, 7 running)
W0702 07:18:51.258] [5,165 / 5,169] PackageTar build/release-tars/kubernetes-server-linux-amd64.tar.gz; 26s linux-sandbox ... (3 actions, 2 running)
W0702 07:19:12.979] Target //build/release-tars:release-tars up-to-date:
W0702 07:19:12.981]   bazel-bin/build/release-tars/kubernetes-client-linux-amd64.tar.gz
W0702 07:19:12.981]   bazel-bin/build/release-tars/kubernetes-node-linux-amd64.tar.gz
W0702 07:19:12.981]   bazel-bin/build/release-tars/kubernetes-server-linux-amd64.tar.gz
W0702 07:19:12.981]   bazel-bin/build/release-tars/kubernetes-manifests.tar.gz
W0702 07:19:12.982]   bazel-bin/build/release-tars/kubernetes-test-portable.tar.gz
W0702 07:19:12.982]   bazel-bin/build/release-tars/kubernetes-test-linux-amd64.tar.gz
W0702 07:19:12.983]   bazel-bin/build/release-tars/kubernetes-test.tar.gz
W0702 07:19:12.983]   bazel-bin/build/release-tars/kubernetes.tar.gz
W0702 07:19:12.983]   bazel-bin/build/release-tars/kubernetes-src.tar.gz
W0702 07:19:13.012] INFO: Elapsed time: 1044.174s, Critical Path: 289.28s
W0702 07:19:13.013] INFO: 5070 processes: 5070 linux-sandbox.
W0702 07:19:13.017] INFO: Build completed successfully, 5169 total actions
W0702 07:19:13.019] INFO: Build completed successfully, 5169 total actions
W0702 07:19:13.025] 2019/07/02 07:19:13 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes bazel-release' finished in 17m24.320986781s
W0702 07:19:13.025] 2019/07/02 07:19:13 util.go:255: Flushing memory.
I0702 07:19:13.125] make: Leaving directory '/go/src/k8s.io/kubernetes'
W0702 07:19:32.940] 2019/07/02 07:19:32 azure.go:674: Deleting resource group: kubetest-42d7ea2a-9c97-11e9-9ef1-02425801647a.
W0702 07:19:33.437] 2019/07/02 07:19:33 azure.go:427: CWD /go/src/k8s.io/kubernetes
W0702 07:19:33.437] 2019/07/02 07:19:33 azure.go:446: Attempting Docker login with azure cred.
W0702 07:19:34.503] 2019/07/02 07:19:34 azure.go:455: Docker login success.
W0702 07:19:34.503] 2019/07/02 07:19:34 azure.go:499: Building and pushing hyperkube.
W0702 07:19:34.503] 2019/07/02 07:19:34 process.go:153: Running: /go/src/k8s.io/kubernetes/hack/dev-push-hyperkube.sh
W0702 07:22:56.552] stat /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/bazel-bin: no such file or directory
W0702 07:26:19.734] 2019/07/02 07:26:19 process.go:155: Step '/go/src/k8s.io/kubernetes/hack/dev-push-hyperkube.sh' finished in 6m45.231268318s
W0702 07:26:19.735] 2019/07/02 07:26:19 azure.go:459: Docker logout.
W0702 07:26:19.802] 2019/07/02 07:26:19 azure.go:512: Custom hyperkube URL: k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1145950156466688000-bd7a9a56 .
W0702 07:26:19.802] 2019/07/02 07:26:19 azure.go:555: downloading /workspace/acs608788772/kubernetes.json from https://raw.githubusercontent.com/Azure/aks-engine/master/examples/kubernetes.json.
W0702 07:26:19.803] 2019/07/02 07:26:19 util.go:42: curl https://raw.githubusercontent.com/Azure/aks-engine/master/examples/kubernetes.json
W0702 07:26:20.070] 2019/07/02 07:26:20 azure.go:312: downloading /workspace/aks-engine.tar.gz from https://github.com/Azure/aks-engine/releases/download/v0.36.1/aks-engine-v0.36.1-linux-amd64.tar.gz.
W0702 07:26:20.070] 2019/07/02 07:26:20 util.go:42: curl https://github.com/Azure/aks-engine/releases/download/v0.36.1/aks-engine-v0.36.1-linux-amd64.tar.gz
W0702 07:26:21.359] 2019/07/02 07:26:21 azure.go:339: Extracting tar file /workspace/aks-engine.tar.gz into directory /go/src/k8s.io/kubernetes .
W0702 07:26:21.360] 2019/07/02 07:26:21 process.go:153: Running: tar -xzf /workspace/aks-engine.tar.gz --strip 1
W0702 07:26:21.498] 2019/07/02 07:26:21 process.go:155: Step 'tar -xzf /workspace/aks-engine.tar.gz --strip 1' finished in 138.942808ms
W0702 07:26:21.498] 2019/07/02 07:26:21 process.go:153: Running: /go/src/k8s.io/kubernetes/aks-engine generate /workspace/acs608788772/kubernetes.json --output-directory /workspace/acs608788772
I0702 07:26:21.681] INFO[0000] Generating assets into /workspace/acs608788772... 
W0702 07:26:40.153] 2019/07/02 07:26:40 process.go:155: Step '/go/src/k8s.io/kubernetes/aks-engine generate /workspace/acs608788772/kubernetes.json --output-directory /workspace/acs608788772' finished in 18.654371252s
W0702 07:26:40.157] 2019/07/02 07:26:40 azure.go:400: Setting kubeconfig env variable: kubeconfig path: /workspace/acs608788772/kubeconfig/kubeconfig.eastus2.json.
W0702 07:26:40.157] 2019/07/02 07:26:40 azure.go:402: Creating resource group: kubetest-42d7ea2a-9c97-11e9-9ef1-02425801647a.
W0702 07:26:40.158] 2019/07/02 07:26:40 azure.go:404: Creating Azure resource group: kubetest-42d7ea2a-9c97-11e9-9ef1-02425801647a for cluster deployment.
W0702 07:26:42.134] 2019/07/02 07:26:42 azure.go:409: Validating deployment ARM templates.
W0702 07:26:43.300] 2019/07/02 07:26:43 azure.go:415: Deploying cluster kubetest-42d7ea2a-9c97-11e9-9ef1-02425801647a in resource group kubetest-42d7ea2a-9c97-11e9-9ef1-02425801647a.
W0702 07:44:51.979] 2019/07/02 07:44:51 azure.go:674: Deleting resource group: kubetest-42d7ea2a-9c97-11e9-9ef1-02425801647a.
W0702 07:52:44.248] 2019/07/02 07:52:44 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml.
W0702 07:52:44.249] 2019/07/02 07:52:44 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"
W0702 07:52:44.524] 2019/07/02 07:52:44 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 275.389634ms
W0702 07:52:44.525] 2019/07/02 07:52:44 main.go:314: Something went wrong: starting e2e cluster: error creating cluster: cannot deploy: cannot get the create deployment future response: Code="DeploymentFailed" Message="At least one resource deployment operation failed. Please list deployment operations for details. Please see https://aka.ms/arm-debug for usage details." Details=[{"code":"Conflict","message":"{\r\n  \"status\": \"Failed\",\r\n  \"error\": {\r\n    \"code\": \"ResourceDeploymentFailure\",\r\n    \"message\": \"The resource operation completed with terminal provisioning state 'Failed'.\",\r\n    \"details\": [\r\n      {\r\n        \"code\": \"VMExtensionProvisioningError\",\r\n        \"message\": \"VM has reported a failure when processing extension 'cse-master-0'. Error message: \\\"Enable failed: failed to execute command: command terminated with exit status=30\\n[stdout]\\n\\n[stderr]\\nConnection to k8s.gcr.io 443 port [tcp/https] succeeded!\\nConnection to gcr.io 443 port [tcp/https] succeeded!\\nConnection to docker.io 443 port [tcp/https] succeeded!\\n\\\".\"\r\n      }\r\n    ]\r\n  }\r\n}"}]
W0702 07:52:44.526] Traceback (most recent call last):
W0702 07:52:44.526]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in <module>
W0702 07:52:44.527]     main(parse_args())
W0702 07:52:44.527]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main
W0702 07:52:44.527]     mode.start(runner_args)
W0702 07:52:44.527]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start
W0702 07:52:44.527]     check_env(env, self.command, *args)
W0702 07:52:44.528]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env
W0702 07:52:44.528]     subprocess.check_call(cmd, env=env)
W0702 07:52:44.528]   File "/usr/lib/python2.7/subprocess.py", line 186, in check_call
W0702 07:52:44.528]     raise CalledProcessError(retcode, cmd)
W0702 07:52:44.530] subprocess.CalledProcessError: Command '('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=bazel', '--up', '--down', '--test', '--deployment=acsengine', '--provider=skeleton', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--ginkgo-parallel=30', '--acsengine-agentpoolcount=3', '--acsengine-admin-username=azureuser', '--acsengine-creds=/etc/azure-cred/credentials', '--acsengine-orchestratorRelease=1.15', '--acsengine-mastervmsize=Standard_DS2_v2', '--acsengine-agentvmsize=Standard_D4s_v3', '--acsengine-hyperkube=True', '--acsengine-location=eastus2', '--acsengine-public-key=/etc/azure-ssh/azure-ssh-pub', '--acsengine-template-url=https://raw.githubusercontent.com/Azure/aks-engine/master/examples/kubernetes.json', '--acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.36.1/aks-engine-v0.36.1-linux-amd64.tar.gz', '--test_args= --ginkgo.skip=\\[sig-node\\]\\sMount\\spropagation|\\[sig-network\\]\\sNetwork\\sshould\\sset\\sTCP\\sCLOSE_WAIT\\stimeout|\\[sig-storage\\]\\sPersistentVolumes-local\\sStress\\swith\\slocal\\svolume\\sprovisioner\\s\\[Serial\\]\\sshould\\suse\\sbe\\sable\\sto\\sprocess\\smany\\spods\\sand\\sreuse\\slocal\\svolumes|should\\sunmount\\sif\\spod\\sis\\sgracefully\\sdeleted\\swhile\\skubelet\\sis\\sdown\\s\\[Disruptive\\]\\[Slow\\]|should\\sunmount\\sif\\spod\\sis\\sforce\\sdeleted\\swhile\\skubelet\\sis\\sdown\\s\\[Disruptive\\]\\[Slow\\]|\\[sig-network\\]\\sServices\\sshould\\sbe\\sable\\sto\\screate\\sa\\sfunctioning\\sNodePort\\sservice|\\[sig-scheduling\\]\\sSchedulerPredicates\\s\\[Serial\\]\\svalidates\\sMaxPods\\slimit\\snumber\\sof\\spods\\sthat\\sare\\sallowed\\sto\\srun\\s\\[Slow\\]|\\[sig-storage\\]\\sDynamic\\sProvisioning\\sDynamicProvisioner\\sDefault\\sshould\\screate\\sand\\sdelete\\sdefault\\spersistent\\svolumes\\s\\[Slow\\]|\\[sig-storage\\]\\sDynamic\\sProvisioning\\sDynamicProvisioner\\sshould\\sprovision\\sstorage\\swith\\sdifferent\\sparameters|\\[sig-storage\\]\\sDynamic\\sProvisioning\\sDynamicProvisioner\\sshould\\stest\\sthat\\sdeleting\\sa\\sclaim\\sbefore\\sthe\\svolume\\sis\\sprovisioned\\sdeletes\\sthe\\svolume.|\\[sig-apps\\]\\sStatefulSet\\s\\[k8s.io\\]\\sBasic\\sStatefulSet\\sfunctionality\\s\\[StatefulSetBasic\\]\\sshould\\sadopt\\smatching\\sorphans\\sand\\srelease\\snon-matching\\spods|\\[sig-apps\\]\\sStatefulSet\\s\\[k8s.io\\]\\sBasic\\sStatefulSet\\sfunctionality\\s\\[StatefulSetBasic\\]\\sshould\\snot\\sdeadlock\\swhen\\sa\\spod.s\\spredecessor\\sfails|\\[sig-apps\\]\\sStatefulSet\\s\\[k8s.io\\]\\sBasic\\sStatefulSet\\sfunctionality\\s\\[StatefulSetBasic\\]\\sshould\\sperform\\srolling\\supdates\\sand\\sroll\\sbacks\\sof\\stemplate\\smodifications\\swith\\sPVCs|\\[sig-apps\\]\\sStatefulSet\\s\\[k8s.io\\]\\sBasic\\sStatefulSet\\sfunctionality\\s\\[StatefulSetBasic\\]\\sshould\\sprovide\\sbasic\\sidentity|\\[sig-storage\\]\\sPersistentVolumes\\sDefault\\sStorageClass\\spods\\sthat\\suse\\smultiple\\svolumes\\sshould\\sbe\\sreschedulable|\\[sig-storage\\]\\sPVC\\sProtection|\\[sig-storage\\]\\sDynamic\\sProvisioning\\s\\[k8s.io\\]\\sGlusterDynamicProvisioner|\\[sig-storage\\]\\sVolumes\\sAzure\\sDisk\\sshould\\sbe\\smountable\\s\\[Slow\\]|\\[sig-apps\\]\\sNetwork\\sPartition\\s\\[Disruptive\\]\\s\\[Slow\\]|\\[sig-network\\]\\sDNS\\sconfigMap|\\[k8s.io\\]\\s\\[sig-node\\]\\sKubelet\\s\\[Serial\\]\\s\\[Slow\\]\\s\\[k8s.io\\]\\s\\[sig-node\\]\\sregular\\sresource\\susage\\stracking\\sresource\\stracking\\sfor\\s0\\spods\\sper\\snode|\\[k8s.io\\]\\s\\[sig-node\\]\\sKubelet\\s\\[Serial\\]\\s\\[Slow\\]\\s\\[k8s.io\\]\\s\\[sig-node\\]\\sregular\\sresource\\susage\\stracking\\sresource\\stracking\\sfor\\s100\\spods\\sper\\snode|Horizontal\\spod\\sautoscaling\\s\\(scale\\sresource:\\sCPU\\)|\\[sig-storage\\]\\sDynamic\\sProvisioning\\sDynamicProvisioner\\sExternal\\sshould\\slet\\san\\sexternal\\sdynamic\\sprovisioner\\screate\\sand\\sdelete\\spersistent\\svolumes\\s\\[Slow\\]|ESIPP|\\[sig-network\\]\\sServices\\sshould\\spreserve\\ssource\\spod\\sIP\\sfor\\straffic\\sthru\\sservice\\scluster\\sIP|In-tree\\sVolumes|PersistentVolumes-local|CSI\\sVolumes|should\\swrite\\sentries\\sto\\s/etc/hosts|\\[Slow\\]|\\[Serial\\]|\\[Disruptive\\]|\\[Flaky\\]|\\[Feature:.+\\]|\\[NodeFeature:.+\\]', '--timeout=420m')' returned non-zero exit status 1
E0702 07:52:44.534] Command failed
I0702 07:52:44.534] process 688 exited with code 1 after 50.9m
E0702 07:52:44.534] FAIL: pull-kubernetes-e2e-aks-engine-azure
I0702 07:52:44.534] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W0702 07:52:45.288] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I0702 07:52:45.318] process 27912 exited with code 0 after 0.0m
I0702 07:52:45.319] Call:  gcloud config get-value account
I0702 07:52:45.558] process 27924 exited with code 0 after 0.0m
I0702 07:52:45.558] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
I0702 07:52:45.558] Upload result and artifacts...
I0702 07:52:45.558] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/Azure_kubernetes/112/pull-kubernetes-e2e-aks-engine-azure/1145950156466688000
I0702 07:52:45.558] Call:  gsutil ls gs://kubernetes-upstream/pr-logs/pull/Azure_kubernetes/112/pull-kubernetes-e2e-aks-engine-azure/1145950156466688000/artifacts
W0702 07:52:46.704] CommandException: One or more URLs matched no objects.
E0702 07:52:46.782] Command failed
I0702 07:52:46.782] process 27936 exited with code 1 after 0.0m
W0702 07:52:46.782] Remote dir gs://kubernetes-upstream/pr-logs/pull/Azure_kubernetes/112/pull-kubernetes-e2e-aks-engine-azure/1145950156466688000/artifacts not exist yet
I0702 07:52:46.783] Call:  gsutil -m -q -o GSUtil:use_magicfile=True cp -r -c -z log,txt,xml /workspace/_artifacts gs://kubernetes-upstream/pr-logs/pull/Azure_kubernetes/112/pull-kubernetes-e2e-aks-engine-azure/1145950156466688000/artifacts
I0702 07:52:48.300] process 28078 exited with code 0 after 0.0m
I0702 07:52:48.300] Call:  git rev-parse HEAD
I0702 07:52:48.303] process 28602 exited with code 0 after 0.0m
I0702 07:52:48.304] Call:  git rev-parse HEAD
I0702 07:52:48.308] process 28603 exited with code 0 after 0.0m
I0702 07:52:48.308] Call:  gsutil stat gs://kubernetes-upstream/pr-logs/directory/pull-kubernetes-e2e-aks-engine-azure/jobResultsCache.json
I0702 07:52:49.247] process 28604 exited with code 0 after 0.0m
I0702 07:52:49.247] Call:  gsutil -q cat 'gs://kubernetes-upstream/pr-logs/directory/pull-kubernetes-e2e-aks-engine-azure/jobResultsCache.json#1562048942105891'
I0702 07:52:50.462] process 28746 exited with code 0 after 0.0m
I0702 07:52:50.463] Call:  gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1562048942105891 cp /tmp/gsutil_COc7yU gs://kubernetes-upstream/pr-logs/directory/pull-kubernetes-e2e-aks-engine-azure/jobResultsCache.json
I0702 07:52:51.719] process 28890 exited with code 0 after 0.0m
I0702 07:52:51.720] Call:  gsutil stat gs://kubernetes-upstream/pr-logs/pull/Azure_kubernetes/112/pull-kubernetes-e2e-aks-engine-azure/jobResultsCache.json
I0702 07:52:52.673] process 29068 exited with code 0 after 0.0m
I0702 07:52:52.674] Call:  gsutil -q cat 'gs://kubernetes-upstream/pr-logs/pull/Azure_kubernetes/112/pull-kubernetes-e2e-aks-engine-azure/jobResultsCache.json#1562048945894744'
I0702 07:52:53.875] process 29210 exited with code 0 after 0.0m
I0702 07:52:53.876] Call:  gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1562048945894744 cp /tmp/gsutil_2bBNKZ gs://kubernetes-upstream/pr-logs/pull/Azure_kubernetes/112/pull-kubernetes-e2e-aks-engine-azure/jobResultsCache.json
I0702 07:52:55.272] process 29354 exited with code 0 after 0.0m
I0702 07:52:55.273] Call:  gsutil -q -h Content-Type:application/json cp /tmp/gsutil_ZTb0nq gs://kubernetes-upstream/pr-logs/pull/Azure_kubernetes/112/pull-kubernetes-e2e-aks-engine-azure/1145950156466688000/finished.json
I0702 07:52:56.598] process 29532 exited with code 0 after 0.0m
I0702 07:52:56.598] Call:  gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_Uhmrgx gs://kubernetes-upstream/pr-logs/pull/Azure_kubernetes/112/pull-kubernetes-e2e-aks-engine-azure/latest-build.txt
I0702 07:52:57.941] process 29710 exited with code 0 after 0.0m
I0702 07:52:57.941] Call:  gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_k6x1il gs://kubernetes-upstream/pr-logs/directory/pull-kubernetes-e2e-aks-engine-azure/latest-build.txt
I0702 07:52:59.373] process 29888 exited with code 0 after 0.0m