W1017 18:29:55.784] ************************************************************************** bootstrap.py is deprecated! test-infra oncall does not support any job still using bootstrap.py. Please migrate your job to podutils! https://github.com/kubernetes/test-infra/blob/master/prow/pod-utilities.md ************************************************************************** I1017 18:29:55.784] Args: --job=chewong-e2e-ccm --service-account=/etc/service-account/service-account.json --upload=gs://kubernetes-jenkins/logs --job=chewong-e2e-ccm --repo=k8s.io/kubernetes=release-1.16 --repo=k8s.io/cloud-provider-azure=master:c470e6f36d76e5a565478fcba22118c06bc1548f,248:84546d4184c381a062c9b0a29a987390dc47f2ce --root=/go/src --service-account=/etc/service-account/service-account.json --timeout=450 --upload=gs://kubernetes-upstream/pr-logs --scenario=kubernetes_e2e -- --gce-ssh= --test=true --up=true --down=true --deployment=acsengine --build=quick --provider=skeleton --ginkgo-parallel=30 --test-ccm=True --acsengine-agentpoolcount=1 '--acsengine-admin-username=$AZURE_SSH_USER' '--acsengine-creds=$AZURE_CREDENTIALS' --acsengine-orchestratorRelease=1.16 --acsengine-mastervmsize=Standard_DS2_v2 --acsengine-agentvmsize=Standard_D4s_v3 --acsengine-hyperkube=True --acsengine-ccm=True --acsengine-location=eastus2 '--acsengine-public-key=$AZURE_SSH_PUBLIC_KEY_FILE' --acsengine-template-url=https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json --acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz --timeout=420m I1017 18:29:55.784] Bootstrap chewong-e2e-ccm... I1017 18:29:55.788] Builder: 0b1b00ba-f10c-11e9-b3d3-b20db476995a I1017 18:29:55.788] Image: chewong/kubekins-e2e:v20191017-test I1017 18:29:55.788] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184899302372151296 I1017 18:29:55.788] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1017 18:29:56.307] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1017 18:29:56.337] process 213 exited with code 0 after 0.0m I1017 18:29:56.338] Call: gcloud config get-value account I1017 18:29:56.580] process 225 exited with code 0 after 0.0m I1017 18:29:56.580] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1017 18:29:56.580] Root: /go/src I1017 18:29:56.581] cd to /go/src I1017 18:29:56.581] Checkout: /go/src/k8s.io/kubernetes release-1.16 to /go/src/k8s.io/kubernetes I1017 18:29:56.581] Call: git init k8s.io/kubernetes I1017 18:29:56.584] Initialized empty Git repository in /go/src/k8s.io/kubernetes/.git/ I1017 18:29:56.585] process 237 exited with code 0 after 0.0m I1017 18:29:56.585] Call: git config --local user.name 'K8S Bootstrap' I1017 18:29:56.587] process 238 exited with code 0 after 0.0m I1017 18:29:56.588] Call: git config --local user.email k8s_bootstrap@localhost I1017 18:29:56.590] process 239 exited with code 0 after 0.0m I1017 18:29:56.590] Call: git fetch --quiet --tags https://github.com/kubernetes/kubernetes release-1.16 I1017 18:30:48.900] process 240 exited with code 0 after 0.9m I1017 18:30:48.900] Call: git checkout -B test FETCH_HEAD W1017 18:30:50.974] Switched to a new branch 'test' I1017 18:30:50.984] process 252 exited with code 0 after 0.0m I1017 18:30:50.985] Call: git show -s --format=format:%ct HEAD I1017 18:30:50.988] process 253 exited with code 0 after 0.0m I1017 18:30:50.989] Checkout: /go/src/k8s.io/cloud-provider-azure master:c470e6f36d76e5a565478fcba22118c06bc1548f,248:84546d4184c381a062c9b0a29a987390dc47f2ce to /go/src/k8s.io/cloud-provider-azure I1017 18:30:50.989] Call: git init k8s.io/cloud-provider-azure I1017 18:30:50.992] Initialized empty Git repository in /go/src/k8s.io/cloud-provider-azure/.git/ I1017 18:30:50.993] process 254 exited with code 0 after 0.0m I1017 18:30:50.993] Call: git config --local user.name 'K8S Bootstrap' I1017 18:30:50.995] process 255 exited with code 0 after 0.0m I1017 18:30:50.996] Call: git config --local user.email k8s_bootstrap@localhost I1017 18:30:50.998] process 256 exited with code 0 after 0.0m I1017 18:30:50.998] Call: git fetch --quiet --tags https://github.com/kubernetes/cloud-provider-azure master +refs/pull/248/head:refs/pr/248 I1017 18:30:52.512] process 257 exited with code 0 after 0.0m I1017 18:30:52.512] Call: git checkout -B test c470e6f36d76e5a565478fcba22118c06bc1548f W1017 18:30:52.930] Switched to a new branch 'test' I1017 18:30:52.933] process 269 exited with code 0 after 0.0m I1017 18:30:52.934] Call: git show -s --format=format:%ct HEAD I1017 18:30:52.936] process 270 exited with code 0 after 0.0m I1017 18:30:52.937] Call: git merge --no-ff -m 'Merge +refs/pull/248/head:refs/pr/248' 84546d4184c381a062c9b0a29a987390dc47f2ce I1017 18:30:53.277] Merge made by the 'recursive' strategy. I1017 18:30:53.279] hack/log-dump.sh | 171 +++++++++++++++++++++++++++++++++++++++++++++++++++++++ I1017 18:30:53.279] 1 file changed, 171 insertions(+) I1017 18:30:53.279] create mode 100755 hack/log-dump.sh I1017 18:30:53.279] process 271 exited with code 0 after 0.0m I1017 18:30:53.280] Configure environment... I1017 18:30:53.280] Call: git show -s --format=format:%ct HEAD I1017 18:30:53.284] process 273 exited with code 0 after 0.0m I1017 18:30:53.284] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1017 18:30:53.921] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1017 18:30:54.031] process 274 exited with code 0 after 0.0m I1017 18:30:54.031] Call: gcloud config get-value account I1017 18:30:54.265] process 286 exited with code 0 after 0.0m I1017 18:30:54.266] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1017 18:30:54.266] Call: bash -c ' set -o errexit set -o nounset export KUBE_ROOT=. source hack/lib/version.sh kube::version::get_version_vars echo $KUBE_GIT_VERSION ' I1017 18:30:54.789] process 298 exited with code 0 after 0.0m I1017 18:30:54.789] Start 1184899302372151296 at v1.16.3-beta.0.11+0d9472c2ffccc1... I1017 18:30:54.791] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil_l_Xoa3 gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184899302372151296/started.json I1017 18:30:56.320] process 331 exited with code 0 after 0.0m I1017 18:30:56.320] Call: gsutil -q -h Content-Type:text/plain -h 'x-goog-meta-link: gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184899302372151296' cp /tmp/gsutil_Ee18PN gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/1184899302372151296.txt I1017 18:30:57.615] process 509 exited with code 0 after 0.0m I1017 18:30:57.616] Call: /workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py --gce-ssh= --test=true --up=true --down=true --deployment=acsengine --build=quick --provider=skeleton --ginkgo-parallel=30 --test-ccm=True --acsengine-agentpoolcount=1 --acsengine-admin-username=azureuser --acsengine-creds=/etc/azure-cred/credentials --acsengine-orchestratorRelease=1.16 --acsengine-mastervmsize=Standard_DS2_v2 --acsengine-agentvmsize=Standard_D4s_v3 --acsengine-hyperkube=True --acsengine-ccm=True --acsengine-location=eastus2 --acsengine-public-key=/etc/ssh-key-secret/ssh-public --acsengine-template-url=https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json --acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz --timeout=420m W1017 18:30:57.653] starts with local mode W1017 18:30:57.653] Environment: W1017 18:30:57.654] ARTIFACTS=/workspace/_artifacts W1017 18:30:57.654] AWS_SSH_PRIVATE_KEY_FILE=/root/.ssh/kube_aws_rsa W1017 18:30:57.654] AWS_SSH_PUBLIC_KEY_FILE=/root/.ssh/kube_aws_rsa.pub W1017 18:30:57.654] AZURE_CREDENTIALS=/etc/azure-cred/credentials W1017 18:30:57.654] AZURE_SSH_PRIVATE_KEY_FILE=/etc/ssh-key-secret/ssh-private W1017 18:30:57.655] AZURE_SSH_PUBLIC_KEY_FILE=/etc/ssh-key-secret/ssh-public W1017 18:30:57.655] AZURE_SSH_USER=azureuser W1017 18:30:57.655] AZ_STORAGE_CONTAINER_NAME=mystoragecontainer W1017 18:30:57.655] BAZEL_REMOTE_CACHE_ENABLED=false W1017 18:30:57.655] BAZEL_VERSION=0.23.2 W1017 18:30:57.655] BOOTSTRAP_MIGRATION=yes W1017 18:30:57.655] BUILD_ID=1184899302372151296 W1017 18:30:57.655] BUILD_NUMBER=1184899302372151296 W1017 18:30:57.655] CLOUDSDK_COMPONENT_MANAGER_DISABLE_UPDATE_CHECK=true W1017 18:30:57.656] CLOUDSDK_CONFIG=/go/src/k8s.io/kubernetes/.config/gcloud W1017 18:30:57.656] CLOUDSDK_CORE_DISABLE_PROMPTS=1 W1017 18:30:57.656] CLOUDSDK_EXPERIMENTAL_FAST_COMPONENT_UPDATE=false W1017 18:30:57.656] CLOUD_CONFIG=random W1017 18:30:57.656] DECK_PORT=tcp://10.0.160.83:80 W1017 18:30:57.656] DECK_PORT_80_TCP=tcp://10.0.160.83:80 W1017 18:30:57.656] DECK_PORT_80_TCP_ADDR=10.0.160.83 W1017 18:30:57.657] DECK_PORT_80_TCP_PORT=80 W1017 18:30:57.657] DECK_PORT_80_TCP_PROTO=tcp W1017 18:30:57.657] DECK_SERVICE_HOST=10.0.160.83 W1017 18:30:57.657] DECK_SERVICE_PORT=80 W1017 18:30:57.657] DOCKER_IN_DOCKER_ENABLED=true W1017 18:30:57.657] DOCKER_IN_DOCKER_IPV6_ENABLED=false W1017 18:30:57.657] GCS_ARTIFACTS_DIR=gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184899302372151296/artifacts W1017 18:30:57.657] GOOGLE_APPLICATION_CREDENTIALS=/etc/service-account/service-account.json W1017 18:30:57.658] GOPATH=/go W1017 18:30:57.658] GO_TARBALL=go1.12.10.linux-amd64.tar.gz W1017 18:30:57.658] HOME=/workspace W1017 18:30:57.658] HOOK_PORT=tcp://10.0.144.133:8888 W1017 18:30:57.658] HOOK_PORT_8888_TCP=tcp://10.0.144.133:8888 W1017 18:30:57.658] HOOK_PORT_8888_TCP_ADDR=10.0.144.133 W1017 18:30:57.658] HOOK_PORT_8888_TCP_PORT=8888 W1017 18:30:57.658] HOOK_PORT_8888_TCP_PROTO=tcp W1017 18:30:57.659] HOOK_SERVICE_HOST=10.0.144.133 W1017 18:30:57.659] HOOK_SERVICE_PORT=8888 W1017 18:30:57.659] HOSTNAME=0b1b00ba-f10c-11e9-b3d3-b20db476995a W1017 18:30:57.659] IMAGE=chewong/kubekins-e2e:v20191017-test W1017 18:30:57.659] INSTANCE_PREFIX=bootstrap-e2e W1017 18:30:57.659] JENKINS_GCE_SSH_PRIVATE_KEY_FILE=/etc/ssh-key-secret/ssh-private W1017 18:30:57.659] JENKINS_GCE_SSH_PUBLIC_KEY_FILE=/etc/ssh-key-secret/ssh-public W1017 18:30:57.660] JOB_NAME=chewong-e2e-ccm W1017 18:30:57.660] JOB_SPEC={"type":"presubmit","job":"chewong-e2e-ccm","buildid":"1184899302372151296","prowjobid":"0b1b00ba-f10c-11e9-b3d3-b20db476995a","refs":{"org":"Azure","repo":"kubernetes","repo_link":"https://github.com/Azure/kubernetes","base_ref":"master","base_sha":"37fca51d74a81df3b6c8b6df5b644e333acd7274","base_link":"https://github.com/Azure/kubernetes/commit/37fca51d74a81df3b6c8b6df5b644e333acd7274","pulls":[{"number":113,"author":"chewong","sha":"879465972041635fd7bc8269da49153b67e63822","link":"https://github.com/Azure/kubernetes/pull/113","commit_link":"https://github.com/Azure/kubernetes/pull/113/commits/879465972041635fd7bc8269da49153b67e63822","author_link":"https://github.com/chewong"}]}} W1017 18:30:57.660] JOB_TYPE=presubmit W1017 18:30:57.660] KUBERNETES_PORT=tcp://10.0.0.1:443 W1017 18:30:57.661] KUBERNETES_PORT_443_TCP=tcp://10.0.0.1:443 W1017 18:30:57.661] KUBERNETES_PORT_443_TCP_ADDR=10.0.0.1 W1017 18:30:57.661] KUBERNETES_PORT_443_TCP_PORT=443 W1017 18:30:57.661] KUBERNETES_PORT_443_TCP_PROTO=tcp W1017 18:30:57.661] KUBERNETES_SERVICE_HOST=10.0.0.1 W1017 18:30:57.661] KUBERNETES_SERVICE_PORT=443 W1017 18:30:57.661] KUBERNETES_SERVICE_PORT_HTTPS=443 W1017 18:30:57.662] KUBETEST_IN_DOCKER=true W1017 18:30:57.662] KUBETEST_MANUAL_DUMP=y W1017 18:30:57.662] KUBE_AWS_INSTANCE_PREFIX=bootstrap-e2e W1017 18:30:57.662] KUBE_GCE_INSTANCE_PREFIX=bootstrap-e2e W1017 18:30:57.662] KUBE_VERBOSE=0 W1017 18:30:57.662] NODE_NAME=0b1b00ba-f10c-11e9-b3d3-b20db476995a W1017 18:30:57.663] PATH=/go/bin:/go/bin:/usr/local/go/bin:/google-cloud-sdk/bin:/workspace:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin W1017 18:30:57.663] PROW_JOB_ID=0b1b00ba-f10c-11e9-b3d3-b20db476995a W1017 18:30:57.663] PULL_BASE_REF=master W1017 18:30:57.663] PULL_BASE_SHA=37fca51d74a81df3b6c8b6df5b644e333acd7274 W1017 18:30:57.663] PULL_NUMBER=113 W1017 18:30:57.663] PULL_PULL_SHA=879465972041635fd7bc8269da49153b67e63822 W1017 18:30:57.664] PULL_REFS=master:37fca51d74a81df3b6c8b6df5b644e333acd7274,113:879465972041635fd7bc8269da49153b67e63822 W1017 18:30:57.664] PWD=/workspace W1017 18:30:57.664] REGISTRY=k8sprowinternal.azurecr.io W1017 18:30:57.664] REPO_NAME=kubernetes W1017 18:30:57.664] REPO_OWNER=Azure W1017 18:30:57.664] SHLVL=2 W1017 18:30:57.664] SOURCE_DATE_EPOCH=1571316399 W1017 18:30:57.665] TERM=xterm W1017 18:30:57.665] TIDE_PORT=tcp://10.0.180.53:80 W1017 18:30:57.665] TIDE_PORT_80_TCP=tcp://10.0.180.53:80 W1017 18:30:57.665] TIDE_PORT_80_TCP_ADDR=10.0.180.53 W1017 18:30:57.665] TIDE_PORT_80_TCP_PORT=80 W1017 18:30:57.665] TIDE_PORT_80_TCP_PROTO=tcp W1017 18:30:57.666] TIDE_SERVICE_HOST=10.0.180.53 W1017 18:30:57.666] TIDE_SERVICE_PORT=80 W1017 18:30:57.666] USER=prow W1017 18:30:57.666] WORKSPACE=/workspace W1017 18:30:57.666] _=./test-infra/jenkins/bootstrap.py W1017 18:30:57.667] Run: ('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=quick', '--up', '--down', '--test', '--deployment=acsengine', '--provider=skeleton', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--ginkgo-parallel=30', '--test-ccm=True', '--acsengine-agentpoolcount=1', '--acsengine-admin-username=azureuser', '--acsengine-creds=/etc/azure-cred/credentials', '--acsengine-orchestratorRelease=1.16', '--acsengine-mastervmsize=Standard_DS2_v2', '--acsengine-agentvmsize=Standard_D4s_v3', '--acsengine-hyperkube=True', '--acsengine-ccm=True', '--acsengine-location=eastus2', '--acsengine-public-key=/etc/ssh-key-secret/ssh-public', '--acsengine-template-url=https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json', '--acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz', '--timeout=420m') W1017 18:30:57.675] 2019/10/17 18:30:57 main.go:332: Limiting testing to 7h0m0s W1017 18:30:57.675] 2019/10/17 18:30:57 azure.go:232: Reading credentials file /etc/azure-cred/credentials W1017 18:30:57.676] 2019/10/17 18:30:57 process.go:153: Running: make -C /go/src/k8s.io/kubernetes quick-release I1017 18:30:57.776] make: Entering directory '/go/src/k8s.io/kubernetes' I1017 18:30:57.776] +++ [1017 18:30:57] Verifying Prerequisites.... I1017 18:30:57.944] +++ [1017 18:30:57] Building Docker image kube-build:build-260a97dfab-5-v1.12.10-1 I1017 18:33:44.085] +++ [1017 18:33:44] Creating data container kube-build-data-260a97dfab-5-v1.12.10-1 I1017 18:34:21.938] +++ [1017 18:34:21] Syncing sources to container I1017 18:34:33.191] +++ [1017 18:34:33] Running build command... I1017 18:34:45.155] +++ [1017 18:34:45] Building go targets for linux/amd64: I1017 18:34:45.155] ./vendor/k8s.io/code-generator/cmd/deepcopy-gen I1017 18:34:54.923] +++ [1017 18:34:54] Building go targets for linux/amd64: I1017 18:34:54.923] ./vendor/k8s.io/code-generator/cmd/defaulter-gen I1017 18:35:01.481] +++ [1017 18:35:01] Building go targets for linux/amd64: I1017 18:35:01.481] ./vendor/k8s.io/code-generator/cmd/conversion-gen I1017 18:35:14.317] +++ [1017 18:35:14] Building go targets for linux/amd64: I1017 18:35:14.318] ./vendor/k8s.io/kube-openapi/cmd/openapi-gen I1017 18:35:28.669] +++ [1017 18:35:28] Building go targets for linux/amd64: I1017 18:35:28.670] ./vendor/github.com/go-bindata/go-bindata/go-bindata I1017 18:35:30.149] +++ [1017 18:35:30] Building go targets for linux/amd64: I1017 18:35:30.149] cmd/kube-proxy I1017 18:35:30.149] cmd/kube-apiserver I1017 18:35:30.149] cmd/kube-controller-manager I1017 18:35:30.149] cmd/kubelet I1017 18:35:30.150] cmd/kubeadm I1017 18:35:30.150] cmd/hyperkube I1017 18:35:30.150] cmd/kube-scheduler I1017 18:35:30.150] vendor/k8s.io/apiextensions-apiserver I1017 18:35:30.150] cluster/gce/gci/mounter I1017 18:39:10.717] +++ [1017 18:39:10] Building go targets for linux/amd64: I1017 18:39:10.718] cmd/kube-proxy I1017 18:39:10.718] cmd/kubeadm I1017 18:39:10.718] cmd/kubelet I1017 18:39:22.548] +++ [1017 18:39:22] Building go targets for linux/amd64: I1017 18:39:22.548] cmd/kubectl I1017 18:39:39.542] +++ [1017 18:39:39] Building go targets for linux/amd64: I1017 18:39:39.542] cmd/gendocs I1017 18:39:39.543] cmd/genkubedocs I1017 18:39:39.543] cmd/genman I1017 18:39:39.543] cmd/genyaml I1017 18:39:39.543] cmd/genswaggertypedocs I1017 18:39:39.543] cmd/linkcheck I1017 18:39:39.543] vendor/github.com/onsi/ginkgo/ginkgo I1017 18:39:39.543] test/e2e/e2e.test I1017 18:39:39.544] cluster/images/conformance/go-runner I1017 18:41:30.733] +++ [1017 18:41:30] Building go targets for linux/amd64: I1017 18:41:30.733] cmd/kubemark I1017 18:41:30.733] vendor/github.com/onsi/ginkgo/ginkgo I1017 18:41:30.734] test/e2e_node/e2e_node.test I1017 18:43:13.163] +++ [1017 18:43:13] Syncing out of container I1017 18:44:10.875] +++ [1017 18:44:10] Building tarball: manifests I1017 18:44:10.879] +++ [1017 18:44:10] Building tarball: src I1017 18:44:10.886] +++ [1017 18:44:10] Starting tarball: client linux-amd64 I1017 18:44:10.892] +++ [1017 18:44:10] Waiting on tarballs I1017 18:44:17.936] +++ [1017 18:44:17] Building images: linux-amd64 I1017 18:44:17.936] +++ [1017 18:44:17] Building tarball: node linux-amd64 I1017 18:44:18.868] +++ [1017 18:44:18] Starting docker build for image: kube-apiserver-amd64 I1017 18:44:18.870] +++ [1017 18:44:18] Starting docker build for image: kube-controller-manager-amd64 I1017 18:44:18.875] +++ [1017 18:44:18] Starting docker build for image: kube-scheduler-amd64 I1017 18:44:18.877] +++ [1017 18:44:18] Starting docker build for image: kube-proxy-amd64 I1017 18:44:18.883] +++ [1017 18:44:18] Building conformance image for arch: amd64 I1017 18:44:18.885] +++ [1017 18:44:18] Building hyperkube image for arch: amd64 I1017 18:45:18.967] +++ [1017 18:45:18] Deleting docker image k8s.gcr.io/kube-scheduler-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1 I1017 18:45:36.984] +++ [1017 18:45:36] Deleting docker image k8s.gcr.io/kube-controller-manager-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1 I1017 18:45:37.093] +++ [1017 18:45:37] Deleting docker image k8s.gcr.io/kube-apiserver-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1 I1017 18:46:10.070] +++ [1017 18:46:10] Deleting docker image k8s.gcr.io/kube-proxy-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1 I1017 18:46:27.165] +++ [1017 18:46:27] Deleting hyperkube image k8s.gcr.io/hyperkube-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1 I1017 18:47:05.231] +++ [1017 18:47:05] Deleting conformance image k8s.gcr.io/conformance-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1 I1017 18:47:05.423] +++ [1017 18:47:05] Docker builds done I1017 18:47:05.426] +++ [1017 18:47:05] Building tarball: server linux-amd64 I1017 18:48:49.191] +++ [1017 18:48:49] Building tarball: final I1017 18:48:49.520] +++ [1017 18:48:49] Starting tarball: test linux-amd64 I1017 18:48:49.521] +++ [1017 18:48:49] Waiting on test tarballs I1017 18:49:44.887] +++ [1017 18:49:44] Building tarball: test portable I1017 18:49:44.970] +++ [1017 18:49:44] Building tarball: test mondo (deprecated by KEP sig-testing/20190118-breaking-apart-the-kubernetes-test-tarball) I1017 18:50:44.291] make: Leaving directory '/go/src/k8s.io/kubernetes' W1017 18:50:44.391] 2019/10/17 18:50:44 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes quick-release' finished in 19m46.61498252s W1017 18:50:44.392] 2019/10/17 18:50:44 util.go:277: Flushing memory. W1017 18:50:56.124] 2019/10/17 18:50:56 azure.go:906: Deleting resource group: kubetest-42f4e1d0-f10c-11e9-add7-02422c563efc. W1017 18:50:56.644] 2019/10/17 18:50:56 azure.go:654: CWD /go/src/k8s.io/kubernetes W1017 18:50:56.644] 2019/10/17 18:50:56 azure.go:673: Attempting Docker login with azure cred. W1017 18:50:58.698] 2019/10/17 18:50:58 azure.go:682: Docker login success. W1017 18:50:58.699] 2019/10/17 18:50:58 azure.go:697: Building ccm. W1017 18:50:58.699] 2019/10/17 18:50:58 azure.go:699: projectPath /go/src/k8s.io/cloud-provider-azure W1017 18:50:58.699] 2019/10/17 18:50:58 process.go:153: Running: docker build -t k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184899302372151296-0d98f38b . I1017 18:51:05.301] Sending build context to Docker daemon 67.18MB I1017 18:51:05.343] Step 1/7 : FROM golang:1.12.9-stretch AS build I1017 18:51:06.361] 1.12.9-stretch: Pulling from library/golang I1017 18:51:06.696] 092586df9206: Pulling fs layer I1017 18:51:06.696] ef599477fae0: Pulling fs layer I1017 18:51:06.696] 4530c6472b5d: Pulling fs layer I1017 18:51:06.696] d34d61487075: Pulling fs layer I1017 18:51:06.697] 89c6ec31b9e9: Pulling fs layer I1017 18:51:06.697] e37857ebcafa: Pulling fs layer I1017 18:51:06.697] b0e29f6c7f0a: Pulling fs layer I1017 18:51:06.697] 89c6ec31b9e9: Waiting I1017 18:51:06.698] b0e29f6c7f0a: Waiting I1017 18:51:06.698] e37857ebcafa: Waiting I1017 18:51:06.698] d34d61487075: Waiting I1017 18:51:07.136] 4530c6472b5d: Verifying Checksum I1017 18:51:07.136] 4530c6472b5d: Download complete I1017 18:51:07.250] ef599477fae0: Verifying Checksum I1017 18:51:07.251] ef599477fae0: Download complete I1017 18:51:07.522] 092586df9206: Verifying Checksum I1017 18:51:07.522] 092586df9206: Download complete I1017 18:51:08.047] d34d61487075: Verifying Checksum I1017 18:51:08.047] d34d61487075: Download complete I1017 18:51:08.231] 89c6ec31b9e9: Verifying Checksum I1017 18:51:08.231] 89c6ec31b9e9: Download complete I1017 18:51:08.438] b0e29f6c7f0a: Verifying Checksum I1017 18:51:08.439] b0e29f6c7f0a: Download complete I1017 18:51:09.218] e37857ebcafa: Verifying Checksum I1017 18:51:09.218] e37857ebcafa: Download complete I1017 18:51:11.147] 092586df9206: Pull complete I1017 18:51:12.011] ef599477fae0: Pull complete I1017 18:51:12.471] 4530c6472b5d: Pull complete I1017 18:51:16.568] d34d61487075: Pull complete I1017 18:51:33.227] 89c6ec31b9e9: Pull complete I1017 18:51:49.398] e37857ebcafa: Pull complete I1017 18:51:51.634] b0e29f6c7f0a: Pull complete I1017 18:51:51.656] Digest: sha256:76b52857546f070cc3ac499accb27b8c411b10ff6d45c0b1da2a8aab7b61fe29 I1017 18:51:51.674] Status: Downloaded newer image for golang:1.12.9-stretch I1017 18:51:51.675] ---> 2c4a601e5da9 I1017 18:51:51.675] Step 2/7 : WORKDIR /go/src/k8s.io/cloud-provider-azure I1017 18:51:51.963] ---> Running in 25b605bb7d43 I1017 18:51:54.589] Removing intermediate container 25b605bb7d43 I1017 18:51:54.589] ---> dfbadf3b831d I1017 18:51:54.590] Step 3/7 : COPY . . I1017 18:52:26.490] ---> fc84709578c0 I1017 18:52:26.490] Step 4/7 : RUN make I1017 18:52:28.073] ---> Running in 62bad0936195 I1017 18:52:35.055] hack/pkg-config.sh > .pkg_config I1017 18:52:35.085] go build -o bin/azure-cloud-controller-manager -ldflags '-s -w -X k8s.io/cloud-provider-azure/pkg/version.gitVersion=v0.3.0-11-gfe3b13bf4 -X k8s.io/cloud-provider-azure/pkg/version.gitCommit=fe3b13bf4e70c53da8e014490b97daeec1950fe1 -X k8s.io/cloud-provider-azure/pkg/version.buildDate=2019-10-17T18:52:35Z' ./cmd/cloud-controller-manager I1017 18:53:23.437] go build -o bin/azure-cloud-node-manager -ldflags '-s -w -X k8s.io/cloud-provider-azure/pkg/version.gitVersion=v0.3.0-11-gfe3b13bf4 -X k8s.io/cloud-provider-azure/pkg/version.gitCommit=fe3b13bf4e70c53da8e014490b97daeec1950fe1 -X k8s.io/cloud-provider-azure/pkg/version.buildDate=2019-10-17T18:52:35Z' ./cmd/cloud-node-manager I1017 18:53:49.254] Removing intermediate container 62bad0936195 I1017 18:53:49.255] ---> 3199e9afc661 I1017 18:53:49.255] Step 5/7 : FROM k8s.gcr.io/debian-base:v1.0.0 I1017 18:53:54.564] v1.0.0: Pulling from debian-base I1017 18:53:54.729] Digest: sha256:3801f944c765dc1b54900826ca67b1380bb8c73b9caf4a2a27ce613b3ba3e742 I1017 18:53:54.768] Status: Downloaded newer image for k8s.gcr.io/debian-base:v1.0.0 I1017 18:53:54.769] ---> 204e96332c91 I1017 18:53:54.769] Step 6/7 : COPY --from=build /go/src/k8s.io/cloud-provider-azure/bin/azure-cloud-controller-manager /usr/local/bin I1017 18:53:56.648] ---> d234e1bcde62 I1017 18:53:56.649] Step 7/7 : RUN ln -s /usr/local/bin/azure-cloud-controller-manager /usr/local/bin/cloud-controller-manager I1017 18:53:56.826] ---> Running in 65ce60afc0df I1017 18:53:59.098] Removing intermediate container 65ce60afc0df I1017 18:53:59.099] ---> c9b5ba9d25ff I1017 18:53:59.198] Successfully built c9b5ba9d25ff I1017 18:53:59.666] Successfully tagged k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184899302372151296-0d98f38b W1017 18:53:59.766] 2019/10/17 18:53:59 process.go:155: Step 'docker build -t k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184899302372151296-0d98f38b .' finished in 3m0.970449081s W1017 18:53:59.767] 2019/10/17 18:53:59 process.go:153: Running: docker push k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184899302372151296-0d98f38b W1017 18:54:05.063] 2019/10/17 18:54:05 process.go:155: Step 'docker push k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184899302372151296-0d98f38b' finished in 5.394286395s W1017 18:54:05.064] 2019/10/17 18:54:05 azure.go:686: Docker logout. W1017 18:54:05.146] 2019/10/17 18:54:05 azure.go:716: Custom cloud controller manager URL: k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184899302372151296-0d98f38b . W1017 18:54:05.147] 2019/10/17 18:54:05 azure.go:654: CWD /go/src/k8s.io/kubernetes W1017 18:54:05.147] 2019/10/17 18:54:05 azure.go:673: Attempting Docker login with azure cred. W1017 18:54:06.037] 2019/10/17 18:54:06 azure.go:682: Docker login success. W1017 18:54:06.037] 2019/10/17 18:54:06 azure.go:726: Building hyperkube. W1017 18:54:06.038] 2019/10/17 18:54:06 process.go:153: Running: make -C /go/src/k8s.io/kubernetes WHAT=cmd/hyperkube W1017 18:57:29.085] 2019/10/17 18:57:29 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes WHAT=cmd/hyperkube' finished in 3m23.048378516s W1017 18:57:29.086] 2019/10/17 18:57:29 azure.go:733: Pushing hyperkube. W1017 18:57:29.086] 2019/10/17 18:57:29 process.go:153: Running: make -C /go/src/k8s.io/kubernetes/cluster/images/hyperkube push HYPERKUBE_BIN=/go/src/k8s.io/kubernetes/_output/bin/hyperkube I1017 18:57:29.186] make: Entering directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube' I1017 18:57:29.187] cp -r ./* /tmp/hyperkube9r6w7z I1017 18:57:29.187] cp /go/src/k8s.io/kubernetes/_output/bin/hyperkube /tmp/hyperkube9r6w7z I1017 18:57:29.285] chmod a+rx /tmp/hyperkube9r6w7z/hyperkube I1017 18:57:29.286] cd /tmp/hyperkube9r6w7z && sed -i.back "s|BASEIMAGE|k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1|g" Dockerfile I1017 18:57:29.288] docker build --pull -t k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184899302372151296-7df42974 /tmp/hyperkube9r6w7z I1017 18:57:30.556] Sending build context to Docker daemon 212.1MB I1017 18:57:30.582] Step 1/2 : FROM k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1 I1017 18:57:30.870] 0.12.1: Pulling from debian-hyperkube-base-amd64 I1017 18:57:30.871] Digest: sha256:5d4ea2fb5fbe9a9a9da74f67cf2faefc881968bc39f2ac5d62d9167e575812a1 I1017 18:57:30.871] Status: Image is up to date for k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1 I1017 18:57:30.871] ---> a46476511725 I1017 18:57:30.872] Step 2/2 : COPY hyperkube /hyperkube I1017 18:58:08.119] ---> e7e8cd4843da I1017 18:58:08.146] Successfully built e7e8cd4843da I1017 18:58:08.211] Successfully tagged k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184899302372151296-7df42974 I1017 18:58:08.213] rm -rf "/tmp/hyperkube9r6w7z" I1017 18:58:08.241] docker push k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184899302372151296-7df42974 I1017 18:58:08.304] The push refers to repository [k8sprowinternal.azurecr.io/hyperkube-amd64] I1017 18:58:08.315] 3dfec3e0be76: Preparing I1017 18:58:08.316] 39b3ac6d96e9: Preparing I1017 18:58:08.316] 7bbae4dddb88: Preparing I1017 18:58:08.316] a00defcfe869: Preparing I1017 18:58:08.316] 2ab0ae805c74: Preparing I1017 18:58:08.316] 43a8fe7d2382: Preparing I1017 18:58:08.316] 3f6a6f542637: Preparing I1017 18:58:08.317] 5ba3be777c2d: Preparing I1017 18:58:08.317] 43a8fe7d2382: Waiting I1017 18:58:08.317] 3f6a6f542637: Waiting I1017 18:58:08.317] 5ba3be777c2d: Waiting I1017 18:58:08.525] a00defcfe869: Layer already exists I1017 18:58:08.548] 2ab0ae805c74: Layer already exists I1017 18:58:08.582] 7bbae4dddb88: Layer already exists I1017 18:58:08.594] 39b3ac6d96e9: Layer already exists I1017 18:58:08.631] 43a8fe7d2382: Layer already exists I1017 18:58:08.669] 5ba3be777c2d: Layer already exists I1017 18:58:08.690] 3f6a6f542637: Layer already exists I1017 18:58:20.566] 3dfec3e0be76: Pushed I1017 18:58:21.322] azure-e2e-1184899302372151296-7df42974: digest: sha256:d905b41d6eac67b5d6380cc8ebfa9b6ad9480194d88443f54427d4c2b996c38c size: 1998 I1017 18:58:21.348] docker rmi k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1184899302372151296-7df42974 2>/dev/null || true I1017 18:58:21.398] docker tag k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184899302372151296-7df42974 k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1184899302372151296-7df42974 I1017 18:58:21.469] docker push k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1184899302372151296-7df42974 I1017 18:58:21.536] The push refers to repository [k8sprowinternal.azurecr.io/hyperkube] I1017 18:58:21.548] 3dfec3e0be76: Preparing I1017 18:58:21.548] 39b3ac6d96e9: Preparing I1017 18:58:21.548] 7bbae4dddb88: Preparing I1017 18:58:21.549] a00defcfe869: Preparing I1017 18:58:21.549] 2ab0ae805c74: Preparing I1017 18:58:21.551] 43a8fe7d2382: Preparing I1017 18:58:21.551] 3f6a6f542637: Preparing I1017 18:58:21.552] 5ba3be777c2d: Preparing I1017 18:58:21.552] 3f6a6f542637: Waiting I1017 18:58:21.552] 5ba3be777c2d: Waiting I1017 18:58:21.552] 43a8fe7d2382: Waiting I1017 18:58:21.643] 39b3ac6d96e9: Layer already exists I1017 18:58:21.666] 2ab0ae805c74: Layer already exists I1017 18:58:21.726] 3dfec3e0be76: Mounted from hyperkube-amd64 I1017 18:58:21.749] 7bbae4dddb88: Layer already exists I1017 18:58:21.778] a00defcfe869: Layer already exists I1017 18:58:21.800] 43a8fe7d2382: Layer already exists I1017 18:58:21.834] 3f6a6f542637: Layer already exists I1017 18:58:21.856] 5ba3be777c2d: Layer already exists I1017 18:58:22.474] azure-e2e-1184899302372151296-7df42974: digest: sha256:d905b41d6eac67b5d6380cc8ebfa9b6ad9480194d88443f54427d4c2b996c38c size: 1998 I1017 18:58:22.507] make: Leaving directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube' W1017 18:58:22.608] 2019/10/17 18:58:22 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes/cluster/images/hyperkube push HYPERKUBE_BIN=/go/src/k8s.io/kubernetes/_output/bin/hyperkube' finished in 53.42198914s W1017 18:58:22.608] 2019/10/17 18:58:22 azure.go:686: Docker logout. W1017 18:58:22.608] 2019/10/17 18:58:22 azure.go:744: Custom hyperkube URL: k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184899302372151296-7df42974 . W1017 18:58:22.609] 2019/10/17 18:58:22 azure.go:787: downloading /workspace/aks635624614/kubernetes.json from https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json. W1017 18:58:22.609] 2019/10/17 18:58:22 util.go:42: curl https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json W1017 18:58:22.853] 2019/10/17 18:58:22 azure.go:529: downloading /workspace/aks-engine.tar.gz from https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz. W1017 18:58:22.853] 2019/10/17 18:58:22 util.go:42: curl https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz W1017 18:58:24.075] 2019/10/17 18:58:24 azure.go:556: Extracting tar file /workspace/aks-engine.tar.gz into directory /go/src/k8s.io/kubernetes . W1017 18:58:24.075] 2019/10/17 18:58:24 process.go:153: Running: tar -xzf /workspace/aks-engine.tar.gz --strip 1 W1017 18:58:24.252] 2019/10/17 18:58:24 process.go:155: Step 'tar -xzf /workspace/aks-engine.tar.gz --strip 1' finished in 176.754663ms W1017 18:58:24.252] 2019/10/17 18:58:24 process.go:153: Running: /go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks635624614/kubernetes.json --output-directory /workspace/aks635624614 I1017 18:58:24.468] INFO[0000] Generating assets into /workspace/aks635624614... W1017 18:58:40.395] 2019/10/17 18:58:40 process.go:155: Step '/go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks635624614/kubernetes.json --output-directory /workspace/aks635624614' finished in 16.142649515s W1017 18:58:40.399] 2019/10/17 18:58:40 azure.go:627: Setting kubeconfig env variable: kubeconfig path: /workspace/aks635624614/kubeconfig/kubeconfig.eastus2.json. W1017 18:58:40.399] 2019/10/17 18:58:40 azure.go:629: Creating resource group: kubetest-42f4e1d0-f10c-11e9-add7-02422c563efc. W1017 18:58:40.399] 2019/10/17 18:58:40 azure.go:631: Creating Azure resource group: kubetest-42f4e1d0-f10c-11e9-add7-02422c563efc for cluster deployment. W1017 18:58:42.416] 2019/10/17 18:58:42 azure.go:636: Validating deployment ARM templates. W1017 18:58:44.855] 2019/10/17 18:58:44 azure.go:642: Deploying cluster kubetest-42f4e1d0-f10c-11e9-add7-02422c563efc in resource group kubetest-42f4e1d0-f10c-11e9-add7-02422c563efc. W1017 19:09:55.128] 2019/10/17 19:09:55 process.go:153: Running: ./cluster/kubectl.sh --match-server-version=false version W1017 19:09:55.828] 2019/10/17 19:09:55 process.go:155: Step './cluster/kubectl.sh --match-server-version=false version' finished in 699.475125ms W1017 19:09:55.828] 2019/10/17 19:09:55 process.go:153: Running: ./cluster/kubectl.sh --match-server-version=false get nodes -oyaml W1017 19:09:57.360] 2019/10/17 19:09:57 process.go:155: Step './cluster/kubectl.sh --match-server-version=false get nodes -oyaml' finished in 1.532009581s W1017 19:09:57.363] 2019/10/17 19:09:57 azure.go:963: KUBE_TEST_REPO_LIST_DOWNLOAD_LOCATION not set. Using default test image repos. W1017 19:09:57.363] 2019/10/17 19:09:57 azure.go:963: KUBE_TEST_REPO_LIST_DOWNLOAD_LOCATION not set. Using default test image repos. W1017 19:09:57.367] 2019/10/17 19:09:57 process.go:153: Running: kubectl get nodes --no-headers W1017 19:09:58.247] 2019/10/17 19:09:58 process.go:155: Step 'kubectl get nodes --no-headers' finished in 880.106725ms W1017 19:09:58.247] 2019/10/17 19:09:58 e2e.go:462: Cluster nodes: W1017 19:09:58.248] k8s-agentpool1-33511100-0 Ready 46s v1.16.3-beta.0.11+0d9472c2ffccc1 W1017 19:09:58.248] k8s-master-33511100-0 Ready 47s v1.16.3-beta.0.11+0d9472c2ffccc1 W1017 19:09:58.248] 2019/10/17 19:09:58 process.go:153: Running: ./cluster/kubectl.sh --match-server-version=false version W1017 19:09:58.681] 2019/10/17 19:09:58 process.go:155: Step './cluster/kubectl.sh --match-server-version=false version' finished in 433.742064ms W1017 19:09:58.681] 2019/10/17 19:09:58 azure.go:916: Attempting to dump control-plane and node component logs to /workspace/_artifacts W1017 19:09:58.681] 2019/10/17 19:09:58 process.go:153: Running: ./hack/log-dump.sh /workspace/_artifacts W1017 19:09:58.682] 2019/10/17 19:09:58 process.go:155: Step './hack/log-dump.sh /workspace/_artifacts' finished in 712.905µs W1017 19:09:58.682] 2019/10/17 19:09:58 azure.go:906: Deleting resource group: kubetest-42f4e1d0-f10c-11e9-add7-02422c563efc. W1017 19:21:23.226] 2019/10/17 19:21:23 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml. W1017 19:21:23.227] 2019/10/17 19:21:23 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}" W1017 19:21:23.821] 2019/10/17 19:21:23 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 594.001213ms W1017 19:21:23.821] 2019/10/17 19:21:23 main.go:319: Something went wrong: encountered 1 errors: [error starting ./hack/log-dump.sh /workspace/_artifacts: fork/exec ./hack/log-dump.sh: exec format error] W1017 19:21:23.823] Traceback (most recent call last): W1017 19:21:23.823] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in W1017 19:21:23.823] main(parse_args()) W1017 19:21:23.823] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main W1017 19:21:23.824] mode.start(runner_args) W1017 19:21:23.824] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start W1017 19:21:23.824] check_env(env, self.command, *args) W1017 19:21:23.824] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env W1017 19:21:23.824] subprocess.check_call(cmd, env=env) W1017 19:21:23.824] File "/usr/lib/python2.7/subprocess.py", line 186, in check_call W1017 19:21:23.824] raise CalledProcessError(retcode, cmd) W1017 19:21:23.825] subprocess.CalledProcessError: Command '('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=quick', '--up', '--down', '--test', '--deployment=acsengine', '--provider=skeleton', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--ginkgo-parallel=30', '--test-ccm=True', '--acsengine-agentpoolcount=1', '--acsengine-admin-username=azureuser', '--acsengine-creds=/etc/azure-cred/credentials', '--acsengine-orchestratorRelease=1.16', '--acsengine-mastervmsize=Standard_DS2_v2', '--acsengine-agentvmsize=Standard_D4s_v3', '--acsengine-hyperkube=True', '--acsengine-ccm=True', '--acsengine-location=eastus2', '--acsengine-public-key=/etc/ssh-key-secret/ssh-public', '--acsengine-template-url=https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json', '--acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz', '--timeout=420m')' returned non-zero exit status 1 E1017 19:21:23.830] Command failed I1017 19:21:23.830] process 687 exited with code 1 after 50.4m E1017 19:21:23.830] FAIL: chewong-e2e-ccm I1017 19:21:23.830] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1017 19:21:24.411] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1017 19:21:24.442] process 18021 exited with code 0 after 0.0m I1017 19:21:24.442] Call: gcloud config get-value account I1017 19:21:24.685] process 18033 exited with code 0 after 0.0m I1017 19:21:24.685] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1017 19:21:24.685] Upload result and artifacts... I1017 19:21:24.685] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184899302372151296 I1017 19:21:24.686] Call: gsutil ls gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184899302372151296/artifacts W1017 19:21:25.710] CommandException: One or more URLs matched no objects. E1017 19:21:25.786] Command failed I1017 19:21:25.787] process 18045 exited with code 1 after 0.0m W1017 19:21:25.787] Remote dir gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184899302372151296/artifacts not exist yet I1017 19:21:25.787] Call: gsutil -m -q -o GSUtil:use_magicfile=True cp -r -c -z log,txt,xml /workspace/_artifacts gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184899302372151296/artifacts I1017 19:21:27.397] process 18187 exited with code 0 after 0.0m I1017 19:21:27.398] Call: git rev-parse HEAD I1017 19:21:27.400] process 18714 exited with code 0 after 0.0m I1017 19:21:27.400] Call: git rev-parse HEAD I1017 19:21:27.403] process 18715 exited with code 0 after 0.0m I1017 19:21:27.404] Call: gsutil stat gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json I1017 19:21:28.362] process 18716 exited with code 0 after 0.0m I1017 19:21:28.363] Call: gsutil -q cat 'gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json#1571339714229582' I1017 19:21:29.567] process 18858 exited with code 0 after 0.0m I1017 19:21:29.568] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1571339714229582 cp /tmp/gsutil_s4IVPo gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json I1017 19:21:30.881] process 19002 exited with code 0 after 0.0m I1017 19:21:30.881] Call: gsutil stat gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json I1017 19:21:31.841] process 19180 exited with code 0 after 0.0m I1017 19:21:31.841] Call: gsutil -q cat 'gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json#1571339717791920' I1017 19:21:33.045] process 19322 exited with code 0 after 0.0m I1017 19:21:33.046] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1571339717791920 cp /tmp/gsutil_fDh1i6 gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json I1017 19:21:34.348] process 19466 exited with code 0 after 0.0m I1017 19:21:34.348] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil_uH_8vp gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184899302372151296/finished.json I1017 19:21:35.768] process 19644 exited with code 0 after 0.0m I1017 19:21:35.769] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_svO8hl gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/latest-build.txt I1017 19:21:37.054] process 19822 exited with code 0 after 0.0m I1017 19:21:37.054] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_UeFOrz gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/latest-build.txt I1017 19:21:38.330] process 20000 exited with code 0 after 0.0m