W1105 19:47:04.918] ************************************************************************** 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 ************************************************************************** I1105 19:47:04.918] Args: --job=chewong-pull-azuredisk-csi-driver-e2e-multi-az --service-account=/etc/service-account/service-account.json --upload=gs://kubernetes-jenkins/logs --job=chewong-pull-azuredisk-csi-driver-e2e-multi-az --root=/go/src --service-account=/etc/service-account/service-account.json --repo=k8s.io/kubernetes=master --repo=sigs.k8s.io/azuredisk-csi-driver=master:b7c03af8eae7388e84115ace30cf2ff3285b0dc9,180:3d974a552d3f3a8ed615de3a6a819edc818404e4 --upload=gs://kubernetes-upstream/pr-logs --timeout=460 --scenario=kubernetes_e2e -- --gce-ssh= --test=true --up=true --down=true --deployment=acsengine --build=bazel --provider=skeleton --ginkgo-parallel=1 --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-location=eastus2 '--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-multi-zones.json --acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz --test-azure-disk-csi-driver=True '--test_args=--ginkgo.focus=\[multi-az\]' --timeout=420m I1105 19:47:04.918] Bootstrap chewong-pull-azuredisk-csi-driver-e2e-multi-az... I1105 19:47:04.924] Builder: aaf55b64-0004-11ea-918b-16773c0c7aed I1105 19:47:04.924] Image: chewong/kubekins-e2e:v20191105-test-1 I1105 19:47:04.924] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191803546169774080 I1105 19:47:04.924] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1105 19:47:15.780] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1105 19:47:15.838] process 188 exited with code 0 after 0.2m I1105 19:47:15.838] Call: gcloud config get-value account I1105 19:47:16.233] process 200 exited with code 0 after 0.0m I1105 19:47:16.233] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1105 19:47:16.234] Root: /go/src I1105 19:47:16.234] cd to /go/src I1105 19:47:16.234] Checkout: /go/src/k8s.io/kubernetes master to /go/src/k8s.io/kubernetes I1105 19:47:16.234] Call: git init k8s.io/kubernetes I1105 19:47:16.240] Initialized empty Git repository in /go/src/k8s.io/kubernetes/.git/ I1105 19:47:16.240] process 212 exited with code 0 after 0.0m I1105 19:47:16.241] Call: git config --local user.name 'K8S Bootstrap' I1105 19:47:16.244] process 213 exited with code 0 after 0.0m I1105 19:47:16.244] Call: git config --local user.email k8s_bootstrap@localhost I1105 19:47:16.248] process 214 exited with code 0 after 0.0m I1105 19:47:16.248] Call: git fetch --quiet --tags https://github.com/kubernetes/kubernetes master I1105 19:51:31.840] process 215 exited with code 0 after 4.3m I1105 19:51:31.840] Call: git checkout -B test FETCH_HEAD W1105 19:51:45.985] Switched to a new branch 'test' I1105 19:51:46.000] process 229 exited with code 0 after 0.2m I1105 19:51:46.001] Call: git show -s --format=format:%ct HEAD I1105 19:51:46.009] process 230 exited with code 0 after 0.0m I1105 19:51:46.010] Checkout: /go/src/sigs.k8s.io/azuredisk-csi-driver master:b7c03af8eae7388e84115ace30cf2ff3285b0dc9,180:3d974a552d3f3a8ed615de3a6a819edc818404e4 to /go/src/sigs.k8s.io/azuredisk-csi-driver I1105 19:51:46.010] Call: git init sigs.k8s.io/azuredisk-csi-driver I1105 19:51:46.018] Initialized empty Git repository in /go/src/sigs.k8s.io/azuredisk-csi-driver/.git/ I1105 19:51:46.019] process 231 exited with code 0 after 0.0m I1105 19:51:46.019] Call: git config --local user.name 'K8S Bootstrap' I1105 19:51:46.026] process 232 exited with code 0 after 0.0m I1105 19:51:46.026] Call: git config --local user.email k8s_bootstrap@localhost I1105 19:51:46.032] process 233 exited with code 0 after 0.0m I1105 19:51:46.033] Call: git fetch --quiet --tags https://github.com/kubernetes-sigs/azuredisk-csi-driver master +refs/pull/180/head:refs/pr/180 I1105 19:52:00.875] process 234 exited with code 0 after 0.2m I1105 19:52:00.876] Call: git checkout -B test b7c03af8eae7388e84115ace30cf2ff3285b0dc9 W1105 19:52:04.441] Switched to a new branch 'test' I1105 19:52:04.446] process 245 exited with code 0 after 0.1m I1105 19:52:04.447] Call: git show -s --format=format:%ct HEAD I1105 19:52:04.452] process 246 exited with code 0 after 0.0m I1105 19:52:04.453] Call: git merge --no-ff -m 'Merge +refs/pull/180/head:refs/pr/180' 3d974a552d3f3a8ed615de3a6a819edc818404e4 I1105 19:52:07.246] Merge made by the 'recursive' strategy. I1105 19:52:07.250] .../templates/csi-azuredisk-controller.yaml | 5 +- I1105 19:52:07.251] deploy/csi-azuredisk-controller.yaml | 3 +- I1105 19:52:07.251] .../storageclass-azuredisk-csi-topology.yaml | 17 +++ I1105 19:52:07.251] pkg/azuredisk/azuredisk.go | 1 + I1105 19:52:07.251] pkg/azuredisk/identityserver.go | 7 ++ I1105 19:52:07.251] pkg/azuredisk/nodeserver.go | 23 +++- I1105 19:52:07.251] test/e2e/driver/azuredisk_csi_driver.go | 20 ++- I1105 19:52:07.252] test/e2e/dynamic_provisioning.go | 134 +++++++++++++++------ I1105 19:52:07.252] ...ynamically_provisioned_reclaim_policy_tester.go | 4 + I1105 19:52:07.252] test/e2e/testsuites/specs.go | 6 +- I1105 19:52:07.252] test/e2e/testsuites/testsuites.go | 8 ++ I1105 19:52:07.252] 11 files changed, 179 insertions(+), 49 deletions(-) I1105 19:52:07.252] create mode 100644 deploy/example/storageclass-azuredisk-csi-topology.yaml I1105 19:52:07.253] process 247 exited with code 0 after 0.0m I1105 19:52:07.253] Configure environment... I1105 19:52:07.253] Call: git show -s --format=format:%ct HEAD I1105 19:52:07.259] process 263 exited with code 0 after 0.0m I1105 19:52:07.259] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1105 19:52:21.707] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1105 19:52:21.904] process 264 exited with code 0 after 0.2m I1105 19:52:21.905] Call: gcloud config get-value account I1105 19:52:22.805] process 278 exited with code 0 after 0.0m I1105 19:52:22.805] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1105 19:52:22.806] 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 ' I1105 19:52:25.585] process 290 exited with code 0 after 0.0m I1105 19:52:25.585] Start 1191803546169774080 at v1.18.0-alpha.0.273+75aca1fe03763d... I1105 19:52:25.591] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil_iFGT49 gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191803546169774080/started.json I1105 19:52:33.670] process 323 exited with code 0 after 0.1m I1105 19:52:33.671] Call: gsutil -q -h Content-Type:text/plain -h 'x-goog-meta-link: gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191803546169774080' cp /tmp/gsutil_IUvMoJ gs://kubernetes-upstream/pr-logs/directory/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191803546169774080.txt I1105 19:52:37.274] process 503 exited with code 0 after 0.1m I1105 19:52:37.275] Call: /workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py --gce-ssh= --test=true --up=true --down=true --deployment=acsengine --build=bazel --provider=skeleton --ginkgo-parallel=1 --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-location=eastus2 --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-multi-zones.json --acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz --test-azure-disk-csi-driver=True '--test_args=--ginkgo.focus=\[multi-az\]' --timeout=420m W1105 19:52:37.344] starts with local mode W1105 19:52:37.344] Environment: W1105 19:52:37.345] ARTIFACTS=/workspace/_artifacts W1105 19:52:37.345] AWS_SSH_PRIVATE_KEY_FILE=/root/.ssh/kube_aws_rsa W1105 19:52:37.345] AWS_SSH_PUBLIC_KEY_FILE=/root/.ssh/kube_aws_rsa.pub W1105 19:52:37.346] AZURE_CREDENTIALS=/etc/azure-cred/credentials W1105 19:52:37.346] AZURE_SSH_PUBLIC_KEY_FILE=/etc/azure-ssh/azure-ssh-pub W1105 19:52:37.346] AZ_STORAGE_CONTAINER_NAME=mystoragecontainer W1105 19:52:37.346] BAZEL_REMOTE_CACHE_ENABLED=false W1105 19:52:37.347] BAZEL_VERSION=0.23.2 W1105 19:52:37.347] BOOTSTRAP_MIGRATION=yes W1105 19:52:37.347] BUILD_ID=1191803546169774080 W1105 19:52:37.347] BUILD_NUMBER=1191803546169774080 W1105 19:52:37.347] CLOUDSDK_COMPONENT_MANAGER_DISABLE_UPDATE_CHECK=true W1105 19:52:37.348] CLOUDSDK_CONFIG=/go/src/k8s.io/kubernetes/.config/gcloud W1105 19:52:37.348] CLOUDSDK_CORE_DISABLE_PROMPTS=1 W1105 19:52:37.348] CLOUDSDK_EXPERIMENTAL_FAST_COMPONENT_UPDATE=false W1105 19:52:37.348] CLOUD_CONFIG=random W1105 19:52:37.349] DECK_PORT=tcp://10.0.160.83:80 W1105 19:52:37.349] DECK_PORT_80_TCP=tcp://10.0.160.83:80 W1105 19:52:37.349] DECK_PORT_80_TCP_ADDR=10.0.160.83 W1105 19:52:37.349] DECK_PORT_80_TCP_PORT=80 W1105 19:52:37.350] DECK_PORT_80_TCP_PROTO=tcp W1105 19:52:37.350] DECK_SERVICE_HOST=10.0.160.83 W1105 19:52:37.350] DECK_SERVICE_PORT=80 W1105 19:52:37.350] DOCKER_IN_DOCKER_ENABLED=true W1105 19:52:37.350] DOCKER_IN_DOCKER_IPV6_ENABLED=false W1105 19:52:37.351] GCS_ARTIFACTS_DIR=gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191803546169774080/artifacts W1105 19:52:37.351] GOOGLE_APPLICATION_CREDENTIALS=/etc/service-account/service-account.json W1105 19:52:37.351] GOPATH=/go W1105 19:52:37.351] GO_TARBALL=go1.12.10.linux-amd64.tar.gz W1105 19:52:37.352] HOME=/workspace W1105 19:52:37.352] HOOK_PORT=tcp://10.0.144.133:8888 W1105 19:52:37.352] HOOK_PORT_8888_TCP=tcp://10.0.144.133:8888 W1105 19:52:37.352] HOOK_PORT_8888_TCP_ADDR=10.0.144.133 W1105 19:52:37.353] HOOK_PORT_8888_TCP_PORT=8888 W1105 19:52:37.353] HOOK_PORT_8888_TCP_PROTO=tcp W1105 19:52:37.353] HOOK_SERVICE_HOST=10.0.144.133 W1105 19:52:37.353] HOOK_SERVICE_PORT=8888 W1105 19:52:37.353] HOSTNAME=aaf55b64-0004-11ea-918b-16773c0c7aed W1105 19:52:37.354] IMAGE=chewong/kubekins-e2e:v20191105-test-1 W1105 19:52:37.354] INSTANCE_PREFIX=bootstrap-e2e W1105 19:52:37.354] JENKINS_GCE_SSH_PRIVATE_KEY_FILE=/root/.ssh/google_compute_engine W1105 19:52:37.354] JENKINS_GCE_SSH_PUBLIC_KEY_FILE=/root/.ssh/google_compute_engine.pub W1105 19:52:37.355] JOB_NAME=chewong-pull-azuredisk-csi-driver-e2e-multi-az W1105 19:52:37.355] JOB_SPEC={"type":"presubmit","job":"chewong-pull-azuredisk-csi-driver-e2e-multi-az","buildid":"1191803546169774080","prowjobid":"aaf55b64-0004-11ea-918b-16773c0c7aed","refs":{"org":"Azure","repo":"kubernetes","repo_link":"https://github.com/Azure/kubernetes","base_ref":"master","base_sha":"cbe7c6e3bea120a6828aae4215696f3b078e8dcb","base_link":"https://github.com/Azure/kubernetes/commit/cbe7c6e3bea120a6828aae4215696f3b078e8dcb","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"}]}} W1105 19:52:37.356] JOB_TYPE=presubmit W1105 19:52:37.356] KUBERNETES_PORT=tcp://10.0.0.1:443 W1105 19:52:37.356] KUBERNETES_PORT_443_TCP=tcp://10.0.0.1:443 W1105 19:52:37.356] KUBERNETES_PORT_443_TCP_ADDR=10.0.0.1 W1105 19:52:37.357] KUBERNETES_PORT_443_TCP_PORT=443 W1105 19:52:37.357] KUBERNETES_PORT_443_TCP_PROTO=tcp W1105 19:52:37.357] KUBERNETES_SERVICE_HOST=10.0.0.1 W1105 19:52:37.358] KUBERNETES_SERVICE_PORT=443 W1105 19:52:37.358] KUBERNETES_SERVICE_PORT_HTTPS=443 W1105 19:52:37.358] KUBETEST_IN_DOCKER=true W1105 19:52:37.358] KUBETEST_MANUAL_DUMP=y W1105 19:52:37.359] KUBE_AWS_INSTANCE_PREFIX=bootstrap-e2e W1105 19:52:37.359] KUBE_GCE_INSTANCE_PREFIX=bootstrap-e2e W1105 19:52:37.359] KUBE_SSH_KEY_PATH=/etc/ssh-key-secret/ssh-private W1105 19:52:37.359] KUBE_SSH_PUBLIC_KEY_PATH=/etc/ssh-key-secret/ssh-public W1105 19:52:37.360] KUBE_SSH_USER=azureuser W1105 19:52:37.360] KUBE_VERBOSE=0 W1105 19:52:37.360] NODE_NAME=aaf55b64-0004-11ea-918b-16773c0c7aed W1105 19:52:37.361] 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 W1105 19:52:37.361] PROW_JOB_ID=aaf55b64-0004-11ea-918b-16773c0c7aed W1105 19:52:37.361] PULL_BASE_REF=master W1105 19:52:37.361] PULL_BASE_SHA=cbe7c6e3bea120a6828aae4215696f3b078e8dcb W1105 19:52:37.361] PULL_NUMBER=113 W1105 19:52:37.362] PULL_PULL_SHA=879465972041635fd7bc8269da49153b67e63822 W1105 19:52:37.362] PULL_REFS=master:cbe7c6e3bea120a6828aae4215696f3b078e8dcb,113:879465972041635fd7bc8269da49153b67e63822 W1105 19:52:37.362] PWD=/workspace W1105 19:52:37.363] REGISTRY=k8sprowinternal.azurecr.io W1105 19:52:37.363] REPO_NAME=kubernetes W1105 19:52:37.363] REPO_OWNER=Azure W1105 19:52:37.363] SHLVL=2 W1105 19:52:37.364] SOURCE_DATE_EPOCH=1572983111 W1105 19:52:37.364] TERM=xterm W1105 19:52:37.364] TIDE_PORT=tcp://10.0.180.53:80 W1105 19:52:37.365] TIDE_PORT_80_TCP=tcp://10.0.180.53:80 W1105 19:52:37.365] TIDE_PORT_80_TCP_ADDR=10.0.180.53 W1105 19:52:37.365] TIDE_PORT_80_TCP_PORT=80 W1105 19:52:37.366] TIDE_PORT_80_TCP_PROTO=tcp W1105 19:52:37.366] TIDE_SERVICE_HOST=10.0.180.53 W1105 19:52:37.366] TIDE_SERVICE_PORT=80 W1105 19:52:37.367] WORKSPACE=/workspace W1105 19:52:37.367] _=./test-infra/jenkins/bootstrap.py W1105 19:52:37.368] Run: ('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=bazel', '--up', '--down', '--test', '--deployment=acsengine', '--provider=skeleton', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--ginkgo-parallel=1', '--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-location=eastus2', '--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-multi-zones.json', '--acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz', '--test-azure-disk-csi-driver=True', '--test_args=--ginkgo.focus=\\[multi-az\\]', '--timeout=420m') W1105 19:52:37.370] 2019/11/05 19:52:37 main.go:332: Limiting testing to 7h0m0s W1105 19:52:37.371] 2019/11/05 19:52:37 azure.go:232: Reading credentials file /etc/azure-cred/credentials W1105 19:52:37.372] 2019/11/05 19:52:37 process.go:153: Running: make -C /go/src/k8s.io/kubernetes bazel-release I1105 19:52:37.472] make: Entering directory '/go/src/k8s.io/kubernetes' W1105 19:52:39.701] Extracting Bazel installation... W1105 19:56:21.765] Starting local Bazel server and connecting to it... W1105 19:56:25.451] Loading: W1105 19:56:25.455] Loading: 0 packages loaded W1105 19:56:26.478] Loading: 0 packages loaded W1105 19:56:28.239] Loading: 0 packages loaded W1105 19:56:29.490] Loading: 0 packages loaded W1105 19:56:31.478] Loading: 0 packages loaded W1105 19:56:32.487] Loading: 0 packages loaded W1105 19:56:32.488] currently loading: build/release-tars W1105 19:56:34.730] Loading: 0 packages loaded W1105 19:56:34.730] currently loading: build/release-tars W1105 19:56:35.115] Analyzing: target //build/release-tars:release-tars (1 packages loaded, 0 targets configured) W1105 19:56:36.603] Analyzing: target //build/release-tars:release-tars (88 packages loaded, 694 targets configured) W1105 19:56:38.970] Analyzing: target //build/release-tars:release-tars (326 packages loaded, 1587 targets configured) W1105 19:56:43.372] Analyzing: target //build/release-tars:release-tars (326 packages loaded, 1587 targets configured) W1105 19:56:46.102] Analyzing: target //build/release-tars:release-tars (1410 packages loaded, 7201 targets configured) W1105 19:56:49.247] Analyzing: target //build/release-tars:release-tars (2701 packages loaded, 20418 targets configured) W1105 19:56:52.865] Analyzing: target //build/release-tars:release-tars (3063 packages loaded, 27560 targets configured) W1105 19:56:58.742] Analyzing: target //build/release-tars:release-tars (3098 packages loaded, 34116 targets configured) W1105 19:57:04.748] Analyzing: target //build/release-tars:release-tars (3099 packages loaded, 34236 targets configured) W1105 19:57:11.123] Analyzing: target //build/release-tars:release-tars (3104 packages loaded, 35202 targets configured) W1105 19:57:19.443] INFO: Analysed target //build/release-tars:release-tars (3104 packages loaded, 36821 targets configured). W1105 19:57:19.446] Building: checking cached actions W1105 19:57:19.446] INFO: Found 1 target... W1105 19:57:20.085] [0 / 14] [-----] Writing file build/release-tars/kubernetes-manifests.args ... (3 actions, 0 running) W1105 19:57:20.090] [0 / 16] [-----] BazelWorkspaceStatusAction stable-status.txt ... (5 actions, 0 running) W1105 19:57:20.099] [0 / 17] [-----] BazelWorkspaceStatusAction stable-status.txt ... (5 actions, 0 running) W1105 19:57:33.138] [38 / 3,405] GoToolchainBinary external/go_sdk/builder [for host]; 11s linux-sandbox ... (7 actions, 4 running) W1105 19:57:34.490] Slow read: a 11617-byte read from /workspace/.cache/bazel/_bazel_root/48d5366022b4e3197674c8d6e2bee219/external/bazel_tools/tools/build_defs/pkg/make_deb.py took 10960 ms. W1105 19:57:44.868] [99 / 4,425] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 9s linux-sandbox ... (8 actions running) W1105 19:57:57.351] [163 / 4,425] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 22s linux-sandbox ... (8 actions, 7 running) W1105 19:58:11.641] [256 / 4,425] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 36s linux-sandbox ... (8 actions running) W1105 19:58:27.869] [411 / 4,425] GoCompilePkg vendor/github.com/google/gofuzz/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/google/gofuzz.a; 1s linux-sandbox ... (8 actions running) W1105 19:58:46.271] [421 / 4,425] GoCompilePkg staging/src/k8s.io/apimachinery/pkg/util/cache/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/cache.a; 15s linux-sandbox ... (8 actions running) W1105 19:59:07.467] [443 / 4,425] GoCompilePkg vendor/github.com/spf13/afero/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/spf13/afero.a; 3s linux-sandbox ... (8 actions, 7 running) W1105 19:59:31.888] [631 / 4,425] GoCompilePkg vendor/github.com/aws/aws-sdk-go/aws/endpoints/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/aws/aws-sdk-go/aws/endpoints.a; 1s linux-sandbox ... (8 actions, 7 running) W1105 20:00:00.114] [865 / 4,425] GoCompilePkg vendor/github.com/Azure/azure-sdk-for-go/services/compute/mgmt/2019-07-01/compute/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/Azure/azure-sdk-for-go/services/compute/mgmt/2019-07-01/compute.a; 2s linux-sandbox ... (8 actions, 5 running) W1105 20:00:32.479] [1,007 / 4,425] GoCompilePkg vendor/golang.org/x/crypto/ssh/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/golang.org/x/crypto/ssh.a; 12s linux-sandbox ... (8 actions, 7 running) W1105 20:01:11.616] [1,255 / 4,425] GoCompilePkg vendor/go.uber.org/zap/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/go.uber.org/zap.a; 2s linux-sandbox ... (8 actions, 7 running) W1105 20:01:54.691] [1,492 / 4,425] GoCompilePkg vendor/google.golang.org/api/compute/v1/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/google.golang.org/api/compute/v1.a; 1s linux-sandbox ... (8 actions, 7 running) W1105 20:02:44.286] [1,832 / 4,425] GoCompilePkg vendor/github.com/GoogleCloudPlatform/k8s-cloud-provider/pkg/cloud/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/GoogleCloudPlatform/k8s-cloud-provider/pkg/cloud.a; 7s linux-sandbox ... (8 actions, 7 running) W1105 20:03:41.398] [1,992 / 4,425] GoCompilePkg staging/src/k8s.io/api/core/v1/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/api/core/v1.a; 6s linux-sandbox ... (8 actions, 7 running) W1105 20:04:48.160] [2,328 / 4,425] GoCompilePkg staging/src/k8s.io/cli-runtime/pkg/printers/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/cli-runtime/pkg/printers.a; 5s linux-sandbox ... (8 actions, 7 running) W1105 20:06:03.616] [2,724 / 4,425] GoCompilePkg plugin/pkg/admission/nodetaint/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/plugin/pkg/admission/nodetaint.a; 0s linux-sandbox ... (8 actions, 7 running) W1105 20:07:30.394] [3,161 / 4,425] GoCompilePkg staging/src/k8s.io/kubectl/pkg/cmd/apply/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/kubectl/pkg/cmd/apply.a; 2s linux-sandbox ... (8 actions, 7 running) W1105 20:09:11.498] [3,582 / 4,425] GoCompilePkg pkg/kubeapiserver/admission/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/pkg/kubeapiserver/admission.a; 3s linux-sandbox ... (7 actions, 6 running) W1105 20:11:06.477] [4,072 / 4,425] GoLink cmd/kube-controller-manager/linux_amd64_pure_stripped/kube-controller-manager; 23s linux-sandbox ... (8 actions, 7 running) W1105 20:13:20.296] [4,373 / 4,428] GoLink cmd/kube-apiserver/linux_amd64_pure_stripped/kube-apiserver; 13s linux-sandbox ... (8 actions, 7 running) W1105 20:15:40.297] Target //build/release-tars:release-tars up-to-date: W1105 20:15:40.299] bazel-bin/build/release-tars/kubernetes-client-linux-amd64.tar.gz W1105 20:15:40.299] bazel-bin/build/release-tars/kubernetes-node-linux-amd64.tar.gz W1105 20:15:40.299] bazel-bin/build/release-tars/kubernetes-server-linux-amd64.tar.gz W1105 20:15:40.300] bazel-bin/build/release-tars/kubernetes-manifests.tar.gz W1105 20:15:40.300] bazel-bin/build/release-tars/kubernetes-test-portable.tar.gz W1105 20:15:40.300] bazel-bin/build/release-tars/kubernetes-test-linux-amd64.tar.gz W1105 20:15:40.301] bazel-bin/build/release-tars/kubernetes.tar.gz W1105 20:15:40.301] bazel-bin/build/release-tars/kubernetes-src.tar.gz W1105 20:15:40.350] INFO: Elapsed time: 1382.800s, Critical Path: 304.36s W1105 20:15:40.350] INFO: 4364 processes: 4364 linux-sandbox. W1105 20:15:40.356] INFO: Build completed successfully, 4429 total actions W1105 20:15:40.363] INFO: Build completed successfully, 4429 total actions W1105 20:15:40.370] 2019/11/05 20:15:40 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes bazel-release' finished in 23m2.998616908s W1105 20:15:40.370] 2019/11/05 20:15:40 util.go:265: Flushing memory. I1105 20:15:40.471] make: Leaving directory '/go/src/k8s.io/kubernetes' W1105 20:15:58.585] 2019/11/05 20:15:58 azure.go:906: Deleting resource group: kubetest-d1403bc4-0005-11ea-a653-02428e41827a. W1105 20:15:59.022] 2019/11/05 20:15:59 azure.go:787: downloading /workspace/aks922635205/kubernetes.json from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/tests/k8s-azure/manifest/linux-vmss-multi-zones.json. W1105 20:15:59.023] 2019/11/05 20:15:59 util.go:42: curl https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/tests/k8s-azure/manifest/linux-vmss-multi-zones.json W1105 20:15:59.168] 2019/11/05 20:15:59 azure.go:529: downloading /workspace/aks-engine.tar.gz from https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz. W1105 20:15:59.169] 2019/11/05 20:15:59 util.go:42: curl https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz W1105 20:16:00.440] 2019/11/05 20:16:00 azure.go:556: Extracting tar file /workspace/aks-engine.tar.gz into directory /go/src/k8s.io/kubernetes . W1105 20:16:00.440] 2019/11/05 20:16:00 process.go:153: Running: tar -xzf /workspace/aks-engine.tar.gz --strip 1 W1105 20:16:00.606] 2019/11/05 20:16:00 process.go:155: Step 'tar -xzf /workspace/aks-engine.tar.gz --strip 1' finished in 166.454874ms W1105 20:16:00.607] 2019/11/05 20:16:00 process.go:153: Running: /go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks922635205/kubernetes.json --output-directory /workspace/aks922635205 I1105 20:16:00.835] WARN[0000] Clusters with VMSS masters are not yet upgradable! You will not be able to upgrade your cluster until a future version of aks-engine! I1105 20:16:00.835] INFO[0000] Generating assets into /workspace/aks922635205... W1105 20:16:19.816] 2019/11/05 20:16:19 process.go:155: Step '/go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks922635205/kubernetes.json --output-directory /workspace/aks922635205' finished in 19.209463734s W1105 20:16:19.820] 2019/11/05 20:16:19 azure.go:627: Setting kubeconfig env variable: kubeconfig path: /workspace/aks922635205/kubeconfig/kubeconfig.eastus2.json. W1105 20:16:19.820] 2019/11/05 20:16:19 azure.go:629: Creating resource group: kubetest-d1403bc4-0005-11ea-a653-02428e41827a. W1105 20:16:19.820] 2019/11/05 20:16:19 azure.go:631: Creating Azure resource group: kubetest-d1403bc4-0005-11ea-a653-02428e41827a for cluster deployment. W1105 20:16:21.379] 2019/11/05 20:16:21 azure.go:636: Validating deployment ARM templates. W1105 20:16:22.788] 2019/11/05 20:16:22 azure.go:642: Deploying cluster kubetest-d1403bc4-0005-11ea-a653-02428e41827a in resource group kubetest-d1403bc4-0005-11ea-a653-02428e41827a. W1105 20:29:43.824] 2019/11/05 20:29:43 azure.go:912: Skippng DumpClusterLogs due to CCM not being enabled. W1105 20:29:43.824] 2019/11/05 20:29:43 azure.go:906: Deleting resource group: kubetest-d1403bc4-0005-11ea-a653-02428e41827a. W1105 20:37:51.962] 2019/11/05 20:37:51 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml. W1105 20:37:51.962] 2019/11/05 20:37:51 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}" W1105 20:37:52.628] 2019/11/05 20:37:52 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 666.255998ms W1105 20:37:52.629] 2019/11/05 20:37:52 main.go:319: Something went wrong: starting e2e cluster: error creating cluster: cannot deploy: cannot get the create deployment future response: Code="DeploymentFailed" Message="At least one resource deployment operation failed. Please list deployment operations for details. Please see https://aka.ms/arm-debug for usage details." Details=[{"code":"BadRequest","message":"{\r\n \"error\": {\r\n \"code\": \"RuleIdleTimeoutIsOutOfRange\",\r\n \"message\": \"Rule /subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-d1403bc4-0005-11ea-a653-02428e41827a/providers/Microsoft.Network/loadBalancers/kubetest-d1403bc4-0005-11ea-a653-02428e41827a/outboundRules/LBOutboundRule has invalid Idle Timeout. The value must be between 4 and 120.\",\r\n \"details\": []\r\n }\r\n}"}] W1105 20:37:52.630] Traceback (most recent call last): W1105 20:37:52.630] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in W1105 20:37:52.631] main(parse_args()) W1105 20:37:52.631] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main W1105 20:37:52.631] mode.start(runner_args) W1105 20:37:52.631] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start W1105 20:37:52.631] check_env(env, self.command, *args) W1105 20:37:52.631] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env W1105 20:37:52.631] subprocess.check_call(cmd, env=env) W1105 20:37:52.632] File "/usr/lib/python2.7/subprocess.py", line 190, in check_call W1105 20:37:52.632] raise CalledProcessError(retcode, cmd) W1105 20:37:52.633] subprocess.CalledProcessError: Command '('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=bazel', '--up', '--down', '--test', '--deployment=acsengine', '--provider=skeleton', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--ginkgo-parallel=1', '--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-location=eastus2', '--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-multi-zones.json', '--acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz', '--test-azure-disk-csi-driver=True', '--test_args=--ginkgo.focus=\\[multi-az\\]', '--timeout=420m')' returned non-zero exit status 1 E1105 20:37:52.639] Command failed I1105 20:37:52.639] process 683 exited with code 1 after 45.3m E1105 20:37:52.639] FAIL: chewong-pull-azuredisk-csi-driver-e2e-multi-az I1105 20:37:52.640] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1105 20:37:53.517] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1105 20:37:53.558] process 2119 exited with code 0 after 0.0m I1105 20:37:53.558] Call: gcloud config get-value account I1105 20:37:53.812] process 2131 exited with code 0 after 0.0m I1105 20:37:53.812] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1105 20:37:53.812] Upload result and artifacts... I1105 20:37:53.812] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191803546169774080 I1105 20:37:53.813] Call: gsutil ls gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191803546169774080/artifacts W1105 20:37:54.874] CommandException: One or more URLs matched no objects. E1105 20:37:54.951] Command failed I1105 20:37:54.952] process 2143 exited with code 1 after 0.0m W1105 20:37:54.952] Remote dir gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191803546169774080/artifacts not exist yet I1105 20:37:54.952] Call: gsutil -m -q -o GSUtil:use_magicfile=True cp -r -c -z log,txt,xml /workspace/_artifacts gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191803546169774080/artifacts I1105 20:37:56.341] process 2287 exited with code 0 after 0.0m I1105 20:37:56.342] Call: git rev-parse HEAD I1105 20:37:56.345] process 2813 exited with code 0 after 0.0m I1105 20:37:56.346] Call: git rev-parse HEAD I1105 20:37:56.349] process 2814 exited with code 0 after 0.0m I1105 20:37:56.349] Call: gsutil stat gs://kubernetes-upstream/pr-logs/directory/chewong-pull-azuredisk-csi-driver-e2e-multi-az/jobResultsCache.json I1105 20:37:57.137] process 2815 exited with code 0 after 0.0m I1105 20:37:57.138] Call: gsutil -q cat 'gs://kubernetes-upstream/pr-logs/directory/chewong-pull-azuredisk-csi-driver-e2e-multi-az/jobResultsCache.json#1572923721010323' I1105 20:37:58.296] process 2959 exited with code 0 after 0.0m I1105 20:37:58.296] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1572923721010323 cp /tmp/gsutil_Jag_MX gs://kubernetes-upstream/pr-logs/directory/chewong-pull-azuredisk-csi-driver-e2e-multi-az/jobResultsCache.json I1105 20:37:59.469] process 3105 exited with code 0 after 0.0m I1105 20:37:59.470] Call: gsutil stat gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/jobResultsCache.json I1105 20:38:00.418] process 3285 exited with code 0 after 0.0m I1105 20:38:00.418] Call: gsutil -q cat 'gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/jobResultsCache.json#1572923724266422' I1105 20:38:01.482] process 3429 exited with code 0 after 0.0m I1105 20:38:01.483] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1572923724266422 cp /tmp/gsutil_jW4WNE gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/jobResultsCache.json I1105 20:38:02.700] process 3575 exited with code 0 after 0.0m I1105 20:38:02.701] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil_TXbSVE gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191803546169774080/finished.json I1105 20:38:04.038] process 3755 exited with code 0 after 0.0m I1105 20:38:04.039] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_deae_7 gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/latest-build.txt I1105 20:38:05.142] process 3935 exited with code 0 after 0.0m I1105 20:38:05.143] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_GUUjj0 gs://kubernetes-upstream/pr-logs/directory/chewong-pull-azuredisk-csi-driver-e2e-multi-az/latest-build.txt I1105 20:38:06.341] process 4115 exited with code 0 after 0.0m