W1126 18:25:58.067] ************************************************************************** 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 18:25:58.067] 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://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/tests/k8s-azure/manifest/linux-vmss-serial.json --acsengine-download-url=https://aka.ms/aks-engine/aks-engine-k8s-e2e.tar.gz '--test_args=--ginkgo.flakeAttempts=2 --num-nodes=2 --ginkgo.focus=azure-disk --ginkgo.skip=\[Slow\]|\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\]' --timeout=420m I1126 18:25:58.068] Bootstrap chewong-in-tree-azure-disk-e2e... I1126 18:25:58.071] Builder: 24a793c7-107a-11ea-b3d3-b20db476995a I1126 18:25:58.072] Image: gcr.io/k8s-testimages/kubekins-e2e:v20191124-4beb966-master I1126 18:25:58.072] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199393810405134336 I1126 18:25:58.072] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1126 18:25:58.597] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1126 18:25:58.641] process 215 exited with code 0 after 0.0m I1126 18:25:58.641] Call: gcloud config get-value account I1126 18:25:58.917] process 228 exited with code 0 after 0.0m I1126 18:25:58.917] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1126 18:25:58.917] Root: /go/src I1126 18:25:58.918] cd to /go/src I1126 18:25:58.918] Checkout: /go/src/k8s.io/kubernetes master:1c5b6cb66e6ae85177e76d4fddf7d99473ab2aed,85621:dd76fdfce5554cc15ee7ed999bea1cffb0436d0a to /go/src/k8s.io/kubernetes I1126 18:25:58.918] Call: git init k8s.io/kubernetes I1126 18:25:58.922] Initialized empty Git repository in /go/src/k8s.io/kubernetes/.git/ I1126 18:25:58.922] process 241 exited with code 0 after 0.0m I1126 18:25:58.922] Call: git config --local user.name 'K8S Bootstrap' I1126 18:25:58.925] process 242 exited with code 0 after 0.0m I1126 18:25:58.925] Call: git config --local user.email k8s_bootstrap@localhost I1126 18:25:58.928] process 243 exited with code 0 after 0.0m I1126 18:25:58.928] Call: git fetch --quiet --tags https://github.com/kubernetes/kubernetes master +refs/pull/85621/head:refs/pr/85621 I1126 18:27:03.450] process 244 exited with code 0 after 1.1m I1126 18:27:03.450] Call: git checkout -B test 1c5b6cb66e6ae85177e76d4fddf7d99473ab2aed W1126 18:27:05.802] Switched to a new branch 'test' I1126 18:27:05.814] process 255 exited with code 0 after 0.0m I1126 18:27:05.814] Call: git show -s --format=format:%ct HEAD I1126 18:27:05.841] process 256 exited with code 0 after 0.0m I1126 18:27:05.841] Call: git merge --no-ff -m 'Merge +refs/pull/85621/head:refs/pr/85621' dd76fdfce5554cc15ee7ed999bea1cffb0436d0a I1126 18:27:06.849] Merge made by the 'recursive' strategy. I1126 18:27:06.852] test/e2e/storage/drivers/in_tree.go | 46 ++++++++++++++++++------------------- I1126 18:27:06.852] test/e2e/storage/in_tree_volumes.go | 2 +- I1126 18:27:06.852] 2 files changed, 24 insertions(+), 24 deletions(-) I1126 18:27:06.852] process 257 exited with code 0 after 0.0m I1126 18:27:06.852] Configure environment... I1126 18:27:06.853] Call: git show -s --format=format:%ct HEAD I1126 18:27:06.857] process 299 exited with code 0 after 0.0m I1126 18:27:06.858] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1126 18:27:08.070] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1126 18:27:08.223] process 300 exited with code 0 after 0.0m I1126 18:27:08.224] Call: gcloud config get-value account I1126 18:27:08.472] process 313 exited with code 0 after 0.0m I1126 18:27:08.472] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1126 18:27:08.473] 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 18:27:08.710] process 326 exited with code 0 after 0.0m I1126 18:27:08.711] Start 1199393810405134336 at v1.18.0-alpha.0.1190+cff90159704e47... I1126 18:27:08.712] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil_JB6Qor gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199393810405134336/started.json I1126 18:27:10.035] process 359 exited with code 0 after 0.0m I1126 18:27:10.036] 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/1199393810405134336' cp /tmp/gsutil_AdGYhQ gs://kubernetes-upstream/pr-logs/directory/chewong-in-tree-azure-disk-e2e/1199393810405134336.txt I1126 18:27:11.300] process 540 exited with code 0 after 0.0m I1126 18:27:11.301] 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://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/tests/k8s-azure/manifest/linux-vmss-serial.json --acsengine-download-url=https://aka.ms/aks-engine/aks-engine-k8s-e2e.tar.gz '--test_args=--ginkgo.flakeAttempts=2 --num-nodes=2 --ginkgo.focus=azure-disk --ginkgo.skip=\[Slow\]|\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\]' --timeout=420m W1126 18:27:11.336] starts with local mode W1126 18:27:11.336] Environment: W1126 18:27:11.336] ARTIFACTS=/workspace/_artifacts W1126 18:27:11.336] AWS_SSH_PRIVATE_KEY_FILE=/root/.ssh/kube_aws_rsa W1126 18:27:11.337] AWS_SSH_PUBLIC_KEY_FILE=/root/.ssh/kube_aws_rsa.pub W1126 18:27:11.337] AZURE_CREDENTIALS=/etc/azure-cred/credentials W1126 18:27:11.337] AZURE_SSH_PUBLIC_KEY_FILE=/etc/azure-ssh/azure-ssh-pub W1126 18:27:11.337] AZ_STORAGE_CONTAINER_NAME=mystoragecontainer W1126 18:27:11.337] BAZEL_REMOTE_CACHE_ENABLED=false W1126 18:27:11.337] BAZEL_VERSION=0.23.2 W1126 18:27:11.337] BOOTSTRAP_MIGRATION=yes W1126 18:27:11.337] BUILD_ID=1199393810405134336 W1126 18:27:11.337] BUILD_NUMBER=1199393810405134336 W1126 18:27:11.338] CLOUDSDK_COMPONENT_MANAGER_DISABLE_UPDATE_CHECK=true W1126 18:27:11.338] CLOUDSDK_CONFIG=/go/src/k8s.io/kubernetes/.config/gcloud W1126 18:27:11.338] CLOUDSDK_CORE_DISABLE_PROMPTS=1 W1126 18:27:11.338] CLOUDSDK_EXPERIMENTAL_FAST_COMPONENT_UPDATE=false W1126 18:27:11.338] CLOUD_CONFIG=random W1126 18:27:11.338] DECK_PORT=tcp://10.0.160.83:80 W1126 18:27:11.338] DECK_PORT_80_TCP=tcp://10.0.160.83:80 W1126 18:27:11.338] DECK_PORT_80_TCP_ADDR=10.0.160.83 W1126 18:27:11.338] DECK_PORT_80_TCP_PORT=80 W1126 18:27:11.338] DECK_PORT_80_TCP_PROTO=tcp W1126 18:27:11.339] DECK_SERVICE_HOST=10.0.160.83 W1126 18:27:11.339] DECK_SERVICE_PORT=80 W1126 18:27:11.339] DOCKER_IN_DOCKER_ENABLED=true W1126 18:27:11.339] DOCKER_IN_DOCKER_IPV6_ENABLED=false W1126 18:27:11.339] GCS_ARTIFACTS_DIR=gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199393810405134336/artifacts W1126 18:27:11.339] GOOGLE_APPLICATION_CREDENTIALS=/etc/service-account/service-account.json W1126 18:27:11.339] GOPATH=/go W1126 18:27:11.340] GO_TARBALL=go1.12.12.linux-amd64.tar.gz W1126 18:27:11.340] HOME=/workspace W1126 18:27:11.340] HOOK_PORT=tcp://10.0.144.133:8888 W1126 18:27:11.340] HOOK_PORT_8888_TCP=tcp://10.0.144.133:8888 W1126 18:27:11.340] HOOK_PORT_8888_TCP_ADDR=10.0.144.133 W1126 18:27:11.340] HOOK_PORT_8888_TCP_PORT=8888 W1126 18:27:11.340] HOOK_PORT_8888_TCP_PROTO=tcp W1126 18:27:11.340] HOOK_SERVICE_HOST=10.0.144.133 W1126 18:27:11.340] HOOK_SERVICE_PORT=8888 W1126 18:27:11.340] HOSTNAME=24a793c7-107a-11ea-b3d3-b20db476995a W1126 18:27:11.341] IMAGE=gcr.io/k8s-testimages/kubekins-e2e:v20191124-4beb966-master W1126 18:27:11.341] INSTANCE_PREFIX=bootstrap-e2e W1126 18:27:11.341] JENKINS_GCE_SSH_PRIVATE_KEY_FILE=/root/.ssh/google_compute_engine W1126 18:27:11.341] JENKINS_GCE_SSH_PUBLIC_KEY_FILE=/root/.ssh/google_compute_engine.pub W1126 18:27:11.341] JOB_NAME=chewong-in-tree-azure-disk-e2e W1126 18:27:11.342] JOB_SPEC={"type":"presubmit","job":"chewong-in-tree-azure-disk-e2e","buildid":"1199393810405134336","prowjobid":"24a793c7-107a-11ea-b3d3-b20db476995a","refs":{"org":"Azure","repo":"kubernetes","repo_link":"https://github.com/Azure/kubernetes","base_ref":"master","base_sha":"036cf78b513df081015052cb6863a02c789a2c89","base_link":"https://github.com/Azure/kubernetes/commit/036cf78b513df081015052cb6863a02c789a2c89","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 18:27:11.342] JOB_TYPE=presubmit W1126 18:27:11.342] KUBERNETES_CONFORMANCE_PROVIDER=azure W1126 18:27:11.342] KUBERNETES_PORT=tcp://10.0.0.1:443 W1126 18:27:11.342] KUBERNETES_PORT_443_TCP=tcp://10.0.0.1:443 W1126 18:27:11.342] KUBERNETES_PORT_443_TCP_ADDR=10.0.0.1 W1126 18:27:11.342] KUBERNETES_PORT_443_TCP_PORT=443 W1126 18:27:11.342] KUBERNETES_PORT_443_TCP_PROTO=tcp W1126 18:27:11.342] KUBERNETES_SERVICE_HOST=10.0.0.1 W1126 18:27:11.342] KUBERNETES_SERVICE_PORT=443 W1126 18:27:11.343] KUBERNETES_SERVICE_PORT_HTTPS=443 W1126 18:27:11.343] KUBETEST_IN_DOCKER=true W1126 18:27:11.343] KUBETEST_MANUAL_DUMP=y W1126 18:27:11.343] KUBE_AWS_INSTANCE_PREFIX=bootstrap-e2e W1126 18:27:11.343] KUBE_GCE_INSTANCE_PREFIX=bootstrap-e2e W1126 18:27:11.343] KUBE_SSH_KEY_PATH=/etc/ssh-key-secret/ssh-private W1126 18:27:11.343] KUBE_SSH_PUBLIC_KEY_PATH=/etc/ssh-key-secret/ssh-public W1126 18:27:11.344] KUBE_SSH_USER=azureuser W1126 18:27:11.344] KUBE_VERBOSE=0 W1126 18:27:11.344] NODE_NAME=24a793c7-107a-11ea-b3d3-b20db476995a W1126 18:27:11.344] 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 18:27:11.344] PROW_JOB_ID=24a793c7-107a-11ea-b3d3-b20db476995a W1126 18:27:11.344] PULL_BASE_REF=master W1126 18:27:11.344] PULL_BASE_SHA=036cf78b513df081015052cb6863a02c789a2c89 W1126 18:27:11.344] PULL_NUMBER=113 W1126 18:27:11.345] PULL_PULL_SHA=879465972041635fd7bc8269da49153b67e63822 W1126 18:27:11.345] PULL_REFS=master:036cf78b513df081015052cb6863a02c789a2c89,113:879465972041635fd7bc8269da49153b67e63822 W1126 18:27:11.345] PWD=/workspace W1126 18:27:11.345] REGISTRY=k8sprowinternal.azurecr.io W1126 18:27:11.345] REPO_NAME=kubernetes W1126 18:27:11.345] REPO_OWNER=Azure W1126 18:27:11.345] SHLVL=2 W1126 18:27:11.345] SOURCE_DATE_EPOCH=1574729000 W1126 18:27:11.346] TERM=xterm W1126 18:27:11.346] TIDE_PORT=tcp://10.0.180.53:80 W1126 18:27:11.346] TIDE_PORT_80_TCP=tcp://10.0.180.53:80 W1126 18:27:11.346] TIDE_PORT_80_TCP_ADDR=10.0.180.53 W1126 18:27:11.346] TIDE_PORT_80_TCP_PORT=80 W1126 18:27:11.346] TIDE_PORT_80_TCP_PROTO=tcp W1126 18:27:11.346] TIDE_SERVICE_HOST=10.0.180.53 W1126 18:27:11.346] TIDE_SERVICE_PORT=80 W1126 18:27:11.347] WORKSPACE=/workspace W1126 18:27:11.347] _=./test-infra/jenkins/bootstrap.py W1126 18:27:11.347] 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://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/tests/k8s-azure/manifest/linux-vmss-serial.json', '--acsengine-download-url=https://aka.ms/aks-engine/aks-engine-k8s-e2e.tar.gz', '--test_args=--ginkgo.flakeAttempts=2 --num-nodes=2 --ginkgo.focus=azure-disk --ginkgo.skip=\\[Slow\\]|\\[Serial\\]|\\[Disruptive\\]|\\[Flaky\\]|\\[Feature:.+\\]', '--timeout=420m') W1126 18:27:11.363] 2019/11/26 18:27:11 main.go:332: Limiting testing to 7h0m0s W1126 18:27:11.365] 2019/11/26 18:27:11 azure.go:242: Reading credentials file /etc/azure-cred/credentials W1126 18:27:11.365] 2019/11/26 18:27:11 process.go:153: Running: make -C /go/src/k8s.io/kubernetes all I1126 18:27:11.466] make: Entering directory '/go/src/k8s.io/kubernetes' I1126 18:27:11.466] make[1]: Entering directory '/go/src/k8s.io/kubernetes' I1126 18:27:19.398] +++ [1126 18:27:19] Building go targets for linux/amd64: I1126 18:27:19.398] ./vendor/k8s.io/code-generator/cmd/deepcopy-gen I1126 18:27:26.646] +++ [1126 18:27:26] Building go targets for linux/amd64: I1126 18:27:26.646] ./vendor/k8s.io/code-generator/cmd/defaulter-gen I1126 18:27:32.682] +++ [1126 18:27:32] Building go targets for linux/amd64: I1126 18:27:32.683] ./vendor/k8s.io/code-generator/cmd/conversion-gen I1126 18:27:43.577] +++ [1126 18:27:43] Building go targets for linux/amd64: I1126 18:27:43.578] ./vendor/k8s.io/kube-openapi/cmd/openapi-gen I1126 18:27:56.213] +++ [1126 18:27:56] Building go targets for linux/amd64: I1126 18:27:56.213] ./vendor/github.com/go-bindata/go-bindata/go-bindata I1126 18:27:57.502] make[1]: Leaving directory '/go/src/k8s.io/kubernetes' I1126 18:27:57.813] +++ [1126 18:27:57] Building go targets for linux/amd64: I1126 18:27:57.814] cmd/kube-proxy I1126 18:27:57.814] cmd/kube-apiserver I1126 18:27:57.814] cmd/kube-controller-manager I1126 18:27:57.814] cmd/kubelet I1126 18:27:57.814] cmd/kubeadm I1126 18:27:57.814] cmd/kube-scheduler I1126 18:27:57.814] vendor/k8s.io/apiextensions-apiserver I1126 18:27:57.814] cluster/gce/gci/mounter I1126 18:27:57.814] cmd/kubectl I1126 18:27:57.814] cmd/gendocs I1126 18:27:57.815] cmd/genkubedocs I1126 18:27:57.815] cmd/genman I1126 18:27:57.815] cmd/genyaml I1126 18:27:57.815] cmd/genswaggertypedocs I1126 18:27:57.815] cmd/linkcheck I1126 18:27:57.815] vendor/github.com/onsi/ginkgo/ginkgo I1126 18:27:57.815] test/e2e/e2e.test I1126 18:27:57.815] cluster/images/conformance/go-runner I1126 18:27:57.816] cmd/kubemark I1126 18:27:57.816] vendor/github.com/onsi/ginkgo/ginkgo I1126 18:27:57.816] test/e2e_node/e2e_node.test I1126 18:32:19.121] make: Leaving directory '/go/src/k8s.io/kubernetes' W1126 18:32:19.222] 2019/11/26 18:32:19 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes all' finished in 5m7.756020391s W1126 18:32:19.222] 2019/11/26 18:32:19 util.go:265: Flushing memory. W1126 18:32:39.194] 2019/11/26 18:32:39 azure.go:959: Deleting resource group: kubetest-5c966145-107a-11ea-9273-024269b29597. W1126 18:32:39.530] 2019/11/26 18:32:39 azure.go:694: CWD /go/src/k8s.io/kubernetes W1126 18:32:39.531] 2019/11/26 18:32:39 azure.go:713: Attempting Docker login with azure cred. W1126 18:32:40.916] 2019/11/26 18:32:40 azure.go:722: Docker login success. W1126 18:32:40.917] 2019/11/26 18:32:40 azure.go:763: Building hyperkube. W1126 18:32:40.918] 2019/11/26 18:32:40 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 18:32:40.918] 2019/11/26 18:32:40 azure.go:781: Pushing hyperkube. W1126 18:32:40.918] 2019/11/26 18:32:40 process.go:153: Running: make -C /go/src/k8s.io/kubernetes/cluster/images/hyperkube push I1126 18:32:41.019] make: Entering directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube' I1126 18:32:41.019] cp -r ./* /tmp/hyperkubeSqUBO6 I1126 18:32:41.019] tar -cvzf /tmp/hyperkubeSqUBO6/binaries.tgz -C /go/src/k8s.io/kubernetes/cluster/images/hyperkube/../../../_output/local/bin/linux/amd64 kube-apiserver kube-controller-manager \ I1126 18:32:41.019] kube-proxy kube-scheduler kubectl kubelet I1126 18:32:41.019] kube-apiserver I1126 18:32:46.321] kube-controller-manager I1126 18:32:51.364] kube-proxy I1126 18:32:53.343] kube-scheduler I1126 18:32:55.566] kubectl I1126 18:32:57.886] kubelet I1126 18:33:03.106] chmod a+rx /tmp/hyperkubeSqUBO6/hyperkube I1126 18:33:03.108] cd /tmp/hyperkubeSqUBO6 && sed -i.back "s|BASEIMAGE|k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1|g" Dockerfile I1126 18:33:03.111] docker build --pull -t k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1199393810405134336-5c965034 /tmp/hyperkubeSqUBO6 I1126 18:33:04.009] Sending build context to Docker daemon 122.6MB I1126 18:33:04.026] Step 1/4 : FROM k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1 I1126 18:33:04.388] 0.12.1: Pulling from debian-hyperkube-base-amd64 I1126 18:33:04.389] 346aee5ea5bc: Pulling fs layer I1126 18:33:04.389] 9c47fde751af: Pulling fs layer I1126 18:33:04.390] be2693a52daf: Pulling fs layer I1126 18:33:04.390] 6b69eb11d043: Pulling fs layer I1126 18:33:04.390] 0abeb1500767: Pulling fs layer I1126 18:33:04.390] 4062d80041b7: Pulling fs layer I1126 18:33:04.390] 23b6daf06fc2: Pulling fs layer I1126 18:33:04.391] 6b69eb11d043: Waiting I1126 18:33:04.391] 0abeb1500767: Waiting I1126 18:33:04.391] 4062d80041b7: Waiting I1126 18:33:04.391] 23b6daf06fc2: Waiting I1126 18:33:04.547] 9c47fde751af: Download complete I1126 18:33:04.574] be2693a52daf: Verifying Checksum I1126 18:33:04.574] be2693a52daf: Download complete I1126 18:33:04.684] 6b69eb11d043: Verifying Checksum I1126 18:33:04.684] 6b69eb11d043: Download complete I1126 18:33:04.714] 0abeb1500767: Download complete I1126 18:33:04.768] 346aee5ea5bc: Verifying Checksum I1126 18:33:04.768] 346aee5ea5bc: Download complete I1126 18:33:05.986] 23b6daf06fc2: Verifying Checksum I1126 18:33:05.987] 23b6daf06fc2: Download complete I1126 18:33:06.049] 346aee5ea5bc: Pull complete I1126 18:33:06.213] 9c47fde751af: Pull complete I1126 18:33:06.408] be2693a52daf: Pull complete I1126 18:33:06.541] 6b69eb11d043: Pull complete I1126 18:33:06.708] 0abeb1500767: Pull complete I1126 18:33:06.989] 4062d80041b7: Verifying Checksum I1126 18:33:06.989] 4062d80041b7: Download complete I1126 18:33:13.196] 4062d80041b7: Pull complete I1126 18:33:14.120] 23b6daf06fc2: Pull complete I1126 18:33:14.144] Digest: sha256:5d4ea2fb5fbe9a9a9da74f67cf2faefc881968bc39f2ac5d62d9167e575812a1 I1126 18:33:14.162] Status: Downloaded newer image for k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1 I1126 18:33:14.163] ---> a46476511725 I1126 18:33:14.164] Step 2/4 : ADD binaries.tgz /usr/local/bin I1126 18:33:41.119] ---> d37d5ab6ff9c I1126 18:33:41.119] Step 3/4 : COPY hyperkube /hyperkube I1126 18:33:42.070] ---> a94410c0100e I1126 18:33:42.071] Step 4/4 : ENTRYPOINT ["/hyperkube"] I1126 18:33:42.231] ---> Running in fe48e2acc6b6 I1126 18:33:43.073] Removing intermediate container fe48e2acc6b6 I1126 18:33:43.074] ---> 00644ad010fc I1126 18:33:43.089] Successfully built 00644ad010fc I1126 18:33:43.165] Successfully tagged k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1199393810405134336-5c965034 I1126 18:33:43.169] rm -rf "/tmp/hyperkubeSqUBO6" I1126 18:33:43.188] docker push k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1199393810405134336-5c965034 I1126 18:33:43.314] The push refers to repository [k8sprowinternal.azurecr.io/hyperkube-amd64] I1126 18:33:43.327] 2bfea5da8243: Preparing I1126 18:33:43.327] 84489a5baf3e: Preparing I1126 18:33:43.327] 39b3ac6d96e9: Preparing I1126 18:33:43.327] 7bbae4dddb88: Preparing I1126 18:33:43.327] a00defcfe869: Preparing I1126 18:33:43.327] 2ab0ae805c74: Preparing I1126 18:33:43.328] 43a8fe7d2382: Preparing I1126 18:33:43.328] 3f6a6f542637: Preparing I1126 18:33:43.328] 5ba3be777c2d: Preparing I1126 18:33:43.328] 2ab0ae805c74: Waiting I1126 18:33:43.328] 43a8fe7d2382: Waiting I1126 18:33:43.328] 3f6a6f542637: Waiting I1126 18:33:43.328] 5ba3be777c2d: Waiting I1126 18:33:43.771] a00defcfe869: Layer already exists I1126 18:33:43.824] 7bbae4dddb88: Layer already exists I1126 18:33:43.846] 39b3ac6d96e9: Layer already exists I1126 18:33:43.895] 2ab0ae805c74: Layer already exists I1126 18:33:43.916] 43a8fe7d2382: Layer already exists I1126 18:33:43.960] 3f6a6f542637: Layer already exists I1126 18:33:43.981] 5ba3be777c2d: Layer already exists I1126 18:33:44.147] 2bfea5da8243: Pushed I1126 18:34:08.601] 84489a5baf3e: Pushed I1126 18:34:09.598] azure-e2e-1199393810405134336-5c965034: digest: sha256:cbde3f104b396cfa2d293072626b9f554053241fb4391e6a8bf15a733526439c size: 2206 I1126 18:34:09.620] docker rmi k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1199393810405134336-5c965034 2>/dev/null || true I1126 18:34:09.663] docker tag k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1199393810405134336-5c965034 k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1199393810405134336-5c965034 I1126 18:34:09.730] docker push k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1199393810405134336-5c965034 I1126 18:34:09.801] The push refers to repository [k8sprowinternal.azurecr.io/hyperkube] I1126 18:34:09.819] 2bfea5da8243: Preparing I1126 18:34:09.819] 84489a5baf3e: Preparing I1126 18:34:09.820] 39b3ac6d96e9: Preparing I1126 18:34:09.820] 7bbae4dddb88: Preparing I1126 18:34:09.820] a00defcfe869: Preparing I1126 18:34:09.820] 2ab0ae805c74: Preparing I1126 18:34:09.820] 43a8fe7d2382: Preparing I1126 18:34:09.820] 3f6a6f542637: Preparing I1126 18:34:09.820] 5ba3be777c2d: Preparing I1126 18:34:09.820] 2ab0ae805c74: Waiting I1126 18:34:09.821] 43a8fe7d2382: Waiting I1126 18:34:09.821] 3f6a6f542637: Waiting I1126 18:34:09.821] 5ba3be777c2d: Waiting I1126 18:34:09.977] a00defcfe869: Layer already exists I1126 18:34:09.998] 39b3ac6d96e9: Layer already exists I1126 18:34:10.020] 7bbae4dddb88: Layer already exists I1126 18:34:10.040] 84489a5baf3e: Mounted from hyperkube-amd64 I1126 18:34:10.040] 2ab0ae805c74: Layer already exists I1126 18:34:10.060] 2bfea5da8243: Mounted from hyperkube-amd64 I1126 18:34:10.066] 43a8fe7d2382: Layer already exists I1126 18:34:10.122] 3f6a6f542637: Layer already exists I1126 18:34:10.157] 5ba3be777c2d: Layer already exists I1126 18:34:11.075] azure-e2e-1199393810405134336-5c965034: digest: sha256:cbde3f104b396cfa2d293072626b9f554053241fb4391e6a8bf15a733526439c size: 2206 I1126 18:34:11.090] make: Leaving directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube' W1126 18:34:11.191] 2019/11/26 18:34:11 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes/cluster/images/hyperkube push' finished in 1m30.172616959s W1126 18:34:11.191] 2019/11/26 18:34:11 azure.go:787: Custom hyperkube URL: k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1199393810405134336-5c965034 . W1126 18:34:11.191] 2019/11/26 18:34:11 azure.go:830: downloading /workspace/aks165562575/kubernetes.json from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/tests/k8s-azure/manifest/linux-vmss-serial.json. W1126 18:34:11.191] 2019/11/26 18:34:11 util.go:42: curl https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/tests/k8s-azure/manifest/linux-vmss-serial.json W1126 18:34:11.257] 2019/11/26 18:34:11 azure.go:569: downloading /workspace/aks-engine.tar.gz from https://aka.ms/aks-engine/aks-engine-k8s-e2e.tar.gz. W1126 18:34:11.258] 2019/11/26 18:34:11 util.go:42: curl https://aka.ms/aks-engine/aks-engine-k8s-e2e.tar.gz W1126 18:34:11.990] 2019/11/26 18:34:11 azure.go:596: Extracting tar file /workspace/aks-engine.tar.gz into directory /go/src/k8s.io/kubernetes . W1126 18:34:11.990] 2019/11/26 18:34:11 process.go:153: Running: tar -xzf /workspace/aks-engine.tar.gz --strip 1 W1126 18:34:12.415] 2019/11/26 18:34:12 process.go:155: Step 'tar -xzf /workspace/aks-engine.tar.gz --strip 1' finished in 425.042112ms W1126 18:34:12.416] 2019/11/26 18:34:12 process.go:153: Running: /go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks165562575/kubernetes.json --output-directory /workspace/aks165562575 I1126 18:34:12.516] INFO[0000] Generating assets into /workspace/aks165562575... W1126 18:34:22.923] 2019/11/26 18:34:22 process.go:155: Step '/go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks165562575/kubernetes.json --output-directory /workspace/aks165562575' finished in 10.507194199s W1126 18:34:22.926] 2019/11/26 18:34:22 azure.go:667: Setting kubeconfig env variable: kubeconfig path: /workspace/aks165562575/kubeconfig/kubeconfig.westus2.json. W1126 18:34:22.926] 2019/11/26 18:34:22 azure.go:669: Creating resource group: kubetest-5c966145-107a-11ea-9273-024269b29597. W1126 18:34:22.926] 2019/11/26 18:34:22 azure.go:671: Creating Azure resource group: kubetest-5c966145-107a-11ea-9273-024269b29597 for cluster deployment. W1126 18:34:23.124] 2019/11/26 18:34:23 azure.go:676: Validating deployment ARM templates. W1126 18:34:24.059] 2019/11/26 18:34:24 azure.go:682: Deploying cluster kubetest-5c966145-107a-11ea-9273-024269b29597 in resource group kubetest-5c966145-107a-11ea-9273-024269b29597. W1126 18:42:25.087] 2019/11/26 18:42:25 azure.go:727: Docker logout. W1126 18:42:25.148] 2019/11/26 18:42:25 process.go:153: Running: kubectl --match-server-version=false version W1126 18:42:25.504] 2019/11/26 18:42:25 process.go:155: Step 'kubectl --match-server-version=false version' finished in 356.798901ms W1126 18:42:25.505] 2019/11/26 18:42:25 process.go:153: Running: kubectl --match-server-version=false get nodes -oyaml W1126 18:42:26.428] 2019/11/26 18:42:26 process.go:155: Step 'kubectl --match-server-version=false get nodes -oyaml' finished in 923.592693ms W1126 18:42:26.428] 2019/11/26 18:42:26 azure.go:1023: KUBE_TEST_REPO_LIST_DOWNLOAD_LOCATION not set. Using default test image repos. W1126 18:42:26.429] 2019/11/26 18:42:26 azure.go:1023: KUBE_TEST_REPO_LIST_DOWNLOAD_LOCATION not set. Using default test image repos. W1126 18:42:26.429] 2019/11/26 18:42:26 process.go:153: Running: kubectl get nodes --no-headers W1126 18:42:26.598] 2019/11/26 18:42:26 process.go:155: Step 'kubectl get nodes --no-headers' finished in 169.545483ms W1126 18:42:26.598] 2019/11/26 18:42:26 e2e.go:474: Cluster nodes: W1126 18:42:26.598] k8s-agentpool1-14895952-vmss000000 Ready agent 48s v1.18.0-alpha.0.1190+cff90159704e47 W1126 18:42:26.598] k8s-agentpool1-14895952-vmss000001 Ready agent 48s v1.18.0-alpha.0.1190+cff90159704e47 W1126 18:42:26.599] k8s-master-14895952-0 Ready master 48s v1.18.0-alpha.0.1190+cff90159704e47 W1126 18:42:26.599] 2019/11/26 18:42:26 process.go:153: Running: kubectl --match-server-version=false version W1126 18:42:26.715] 2019/11/26 18:42:26 process.go:155: Step 'kubectl --match-server-version=false version' finished in 117.53399ms W1126 18:42:26.716] 2019/11/26 18:42:26 process.go:153: Running: ./hack/ginkgo-e2e.sh --ginkgo.flakeAttempts=2 --num-nodes=2 --ginkgo.focus=azure-disk --ginkgo.skip=\[Slow\]|\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\] --report-dir=/workspace/_artifacts --disable-log-dump=true I1126 18:42:26.816] Conformance test: not doing test setup. I1126 18:42:31.728] I1126 18:42:31.729] ------------------------------------------------------------------- I1126 18:42:31.729] | | I1126 18:42:31.729] | Ginkgo timed out waiting for all parallel nodes to report back! | I1126 18:42:31.729] | | I1126 18:42:31.729] ------------------------------------------------------------------- I1126 18:42:31.730] I1126 18:42:31.730] e2e timed out. path: ./_output/bin I1126 18:42:31.730] [1] I1126 18:42:30.628234 14124 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 18:42:31.730] [1] Nov 26 18:42:30.628: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 18:42:31.730] [1] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 18:42:31.731] [1] I1126 18:42:31.731] [1] goroutine 1 [running]: I1126 18:42:31.731] [1] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 18:42:31.731] [1] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 18:42:31.731] [1] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7fff4e613af8, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 18:42:31.731] [1] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 18:42:31.732] [1] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 18:42:31.732] [1] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 18:42:31.732] [1] k8s.io/kubernetes/test/e2e.TestMain(0xc001c94c00) I1126 18:42:31.732] [1] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 18:42:31.732] [1] main.main() I1126 18:42:31.732] [1] /tmp/go-build586252738/b001/_testmain.go:42 +0x135 I1126 18:42:31.733] [2] I1126 18:42:29.902971 14131 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 18:42:31.733] [2] Nov 26 18:42:29.903: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 18:42:31.733] [2] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 18:42:31.733] [2] I1126 18:42:31.733] [2] goroutine 1 [running]: I1126 18:42:31.733] [2] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 18:42:31.734] [2] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 18:42:31.734] [2] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7ffec73e7af8, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 18:42:31.734] [2] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 18:42:31.734] [2] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 18:42:31.734] [2] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 18:42:31.734] [2] k8s.io/kubernetes/test/e2e.TestMain(0xc002073c80) I1126 18:42:31.735] [2] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 18:42:31.735] [2] main.main() I1126 18:42:31.735] [2] /tmp/go-build586252738/b001/_testmain.go:42 +0x135 I1126 18:42:31.735] [3] I1126 18:42:30.246689 14132 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 18:42:31.735] [3] Nov 26 18:42:30.246: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 18:42:31.735] [3] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 18:42:31.736] [3] I1126 18:42:31.736] [3] goroutine 1 [running]: I1126 18:42:31.736] [3] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 18:42:31.736] [3] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 18:42:31.736] [3] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7ffc018a5af8, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 18:42:31.737] [3] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 18:42:31.737] [3] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 18:42:31.737] [3] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 18:42:31.737] [3] k8s.io/kubernetes/test/e2e.TestMain(0xc002680a00) I1126 18:42:31.737] [3] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 18:42:31.737] [3] main.main() I1126 18:42:31.738] [3] /tmp/go-build586252738/b001/_testmain.go:42 +0x135 I1126 18:42:31.738] [4] I1126 18:42:30.417653 14127 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 18:42:31.738] [4] Nov 26 18:42:30.417: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 18:42:31.738] [4] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 18:42:31.738] [4] I1126 18:42:31.738] [4] goroutine 1 [running]: I1126 18:42:31.739] [4] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 18:42:31.739] [4] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 18:42:31.739] [4] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7ffce1c2faf8, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 18:42:31.739] [4] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 18:42:31.740] [4] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 18:42:31.740] [4] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 18:42:31.740] [4] k8s.io/kubernetes/test/e2e.TestMain(0xc002976200) I1126 18:42:31.740] [4] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 18:42:31.740] [4] main.main() I1126 18:42:31.740] [4] /tmp/go-build586252738/b001/_testmain.go:42 +0x135 I1126 18:42:31.741] [5] I1126 18:42:29.970044 14122 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 18:42:31.741] [5] Nov 26 18:42:29.970: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 18:42:31.741] [5] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 18:42:31.741] [5] I1126 18:42:31.741] [5] goroutine 1 [running]: I1126 18:42:31.741] [5] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 18:42:31.742] [5] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 18:42:31.742] [5] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7ffc0104baf8, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 18:42:31.742] [5] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 18:42:31.742] [5] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 18:42:31.742] [5] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 18:42:31.743] [5] k8s.io/kubernetes/test/e2e.TestMain(0xc001107d80) I1126 18:42:31.743] [5] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 18:42:31.743] [5] main.main() I1126 18:42:31.744] [5] /tmp/go-build586252738/b001/_testmain.go:42 +0x135 I1126 18:42:31.744] [6] I1126 18:42:29.969674 14123 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 18:42:31.744] [6] Nov 26 18:42:29.969: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 18:42:31.744] [6] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 18:42:31.744] [6] I1126 18:42:31.745] [6] goroutine 1 [running]: I1126 18:42:31.745] [6] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 18:42:31.745] [6] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 18:42:31.745] [6] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7ffded046af8, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 18:42:31.745] [6] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 18:42:31.746] [6] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 18:42:31.746] [6] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 18:42:31.746] [6] k8s.io/kubernetes/test/e2e.TestMain(0xc000ef1580) I1126 18:42:31.746] [6] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 18:42:31.746] [6] main.main() I1126 18:42:31.746] [6] /tmp/go-build586252738/b001/_testmain.go:42 +0x135 I1126 18:42:31.747] [7] I1126 18:42:30.722749 14125 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 18:42:31.747] [7] Nov 26 18:42:30.722: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 18:42:31.747] [7] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 18:42:31.747] [7] I1126 18:42:31.747] [7] goroutine 1 [running]: I1126 18:42:31.747] [7] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 18:42:31.747] [7] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 18:42:31.747] [7] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7ffd335a0af8, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 18:42:31.748] [7] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 18:42:31.748] [7] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 18:42:31.748] [7] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 18:42:31.748] [7] k8s.io/kubernetes/test/e2e.TestMain(0xc001345e80) I1126 18:42:31.748] [7] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 18:42:31.748] [7] main.main() I1126 18:42:31.748] [7] /tmp/go-build586252738/b001/_testmain.go:42 +0x135 I1126 18:42:31.749] [8] I1126 18:42:29.973684 14121 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 18:42:31.749] [8] Nov 26 18:42:29.973: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 18:42:31.749] [8] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 18:42:31.749] [8] I1126 18:42:31.749] [8] goroutine 1 [running]: I1126 18:42:31.749] [8] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 18:42:31.749] [8] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 18:42:31.749] [8] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7fffe8fecaf8, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 18:42:31.750] [8] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 18:42:31.750] [8] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 18:42:31.750] [8] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 18:42:31.750] [8] k8s.io/kubernetes/test/e2e.TestMain(0xc0022d6e00) I1126 18:42:31.750] [8] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 18:42:31.750] [8] main.main() I1126 18:42:31.750] [8] /tmp/go-build586252738/b001/_testmain.go:42 +0x135 I1126 18:42:31.751] [9] Nov 26 18:42:30.648: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 18:42:31.751] [9] I1126 18:42:30.648328 14129 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 18:42:31.751] [9] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 18:42:31.751] [9] I1126 18:42:31.751] [9] goroutine 1 [running]: I1126 18:42:31.751] [9] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 18:42:31.751] [9] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 18:42:31.751] [9] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7ffdf3cecaf8, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 18:42:31.752] [9] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 18:42:31.752] [9] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 18:42:31.752] [9] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 18:42:31.752] [9] k8s.io/kubernetes/test/e2e.TestMain(0xc0027aa900) I1126 18:42:31.752] [9] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 18:42:31.752] [9] main.main() I1126 18:42:31.752] [9] /tmp/go-build586252738/b001/_testmain.go:42 +0x135 I1126 18:42:31.753] [10] I1126 18:42:29.963879 14120 test_context.go:419] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready I1126 18:42:31.753] [10] Nov 26 18:42:29.963: INFO: Couldn't open cloud provider configuration random: &os.PathError{Op:"open", Path:"random", Err:0x2} I1126 18:42:31.753] [10] panic: interface conversion: cloudprovider.Interface is nil, not *azure.Cloud I1126 18:42:31.753] [10] I1126 18:42:31.753] [10] goroutine 1 [running]: I1126 18:42:31.754] [10] k8s.io/kubernetes/test/e2e/framework/providers/azure.newProvider(0x0, 0x0, 0x0, 0x0) I1126 18:42:31.754] [10] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/providers/azure/azure.go:48 +0x31b I1126 18:42:31.754] [10] k8s.io/kubernetes/test/e2e/framework.SetupProviderConfig(0x7fffd5a89af8, 0x5, 0x0, 0x0, 0x0, 0x0) I1126 18:42:31.754] [10] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/provider.go:83 +0xdf I1126 18:42:31.754] [10] k8s.io/kubernetes/test/e2e/framework.AfterReadingAllFlags(0x7d195c0) I1126 18:42:31.755] [10] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/test_context.go:432 +0x13b I1126 18:42:31.755] [10] k8s.io/kubernetes/test/e2e.TestMain(0xc001c88700) I1126 18:42:31.755] [10] _output/local/go/src/k8s.io/kubernetes/test/e2e/e2e_test.go:90 +0x362 I1126 18:42:31.755] [10] main.main() I1126 18:42:31.755] [10] /tmp/go-build586252738/b001/_testmain.go:42 +0x135 I1126 18:42:31.755] I1126 18:42:31.755] Ginkgo ran 1 suite in 4.719575437s I1126 18:42:31.756] Test Suite Failed W1126 18:42:31.856] 2019/11/26 18:42:31 process.go:155: Step './hack/ginkgo-e2e.sh --ginkgo.flakeAttempts=2 --num-nodes=2 --ginkgo.focus=azure-disk --ginkgo.skip=\[Slow\]|\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\] --report-dir=/workspace/_artifacts --disable-log-dump=true' finished in 5.018013796s W1126 18:42:31.856] 2019/11/26 18:42:31 azure.go:965: Skippng DumpClusterLogs due to CCM not being enabled. W1126 18:42:31.857] 2019/11/26 18:42:31 azure.go:959: Deleting resource group: kubetest-5c966145-107a-11ea-9273-024269b29597. W1126 18:50:17.196] 2019/11/26 18:50:17 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml. W1126 18:50:17.197] 2019/11/26 18:50:17 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}" W1126 18:50:17.932] 2019/11/26 18:50:17 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 735.261538ms W1126 18:50:17.932] 2019/11/26 18:50:17 main.go:319: Something went wrong: encountered 1 errors: [error during ./hack/ginkgo-e2e.sh --ginkgo.flakeAttempts=2 --num-nodes=2 --ginkgo.focus=azure-disk --ginkgo.skip=\[Slow\]|\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\] --report-dir=/workspace/_artifacts --disable-log-dump=true: exit status 1] W1126 18:50:17.934] Traceback (most recent call last): W1126 18:50:17.934] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in W1126 18:50:17.934] main(parse_args()) W1126 18:50:17.935] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main W1126 18:50:17.935] mode.start(runner_args) W1126 18:50:17.935] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start W1126 18:50:17.935] check_env(env, self.command, *args) W1126 18:50:17.935] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env W1126 18:50:17.935] subprocess.check_call(cmd, env=env) W1126 18:50:17.935] File "/usr/lib/python2.7/subprocess.py", line 190, in check_call W1126 18:50:17.935] raise CalledProcessError(retcode, cmd) W1126 18:50:17.936] 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://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/tests/k8s-azure/manifest/linux-vmss-serial.json', '--acsengine-download-url=https://aka.ms/aks-engine/aks-engine-k8s-e2e.tar.gz', '--test_args=--ginkgo.flakeAttempts=2 --num-nodes=2 --ginkgo.focus=azure-disk --ginkgo.skip=\\[Slow\\]|\\[Serial\\]|\\[Disruptive\\]|\\[Flaky\\]|\\[Feature:.+\\]', '--timeout=420m')' returned non-zero exit status 1 E1126 18:50:17.942] Command failed I1126 18:50:17.942] process 721 exited with code 1 after 23.1m E1126 18:50:17.942] FAIL: chewong-in-tree-azure-disk-e2e I1126 18:50:17.942] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1126 18:50:18.712] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1126 18:50:18.752] process 14290 exited with code 0 after 0.0m I1126 18:50:18.753] Call: gcloud config get-value account I1126 18:50:19.009] process 14303 exited with code 0 after 0.0m I1126 18:50:19.009] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1126 18:50:19.009] Upload result and artifacts... I1126 18:50:19.009] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199393810405134336 I1126 18:50:19.009] Call: gsutil ls gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199393810405134336/artifacts W1126 18:50:20.005] CommandException: One or more URLs matched no objects. E1126 18:50:20.082] Command failed I1126 18:50:20.082] process 14316 exited with code 1 after 0.0m W1126 18:50:20.082] Remote dir gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199393810405134336/artifacts not exist yet I1126 18:50:20.083] 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/1199393810405134336/artifacts I1126 18:50:21.786] process 14461 exited with code 0 after 0.0m I1126 18:50:21.786] Call: git rev-parse HEAD I1126 18:50:21.789] process 14991 exited with code 0 after 0.0m I1126 18:50:21.790] Call: git rev-parse HEAD I1126 18:50:21.793] process 14992 exited with code 0 after 0.0m I1126 18:50:21.794] Call: gsutil stat gs://kubernetes-upstream/pr-logs/directory/chewong-in-tree-azure-disk-e2e/jobResultsCache.json I1126 18:50:22.583] process 14993 exited with code 0 after 0.0m I1126 18:50:22.583] Call: gsutil -q cat 'gs://kubernetes-upstream/pr-logs/directory/chewong-in-tree-azure-disk-e2e/jobResultsCache.json#1574792231655894' I1126 18:50:23.658] process 15138 exited with code 0 after 0.0m I1126 18:50:23.659] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1574792231655894 cp /tmp/gsutil_jgyl3Q gs://kubernetes-upstream/pr-logs/directory/chewong-in-tree-azure-disk-e2e/jobResultsCache.json I1126 18:50:24.898] process 15285 exited with code 0 after 0.0m I1126 18:50:24.898] Call: gsutil stat gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/jobResultsCache.json I1126 18:50:25.691] process 15466 exited with code 0 after 0.0m I1126 18:50:25.691] Call: gsutil -q cat 'gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/jobResultsCache.json#1574792234934756' I1126 18:50:26.779] process 15611 exited with code 0 after 0.0m I1126 18:50:26.780] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1574792234934756 cp /tmp/gsutil_6ZmWw4 gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/jobResultsCache.json I1126 18:50:28.114] process 15758 exited with code 0 after 0.0m I1126 18:50:28.114] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil_J_pqNk gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199393810405134336/finished.json I1126 18:50:29.323] process 15939 exited with code 0 after 0.0m I1126 18:50:29.323] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_gLAnlz gs://kubernetes-upstream/pr-logs/directory/chewong-in-tree-azure-disk-e2e/latest-build.txt I1126 18:50:30.695] process 16120 exited with code 0 after 0.0m I1126 18:50:30.696] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_SgsdCO gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/latest-build.txt I1126 18:50:31.955] process 16301 exited with code 0 after 0.0m