W1126 19:14:59.299] ************************************************************************** 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 ************************************************************************** I1126 19:14:59.300] Args: --job=chewong-in-tree-azure-disk-e2e --service-account=/etc/service-account/service-account.json --upload=gs://kubernetes-jenkins/logs --job=chewong-in-tree-azure-disk-e2e --root=/go/src --service-account=/etc/service-account/service-account.json --repo=k8s.io/kubernetes=master:1c5b6cb66e6ae85177e76d4fddf7d99473ab2aed,85621:dd76fdfce5554cc15ee7ed999bea1cffb0436d0a --upload=gs://kubernetes-upstream/pr-logs --timeout=460 --scenario=kubernetes_e2e -- --gce-ssh= --test=true --up=true --down=true --deployment=acsengine --build=host-go --provider=azure --ginkgo-parallel=10 --acsengine-agentpoolcount=2 --acsengine-admin-username=azureuser '--acsengine-creds=$AZURE_CREDENTIALS' --acsengine-orchestratorRelease=1.16 --acsengine-mastervmsize=Standard_DS2_v2 --acsengine-agentvmsize=Standard_D4s_v3 --acsengine-hyperkube=True --acsengine-location=westus2 '--acsengine-public-key=$AZURE_SSH_PUBLIC_KEY_FILE' --acsengine-template-url=https://gist.githubusercontent.com/chewong/facb90983ad2337a0049538cf82f9bf9/raw/5a5bad9e47b137a684f2fa98d645175315aa8161/linux.json --acsengine-download-url=https://aka.ms/aks-engine/aks-engine-k8s-e2e.tar.gz '--test_args=--ginkgo.focus=azure-disk --ginkgo.skip=\[Slow\]|\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\]' --timeout=420m I1126 19:14:59.300] Bootstrap chewong-in-tree-azure-disk-e2e... I1126 19:14:59.303] Builder: f425d412-1080-11ea-918b-16773c0c7aed I1126 19:14:59.303] Image: gcr.io/k8s-testimages/kubekins-e2e:v20191124-4beb966-master I1126 19:14:59.304] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199406141650505728 I1126 19:14:59.304] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1126 19:14:59.797] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1126 19:14:59.829] process 212 exited with code 0 after 0.0m I1126 19:14:59.830] Call: gcloud config get-value account I1126 19:15:00.080] process 225 exited with code 0 after 0.0m I1126 19:15:00.081] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1126 19:15:00.081] Root: /go/src I1126 19:15:00.081] cd to /go/src I1126 19:15:00.081] Checkout: /go/src/k8s.io/kubernetes master:1c5b6cb66e6ae85177e76d4fddf7d99473ab2aed,85621:dd76fdfce5554cc15ee7ed999bea1cffb0436d0a to /go/src/k8s.io/kubernetes I1126 19:15:00.081] Call: git init k8s.io/kubernetes I1126 19:15:00.086] Initialized empty Git repository in /go/src/k8s.io/kubernetes/.git/ I1126 19:15:00.086] process 238 exited with code 0 after 0.0m I1126 19:15:00.086] Call: git config --local user.name 'K8S Bootstrap' I1126 19:15:00.089] process 239 exited with code 0 after 0.0m I1126 19:15:00.089] Call: git config --local user.email k8s_bootstrap@localhost I1126 19:15:00.091] process 240 exited with code 0 after 0.0m I1126 19:15:00.092] Call: git fetch --quiet --tags https://github.com/kubernetes/kubernetes master +refs/pull/85621/head:refs/pr/85621 I1126 19:15:59.196] process 241 exited with code 0 after 1.0m I1126 19:15:59.196] Call: git checkout -B test 1c5b6cb66e6ae85177e76d4fddf7d99473ab2aed W1126 19:16:01.382] Switched to a new branch 'test' I1126 19:16:01.392] process 252 exited with code 0 after 0.0m I1126 19:16:01.392] Call: git show -s --format=format:%ct HEAD I1126 19:16:01.417] process 253 exited with code 0 after 0.0m I1126 19:16:01.417] Call: git merge --no-ff -m 'Merge +refs/pull/85621/head:refs/pr/85621' dd76fdfce5554cc15ee7ed999bea1cffb0436d0a I1126 19:16:02.026] Merge made by the 'recursive' strategy. I1126 19:16:02.029] test/e2e/storage/drivers/in_tree.go | 46 ++++++++++++++++++------------------- I1126 19:16:02.029] test/e2e/storage/in_tree_volumes.go | 2 +- I1126 19:16:02.029] 2 files changed, 24 insertions(+), 24 deletions(-) I1126 19:16:02.030] process 254 exited with code 0 after 0.0m I1126 19:16:02.030] Configure environment... I1126 19:16:02.030] Call: git show -s --format=format:%ct HEAD I1126 19:16:02.034] process 296 exited with code 0 after 0.0m I1126 19:16:02.035] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1126 19:16:02.687] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1126 19:16:02.807] process 297 exited with code 0 after 0.0m I1126 19:16:02.807] Call: gcloud config get-value account I1126 19:16:03.052] process 310 exited with code 0 after 0.0m I1126 19:16:03.052] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1126 19:16:03.052] 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 ' I1126 19:16:03.285] process 323 exited with code 0 after 0.0m I1126 19:16:03.285] Start 1199406141650505728 at v1.18.0-alpha.0.1190+cff90159704e47... I1126 19:16:03.287] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil__j2va0 gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199406141650505728/started.json I1126 19:16:04.609] process 356 exited with code 0 after 0.0m I1126 19:16:04.610] Call: gsutil -q -h Content-Type:text/plain -h 'x-goog-meta-link: gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199406141650505728' cp /tmp/gsutil_ppSNwD gs://kubernetes-upstream/pr-logs/directory/chewong-in-tree-azure-disk-e2e/1199406141650505728.txt I1126 19:16:05.947] process 537 exited with code 0 after 0.0m I1126 19:16:05.948] Call: /workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py --gce-ssh= --test=true --up=true --down=true --deployment=acsengine --build=host-go --provider=azure --ginkgo-parallel=10 --acsengine-agentpoolcount=2 --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-location=westus2 --acsengine-public-key=/etc/azure-ssh/azure-ssh-pub --acsengine-template-url=https://gist.githubusercontent.com/chewong/facb90983ad2337a0049538cf82f9bf9/raw/5a5bad9e47b137a684f2fa98d645175315aa8161/linux.json --acsengine-download-url=https://aka.ms/aks-engine/aks-engine-k8s-e2e.tar.gz '--test_args=--ginkgo.focus=azure-disk --ginkgo.skip=\[Slow\]|\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\]' --timeout=420m W1126 19:16:05.983] starts with local mode W1126 19:16:05.984] Environment: W1126 19:16:05.984] ARTIFACTS=/workspace/_artifacts W1126 19:16:05.984] AWS_SSH_PRIVATE_KEY_FILE=/root/.ssh/kube_aws_rsa W1126 19:16:05.984] AWS_SSH_PUBLIC_KEY_FILE=/root/.ssh/kube_aws_rsa.pub W1126 19:16:05.984] AZURE_CREDENTIALS=/etc/azure-cred/credentials W1126 19:16:05.984] AZURE_SSH_PUBLIC_KEY_FILE=/etc/azure-ssh/azure-ssh-pub W1126 19:16:05.985] AZ_STORAGE_CONTAINER_NAME=mystoragecontainer W1126 19:16:05.985] BAZEL_REMOTE_CACHE_ENABLED=false W1126 19:16:05.985] BAZEL_VERSION=0.23.2 W1126 19:16:05.985] BOOTSTRAP_MIGRATION=yes W1126 19:16:05.985] BUILD_ID=1199406141650505728 W1126 19:16:05.985] BUILD_NUMBER=1199406141650505728 W1126 19:16:05.985] CLOUDSDK_COMPONENT_MANAGER_DISABLE_UPDATE_CHECK=true W1126 19:16:05.986] CLOUDSDK_CONFIG=/go/src/k8s.io/kubernetes/.config/gcloud W1126 19:16:05.986] CLOUDSDK_CORE_DISABLE_PROMPTS=1 W1126 19:16:05.986] CLOUDSDK_EXPERIMENTAL_FAST_COMPONENT_UPDATE=false W1126 19:16:05.986] CLOUD_CONFIG=random W1126 19:16:05.986] DECK_PORT=tcp://10.0.160.83:80 W1126 19:16:05.986] DECK_PORT_80_TCP=tcp://10.0.160.83:80 W1126 19:16:05.987] DECK_PORT_80_TCP_ADDR=10.0.160.83 W1126 19:16:05.987] DECK_PORT_80_TCP_PORT=80 W1126 19:16:05.987] DECK_PORT_80_TCP_PROTO=tcp W1126 19:16:05.987] DECK_SERVICE_HOST=10.0.160.83 W1126 19:16:05.987] DECK_SERVICE_PORT=80 W1126 19:16:05.987] DOCKER_IN_DOCKER_ENABLED=true W1126 19:16:05.987] DOCKER_IN_DOCKER_IPV6_ENABLED=false W1126 19:16:05.988] GCS_ARTIFACTS_DIR=gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199406141650505728/artifacts W1126 19:16:05.988] GOOGLE_APPLICATION_CREDENTIALS=/etc/service-account/service-account.json W1126 19:16:05.988] GOPATH=/go W1126 19:16:05.988] GO_TARBALL=go1.12.12.linux-amd64.tar.gz W1126 19:16:05.988] HOME=/workspace W1126 19:16:05.988] HOOK_PORT=tcp://10.0.144.133:8888 W1126 19:16:05.988] HOOK_PORT_8888_TCP=tcp://10.0.144.133:8888 W1126 19:16:05.988] HOOK_PORT_8888_TCP_ADDR=10.0.144.133 W1126 19:16:05.989] HOOK_PORT_8888_TCP_PORT=8888 W1126 19:16:05.989] HOOK_PORT_8888_TCP_PROTO=tcp W1126 19:16:05.989] HOOK_SERVICE_HOST=10.0.144.133 W1126 19:16:05.989] HOOK_SERVICE_PORT=8888 W1126 19:16:05.989] HOSTNAME=f425d412-1080-11ea-918b-16773c0c7aed W1126 19:16:05.989] IMAGE=gcr.io/k8s-testimages/kubekins-e2e:v20191124-4beb966-master W1126 19:16:05.989] INSTANCE_PREFIX=bootstrap-e2e W1126 19:16:05.990] JENKINS_GCE_SSH_PRIVATE_KEY_FILE=/root/.ssh/google_compute_engine W1126 19:16:05.990] JENKINS_GCE_SSH_PUBLIC_KEY_FILE=/root/.ssh/google_compute_engine.pub W1126 19:16:05.990] JOB_NAME=chewong-in-tree-azure-disk-e2e W1126 19:16:05.990] JOB_SPEC={"type":"presubmit","job":"chewong-in-tree-azure-disk-e2e","buildid":"1199406141650505728","prowjobid":"f425d412-1080-11ea-918b-16773c0c7aed","refs":{"org":"Azure","repo":"kubernetes","repo_link":"https://github.com/Azure/kubernetes","base_ref":"master","base_sha":"e4ad76e29854f1fc167fd78a98c0a455b2f4282a","base_link":"https://github.com/Azure/kubernetes/commit/e4ad76e29854f1fc167fd78a98c0a455b2f4282a","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"}]}} W1126 19:16:05.990] JOB_TYPE=presubmit W1126 19:16:05.991] KUBERNETES_CONFORMANCE_PROVIDER=azure W1126 19:16:05.991] KUBERNETES_PORT=tcp://10.0.0.1:443 W1126 19:16:05.991] KUBERNETES_PORT_443_TCP=tcp://10.0.0.1:443 W1126 19:16:05.991] KUBERNETES_PORT_443_TCP_ADDR=10.0.0.1 W1126 19:16:05.991] KUBERNETES_PORT_443_TCP_PORT=443 W1126 19:16:05.991] KUBERNETES_PORT_443_TCP_PROTO=tcp W1126 19:16:05.991] KUBERNETES_SERVICE_HOST=10.0.0.1 W1126 19:16:05.991] KUBERNETES_SERVICE_PORT=443 W1126 19:16:05.992] KUBERNETES_SERVICE_PORT_HTTPS=443 W1126 19:16:05.992] KUBETEST_IN_DOCKER=true W1126 19:16:05.992] KUBETEST_MANUAL_DUMP=y W1126 19:16:05.992] KUBE_AWS_INSTANCE_PREFIX=bootstrap-e2e W1126 19:16:05.992] KUBE_GCE_INSTANCE_PREFIX=bootstrap-e2e W1126 19:16:05.992] KUBE_SSH_KEY_PATH=/etc/ssh-key-secret/ssh-private W1126 19:16:05.992] KUBE_SSH_PUBLIC_KEY_PATH=/etc/ssh-key-secret/ssh-public W1126 19:16:05.992] KUBE_SSH_USER=azureuser W1126 19:16:05.993] KUBE_VERBOSE=0 W1126 19:16:05.993] NODE_NAME=f425d412-1080-11ea-918b-16773c0c7aed W1126 19:16:05.993] 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 W1126 19:16:05.993] PROW_JOB_ID=f425d412-1080-11ea-918b-16773c0c7aed W1126 19:16:05.993] PULL_BASE_REF=master W1126 19:16:05.993] PULL_BASE_SHA=e4ad76e29854f1fc167fd78a98c0a455b2f4282a W1126 19:16:05.993] PULL_NUMBER=113 W1126 19:16:05.994] PULL_PULL_SHA=879465972041635fd7bc8269da49153b67e63822 W1126 19:16:05.994] PULL_REFS=master:e4ad76e29854f1fc167fd78a98c0a455b2f4282a,113:879465972041635fd7bc8269da49153b67e63822 W1126 19:16:05.994] PWD=/workspace W1126 19:16:05.994] REGISTRY=k8sprowinternal.azurecr.io W1126 19:16:05.994] REPO_NAME=kubernetes W1126 19:16:05.994] REPO_OWNER=Azure W1126 19:16:05.994] SHLVL=2 W1126 19:16:05.994] SOURCE_DATE_EPOCH=1574729000 W1126 19:16:05.995] TERM=xterm W1126 19:16:05.995] TIDE_PORT=tcp://10.0.180.53:80 W1126 19:16:05.995] TIDE_PORT_80_TCP=tcp://10.0.180.53:80 W1126 19:16:05.995] TIDE_PORT_80_TCP_ADDR=10.0.180.53 W1126 19:16:05.995] TIDE_PORT_80_TCP_PORT=80 W1126 19:16:05.995] TIDE_PORT_80_TCP_PROTO=tcp W1126 19:16:05.995] TIDE_SERVICE_HOST=10.0.180.53 W1126 19:16:05.995] TIDE_SERVICE_PORT=80 W1126 19:16:05.995] WORKSPACE=/workspace W1126 19:16:05.996] _=./test-infra/jenkins/bootstrap.py W1126 19:16:05.996] Run: ('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=host-go', '--up', '--down', '--test', '--deployment=acsengine', '--provider=azure', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--ginkgo-parallel=10', '--acsengine-agentpoolcount=2', '--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-location=westus2', '--acsengine-public-key=/etc/azure-ssh/azure-ssh-pub', '--acsengine-template-url=https://gist.githubusercontent.com/chewong/facb90983ad2337a0049538cf82f9bf9/raw/5a5bad9e47b137a684f2fa98d645175315aa8161/linux.json', '--acsengine-download-url=https://aka.ms/aks-engine/aks-engine-k8s-e2e.tar.gz', '--test_args=--ginkgo.focus=azure-disk --ginkgo.skip=\\[Slow\\]|\\[Serial\\]|\\[Disruptive\\]|\\[Flaky\\]|\\[Feature:.+\\]', '--timeout=420m') W1126 19:16:06.003] 2019/11/26 19:16:06 main.go:332: Limiting testing to 7h0m0s W1126 19:16:06.007] 2019/11/26 19:16:06 azure.go:242: Reading credentials file /etc/azure-cred/credentials W1126 19:16:06.007] 2019/11/26 19:16:06 process.go:153: Running: make -C /go/src/k8s.io/kubernetes all I1126 19:16:06.107] make: Entering directory '/go/src/k8s.io/kubernetes' I1126 19:16:06.108] make[1]: Entering directory '/go/src/k8s.io/kubernetes' I1126 19:16:13.942] +++ [1126 19:16:13] Building go targets for linux/amd64: I1126 19:16:13.942] ./vendor/k8s.io/code-generator/cmd/deepcopy-gen I1126 19:16:21.001] +++ [1126 19:16:21] Building go targets for linux/amd64: I1126 19:16:21.001] ./vendor/k8s.io/code-generator/cmd/defaulter-gen I1126 19:16:26.653] +++ [1126 19:16:26] Building go targets for linux/amd64: I1126 19:16:26.653] ./vendor/k8s.io/code-generator/cmd/conversion-gen I1126 19:16:36.759] +++ [1126 19:16:36] Building go targets for linux/amd64: I1126 19:16:36.759] ./vendor/k8s.io/kube-openapi/cmd/openapi-gen I1126 19:16:48.895] +++ [1126 19:16:48] Building go targets for linux/amd64: I1126 19:16:48.896] ./vendor/github.com/go-bindata/go-bindata/go-bindata I1126 19:16:50.203] make[1]: Leaving directory '/go/src/k8s.io/kubernetes' I1126 19:16:50.509] +++ [1126 19:16:50] Building go targets for linux/amd64: I1126 19:16:50.509] cmd/kube-proxy I1126 19:16:50.510] cmd/kube-apiserver I1126 19:16:50.510] cmd/kube-controller-manager I1126 19:16:50.510] cmd/kubelet I1126 19:16:50.510] cmd/kubeadm I1126 19:16:50.510] cmd/kube-scheduler I1126 19:16:50.510] vendor/k8s.io/apiextensions-apiserver I1126 19:16:50.510] cluster/gce/gci/mounter I1126 19:16:50.510] cmd/kubectl I1126 19:16:50.510] cmd/gendocs I1126 19:16:50.510] cmd/genkubedocs I1126 19:16:50.510] cmd/genman I1126 19:16:50.511] cmd/genyaml I1126 19:16:50.511] cmd/genswaggertypedocs I1126 19:16:50.511] cmd/linkcheck I1126 19:16:50.511] vendor/github.com/onsi/ginkgo/ginkgo I1126 19:16:50.511] test/e2e/e2e.test I1126 19:16:50.511] cluster/images/conformance/go-runner I1126 19:16:50.511] cmd/kubemark I1126 19:16:50.511] vendor/github.com/onsi/ginkgo/ginkgo I1126 19:16:50.511] test/e2e_node/e2e_node.test I1126 19:21:12.846] make: Leaving directory '/go/src/k8s.io/kubernetes' W1126 19:21:12.946] 2019/11/26 19:21:12 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes all' finished in 5m6.838788913s W1126 19:21:12.946] 2019/11/26 19:21:12 util.go:265: Flushing memory. W1126 19:21:32.982] 2019/11/26 19:21:32 azure.go:959: Deleting resource group: kubetest-31c4da8b-1081-11ea-bdaf-0242daa89aab. W1126 19:21:33.316] 2019/11/26 19:21:33 azure.go:694: CWD /go/src/k8s.io/kubernetes W1126 19:21:33.316] 2019/11/26 19:21:33 azure.go:713: Attempting Docker login with azure cred. W1126 19:21:34.575] 2019/11/26 19:21:34 azure.go:722: Docker login success. W1126 19:21:34.576] 2019/11/26 19:21:34 azure.go:763: Building hyperkube. W1126 19:21:34.577] 2019/11/26 19:21:34 util.go:56: Warning: Couldn't find directory src/k8s.io/kubernetes/cmd/hyperkube under any of GOPATH /go, defaulting to /go/src/k8s.io/kubernetes/cmd/hyperkube W1126 19:21:34.577] 2019/11/26 19:21:34 azure.go:781: Pushing hyperkube. W1126 19:21:34.577] 2019/11/26 19:21:34 process.go:153: Running: make -C /go/src/k8s.io/kubernetes/cluster/images/hyperkube push I1126 19:21:34.677] make: Entering directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube' I1126 19:21:34.678] cp -r ./* /tmp/hyperkubeKc3W8y I1126 19:21:34.678] tar -cvzf /tmp/hyperkubeKc3W8y/binaries.tgz -C /go/src/k8s.io/kubernetes/cluster/images/hyperkube/../../../_output/local/bin/linux/amd64 kube-apiserver kube-controller-manager \ I1126 19:21:34.678] kube-proxy kube-scheduler kubectl kubelet I1126 19:21:34.678] kube-apiserver I1126 19:21:40.121] kube-controller-manager I1126 19:21:45.269] kube-proxy I1126 19:21:47.268] kube-scheduler I1126 19:21:49.524] kubectl I1126 19:21:51.861] kubelet I1126 19:21:57.241] chmod a+rx /tmp/hyperkubeKc3W8y/hyperkube I1126 19:21:57.242] cd /tmp/hyperkubeKc3W8y && sed -i.back "s|BASEIMAGE|k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1|g" Dockerfile I1126 19:21:57.245] docker build --pull -t k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1199406141650505728-31c4cbed /tmp/hyperkubeKc3W8y I1126 19:21:58.134] Sending build context to Docker daemon 122.6MB I1126 19:21:58.156] Step 1/4 : FROM k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1 I1126 19:21:58.518] 0.12.1: Pulling from debian-hyperkube-base-amd64 I1126 19:21:58.519] 346aee5ea5bc: Pulling fs layer I1126 19:21:58.519] 9c47fde751af: Pulling fs layer I1126 19:21:58.519] be2693a52daf: Pulling fs layer I1126 19:21:58.519] 6b69eb11d043: Pulling fs layer I1126 19:21:58.519] 0abeb1500767: Pulling fs layer I1126 19:21:58.519] 4062d80041b7: Pulling fs layer I1126 19:21:58.520] 23b6daf06fc2: Pulling fs layer I1126 19:21:58.520] 0abeb1500767: Waiting I1126 19:21:58.520] 4062d80041b7: Waiting I1126 19:21:58.520] 23b6daf06fc2: Waiting I1126 19:21:58.520] 6b69eb11d043: Waiting I1126 19:21:58.673] 9c47fde751af: Verifying Checksum I1126 19:21:58.673] 9c47fde751af: Download complete I1126 19:21:58.700] be2693a52daf: Verifying Checksum I1126 19:21:58.700] be2693a52daf: Download complete I1126 19:21:58.810] 6b69eb11d043: Verifying Checksum I1126 19:21:58.810] 6b69eb11d043: Download complete I1126 19:21:58.837] 0abeb1500767: Download complete I1126 19:21:59.339] 346aee5ea5bc: Verifying Checksum I1126 19:21:59.583] 23b6daf06fc2: Verifying Checksum I1126 19:21:59.583] 23b6daf06fc2: Download complete I1126 19:22:00.555] 346aee5ea5bc: Pull complete I1126 19:22:00.756] 9c47fde751af: Pull complete I1126 19:22:00.968] be2693a52daf: Pull complete I1126 19:22:00.991] 4062d80041b7: Verifying Checksum I1126 19:22:00.991] 4062d80041b7: Download complete I1126 19:22:01.119] 6b69eb11d043: Pull complete I1126 19:22:01.275] 0abeb1500767: Pull complete I1126 19:22:07.466] 4062d80041b7: Pull complete I1126 19:22:09.664] 23b6daf06fc2: Pull complete I1126 19:22:09.688] Digest: sha256:5d4ea2fb5fbe9a9a9da74f67cf2faefc881968bc39f2ac5d62d9167e575812a1 I1126 19:22:09.708] Status: Downloaded newer image for k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1 I1126 19:22:09.709] ---> a46476511725 I1126 19:22:09.709] Step 2/4 : ADD binaries.tgz /usr/local/bin I1126 19:22:35.905] ---> b2421cbc3381 I1126 19:22:35.905] Step 3/4 : COPY hyperkube /hyperkube I1126 19:22:36.563] ---> 0aacdc6ba19d I1126 19:22:36.563] Step 4/4 : ENTRYPOINT ["/hyperkube"] I1126 19:22:36.742] ---> Running in 81e99a4a575f I1126 19:22:37.307] Removing intermediate container 81e99a4a575f I1126 19:22:37.307] ---> c9bf0c2c4d92 I1126 19:22:37.323] Successfully built c9bf0c2c4d92 I1126 19:22:37.394] Successfully tagged k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1199406141650505728-31c4cbed I1126 19:22:37.398] rm -rf "/tmp/hyperkubeKc3W8y" I1126 19:22:37.418] docker push k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1199406141650505728-31c4cbed I1126 19:22:37.486] The push refers to repository [k8sprowinternal.azurecr.io/hyperkube-amd64] I1126 19:22:37.500] 7a562a3c9fa1: Preparing I1126 19:22:37.500] 3aa6e7c37101: Preparing I1126 19:22:37.500] 39b3ac6d96e9: Preparing I1126 19:22:37.500] 7bbae4dddb88: Preparing I1126 19:22:37.500] a00defcfe869: Preparing I1126 19:22:37.501] 2ab0ae805c74: Preparing I1126 19:22:37.501] 43a8fe7d2382: Preparing I1126 19:22:37.501] 3f6a6f542637: Preparing I1126 19:22:37.501] 5ba3be777c2d: Preparing I1126 19:22:37.501] 2ab0ae805c74: Waiting I1126 19:22:37.501] 43a8fe7d2382: Waiting I1126 19:22:37.501] 5ba3be777c2d: Waiting I1126 19:22:37.751] 7bbae4dddb88: Layer already exists I1126 19:22:37.772] 39b3ac6d96e9: Layer already exists I1126 19:22:37.797] a00defcfe869: Layer already exists I1126 19:22:37.819] 2ab0ae805c74: Layer already exists I1126 19:22:37.889] 3f6a6f542637: Layer already exists I1126 19:22:37.903] 7a562a3c9fa1: Pushed I1126 19:22:38.080] 43a8fe7d2382: Layer already exists I1126 19:22:38.101] 5ba3be777c2d: Layer already exists I1126 19:23:02.581] 3aa6e7c37101: Pushed I1126 19:23:03.432] azure-e2e-1199406141650505728-31c4cbed: digest: sha256:37bc12acf754f85a73bb1539bd4c6667c49a496d8297f7d35513154c288d6fb6 size: 2206 I1126 19:23:03.461] docker rmi k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1199406141650505728-31c4cbed 2>/dev/null || true I1126 19:23:03.508] docker tag k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1199406141650505728-31c4cbed k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1199406141650505728-31c4cbed I1126 19:23:03.575] docker push k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1199406141650505728-31c4cbed I1126 19:23:03.639] The push refers to repository [k8sprowinternal.azurecr.io/hyperkube] I1126 19:23:03.651] 7a562a3c9fa1: Preparing I1126 19:23:03.651] 3aa6e7c37101: Preparing I1126 19:23:03.651] 39b3ac6d96e9: Preparing I1126 19:23:03.651] 7bbae4dddb88: Preparing I1126 19:23:03.652] a00defcfe869: Preparing I1126 19:23:03.652] 2ab0ae805c74: Preparing I1126 19:23:03.652] 43a8fe7d2382: Preparing I1126 19:23:03.652] 3f6a6f542637: Preparing I1126 19:23:03.652] 5ba3be777c2d: Preparing I1126 19:23:03.652] 2ab0ae805c74: Waiting I1126 19:23:03.652] 43a8fe7d2382: Waiting I1126 19:23:03.652] 5ba3be777c2d: Waiting I1126 19:23:03.749] a00defcfe869: Layer already exists I1126 19:23:03.770] 39b3ac6d96e9: Layer already exists I1126 19:23:03.793] 7bbae4dddb88: Layer already exists I1126 19:23:04.043] 43a8fe7d2382: Layer already exists I1126 19:23:04.052] 7a562a3c9fa1: Mounted from hyperkube-amd64 I1126 19:23:04.066] 2ab0ae805c74: Layer already exists I1126 19:23:04.110] 5ba3be777c2d: Layer already exists I1126 19:23:04.133] 3f6a6f542637: Layer already exists I1126 19:23:04.174] 3aa6e7c37101: Mounted from hyperkube-amd64 I1126 19:23:05.156] azure-e2e-1199406141650505728-31c4cbed: digest: sha256:37bc12acf754f85a73bb1539bd4c6667c49a496d8297f7d35513154c288d6fb6 size: 2206 I1126 19:23:05.172] make: Leaving directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube' W1126 19:23:05.273] 2019/11/26 19:23:05 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes/cluster/images/hyperkube push' finished in 1m30.595659223s W1126 19:23:05.273] 2019/11/26 19:23:05 azure.go:787: Custom hyperkube URL: k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1199406141650505728-31c4cbed . W1126 19:23:05.273] 2019/11/26 19:23:05 azure.go:830: downloading /workspace/aks562465001/kubernetes.json from https://gist.githubusercontent.com/chewong/facb90983ad2337a0049538cf82f9bf9/raw/5a5bad9e47b137a684f2fa98d645175315aa8161/linux.json. W1126 19:23:05.273] 2019/11/26 19:23:05 util.go:42: curl https://gist.githubusercontent.com/chewong/facb90983ad2337a0049538cf82f9bf9/raw/5a5bad9e47b137a684f2fa98d645175315aa8161/linux.json W1126 19:23:05.537] 2019/11/26 19:23:05 azure.go:569: downloading /workspace/aks-engine.tar.gz from https://aka.ms/aks-engine/aks-engine-k8s-e2e.tar.gz. W1126 19:23:05.537] 2019/11/26 19:23:05 util.go:42: curl https://aka.ms/aks-engine/aks-engine-k8s-e2e.tar.gz W1126 19:23:06.382] 2019/11/26 19:23:06 azure.go:596: Extracting tar file /workspace/aks-engine.tar.gz into directory /go/src/k8s.io/kubernetes . W1126 19:23:06.382] 2019/11/26 19:23:06 process.go:153: Running: tar -xzf /workspace/aks-engine.tar.gz --strip 1 W1126 19:23:06.820] 2019/11/26 19:23:06 process.go:155: Step 'tar -xzf /workspace/aks-engine.tar.gz --strip 1' finished in 437.910875ms W1126 19:23:06.820] 2019/11/26 19:23:06 process.go:153: Running: /go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks562465001/kubernetes.json --output-directory /workspace/aks562465001 I1126 19:23:06.920] INFO[0000] Generating assets into /workspace/aks562465001... W1126 19:23:14.030] 2019/11/26 19:23:14 process.go:155: Step '/go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks562465001/kubernetes.json --output-directory /workspace/aks562465001' finished in 7.210663899s W1126 19:23:14.034] 2019/11/26 19:23:14 azure.go:667: Setting kubeconfig env variable: kubeconfig path: /workspace/aks562465001/kubeconfig/kubeconfig.westus2.json. W1126 19:23:14.034] 2019/11/26 19:23:14 azure.go:669: Creating resource group: kubetest-31c4da8b-1081-11ea-bdaf-0242daa89aab. W1126 19:23:14.034] 2019/11/26 19:23:14 azure.go:671: Creating Azure resource group: kubetest-31c4da8b-1081-11ea-bdaf-0242daa89aab for cluster deployment. W1126 19:23:14.183] 2019/11/26 19:23:14 azure.go:676: Validating deployment ARM templates. W1126 19:23:15.066] 2019/11/26 19:23:15 azure.go:682: Deploying cluster kubetest-31c4da8b-1081-11ea-bdaf-0242daa89aab in resource group kubetest-31c4da8b-1081-11ea-bdaf-0242daa89aab. W1126 19:31:16.252] 2019/11/26 19:31:16 azure.go:727: Docker logout. W1126 19:31:16.324] 2019/11/26 19:31:16 process.go:153: Running: kubectl --match-server-version=false version W1126 19:31:16.688] 2019/11/26 19:31:16 process.go:155: Step 'kubectl --match-server-version=false version' finished in 363.948518ms W1126 19:31:16.688] 2019/11/26 19:31:16 process.go:153: Running: kubectl --match-server-version=false get nodes -oyaml W1126 19:31:17.574] 2019/11/26 19:31:17 process.go:155: Step 'kubectl --match-server-version=false get nodes -oyaml' finished in 886.503462ms W1126 19:31:17.575] 2019/11/26 19:31:17 azure.go:1023: KUBE_TEST_REPO_LIST_DOWNLOAD_LOCATION not set. Using default test image repos. W1126 19:31:17.575] 2019/11/26 19:31:17 azure.go:1023: KUBE_TEST_REPO_LIST_DOWNLOAD_LOCATION not set. Using default test image repos. W1126 19:31:17.575] 2019/11/26 19:31:17 process.go:153: Running: kubectl get nodes --no-headers W1126 19:31:17.747] 2019/11/26 19:31:17 process.go:155: Step 'kubectl get nodes --no-headers' finished in 172.924138ms W1126 19:31:17.748] 2019/11/26 19:31:17 e2e.go:474: Cluster nodes: W1126 19:31:17.748] k8s-agentpool1-34062161-vmss000000 Ready agent 59s v1.18.0-alpha.0.1190+cff90159704e47 W1126 19:31:17.748] k8s-agentpool1-34062161-vmss000001 Ready agent 59s v1.18.0-alpha.0.1190+cff90159704e47 W1126 19:31:17.748] k8s-master-34062161-0 Ready master 59s v1.18.0-alpha.0.1190+cff90159704e47 W1126 19:31:17.748] 2019/11/26 19:31:17 process.go:153: Running: kubectl --match-server-version=false version W1126 19:31:17.868] 2019/11/26 19:31:17 process.go:155: Step 'kubectl --match-server-version=false version' finished in 120.821436ms W1126 19:31:17.869] 2019/11/26 19:31:17 process.go:153: Running: ./hack/ginkgo-e2e.sh --ginkgo.focus=azure-disk --ginkgo.skip=\[Slow\]|\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\] --report-dir=/workspace/_artifacts --disable-log-dump=true I1126 19:31:17.970] Conformance test: not doing test setup. I1126 19:31:22.857] I1126 19:31:22.857] ------------------------------------------------------------------- I1126 19:31:22.858] | | I1126 19:31:22.858] | Ginkgo timed out waiting for all parallel nodes to report back! | I1126 19:31:22.858] | | I1126 19:31:22.858] ------------------------------------------------------------------- I1126 19:31:22.858] I1126 19:31:22.859] e2e timed out. path: ./_output/bin I1126 19:31:22.859] [1] Nov 26 19:31:21.451: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 19:31:22.859] [1] I1126 19:31:21.451032 14205 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 19:31:22.859] [1] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 19:31:22.859] [1] I1126 19:31:22.859] [1] goroutine 1 [running]: I1126 19:31:22.860] [1] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 19:31:22.860] [1] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 19:31:22.860] [1] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7ffd41090b1f, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 19:31:22.860] [1] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 19:31:22.860] [1] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 19:31:22.860] [1] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 19:31:22.861] [1] k8s.io/kubernetes/test/e2e.TestMain(0xc0012e8000) I1126 19:31:22.861] [1] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 19:31:22.861] [1] main.main() I1126 19:31:22.861] [1] /tmp/go-build285600323/b001/_testmain.go:42 +0x135 I1126 19:31:22.861] [2] I1126 19:31:21.052309 14210 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 19:31:22.862] [2] Nov 26 19:31:21.052: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 19:31:22.862] [2] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 19:31:22.862] [2] I1126 19:31:22.862] [2] goroutine 1 [running]: I1126 19:31:22.862] [2] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 19:31:22.862] [2] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 19:31:22.863] [2] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7ffe63ba6b1f, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 19:31:22.863] [2] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 19:31:22.863] [2] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 19:31:22.863] [2] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 19:31:22.863] [2] k8s.io/kubernetes/test/e2e.TestMain(0xc0014bcb00) I1126 19:31:22.863] [2] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 19:31:22.863] [2] main.main() I1126 19:31:22.864] [2] /tmp/go-build285600323/b001/_testmain.go:42 +0x135 I1126 19:31:22.864] [3] I1126 19:31:21.852219 14215 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 19:31:22.864] [3] Nov 26 19:31:21.852: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 19:31:22.864] [3] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 19:31:22.864] [3] I1126 19:31:22.865] [3] goroutine 1 [running]: I1126 19:31:22.865] [3] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 19:31:22.865] [3] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 19:31:22.865] [3] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7ffc372bcb1f, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 19:31:22.865] [3] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 19:31:22.865] [3] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 19:31:22.866] [3] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 19:31:22.866] [3] k8s.io/kubernetes/test/e2e.TestMain(0xc002518300) I1126 19:31:22.866] [3] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 19:31:22.866] [3] main.main() I1126 19:31:22.866] [3] /tmp/go-build285600323/b001/_testmain.go:42 +0x135 I1126 19:31:22.866] [4] I1126 19:31:21.159388 14209 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 19:31:22.867] [4] Nov 26 19:31:21.159: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 19:31:22.867] [4] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 19:31:22.867] [4] I1126 19:31:22.867] [4] goroutine 1 [running]: I1126 19:31:22.867] [4] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 19:31:22.867] [4] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 19:31:22.868] [4] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7ffcbb776b1f, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 19:31:22.868] [4] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 19:31:22.868] [4] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 19:31:22.868] [4] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 19:31:22.868] [4] k8s.io/kubernetes/test/e2e.TestMain(0xc00071cb00) I1126 19:31:22.869] [4] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 19:31:22.869] [4] main.main() I1126 19:31:22.869] [4] /tmp/go-build285600323/b001/_testmain.go:42 +0x135 I1126 19:31:22.869] [5] I1126 19:31:21.142528 14218 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 19:31:22.869] [5] Nov 26 19:31:21.142: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 19:31:22.869] [5] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 19:31:22.870] [5] I1126 19:31:22.870] [5] goroutine 1 [running]: I1126 19:31:22.870] [5] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 19:31:22.870] [5] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 19:31:22.870] [5] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7ffe3c1bcb1f, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 19:31:22.871] [5] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 19:31:22.871] [5] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 19:31:22.871] [5] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 19:31:22.871] [5] k8s.io/kubernetes/test/e2e.TestMain(0xc001518100) I1126 19:31:22.871] [5] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 19:31:22.871] [5] main.main() I1126 19:31:22.872] [5] /tmp/go-build285600323/b001/_testmain.go:42 +0x135 I1126 19:31:22.872] [6] I1126 19:31:21.182243 14212 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 19:31:22.872] [6] Nov 26 19:31:21.182: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 19:31:22.872] [6] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 19:31:22.872] [6] I1126 19:31:22.872] [6] goroutine 1 [running]: I1126 19:31:22.873] [6] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 19:31:22.873] [6] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 19:31:22.873] [6] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7fff6943db1f, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 19:31:22.873] [6] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 19:31:22.873] [6] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 19:31:22.874] [6] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 19:31:22.874] [6] k8s.io/kubernetes/test/e2e.TestMain(0xc001c64c00) I1126 19:31:22.874] [6] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 19:31:22.874] [6] main.main() I1126 19:31:22.874] [6] /tmp/go-build285600323/b001/_testmain.go:42 +0x135 I1126 19:31:22.874] [7] I1126 19:31:21.793172 14208 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 19:31:22.875] [7] Nov 26 19:31:21.793: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 19:31:22.875] [7] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 19:31:22.875] [7] I1126 19:31:22.875] [7] goroutine 1 [running]: I1126 19:31:22.875] [7] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 19:31:22.875] [7] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 19:31:22.876] [7] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7fff478c8b1f, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 19:31:22.876] [7] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 19:31:22.876] [7] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 19:31:22.876] [7] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 19:31:22.876] [7] k8s.io/kubernetes/test/e2e.TestMain(0xc001872100) I1126 19:31:22.876] [7] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 19:31:22.877] [7] main.main() I1126 19:31:22.877] [7] /tmp/go-build285600323/b001/_testmain.go:42 +0x135 I1126 19:31:22.877] [8] Nov 26 19:31:21.082: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 19:31:22.877] [8] I1126 19:31:21.082441 14221 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 19:31:22.877] [8] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 19:31:22.877] [8] I1126 19:31:22.878] [8] goroutine 1 [running]: I1126 19:31:22.878] [8] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 19:31:22.878] [8] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 19:31:22.878] [8] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7ffd161eab1f, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 19:31:22.878] [8] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 19:31:22.878] [8] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 19:31:22.879] [8] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 19:31:22.879] [8] k8s.io/kubernetes/test/e2e.TestMain(0xc002581180) I1126 19:31:22.879] [8] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 19:31:22.879] [8] main.main() I1126 19:31:22.879] [8] /tmp/go-build285600323/b001/_testmain.go:42 +0x135 I1126 19:31:22.879] [9] I1126 19:31:21.852064 14207 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 19:31:22.880] [9] Nov 26 19:31:21.852: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 19:31:22.880] [9] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 19:31:22.880] [9] I1126 19:31:22.880] [9] goroutine 1 [running]: I1126 19:31:22.880] [9] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 19:31:22.880] [9] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 19:31:22.881] [9] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7ffe5ec49b1f, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 19:31:22.881] [9] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 19:31:22.881] [9] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 19:31:22.881] [9] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 19:31:22.881] [9] k8s.io/kubernetes/test/e2e.TestMain(0xc001a9fd80) I1126 19:31:22.882] [9] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 19:31:22.882] [9] main.main() I1126 19:31:22.882] [9] /tmp/go-build285600323/b001/_testmain.go:42 +0x135 I1126 19:31:22.882] [10] I1126 19:31:21.094517 14214 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 19:31:22.882] [10] Nov 26 19:31:21.094: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 19:31:22.882] [10] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 19:31:22.883] [10] I1126 19:31:22.883] [10] goroutine 1 [running]: I1126 19:31:22.883] [10] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 19:31:22.883] [10] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 19:31:22.883] [10] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7ffc2108db1f, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 19:31:22.883] [10] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 19:31:22.884] [10] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 19:31:22.884] [10] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 19:31:22.884] [10] k8s.io/kubernetes/test/e2e.TestMain(0xc0014e0900) I1126 19:31:22.884] [10] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 19:31:22.884] [10] main.main() I1126 19:31:22.884] [10] /tmp/go-build285600323/b001/_testmain.go:42 +0x135 I1126 19:31:22.885] I1126 19:31:22.885] Ginkgo ran 1 suite in 4.702262997s I1126 19:31:22.885] Test Suite Failed W1126 19:31:22.985] 2019/11/26 19:31:22 process.go:155: Step './hack/ginkgo-e2e.sh --ginkgo.focus=azure-disk --ginkgo.skip=\[Slow\]|\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\] --report-dir=/workspace/_artifacts --disable-log-dump=true' finished in 4.993784054s W1126 19:31:22.986] 2019/11/26 19:31:22 azure.go:965: Skippng DumpClusterLogs due to CCM not being enabled. W1126 19:31:22.986] 2019/11/26 19:31:22 azure.go:959: Deleting resource group: kubetest-31c4da8b-1081-11ea-bdaf-0242daa89aab. W1126 19:38:08.397] 2019/11/26 19:38:08 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml. W1126 19:38:08.397] 2019/11/26 19:38:08 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}" W1126 19:38:09.074] 2019/11/26 19:38:09 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 677.159197ms W1126 19:38:09.075] 2019/11/26 19:38:09 main.go:319: Something went wrong: encountered 1 errors: [error during ./hack/ginkgo-e2e.sh --ginkgo.focus=azure-disk --ginkgo.skip=\[Slow\]|\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\] --report-dir=/workspace/_artifacts --disable-log-dump=true: exit status 1] W1126 19:38:09.076] Traceback (most recent call last): W1126 19:38:09.076] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in W1126 19:38:09.077] main(parse_args()) W1126 19:38:09.077] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main W1126 19:38:09.077] mode.start(runner_args) W1126 19:38:09.077] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start W1126 19:38:09.077] check_env(env, self.command, *args) W1126 19:38:09.077] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env W1126 19:38:09.077] subprocess.check_call(cmd, env=env) W1126 19:38:09.077] File "/usr/lib/python2.7/subprocess.py", line 190, in check_call W1126 19:38:09.078] raise CalledProcessError(retcode, cmd) W1126 19:38:09.078] subprocess.CalledProcessError: Command '('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=host-go', '--up', '--down', '--test', '--deployment=acsengine', '--provider=azure', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--ginkgo-parallel=10', '--acsengine-agentpoolcount=2', '--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-location=westus2', '--acsengine-public-key=/etc/azure-ssh/azure-ssh-pub', '--acsengine-template-url=https://gist.githubusercontent.com/chewong/facb90983ad2337a0049538cf82f9bf9/raw/5a5bad9e47b137a684f2fa98d645175315aa8161/linux.json', '--acsengine-download-url=https://aka.ms/aks-engine/aks-engine-k8s-e2e.tar.gz', '--test_args=--ginkgo.focus=azure-disk --ginkgo.skip=\\[Slow\\]|\\[Serial\\]|\\[Disruptive\\]|\\[Flaky\\]|\\[Feature:.+\\]', '--timeout=420m')' returned non-zero exit status 1 E1126 19:38:09.084] Command failed I1126 19:38:09.084] process 718 exited with code 1 after 22.1m E1126 19:38:09.084] FAIL: chewong-in-tree-azure-disk-e2e I1126 19:38:09.084] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1126 19:38:09.839] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1126 19:38:09.874] process 14374 exited with code 0 after 0.0m I1126 19:38:09.875] Call: gcloud config get-value account I1126 19:38:10.132] process 14387 exited with code 0 after 0.0m I1126 19:38:10.132] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1126 19:38:10.132] Upload result and artifacts... I1126 19:38:10.132] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199406141650505728 I1126 19:38:10.133] Call: gsutil ls gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199406141650505728/artifacts W1126 19:38:11.193] CommandException: One or more URLs matched no objects. E1126 19:38:11.265] Command failed I1126 19:38:11.265] process 14400 exited with code 1 after 0.0m W1126 19:38:11.265] Remote dir gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199406141650505728/artifacts not exist yet I1126 19:38:11.265] Call: gsutil -m -q -o GSUtil:use_magicfile=True cp -r -c -z log,txt,xml /workspace/_artifacts gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199406141650505728/artifacts I1126 19:38:12.788] process 14545 exited with code 0 after 0.0m I1126 19:38:12.788] Call: git rev-parse HEAD I1126 19:38:12.791] process 15075 exited with code 0 after 0.0m I1126 19:38:12.792] Call: git rev-parse HEAD I1126 19:38:12.796] process 15076 exited with code 0 after 0.0m I1126 19:38:12.796] Call: gsutil stat gs://kubernetes-upstream/pr-logs/directory/chewong-in-tree-azure-disk-e2e/jobResultsCache.json I1126 19:38:13.619] process 15077 exited with code 0 after 0.0m I1126 19:38:13.620] Call: gsutil -q cat 'gs://kubernetes-upstream/pr-logs/directory/chewong-in-tree-azure-disk-e2e/jobResultsCache.json#1574794864857702' I1126 19:38:14.629] process 15222 exited with code 0 after 0.0m I1126 19:38:14.630] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1574794864857702 cp /tmp/gsutil_oZDozL gs://kubernetes-upstream/pr-logs/directory/chewong-in-tree-azure-disk-e2e/jobResultsCache.json I1126 19:38:15.877] process 15369 exited with code 0 after 0.0m I1126 19:38:15.878] Call: gsutil stat gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/jobResultsCache.json I1126 19:38:16.693] process 15550 exited with code 0 after 0.0m I1126 19:38:16.694] Call: gsutil -q cat 'gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/jobResultsCache.json#1574794867914205' I1126 19:38:17.671] process 15695 exited with code 0 after 0.0m I1126 19:38:17.672] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1574794867914205 cp /tmp/gsutil_9LeGt2 gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/jobResultsCache.json I1126 19:38:19.016] process 15842 exited with code 0 after 0.0m I1126 19:38:19.017] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil_8PsPd6 gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199406141650505728/finished.json I1126 19:38:20.558] process 16023 exited with code 0 after 0.0m I1126 19:38:20.559] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_Ztqq67 gs://kubernetes-upstream/pr-logs/directory/chewong-in-tree-azure-disk-e2e/latest-build.txt I1126 19:38:21.914] process 16204 exited with code 0 after 0.0m I1126 19:38:21.915] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_xSDsqF gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/latest-build.txt I1126 19:38:23.148] process 16385 exited with code 0 after 0.0m