W1017 18:34:02.690] ************************************************************************** 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:34:02.691] 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:34:02.691] Bootstrap chewong-e2e-ccm... I1017 18:34:02.694] Builder: 9ce62807-f10c-11e9-918b-16773c0c7aed I1017 18:34:02.694] Image: chewong/kubekins-e2e:v20191017-test-2 I1017 18:34:02.695] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184900309072220160 I1017 18:34:02.695] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1017 18:34:03.323] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1017 18:34:03.353] process 215 exited with code 0 after 0.0m I1017 18:34:03.353] Call: gcloud config get-value account I1017 18:34:03.594] process 227 exited with code 0 after 0.0m I1017 18:34:03.595] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1017 18:34:03.595] Root: /go/src I1017 18:34:03.595] cd to /go/src I1017 18:34:03.595] Checkout: /go/src/k8s.io/kubernetes release-1.16 to /go/src/k8s.io/kubernetes I1017 18:34:03.595] Call: git init k8s.io/kubernetes I1017 18:34:03.599] Initialized empty Git repository in /go/src/k8s.io/kubernetes/.git/ I1017 18:34:03.599] process 239 exited with code 0 after 0.0m I1017 18:34:03.599] Call: git config --local user.name 'K8S Bootstrap' I1017 18:34:03.602] process 240 exited with code 0 after 0.0m I1017 18:34:03.602] Call: git config --local user.email k8s_bootstrap@localhost I1017 18:34:03.604] process 241 exited with code 0 after 0.0m I1017 18:34:03.604] Call: git fetch --quiet --tags https://github.com/kubernetes/kubernetes release-1.16 I1017 18:34:57.612] process 242 exited with code 0 after 0.9m I1017 18:34:57.613] Call: git checkout -B test FETCH_HEAD W1017 18:34:59.858] Switched to a new branch 'test' I1017 18:34:59.866] process 254 exited with code 0 after 0.0m I1017 18:34:59.866] Call: git show -s --format=format:%ct HEAD I1017 18:34:59.870] process 255 exited with code 0 after 0.0m I1017 18:34:59.870] Checkout: /go/src/k8s.io/cloud-provider-azure master:c470e6f36d76e5a565478fcba22118c06bc1548f,248:84546d4184c381a062c9b0a29a987390dc47f2ce to /go/src/k8s.io/cloud-provider-azure I1017 18:34:59.870] Call: git init k8s.io/cloud-provider-azure I1017 18:34:59.874] Initialized empty Git repository in /go/src/k8s.io/cloud-provider-azure/.git/ I1017 18:34:59.874] process 256 exited with code 0 after 0.0m I1017 18:34:59.875] Call: git config --local user.name 'K8S Bootstrap' I1017 18:34:59.877] process 257 exited with code 0 after 0.0m I1017 18:34:59.877] Call: git config --local user.email k8s_bootstrap@localhost I1017 18:34:59.880] process 258 exited with code 0 after 0.0m I1017 18:34:59.880] Call: git fetch --quiet --tags https://github.com/kubernetes/cloud-provider-azure master +refs/pull/248/head:refs/pr/248 I1017 18:35:01.410] process 259 exited with code 0 after 0.0m I1017 18:35:01.410] Call: git checkout -B test c470e6f36d76e5a565478fcba22118c06bc1548f W1017 18:35:01.886] Switched to a new branch 'test' I1017 18:35:01.889] process 271 exited with code 0 after 0.0m I1017 18:35:01.889] Call: git show -s --format=format:%ct HEAD I1017 18:35:01.892] process 272 exited with code 0 after 0.0m I1017 18:35:01.893] Call: git merge --no-ff -m 'Merge +refs/pull/248/head:refs/pr/248' 84546d4184c381a062c9b0a29a987390dc47f2ce I1017 18:35:02.260] Merge made by the 'recursive' strategy. I1017 18:35:02.262] hack/log-dump.sh | 171 +++++++++++++++++++++++++++++++++++++++++++++++++++++++ I1017 18:35:02.263] 1 file changed, 171 insertions(+) I1017 18:35:02.263] create mode 100755 hack/log-dump.sh I1017 18:35:02.263] process 273 exited with code 0 after 0.0m I1017 18:35:02.263] Configure environment... I1017 18:35:02.263] Call: git show -s --format=format:%ct HEAD I1017 18:35:02.267] process 275 exited with code 0 after 0.0m I1017 18:35:02.267] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1017 18:35:02.994] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1017 18:35:03.119] process 276 exited with code 0 after 0.0m I1017 18:35:03.119] Call: gcloud config get-value account I1017 18:35:03.374] process 288 exited with code 0 after 0.0m I1017 18:35:03.375] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1017 18:35:03.375] 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:35:03.857] process 300 exited with code 0 after 0.0m I1017 18:35:03.858] Start 1184900309072220160 at v1.16.3-beta.0.11+0d9472c2ffccc1... I1017 18:35:03.860] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil_RsVBSc gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184900309072220160/started.json I1017 18:35:05.423] process 333 exited with code 0 after 0.0m I1017 18:35:05.424] 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/1184900309072220160' cp /tmp/gsutil_8phIBf gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/1184900309072220160.txt I1017 18:35:06.821] process 511 exited with code 0 after 0.0m I1017 18:35:06.823] 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:35:06.872] starts with local mode W1017 18:35:06.873] Environment: W1017 18:35:06.873] ARTIFACTS=/workspace/_artifacts W1017 18:35:06.873] AWS_SSH_PRIVATE_KEY_FILE=/root/.ssh/kube_aws_rsa W1017 18:35:06.874] AWS_SSH_PUBLIC_KEY_FILE=/root/.ssh/kube_aws_rsa.pub W1017 18:35:06.874] AZURE_CREDENTIALS=/etc/azure-cred/credentials W1017 18:35:06.874] AZURE_SSH_PRIVATE_KEY_FILE=/etc/ssh-key-secret/ssh-private W1017 18:35:06.874] AZURE_SSH_PUBLIC_KEY_FILE=/etc/ssh-key-secret/ssh-public W1017 18:35:06.874] AZURE_SSH_USER=azureuser W1017 18:35:06.875] AZ_STORAGE_CONTAINER_NAME=mystoragecontainer W1017 18:35:06.875] BAZEL_REMOTE_CACHE_ENABLED=false W1017 18:35:06.875] BAZEL_VERSION=0.23.2 W1017 18:35:06.875] BOOTSTRAP_MIGRATION=yes W1017 18:35:06.875] BUILD_ID=1184900309072220160 W1017 18:35:06.876] BUILD_NUMBER=1184900309072220160 W1017 18:35:06.876] CLOUDSDK_COMPONENT_MANAGER_DISABLE_UPDATE_CHECK=true W1017 18:35:06.876] CLOUDSDK_CONFIG=/go/src/k8s.io/kubernetes/.config/gcloud W1017 18:35:06.876] CLOUDSDK_CORE_DISABLE_PROMPTS=1 W1017 18:35:06.877] CLOUDSDK_EXPERIMENTAL_FAST_COMPONENT_UPDATE=false W1017 18:35:06.877] CLOUD_CONFIG=random W1017 18:35:06.877] DECK_PORT=tcp://10.0.160.83:80 W1017 18:35:06.877] DECK_PORT_80_TCP=tcp://10.0.160.83:80 W1017 18:35:06.878] DECK_PORT_80_TCP_ADDR=10.0.160.83 W1017 18:35:06.878] DECK_PORT_80_TCP_PORT=80 W1017 18:35:06.878] DECK_PORT_80_TCP_PROTO=tcp W1017 18:35:06.878] DECK_SERVICE_HOST=10.0.160.83 W1017 18:35:06.878] DECK_SERVICE_PORT=80 W1017 18:35:06.879] DOCKER_IN_DOCKER_ENABLED=true W1017 18:35:06.879] DOCKER_IN_DOCKER_IPV6_ENABLED=false W1017 18:35:06.879] GCS_ARTIFACTS_DIR=gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184900309072220160/artifacts W1017 18:35:06.879] GOOGLE_APPLICATION_CREDENTIALS=/etc/service-account/service-account.json W1017 18:35:06.879] GOPATH=/go W1017 18:35:06.879] GO_TARBALL=go1.12.10.linux-amd64.tar.gz W1017 18:35:06.880] HOME=/workspace W1017 18:35:06.880] HOOK_PORT=tcp://10.0.144.133:8888 W1017 18:35:06.880] HOOK_PORT_8888_TCP=tcp://10.0.144.133:8888 W1017 18:35:06.880] HOOK_PORT_8888_TCP_ADDR=10.0.144.133 W1017 18:35:06.880] HOOK_PORT_8888_TCP_PORT=8888 W1017 18:35:06.880] HOOK_PORT_8888_TCP_PROTO=tcp W1017 18:35:06.880] HOOK_SERVICE_HOST=10.0.144.133 W1017 18:35:06.881] HOOK_SERVICE_PORT=8888 W1017 18:35:06.881] HOSTNAME=9ce62807-f10c-11e9-918b-16773c0c7aed W1017 18:35:06.881] IMAGE=chewong/kubekins-e2e:v20191017-test-2 W1017 18:35:06.881] INSTANCE_PREFIX=bootstrap-e2e W1017 18:35:06.881] JENKINS_GCE_SSH_PRIVATE_KEY_FILE=/etc/ssh-key-secret/ssh-private W1017 18:35:06.881] JENKINS_GCE_SSH_PUBLIC_KEY_FILE=/etc/ssh-key-secret/ssh-public W1017 18:35:06.881] JOB_NAME=chewong-e2e-ccm W1017 18:35:06.882] JOB_SPEC={"type":"presubmit","job":"chewong-e2e-ccm","buildid":"1184900309072220160","prowjobid":"9ce62807-f10c-11e9-918b-16773c0c7aed","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:35:06.882] JOB_TYPE=presubmit W1017 18:35:06.882] KUBERNETES_PORT=tcp://10.0.0.1:443 W1017 18:35:06.882] KUBERNETES_PORT_443_TCP=tcp://10.0.0.1:443 W1017 18:35:06.883] KUBERNETES_PORT_443_TCP_ADDR=10.0.0.1 W1017 18:35:06.883] KUBERNETES_PORT_443_TCP_PORT=443 W1017 18:35:06.883] KUBERNETES_PORT_443_TCP_PROTO=tcp W1017 18:35:06.883] KUBERNETES_SERVICE_HOST=10.0.0.1 W1017 18:35:06.883] KUBERNETES_SERVICE_PORT=443 W1017 18:35:06.883] KUBERNETES_SERVICE_PORT_HTTPS=443 W1017 18:35:06.883] KUBETEST_IN_DOCKER=true W1017 18:35:06.883] KUBETEST_MANUAL_DUMP=y W1017 18:35:06.884] KUBE_AWS_INSTANCE_PREFIX=bootstrap-e2e W1017 18:35:06.884] KUBE_GCE_INSTANCE_PREFIX=bootstrap-e2e W1017 18:35:06.884] KUBE_VERBOSE=0 W1017 18:35:06.884] NODE_NAME=9ce62807-f10c-11e9-918b-16773c0c7aed W1017 18:35:06.884] 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:35:06.884] PROW_JOB_ID=9ce62807-f10c-11e9-918b-16773c0c7aed W1017 18:35:06.885] PULL_BASE_REF=master W1017 18:35:06.885] PULL_BASE_SHA=37fca51d74a81df3b6c8b6df5b644e333acd7274 W1017 18:35:06.885] PULL_NUMBER=113 W1017 18:35:06.885] PULL_PULL_SHA=879465972041635fd7bc8269da49153b67e63822 W1017 18:35:06.885] PULL_REFS=master:37fca51d74a81df3b6c8b6df5b644e333acd7274,113:879465972041635fd7bc8269da49153b67e63822 W1017 18:35:06.885] PWD=/workspace W1017 18:35:06.885] REGISTRY=k8sprowinternal.azurecr.io W1017 18:35:06.886] REPO_NAME=kubernetes W1017 18:35:06.886] REPO_OWNER=Azure W1017 18:35:06.886] SHLVL=2 W1017 18:35:06.886] SOURCE_DATE_EPOCH=1571316399 W1017 18:35:06.886] TERM=xterm W1017 18:35:06.886] TIDE_PORT=tcp://10.0.180.53:80 W1017 18:35:06.886] TIDE_PORT_80_TCP=tcp://10.0.180.53:80 W1017 18:35:06.887] TIDE_PORT_80_TCP_ADDR=10.0.180.53 W1017 18:35:06.887] TIDE_PORT_80_TCP_PORT=80 W1017 18:35:06.887] TIDE_PORT_80_TCP_PROTO=tcp W1017 18:35:06.887] TIDE_SERVICE_HOST=10.0.180.53 W1017 18:35:06.887] TIDE_SERVICE_PORT=80 W1017 18:35:06.887] USER=prow W1017 18:35:06.888] WORKSPACE=/workspace W1017 18:35:06.888] _=./test-infra/jenkins/bootstrap.py W1017 18:35:06.888] 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:35:06.897] 2019/10/17 18:35:06 main.go:332: Limiting testing to 7h0m0s W1017 18:35:06.897] 2019/10/17 18:35:06 azure.go:232: Reading credentials file /etc/azure-cred/credentials W1017 18:35:06.897] 2019/10/17 18:35:06 process.go:153: Running: make -C /go/src/k8s.io/kubernetes quick-release I1017 18:35:06.998] make: Entering directory '/go/src/k8s.io/kubernetes' I1017 18:35:06.998] +++ [1017 18:35:06] Verifying Prerequisites.... I1017 18:35:07.251] +++ [1017 18:35:07] Building Docker image kube-build:build-c695761210-5-v1.12.10-1 I1017 18:39:58.995] +++ [1017 18:39:58] Creating data container kube-build-data-c695761210-5-v1.12.10-1 I1017 18:40:49.471] +++ [1017 18:40:49] Syncing sources to container I1017 18:41:00.134] +++ [1017 18:41:00] Running build command... I1017 18:41:19.159] +++ [1017 18:41:19] Building go targets for linux/amd64: I1017 18:41:19.159] ./vendor/k8s.io/code-generator/cmd/deepcopy-gen I1017 18:41:27.565] +++ [1017 18:41:27] Building go targets for linux/amd64: I1017 18:41:27.566] ./vendor/k8s.io/code-generator/cmd/defaulter-gen I1017 18:41:34.640] +++ [1017 18:41:34] Building go targets for linux/amd64: I1017 18:41:34.640] ./vendor/k8s.io/code-generator/cmd/conversion-gen I1017 18:41:47.154] +++ [1017 18:41:47] Building go targets for linux/amd64: I1017 18:41:47.155] ./vendor/k8s.io/kube-openapi/cmd/openapi-gen I1017 18:42:04.697] +++ [1017 18:42:04] Building go targets for linux/amd64: I1017 18:42:04.697] ./vendor/github.com/go-bindata/go-bindata/go-bindata I1017 18:42:07.532] +++ [1017 18:42:07] Building go targets for linux/amd64: I1017 18:42:07.532] cmd/kube-proxy I1017 18:42:07.532] cmd/kube-apiserver I1017 18:42:07.532] cmd/kube-controller-manager I1017 18:42:07.532] cmd/kubelet I1017 18:42:07.533] cmd/kubeadm I1017 18:42:07.533] cmd/hyperkube I1017 18:42:07.533] cmd/kube-scheduler I1017 18:42:07.533] vendor/k8s.io/apiextensions-apiserver I1017 18:42:07.533] cluster/gce/gci/mounter I1017 18:46:18.098] +++ [1017 18:46:18] Building go targets for linux/amd64: I1017 18:46:18.098] cmd/kube-proxy I1017 18:46:18.099] cmd/kubeadm I1017 18:46:18.099] cmd/kubelet I1017 18:46:31.334] +++ [1017 18:46:31] Building go targets for linux/amd64: I1017 18:46:31.334] cmd/kubectl I1017 18:46:49.419] +++ [1017 18:46:49] Building go targets for linux/amd64: I1017 18:46:49.420] cmd/gendocs I1017 18:46:49.420] cmd/genkubedocs I1017 18:46:49.420] cmd/genman I1017 18:46:49.420] cmd/genyaml I1017 18:46:49.420] cmd/genswaggertypedocs I1017 18:46:49.421] cmd/linkcheck I1017 18:46:49.421] vendor/github.com/onsi/ginkgo/ginkgo I1017 18:46:49.421] test/e2e/e2e.test I1017 18:46:49.422] cluster/images/conformance/go-runner I1017 18:49:17.700] +++ [1017 18:49:17] Building go targets for linux/amd64: I1017 18:49:17.700] cmd/kubemark I1017 18:49:17.700] vendor/github.com/onsi/ginkgo/ginkgo I1017 18:49:17.700] test/e2e_node/e2e_node.test I1017 18:50:53.699] +++ [1017 18:50:53] Syncing out of container I1017 18:51:51.795] +++ [1017 18:51:51] Building tarball: src I1017 18:51:51.796] +++ [1017 18:51:51] Starting tarball: client linux-amd64 I1017 18:51:51.796] +++ [1017 18:51:51] Building tarball: manifests I1017 18:51:51.798] +++ [1017 18:51:51] Waiting on tarballs I1017 18:51:59.698] +++ [1017 18:51:59] Building tarball: node linux-amd64 I1017 18:51:59.699] +++ [1017 18:51:59] Building images: linux-amd64 I1017 18:52:00.355] +++ [1017 18:52:00] Starting docker build for image: kube-apiserver-amd64 I1017 18:52:00.357] +++ [1017 18:52:00] Starting docker build for image: kube-controller-manager-amd64 I1017 18:52:00.360] +++ [1017 18:52:00] Starting docker build for image: kube-scheduler-amd64 I1017 18:52:00.363] +++ [1017 18:52:00] Starting docker build for image: kube-proxy-amd64 I1017 18:52:00.366] +++ [1017 18:52:00] Building conformance image for arch: amd64 I1017 18:52:00.367] +++ [1017 18:52:00] Building hyperkube image for arch: amd64 I1017 18:52:49.474] +++ [1017 18:52:49] Deleting docker image k8s.gcr.io/kube-scheduler-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1 I1017 18:52:50.667] +++ [1017 18:52:50] Deleting docker image k8s.gcr.io/kube-apiserver-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1 I1017 18:52:51.439] +++ [1017 18:52:51] Deleting docker image k8s.gcr.io/kube-controller-manager-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1 I1017 18:53:02.042] +++ [1017 18:53:02] Deleting docker image k8s.gcr.io/kube-proxy-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1 I1017 18:53:45.308] +++ [1017 18:53:45] Deleting hyperkube image k8s.gcr.io/hyperkube-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1 I1017 18:54:17.743] +++ [1017 18:54:17] Deleting conformance image k8s.gcr.io/conformance-amd64:v1.16.3-beta.0.11_0d9472c2ffccc1 I1017 18:54:17.968] +++ [1017 18:54:17] Docker builds done I1017 18:54:17.972] +++ [1017 18:54:17] Building tarball: server linux-amd64 I1017 18:56:04.336] +++ [1017 18:56:04] Building tarball: final I1017 18:56:04.799] +++ [1017 18:56:04] Starting tarball: test linux-amd64 I1017 18:56:04.800] +++ [1017 18:56:04] Waiting on test tarballs I1017 18:57:16.150] +++ [1017 18:57:16] Building tarball: test portable I1017 18:57:16.524] +++ [1017 18:57:16] Building tarball: test mondo (deprecated by KEP sig-testing/20190118-breaking-apart-the-kubernetes-test-tarball) I1017 18:58:11.982] make: Leaving directory '/go/src/k8s.io/kubernetes' W1017 18:58:12.082] 2019/10/17 18:58:11 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes quick-release' finished in 23m5.084349796s W1017 18:58:12.082] 2019/10/17 18:58:11 util.go:277: Flushing memory. W1017 18:58:14.777] 2019/10/17 18:58:14 azure.go:654: CWD /go/src/k8s.io/kubernetes W1017 18:58:14.777] 2019/10/17 18:58:14 azure.go:673: Attempting Docker login with azure cred. W1017 18:58:15.686] 2019/10/17 18:58:15 azure.go:682: Docker login success. W1017 18:58:15.687] 2019/10/17 18:58:15 azure.go:697: Building ccm. W1017 18:58:15.687] 2019/10/17 18:58:15 azure.go:699: projectPath /go/src/k8s.io/cloud-provider-azure W1017 18:58:15.687] 2019/10/17 18:58:15 process.go:153: Running: docker build -t k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184900309072220160-12beb027 . I1017 18:58:18.051] Sending build context to Docker daemon 67.18MB I1017 18:58:18.079] Step 1/7 : FROM golang:1.12.9-stretch AS build I1017 18:58:18.954] 1.12.9-stretch: Pulling from library/golang I1017 18:58:19.279] 092586df9206: Pulling fs layer I1017 18:58:19.279] ef599477fae0: Pulling fs layer I1017 18:58:19.279] 4530c6472b5d: Pulling fs layer I1017 18:58:19.280] d34d61487075: Pulling fs layer I1017 18:58:19.280] 89c6ec31b9e9: Pulling fs layer I1017 18:58:19.280] e37857ebcafa: Pulling fs layer I1017 18:58:19.280] b0e29f6c7f0a: Pulling fs layer I1017 18:58:19.280] d34d61487075: Waiting I1017 18:58:19.280] 89c6ec31b9e9: Waiting I1017 18:58:19.280] b0e29f6c7f0a: Waiting I1017 18:58:19.280] e37857ebcafa: Waiting I1017 18:58:19.765] 4530c6472b5d: Verifying Checksum I1017 18:58:19.765] 4530c6472b5d: Download complete I1017 18:58:19.805] ef599477fae0: Verifying Checksum I1017 18:58:19.806] ef599477fae0: Download complete I1017 18:58:20.089] 092586df9206: Verifying Checksum I1017 18:58:20.089] 092586df9206: Download complete I1017 18:58:20.618] d34d61487075: Download complete I1017 18:58:20.982] 89c6ec31b9e9: Download complete I1017 18:58:21.004] b0e29f6c7f0a: Download complete I1017 18:58:21.632] e37857ebcafa: Verifying Checksum I1017 18:58:21.632] e37857ebcafa: Download complete I1017 18:58:23.267] 092586df9206: Pull complete I1017 18:58:24.061] ef599477fae0: Pull complete I1017 18:58:24.432] 4530c6472b5d: Pull complete I1017 18:58:28.423] d34d61487075: Pull complete I1017 18:58:32.949] 89c6ec31b9e9: Pull complete I1017 18:58:41.531] e37857ebcafa: Pull complete I1017 18:58:41.683] b0e29f6c7f0a: Pull complete I1017 18:58:41.707] Digest: sha256:76b52857546f070cc3ac499accb27b8c411b10ff6d45c0b1da2a8aab7b61fe29 I1017 18:58:41.725] Status: Downloaded newer image for golang:1.12.9-stretch I1017 18:58:41.726] ---> 2c4a601e5da9 I1017 18:58:41.726] Step 2/7 : WORKDIR /go/src/k8s.io/cloud-provider-azure I1017 18:58:53.010] ---> Running in 0af20ac7b8c9 I1017 18:58:54.178] Removing intermediate container 0af20ac7b8c9 I1017 18:58:54.179] ---> b5f901c54380 I1017 18:58:54.179] Step 3/7 : COPY . . I1017 18:59:00.011] ---> b55bf40260a4 I1017 18:59:00.011] Step 4/7 : RUN make I1017 18:59:00.212] ---> Running in a39cd657182d I1017 18:59:01.063] hack/pkg-config.sh > .pkg_config I1017 18:59:01.086] 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:59:01Z' ./cmd/cloud-controller-manager I1017 18:59:43.083] 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:59:01Z' ./cmd/cloud-node-manager I1017 19:00:06.979] Removing intermediate container a39cd657182d I1017 19:00:06.980] ---> 41d926660ebe I1017 19:00:06.980] Step 5/7 : FROM k8s.gcr.io/debian-base:v1.0.0 I1017 19:00:07.284] v1.0.0: Pulling from debian-base I1017 19:00:07.453] Digest: sha256:3801f944c765dc1b54900826ca67b1380bb8c73b9caf4a2a27ce613b3ba3e742 I1017 19:00:08.679] Status: Downloaded newer image for k8s.gcr.io/debian-base:v1.0.0 I1017 19:00:08.679] ---> 204e96332c91 I1017 19:00:08.680] Step 6/7 : COPY --from=build /go/src/k8s.io/cloud-provider-azure/bin/azure-cloud-controller-manager /usr/local/bin I1017 19:00:11.437] ---> 2c92dc346bf1 I1017 19:00:11.437] Step 7/7 : RUN ln -s /usr/local/bin/azure-cloud-controller-manager /usr/local/bin/cloud-controller-manager I1017 19:00:11.579] ---> Running in 5303fc3f04c9 I1017 19:00:13.170] Removing intermediate container 5303fc3f04c9 I1017 19:00:13.171] ---> dbd78e91db48 I1017 19:00:13.276] Successfully built dbd78e91db48 I1017 19:00:14.144] Successfully tagged k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184900309072220160-12beb027 W1017 19:00:14.244] 2019/10/17 19:00:14 process.go:155: Step 'docker build -t k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184900309072220160-12beb027 .' finished in 1m58.460375157s W1017 19:00:14.245] 2019/10/17 19:00:14 process.go:153: Running: docker push k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184900309072220160-12beb027 W1017 19:00:18.499] 2019/10/17 19:00:18 process.go:155: Step 'docker push k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184900309072220160-12beb027' finished in 4.351612211s W1017 19:00:18.499] 2019/10/17 19:00:18 azure.go:686: Docker logout. W1017 19:00:18.566] 2019/10/17 19:00:18 azure.go:716: Custom cloud controller manager URL: k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184900309072220160-12beb027 . W1017 19:00:18.566] 2019/10/17 19:00:18 azure.go:654: CWD /go/src/k8s.io/kubernetes W1017 19:00:18.566] 2019/10/17 19:00:18 azure.go:673: Attempting Docker login with azure cred. W1017 19:00:19.389] 2019/10/17 19:00:19 azure.go:682: Docker login success. W1017 19:00:19.390] 2019/10/17 19:00:19 azure.go:726: Building hyperkube. W1017 19:00:19.390] 2019/10/17 19:00:19 process.go:153: Running: make -C /go/src/k8s.io/kubernetes WHAT=cmd/hyperkube W1017 19:03:10.339] 2019/10/17 19:03:10 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes WHAT=cmd/hyperkube' finished in 2m50.949545315s W1017 19:03:10.339] 2019/10/17 19:03:10 azure.go:733: Pushing hyperkube. W1017 19:03:10.339] 2019/10/17 19:03:10 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 19:03:10.440] make: Entering directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube' I1017 19:03:10.440] cp -r ./* /tmp/hyperkube2AjpC2 I1017 19:03:10.440] cp /go/src/k8s.io/kubernetes/_output/bin/hyperkube /tmp/hyperkube2AjpC2 I1017 19:03:10.522] chmod a+rx /tmp/hyperkube2AjpC2/hyperkube I1017 19:03:10.523] cd /tmp/hyperkube2AjpC2 && sed -i.back "s|BASEIMAGE|k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1|g" Dockerfile I1017 19:03:10.525] docker build --pull -t k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184900309072220160-5c87681f /tmp/hyperkube2AjpC2 I1017 19:03:11.707] Sending build context to Docker daemon 212.1MB I1017 19:03:11.735] Step 1/2 : FROM k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1 I1017 19:03:12.034] 0.12.1: Pulling from debian-hyperkube-base-amd64 I1017 19:03:12.048] Digest: sha256:5d4ea2fb5fbe9a9a9da74f67cf2faefc881968bc39f2ac5d62d9167e575812a1 I1017 19:03:12.048] Status: Image is up to date for k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1 I1017 19:03:12.048] ---> a46476511725 I1017 19:03:12.049] Step 2/2 : COPY hyperkube /hyperkube I1017 19:03:31.280] ---> c74da697b77d I1017 19:03:31.306] Successfully built c74da697b77d I1017 19:03:31.400] Successfully tagged k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184900309072220160-5c87681f I1017 19:03:31.406] rm -rf "/tmp/hyperkube2AjpC2" I1017 19:03:31.436] docker push k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184900309072220160-5c87681f I1017 19:03:31.498] The push refers to repository [k8sprowinternal.azurecr.io/hyperkube-amd64] I1017 19:03:31.541] 7ece58f8fc9f: Preparing I1017 19:03:31.541] 39b3ac6d96e9: Preparing I1017 19:03:31.542] 7bbae4dddb88: Preparing I1017 19:03:31.542] a00defcfe869: Preparing I1017 19:03:31.542] 2ab0ae805c74: Preparing I1017 19:03:31.542] 43a8fe7d2382: Preparing I1017 19:03:31.542] 3f6a6f542637: Preparing I1017 19:03:31.542] 5ba3be777c2d: Preparing I1017 19:03:31.543] 3f6a6f542637: Waiting I1017 19:03:31.543] 43a8fe7d2382: Waiting I1017 19:03:31.543] 5ba3be777c2d: Waiting I1017 19:03:31.728] a00defcfe869: Layer already exists I1017 19:03:31.755] 2ab0ae805c74: Layer already exists I1017 19:03:31.792] 39b3ac6d96e9: Layer already exists I1017 19:03:31.804] 7bbae4dddb88: Layer already exists I1017 19:03:31.839] 43a8fe7d2382: Layer already exists I1017 19:03:31.849] 3f6a6f542637: Layer already exists I1017 19:03:31.872] 5ba3be777c2d: Layer already exists I1017 19:03:41.733] 7ece58f8fc9f: Pushed I1017 19:03:42.969] azure-e2e-1184900309072220160-5c87681f: digest: sha256:3fa548ceb8237ec668d5166ded643b27eae724ac04c3ad6326668ee3d2be3bb9 size: 1998 I1017 19:03:42.989] docker rmi k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1184900309072220160-5c87681f 2>/dev/null || true I1017 19:03:43.030] docker tag k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184900309072220160-5c87681f k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1184900309072220160-5c87681f I1017 19:03:43.096] docker push k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1184900309072220160-5c87681f I1017 19:03:43.153] The push refers to repository [k8sprowinternal.azurecr.io/hyperkube] I1017 19:03:43.165] 7ece58f8fc9f: Preparing I1017 19:03:43.165] 39b3ac6d96e9: Preparing I1017 19:03:43.165] 7bbae4dddb88: Preparing I1017 19:03:43.165] a00defcfe869: Preparing I1017 19:03:43.166] 2ab0ae805c74: Preparing I1017 19:03:43.166] 43a8fe7d2382: Preparing I1017 19:03:43.166] 3f6a6f542637: Preparing I1017 19:03:43.166] 5ba3be777c2d: Preparing I1017 19:03:43.166] 43a8fe7d2382: Waiting I1017 19:03:43.166] 3f6a6f542637: Waiting I1017 19:03:43.166] 5ba3be777c2d: Waiting I1017 19:03:43.249] a00defcfe869: Layer already exists I1017 19:03:43.270] 2ab0ae805c74: Layer already exists I1017 19:03:43.306] 39b3ac6d96e9: Layer already exists I1017 19:03:43.329] 7bbae4dddb88: Layer already exists I1017 19:03:43.351] 43a8fe7d2382: Layer already exists I1017 19:03:43.377] 3f6a6f542637: Layer already exists I1017 19:03:43.388] 5ba3be777c2d: Layer already exists I1017 19:03:43.397] 7ece58f8fc9f: Mounted from hyperkube-amd64 I1017 19:03:43.993] azure-e2e-1184900309072220160-5c87681f: digest: sha256:3fa548ceb8237ec668d5166ded643b27eae724ac04c3ad6326668ee3d2be3bb9 size: 1998 I1017 19:03:44.009] make: Leaving directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube' W1017 19:03:44.110] 2019/10/17 19:03:44 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 33.67035475s W1017 19:03:44.110] 2019/10/17 19:03:44 azure.go:686: Docker logout. W1017 19:03:44.110] 2019/10/17 19:03:44 azure.go:744: Custom hyperkube URL: k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184900309072220160-5c87681f . W1017 19:03:44.111] 2019/10/17 19:03:44 azure.go:787: downloading /workspace/aks970795039/kubernetes.json from https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json. W1017 19:03:44.111] 2019/10/17 19:03:44 util.go:42: curl https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json W1017 19:03:44.370] 2019/10/17 19:03:44 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 19:03:44.371] 2019/10/17 19:03:44 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 19:03:45.663] 2019/10/17 19:03:45 azure.go:556: Extracting tar file /workspace/aks-engine.tar.gz into directory /go/src/k8s.io/kubernetes . W1017 19:03:45.663] 2019/10/17 19:03:45 process.go:153: Running: tar -xzf /workspace/aks-engine.tar.gz --strip 1 W1017 19:03:45.816] 2019/10/17 19:03:45 process.go:155: Step 'tar -xzf /workspace/aks-engine.tar.gz --strip 1' finished in 153.602488ms W1017 19:03:45.817] 2019/10/17 19:03:45 process.go:153: Running: /go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks970795039/kubernetes.json --output-directory /workspace/aks970795039 I1017 19:03:46.014] INFO[0000] Generating assets into /workspace/aks970795039... W1017 19:03:53.469] 2019/10/17 19:03:53 process.go:155: Step '/go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks970795039/kubernetes.json --output-directory /workspace/aks970795039' finished in 7.652715529s W1017 19:03:53.473] 2019/10/17 19:03:53 azure.go:627: Setting kubeconfig env variable: kubeconfig path: /workspace/aks970795039/kubeconfig/kubeconfig.eastus2.json. W1017 19:03:53.473] 2019/10/17 19:03:53 azure.go:629: Creating resource group: kubetest-d7811873-f10c-11e9-88e0-be829b849347. W1017 19:03:53.474] 2019/10/17 19:03:53 azure.go:631: Creating Azure resource group: kubetest-d7811873-f10c-11e9-88e0-be829b849347 for cluster deployment. W1017 19:03:55.339] 2019/10/17 19:03:55 azure.go:636: Validating deployment ARM templates. W1017 19:03:56.853] 2019/10/17 19:03:56 azure.go:642: Deploying cluster kubetest-d7811873-f10c-11e9-88e0-be829b849347 in resource group kubetest-d7811873-f10c-11e9-88e0-be829b849347. W1017 19:15:03.977] 2019/10/17 19:15:03 process.go:153: Running: ./cluster/kubectl.sh --match-server-version=false version W1017 19:15:04.695] 2019/10/17 19:15:04 process.go:155: Step './cluster/kubectl.sh --match-server-version=false version' finished in 717.839172ms W1017 19:15:04.695] 2019/10/17 19:15:04 process.go:153: Running: ./cluster/kubectl.sh --match-server-version=false get nodes -oyaml W1017 19:15:06.012] 2019/10/17 19:15:06 process.go:155: Step './cluster/kubectl.sh --match-server-version=false get nodes -oyaml' finished in 1.317231125s W1017 19:15:06.012] 2019/10/17 19:15:06 azure.go:961: KUBE_TEST_REPO_LIST_DOWNLOAD_LOCATION not set. Using default test image repos. W1017 19:15:06.012] 2019/10/17 19:15:06 azure.go:961: KUBE_TEST_REPO_LIST_DOWNLOAD_LOCATION not set. Using default test image repos. W1017 19:15:06.013] 2019/10/17 19:15:06 process.go:153: Running: kubectl get nodes --no-headers W1017 19:15:06.427] 2019/10/17 19:15:06 process.go:155: Step 'kubectl get nodes --no-headers' finished in 414.996422ms W1017 19:15:06.428] 2019/10/17 19:15:06 e2e.go:462: Cluster nodes: W1017 19:15:06.428] k8s-agentpool1-25883020-0 Ready 23s v1.16.3-beta.0.11+0d9472c2ffccc1 W1017 19:15:06.428] k8s-master-25883020-0 Ready 23s v1.16.3-beta.0.11+0d9472c2ffccc1 W1017 19:15:06.428] 2019/10/17 19:15:06 process.go:153: Running: ./cluster/kubectl.sh --match-server-version=false version W1017 19:15:06.853] 2019/10/17 19:15:06 process.go:155: Step './cluster/kubectl.sh --match-server-version=false version' finished in 426.231909ms W1017 19:15:06.854] 2019/10/17 19:15:06 azure.go:915: Attempting to dump control-plane and node component logs to /workspace/_artifacts W1017 19:15:06.854] 2019/10/17 19:15:06 process.go:153: Running: ./hack/log-dump.sh /workspace/_artifacts W1017 19:15:06.854] 2019/10/17 19:15:06 process.go:155: Step './hack/log-dump.sh /workspace/_artifacts' finished in 886.707µs W1017 19:15:06.855] 2019/10/17 19:15:06 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml. W1017 19:15:06.855] 2019/10/17 19:15:06 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}" W1017 19:15:06.997] 2019/10/17 19:15:06 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 141.845201ms W1017 19:15:06.997] 2019/10/17 19:15:06 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:15:06.999] Traceback (most recent call last): W1017 19:15:06.999] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in W1017 19:15:07.000] main(parse_args()) W1017 19:15:07.000] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main W1017 19:15:07.000] mode.start(runner_args) W1017 19:15:07.000] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start W1017 19:15:07.000] check_env(env, self.command, *args) W1017 19:15:07.001] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env W1017 19:15:07.001] subprocess.check_call(cmd, env=env) W1017 19:15:07.001] File "/usr/lib/python2.7/subprocess.py", line 186, in check_call W1017 19:15:07.001] raise CalledProcessError(retcode, cmd) W1017 19:15:07.002] 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:15:07.007] Command failed I1017 19:15:07.007] process 689 exited with code 1 after 40.0m E1017 19:15:07.007] FAIL: chewong-e2e-ccm I1017 19:15:07.007] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1017 19:15:07.820] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1017 19:15:07.850] process 17772 exited with code 0 after 0.0m I1017 19:15:07.850] Call: gcloud config get-value account I1017 19:15:08.096] process 17784 exited with code 0 after 0.0m I1017 19:15:08.096] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1017 19:15:08.096] Upload result and artifacts... I1017 19:15:08.096] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184900309072220160 I1017 19:15:08.097] Call: gsutil ls gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184900309072220160/artifacts W1017 19:15:09.267] CommandException: One or more URLs matched no objects. E1017 19:15:09.346] Command failed I1017 19:15:09.347] process 17796 exited with code 1 after 0.0m W1017 19:15:09.347] Remote dir gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184900309072220160/artifacts not exist yet I1017 19:15:09.347] 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/1184900309072220160/artifacts I1017 19:15:10.925] process 17938 exited with code 0 after 0.0m I1017 19:15:10.926] Call: git rev-parse HEAD I1017 19:15:10.928] process 18465 exited with code 0 after 0.0m I1017 19:15:10.928] Call: git rev-parse HEAD I1017 19:15:10.932] process 18466 exited with code 0 after 0.0m I1017 19:15:10.932] Call: gsutil stat gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json I1017 19:15:11.924] process 18467 exited with code 0 after 0.0m I1017 19:15:11.925] Call: gsutil -q cat 'gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json#1571336207958724' I1017 19:15:13.158] process 18609 exited with code 0 after 0.0m I1017 19:15:13.159] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1571336207958724 cp /tmp/gsutil_Q_KhoS gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json I1017 19:15:14.442] process 18753 exited with code 0 after 0.0m I1017 19:15:14.443] Call: gsutil stat gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json I1017 19:15:15.376] process 18931 exited with code 0 after 0.0m I1017 19:15:15.376] Call: gsutil -q cat 'gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json#1571336211487593' I1017 19:15:16.668] process 19073 exited with code 0 after 0.0m I1017 19:15:16.669] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1571336211487593 cp /tmp/gsutil_pWy7fl gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json I1017 19:15:18.098] process 19217 exited with code 0 after 0.0m I1017 19:15:18.099] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil_X1rqLf gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184900309072220160/finished.json I1017 19:15:19.416] process 19395 exited with code 0 after 0.0m I1017 19:15:19.417] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_nv8UAQ gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/latest-build.txt I1017 19:15:20.860] process 19573 exited with code 0 after 0.0m I1017 19:15:20.861] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_oNkUQh gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/latest-build.txt I1017 19:15:22.203] process 19751 exited with code 0 after 0.0m