W1014 23:45:56.449] ************************************************************************** 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 ************************************************************************** I1014 23:45:56.449] 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=master --repo=k8s.io/cloud-provider-azure=master:c470e6f36d76e5a565478fcba22118c06bc1548f,248:95c5c01d4ae3237e932ed7bae98f82bd66987c26 --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=bazel --provider=skeleton --ginkgo-parallel=30 --test-ccm=True --acsengine-agentpoolcount=3 '--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-ccm=True --acsengine-location=eastus2 '--acsengine-public-key=$AZURE_SSH_PUBLIC_KEY_FILE' --acsengine-template-url=https://raw.githubusercontent.com/feiskyer/cloud-provider-azure/test/tests/k8s-azure/manifest/linux.json --acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.36.5/aks-engine-v0.36.5-linux-amd64.tar.gz --timeout=420m I1014 23:45:56.450] Bootstrap chewong-e2e-ccm... I1014 23:45:56.453] Builder: b083fa28-eedc-11e9-b3d3-b20db476995a I1014 23:45:56.453] Image: chewong/kubekins-e2e:v20191014-test I1014 23:45:56.454] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1183891662724665344 I1014 23:45:56.454] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1014 23:45:56.950] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1014 23:45:56.979] process 214 exited with code 0 after 0.0m I1014 23:45:56.980] Call: gcloud config get-value account I1014 23:45:57.213] process 226 exited with code 0 after 0.0m I1014 23:45:57.214] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1014 23:45:57.214] Root: /go/src I1014 23:45:57.214] cd to /go/src I1014 23:45:57.214] Checkout: /go/src/k8s.io/kubernetes master to /go/src/k8s.io/kubernetes I1014 23:45:57.214] Call: git init k8s.io/kubernetes I1014 23:45:57.220] Initialized empty Git repository in /go/src/k8s.io/kubernetes/.git/ I1014 23:45:57.220] process 238 exited with code 0 after 0.0m I1014 23:45:57.220] Call: git config --local user.name 'K8S Bootstrap' I1014 23:45:57.223] process 239 exited with code 0 after 0.0m I1014 23:45:57.223] Call: git config --local user.email k8s_bootstrap@localhost I1014 23:45:57.225] process 240 exited with code 0 after 0.0m I1014 23:45:57.225] Call: git fetch --quiet --tags https://github.com/kubernetes/kubernetes master I1014 23:46:46.757] process 241 exited with code 0 after 0.8m I1014 23:46:46.758] Call: git checkout -B test FETCH_HEAD W1014 23:46:48.975] Switched to a new branch 'test' I1014 23:46:48.984] process 253 exited with code 0 after 0.0m I1014 23:46:48.985] Call: git show -s --format=format:%ct HEAD I1014 23:46:48.992] process 254 exited with code 0 after 0.0m I1014 23:46:48.993] Checkout: /go/src/k8s.io/cloud-provider-azure master:c470e6f36d76e5a565478fcba22118c06bc1548f,248:95c5c01d4ae3237e932ed7bae98f82bd66987c26 to /go/src/k8s.io/cloud-provider-azure I1014 23:46:48.993] Call: git init k8s.io/cloud-provider-azure I1014 23:46:48.997] Initialized empty Git repository in /go/src/k8s.io/cloud-provider-azure/.git/ I1014 23:46:48.997] process 255 exited with code 0 after 0.0m I1014 23:46:48.997] Call: git config --local user.name 'K8S Bootstrap' I1014 23:46:48.999] process 256 exited with code 0 after 0.0m I1014 23:46:49.000] Call: git config --local user.email k8s_bootstrap@localhost I1014 23:46:49.002] process 257 exited with code 0 after 0.0m I1014 23:46:49.002] Call: git fetch --quiet --tags https://github.com/kubernetes/cloud-provider-azure master +refs/pull/248/head:refs/pr/248 I1014 23:46:50.393] process 258 exited with code 0 after 0.0m I1014 23:46:50.394] Call: git checkout -B test c470e6f36d76e5a565478fcba22118c06bc1548f W1014 23:46:50.822] Switched to a new branch 'test' I1014 23:46:50.825] process 270 exited with code 0 after 0.0m I1014 23:46:50.825] Call: git show -s --format=format:%ct HEAD I1014 23:46:50.828] process 271 exited with code 0 after 0.0m I1014 23:46:50.828] Call: git merge --no-ff -m 'Merge +refs/pull/248/head:refs/pr/248' 95c5c01d4ae3237e932ed7bae98f82bd66987c26 I1014 23:46:51.159] Merge made by the 'recursive' strategy. I1014 23:46:51.160] hack/log-dump.sh | 161 +++++++++++++++++++++++++++++++++++++++++++++++++++++++ I1014 23:46:51.161] 1 file changed, 161 insertions(+) I1014 23:46:51.161] create mode 100755 hack/log-dump.sh I1014 23:46:51.161] process 272 exited with code 0 after 0.0m I1014 23:46:51.161] Configure environment... I1014 23:46:51.161] Call: git show -s --format=format:%ct HEAD I1014 23:46:51.170] process 274 exited with code 0 after 0.0m I1014 23:46:51.170] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1014 23:46:51.787] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1014 23:46:51.901] process 275 exited with code 0 after 0.0m I1014 23:46:51.902] Call: gcloud config get-value account I1014 23:46:52.135] process 287 exited with code 0 after 0.0m I1014 23:46:52.135] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1014 23:46:52.135] 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 ' I1014 23:46:52.703] process 299 exited with code 0 after 0.0m I1014 23:46:52.703] Start 1183891662724665344 at v1.17.0-alpha.1.424+aafbb93fe24109... I1014 23:46:52.705] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil_RDF31d gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1183891662724665344/started.json I1014 23:46:54.093] process 332 exited with code 0 after 0.0m I1014 23:46:54.094] 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/1183891662724665344' cp /tmp/gsutil_XxuTjk gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/1183891662724665344.txt I1014 23:46:55.501] process 510 exited with code 0 after 0.0m I1014 23:46:55.502] 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=30 --test-ccm=True --acsengine-agentpoolcount=3 --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-ccm=True --acsengine-location=eastus2 --acsengine-public-key=/etc/azure-ssh/azure-ssh-pub --acsengine-template-url=https://raw.githubusercontent.com/feiskyer/cloud-provider-azure/test/tests/k8s-azure/manifest/linux.json --acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.36.5/aks-engine-v0.36.5-linux-amd64.tar.gz --timeout=420m W1014 23:46:55.541] starts with local mode W1014 23:46:55.541] Environment: W1014 23:46:55.541] ARTIFACTS=/workspace/_artifacts W1014 23:46:55.541] AWS_SSH_PRIVATE_KEY_FILE=/root/.ssh/kube_aws_rsa W1014 23:46:55.541] AWS_SSH_PUBLIC_KEY_FILE=/root/.ssh/kube_aws_rsa.pub W1014 23:46:55.542] AZURE_CREDENTIALS=/etc/azure-cred/credentials W1014 23:46:55.542] AZURE_SSH_PRIVATE_KEY_FILE=/etc/azure-ssh/azure-ssh W1014 23:46:55.542] AZURE_SSH_PUBLIC_KEY_FILE=/etc/azure-ssh/azure-ssh-pub W1014 23:46:55.542] AZURE_SSH_USER=azureuser W1014 23:46:55.542] AZ_STORAGE_CONTAINER_NAME=mystoragecontainer W1014 23:46:55.542] BAZEL_REMOTE_CACHE_ENABLED=false W1014 23:46:55.542] BAZEL_VERSION=0.23.2 W1014 23:46:55.543] BOOTSTRAP_MIGRATION=yes W1014 23:46:55.543] BUILD_ID=1183891662724665344 W1014 23:46:55.543] BUILD_NUMBER=1183891662724665344 W1014 23:46:55.543] CLOUDSDK_COMPONENT_MANAGER_DISABLE_UPDATE_CHECK=true W1014 23:46:55.543] CLOUDSDK_CONFIG=/go/src/k8s.io/kubernetes/.config/gcloud W1014 23:46:55.543] CLOUDSDK_CORE_DISABLE_PROMPTS=1 W1014 23:46:55.543] CLOUDSDK_EXPERIMENTAL_FAST_COMPONENT_UPDATE=false W1014 23:46:55.544] CLOUD_CONFIG=random W1014 23:46:55.544] DECK_PORT=tcp://10.0.160.83:80 W1014 23:46:55.544] DECK_PORT_80_TCP=tcp://10.0.160.83:80 W1014 23:46:55.544] DECK_PORT_80_TCP_ADDR=10.0.160.83 W1014 23:46:55.544] DECK_PORT_80_TCP_PORT=80 W1014 23:46:55.544] DECK_PORT_80_TCP_PROTO=tcp W1014 23:46:55.545] DECK_SERVICE_HOST=10.0.160.83 W1014 23:46:55.545] DECK_SERVICE_PORT=80 W1014 23:46:55.545] DOCKER_IN_DOCKER_ENABLED=true W1014 23:46:55.545] DOCKER_IN_DOCKER_IPV6_ENABLED=false W1014 23:46:55.545] GCS_ARTIFACTS_DIR=gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1183891662724665344/artifacts W1014 23:46:55.545] GOOGLE_APPLICATION_CREDENTIALS=/etc/service-account/service-account.json W1014 23:46:55.545] GOPATH=/go W1014 23:46:55.546] GO_TARBALL=go1.12.1.linux-amd64.tar.gz W1014 23:46:55.546] HOME=/workspace W1014 23:46:55.546] HOOK_PORT=tcp://10.0.144.133:8888 W1014 23:46:55.546] HOOK_PORT_8888_TCP=tcp://10.0.144.133:8888 W1014 23:46:55.546] HOOK_PORT_8888_TCP_ADDR=10.0.144.133 W1014 23:46:55.546] HOOK_PORT_8888_TCP_PORT=8888 W1014 23:46:55.547] HOOK_PORT_8888_TCP_PROTO=tcp W1014 23:46:55.547] HOOK_SERVICE_HOST=10.0.144.133 W1014 23:46:55.547] HOOK_SERVICE_PORT=8888 W1014 23:46:55.547] HOSTNAME=b083fa28-eedc-11e9-b3d3-b20db476995a W1014 23:46:55.547] IMAGE=chewong/kubekins-e2e:v20191014-test W1014 23:46:55.547] INSTANCE_PREFIX=bootstrap-e2e W1014 23:46:55.547] JENKINS_GCE_SSH_PRIVATE_KEY_FILE=/root/.ssh/google_compute_engine W1014 23:46:55.548] JENKINS_GCE_SSH_PUBLIC_KEY_FILE=/root/.ssh/google_compute_engine.pub W1014 23:46:55.548] JOB_NAME=chewong-e2e-ccm W1014 23:46:55.548] JOB_SPEC={"type":"presubmit","job":"chewong-e2e-ccm","buildid":"1183891662724665344","prowjobid":"b083fa28-eedc-11e9-b3d3-b20db476995a","refs":{"org":"Azure","repo":"kubernetes","repo_link":"https://github.com/Azure/kubernetes","base_ref":"master","base_sha":"aafbb93fe24109c4a30766654849d848dc9817f5","base_link":"https://github.com/Azure/kubernetes/commit/aafbb93fe24109c4a30766654849d848dc9817f5","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"}]}} W1014 23:46:55.548] JOB_TYPE=presubmit W1014 23:46:55.549] KUBERNETES_PORT=tcp://10.0.0.1:443 W1014 23:46:55.549] KUBERNETES_PORT_443_TCP=tcp://10.0.0.1:443 W1014 23:46:55.549] KUBERNETES_PORT_443_TCP_ADDR=10.0.0.1 W1014 23:46:55.549] KUBERNETES_PORT_443_TCP_PORT=443 W1014 23:46:55.549] KUBERNETES_PORT_443_TCP_PROTO=tcp W1014 23:46:55.549] KUBERNETES_SERVICE_HOST=10.0.0.1 W1014 23:46:55.550] KUBERNETES_SERVICE_PORT=443 W1014 23:46:55.550] KUBERNETES_SERVICE_PORT_HTTPS=443 W1014 23:46:55.550] KUBETEST_IN_DOCKER=true W1014 23:46:55.550] KUBETEST_MANUAL_DUMP=y W1014 23:46:55.550] KUBE_AWS_INSTANCE_PREFIX=bootstrap-e2e W1014 23:46:55.550] KUBE_GCE_INSTANCE_PREFIX=bootstrap-e2e W1014 23:46:55.550] KUBE_VERBOSE=0 W1014 23:46:55.551] NODE_NAME=b083fa28-eedc-11e9-b3d3-b20db476995a W1014 23:46:55.551] 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 W1014 23:46:55.551] PROW_JOB_ID=b083fa28-eedc-11e9-b3d3-b20db476995a W1014 23:46:55.551] PULL_BASE_REF=master W1014 23:46:55.551] PULL_BASE_SHA=aafbb93fe24109c4a30766654849d848dc9817f5 W1014 23:46:55.551] PULL_NUMBER=113 W1014 23:46:55.552] PULL_PULL_SHA=879465972041635fd7bc8269da49153b67e63822 W1014 23:46:55.552] PULL_REFS=master:aafbb93fe24109c4a30766654849d848dc9817f5,113:879465972041635fd7bc8269da49153b67e63822 W1014 23:46:55.552] PWD=/workspace W1014 23:46:55.552] REGISTRY=k8sprowinternal.azurecr.io W1014 23:46:55.552] REPO_NAME=kubernetes W1014 23:46:55.552] REPO_OWNER=Azure W1014 23:46:55.552] SHLVL=2 W1014 23:46:55.553] SOURCE_DATE_EPOCH=1571092910 W1014 23:46:55.553] TERM=xterm W1014 23:46:55.553] TIDE_PORT=tcp://10.0.180.53:80 W1014 23:46:55.553] TIDE_PORT_80_TCP=tcp://10.0.180.53:80 W1014 23:46:55.553] TIDE_PORT_80_TCP_ADDR=10.0.180.53 W1014 23:46:55.553] TIDE_PORT_80_TCP_PORT=80 W1014 23:46:55.553] TIDE_PORT_80_TCP_PROTO=tcp W1014 23:46:55.554] TIDE_SERVICE_HOST=10.0.180.53 W1014 23:46:55.554] TIDE_SERVICE_PORT=80 W1014 23:46:55.554] WORKSPACE=/workspace W1014 23:46:55.554] _=./test-infra/jenkins/bootstrap.py W1014 23:46:55.555] 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=30', '--test-ccm=True', '--acsengine-agentpoolcount=3', '--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-ccm=True', '--acsengine-location=eastus2', '--acsengine-public-key=/etc/azure-ssh/azure-ssh-pub', '--acsengine-template-url=https://raw.githubusercontent.com/feiskyer/cloud-provider-azure/test/tests/k8s-azure/manifest/linux.json', '--acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.36.5/aks-engine-v0.36.5-linux-amd64.tar.gz', '--timeout=420m') W1014 23:46:55.555] 2019/10/14 23:46:55 main.go:332: Limiting testing to 7h0m0s W1014 23:46:55.555] 2019/10/14 23:46:55 azure.go:232: Reading credentials file /etc/azure-cred/credentials W1014 23:46:55.556] 2019/10/14 23:46:55 process.go:153: Running: make -C /go/src/k8s.io/kubernetes bazel-release W1014 23:46:55.626] Extracting Bazel installation... I1014 23:46:55.726] make: Entering directory '/go/src/k8s.io/kubernetes' W1014 23:47:04.465] Starting local Bazel server and connecting to it... W1014 23:47:06.284] Loading: W1014 23:47:06.288] Loading: 0 packages loaded W1014 23:47:07.290] Loading: 0 packages loaded W1014 23:47:08.854] Loading: 0 packages loaded W1014 23:47:10.291] Loading: 0 packages loaded W1014 23:47:12.234] Loading: 0 packages loaded W1014 23:47:13.291] Loading: 0 packages loaded W1014 23:47:13.291] currently loading: build/release-tars W1014 23:47:15.479] Loading: 0 packages loaded W1014 23:47:15.480] currently loading: build/release-tars W1014 23:47:15.832] Analyzing: target //build/release-tars:release-tars (1 packages loaded, 0 targets configured) W1014 23:47:17.291] Analyzing: target //build/release-tars:release-tars (182 packages loaded, 1063 targets configured) W1014 23:47:18.963] Analyzing: target //build/release-tars:release-tars (746 packages loaded, 3076 targets configured) W1014 23:47:20.887] Analyzing: target //build/release-tars:release-tars (1606 packages loaded, 8629 targets configured) W1014 23:47:23.100] Analyzing: target //build/release-tars:release-tars (2475 packages loaded, 17591 targets configured) W1014 23:47:26.315] Analyzing: target //build/release-tars:release-tars (3042 packages loaded, 27225 targets configured) W1014 23:47:29.581] Analyzing: target //build/release-tars:release-tars (3073 packages loaded, 33848 targets configured) W1014 23:47:33.132] Analyzing: target //build/release-tars:release-tars (3085 packages loaded, 35130 targets configured) W1014 23:47:39.932] Analyzing: target //build/release-tars:release-tars (3087 packages loaded, 39250 targets configured) W1014 23:47:51.185] INFO: Analysed target //build/release-tars:release-tars (3087 packages loaded, 42371 targets configured). W1014 23:47:51.187] Building: checking cached actions W1014 23:47:51.188] INFO: Found 1 target... W1014 23:47:51.381] [0 / 25] [-----] Writing file build/release-tars/kubernetes-client-linux-amd64.args W1014 23:48:00.148] [144 / 5,320] Compiling vendor/github.com/google/certificate-transparency-go/x509/linux_amd64_stripped/go_default_library%linux_amd64%cgo_codegen%/cert_pool.cgo2.c; 2s linux-sandbox ... (5 actions running) W1014 23:48:08.591] [209 / 5,320] GoAsm vendor/gonum.org/v1/gonum/internal/asm/f32/linux_amd64_stripped/go_default_library%/axpyunitary_amd64.o; 2s linux-sandbox ... (7 actions, 6 running) W1014 23:48:18.217] [304 / 5,320] GoCompile vendor/gonum.org/v1/gonum/blas/gonum/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/gonum.org/v1/gonum/blas/gonum.a; 4s linux-sandbox ... (7 actions, 6 running) W1014 23:48:30.108] [476 / 5,320] GoCompile vendor/gonum.org/v1/gonum/mat/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/gonum.org/v1/gonum/mat.a; 4s linux-sandbox ... (8 actions, 7 running) W1014 23:48:42.731] [701 / 5,320] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 10s linux-sandbox ... (8 actions, 7 running) W1014 23:48:57.287] [965 / 5,320] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 25s linux-sandbox ... (8 actions running) W1014 23:49:15.327] [1,116 / 5,320] GoLink vendor/github.com/onsi/ginkgo/ginkgo/linux_amd64_stripped/ginkgo; 2s linux-sandbox ... (8 actions running) W1014 23:49:34.705] [1,280 / 5,320] GoCompile staging/src/k8s.io/client-go/util/jsonpath/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/client-go/util/jsonpath.a; 0s linux-sandbox ... (8 actions running) W1014 23:49:57.817] [1,477 / 5,320] GoCompile vendor/github.com/libopenstorage/openstorage/pkg/parser/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/libopenstorage/openstorage/pkg/parser.a; 2s linux-sandbox ... (8 actions, 7 running) W1014 23:50:24.558] [1,648 / 5,320] GoCompile vendor/github.com/Azure/azure-sdk-for-go/services/network/mgmt/2019-06-01/network/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/Azure/azure-sdk-for-go/services/network/mgmt/2019-06-01/network.a; 14s linux-sandbox ... (8 actions, 7 running) W1014 23:50:54.364] [1,806 / 5,320] GoCompile vendor/github.com/vmware/govmomi/object/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/vmware/govmomi/object.a; 3s linux-sandbox ... (8 actions, 7 running) W1014 23:51:29.076] [2,372 / 5,320] GoCompile vendor/github.com/vmware/govmomi/vim25/types/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/vmware/govmomi/vim25/types.a; 13s linux-sandbox ... (8 actions, 7 running) W1014 23:52:08.737] [2,621 / 5,320] GoCompile vendor/github.com/Azure/azure-sdk-for-go/services/network/mgmt/2019-06-01/network/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/Azure/azure-sdk-for-go/services/network/mgmt/2019-06-01/network.a; 13s linux-sandbox ... (8 actions, 7 running) W1014 23:52:56.754] [2,770 / 5,320] ; 30s linux-sandbox ... (8 actions, 7 running) W1014 23:53:50.212] [2,850 / 5,320] ; 83s linux-sandbox ... (8 actions, 7 running) W1014 23:54:50.903] [3,142 / 5,320] GoCompile staging/src/k8s.io/client-go/kubernetes/typed/core/v1/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/client-go/kubernetes/typed/core/v1.a; 0s linux-sandbox ... (8 actions, 7 running) W1014 23:56:00.763] [3,462 / 5,320] GoLink cmd/kubectl/linux_amd64_pure_stripped/kubectl; 3s linux-sandbox ... (8 actions, 7 running) W1014 23:57:21.252] [3,842 / 5,320] GoCompile cmd/kubeadm/app/cmd/phases/upgrade/node/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/cmd/kubeadm/app/cmd/phases/upgrade/node.a; 6s linux-sandbox ... (8 actions, 7 running) W1014 23:58:53.946] [4,579 / 5,320] GoCompile staging/src/k8s.io/client-go/kubernetes/typed/apps/v1beta1/fake/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/client-go/kubernetes/typed/apps/v1beta1/fake.a; 3s linux-sandbox ... (8 actions, 7 running) W1015 00:00:40.904] [4,952 / 5,320] GZIP build/kube-controller-manager-internal-layer.tar.gz; 21s linux-sandbox ... (8 actions, 7 running) W1015 00:02:52.063] [5,300 / 5,320] GoLink cmd/kubelet/kubelet; 22s linux-sandbox ... (6 actions, 5 running) W1015 00:05:21.689] [5,319 / 5,320] PackageTar build/release-tars/kubernetes-test-linux-amd64.tar.gz; 8s linux-sandbox W1015 00:05:25.552] Target //build/release-tars:release-tars up-to-date: W1015 00:05:25.553] bazel-bin/build/release-tars/kubernetes-client-linux-amd64.tar.gz W1015 00:05:25.554] bazel-bin/build/release-tars/kubernetes-node-linux-amd64.tar.gz W1015 00:05:25.554] bazel-bin/build/release-tars/kubernetes-server-linux-amd64.tar.gz W1015 00:05:25.554] bazel-bin/build/release-tars/kubernetes-manifests.tar.gz W1015 00:05:25.555] bazel-bin/build/release-tars/kubernetes-test-portable.tar.gz W1015 00:05:25.555] bazel-bin/build/release-tars/kubernetes-test-linux-amd64.tar.gz W1015 00:05:25.555] bazel-bin/build/release-tars/kubernetes.tar.gz W1015 00:05:25.556] bazel-bin/build/release-tars/kubernetes-src.tar.gz W1015 00:05:25.596] INFO: Elapsed time: 1109.942s, Critical Path: 367.08s W1015 00:05:25.597] INFO: 5229 processes: 5229 linux-sandbox. W1015 00:05:25.601] INFO: Build completed successfully, 5320 total actions W1015 00:05:25.603] INFO: Build completed successfully, 5320 total actions W1015 00:05:25.610] 2019/10/15 00:05:25 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes bazel-release' finished in 18m30.054596253s W1015 00:05:25.611] 2019/10/15 00:05:25 util.go:277: Flushing memory. I1015 00:05:25.711] make: Leaving directory '/go/src/k8s.io/kubernetes' W1015 00:06:27.613] 2019/10/15 00:06:27 azure.go:906: Deleting resource group: kubetest-e77e8c4c-eedc-11e9-88e4-0242e3281124. W1015 00:06:28.101] 2019/10/15 00:06:28 azure.go:654: CWD /go/src/k8s.io/kubernetes W1015 00:06:28.101] 2019/10/15 00:06:28 azure.go:673: Attempting Docker login with azure cred. W1015 00:06:29.566] 2019/10/15 00:06:29 azure.go:682: Docker login success. W1015 00:06:29.566] 2019/10/15 00:06:29 azure.go:697: Building ccm. W1015 00:06:29.566] 2019/10/15 00:06:29 azure.go:699: projectPath /go/src/k8s.io/cloud-provider-azure W1015 00:06:29.566] 2019/10/15 00:06:29 process.go:153: Running: docker build -t k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1183891662724665344-a262ce3c . I1015 00:06:31.779] Sending build context to Docker daemon 67.18MB I1015 00:06:31.811] Step 1/7 : FROM golang:1.12.9-stretch AS build I1015 00:06:32.791] 1.12.9-stretch: Pulling from library/golang I1015 00:06:33.109] 092586df9206: Pulling fs layer I1015 00:06:33.109] ef599477fae0: Pulling fs layer I1015 00:06:33.109] 4530c6472b5d: Pulling fs layer I1015 00:06:33.109] d34d61487075: Pulling fs layer I1015 00:06:33.110] 89c6ec31b9e9: Pulling fs layer I1015 00:06:33.110] e37857ebcafa: Pulling fs layer I1015 00:06:33.110] b0e29f6c7f0a: Pulling fs layer I1015 00:06:33.110] d34d61487075: Waiting I1015 00:06:33.110] 89c6ec31b9e9: Waiting I1015 00:06:33.110] e37857ebcafa: Waiting I1015 00:06:33.110] b0e29f6c7f0a: Waiting I1015 00:06:33.558] 4530c6472b5d: Verifying Checksum I1015 00:06:33.559] 4530c6472b5d: Download complete I1015 00:06:33.614] ef599477fae0: Verifying Checksum I1015 00:06:33.615] ef599477fae0: Download complete I1015 00:06:33.862] 092586df9206: Verifying Checksum I1015 00:06:33.862] 092586df9206: Download complete I1015 00:06:34.602] d34d61487075: Verifying Checksum I1015 00:06:34.602] d34d61487075: Download complete I1015 00:06:34.913] 89c6ec31b9e9: Verifying Checksum I1015 00:06:34.913] 89c6ec31b9e9: Download complete I1015 00:06:34.986] b0e29f6c7f0a: Verifying Checksum I1015 00:06:35.495] e37857ebcafa: Verifying Checksum I1015 00:06:35.495] e37857ebcafa: Download complete I1015 00:06:37.084] 092586df9206: Pull complete I1015 00:06:37.841] ef599477fae0: Pull complete I1015 00:06:38.182] 4530c6472b5d: Pull complete I1015 00:06:41.756] d34d61487075: Pull complete I1015 00:06:45.211] 89c6ec31b9e9: Pull complete I1015 00:06:52.559] e37857ebcafa: Pull complete I1015 00:06:52.696] b0e29f6c7f0a: Pull complete I1015 00:06:52.719] Digest: sha256:76b52857546f070cc3ac499accb27b8c411b10ff6d45c0b1da2a8aab7b61fe29 I1015 00:06:52.737] Status: Downloaded newer image for golang:1.12.9-stretch I1015 00:06:52.738] ---> 2c4a601e5da9 I1015 00:06:52.738] Step 2/7 : WORKDIR /go/src/k8s.io/cloud-provider-azure I1015 00:07:04.649] ---> Running in 54e38d24ef75 I1015 00:07:05.834] Removing intermediate container 54e38d24ef75 I1015 00:07:05.834] ---> c64a0ccd479c I1015 00:07:05.835] Step 3/7 : COPY . . I1015 00:07:11.675] ---> 9d668a7f9aff I1015 00:07:11.675] Step 4/7 : RUN make I1015 00:07:11.851] ---> Running in 6da08ab93fac I1015 00:07:12.711] hack/pkg-config.sh > .pkg_config I1015 00:07:12.734] go build -o bin/azure-cloud-controller-manager -ldflags '-s -w -X k8s.io/cloud-provider-azure/pkg/version.gitVersion=v0.3.0-10-gbdcbdd2f0 -X k8s.io/cloud-provider-azure/pkg/version.gitCommit=bdcbdd2f0a8f0773b4c52ac0a09d52b5fe6cfcbd -X k8s.io/cloud-provider-azure/pkg/version.buildDate=2019-10-15T00:07:12Z' ./cmd/cloud-controller-manager I1015 00:07:54.597] go build -o bin/azure-cloud-node-manager -ldflags '-s -w -X k8s.io/cloud-provider-azure/pkg/version.gitVersion=v0.3.0-10-gbdcbdd2f0 -X k8s.io/cloud-provider-azure/pkg/version.gitCommit=bdcbdd2f0a8f0773b4c52ac0a09d52b5fe6cfcbd -X k8s.io/cloud-provider-azure/pkg/version.buildDate=2019-10-15T00:07:12Z' ./cmd/cloud-node-manager I1015 00:08:18.513] Removing intermediate container 6da08ab93fac I1015 00:08:18.513] ---> 2f68d3c88ff3 I1015 00:08:18.513] Step 5/7 : FROM k8s.gcr.io/debian-base:v1.0.0 I1015 00:08:18.823] v1.0.0: Pulling from debian-base I1015 00:08:18.991] 39fafc05754f: Pulling fs layer I1015 00:08:19.487] 39fafc05754f: Verifying Checksum I1015 00:08:19.488] 39fafc05754f: Download complete I1015 00:08:21.952] 39fafc05754f: Pull complete I1015 00:08:21.977] Digest: sha256:3801f944c765dc1b54900826ca67b1380bb8c73b9caf4a2a27ce613b3ba3e742 I1015 00:08:21.997] Status: Downloaded newer image for k8s.gcr.io/debian-base:v1.0.0 I1015 00:08:21.997] ---> 204e96332c91 I1015 00:08:21.998] Step 6/7 : COPY --from=build /go/src/k8s.io/cloud-provider-azure/bin/azure-cloud-controller-manager /usr/local/bin I1015 00:08:25.057] ---> 056e764170f6 I1015 00:08:25.057] Step 7/7 : RUN ln -s /usr/local/bin/azure-cloud-controller-manager /usr/local/bin/cloud-controller-manager I1015 00:08:25.216] ---> Running in 43a2ccdf9703 I1015 00:08:27.061] Removing intermediate container 43a2ccdf9703 I1015 00:08:27.062] ---> f8fa1cbe5fc3 I1015 00:08:27.165] Successfully built f8fa1cbe5fc3 I1015 00:08:27.290] Successfully tagged k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1183891662724665344-a262ce3c W1015 00:08:27.391] 2019/10/15 00:08:27 process.go:155: Step 'docker build -t k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1183891662724665344-a262ce3c .' finished in 1m57.728795775s W1015 00:08:27.391] 2019/10/15 00:08:27 process.go:153: Running: docker push k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1183891662724665344-a262ce3c W1015 00:08:32.142] 2019/10/15 00:08:32 process.go:155: Step 'docker push k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1183891662724665344-a262ce3c' finished in 4.847788782s W1015 00:08:32.143] 2019/10/15 00:08:32 azure.go:686: Docker logout. W1015 00:08:32.207] 2019/10/15 00:08:32 azure.go:716: Custom cloud controller manager URL: k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1183891662724665344-a262ce3c . W1015 00:08:32.207] 2019/10/15 00:08:32 azure.go:787: downloading /workspace/aks339603008/kubernetes.json from https://raw.githubusercontent.com/feiskyer/cloud-provider-azure/test/tests/k8s-azure/manifest/linux.json. W1015 00:08:32.208] 2019/10/15 00:08:32 util.go:42: curl https://raw.githubusercontent.com/feiskyer/cloud-provider-azure/test/tests/k8s-azure/manifest/linux.json W1015 00:08:32.534] 2019/10/15 00:08:32 azure.go:795: url=https://raw.githubusercontent.com/feiskyer/cloud-provider-azure/test/tests/k8s-azure/manifest/linux.json failed get /workspace/aks339603008/kubernetes.json: . W1015 00:08:32.534] 2019/10/15 00:08:32 azure.go:787: downloading /workspace/aks339603008/kubernetes.json from https://raw.githubusercontent.com/feiskyer/cloud-provider-azure/test/tests/k8s-azure/manifest/linux.json. W1015 00:08:32.535] 2019/10/15 00:08:32 util.go:42: curl https://raw.githubusercontent.com/feiskyer/cloud-provider-azure/test/tests/k8s-azure/manifest/linux.json W1015 00:08:32.637] 2019/10/15 00:08:32 process.go:153: Running: /workspace/_artifacts W1015 00:08:32.638] 2019/10/15 00:08:32 process.go:155: Step '/workspace/_artifacts' finished in 1.007908ms W1015 00:08:32.638] 2019/10/15 00:08:32 azure.go:906: Deleting resource group: kubetest-e77e8c4c-eedc-11e9-88e4-0242e3281124. W1015 00:08:32.669] 2019/10/15 00:08:32 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml. W1015 00:08:32.670] 2019/10/15 00:08:32 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}" W1015 00:08:33.836] 2019/10/15 00:08:33 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 1.166589213s W1015 00:08:33.837] 2019/10/15 00:08:33 main.go:319: Something went wrong: starting e2e cluster: error downloading ApiModel template: https://raw.githubusercontent.com/feiskyer/cloud-provider-azure/test/tests/k8s-azure/manifest/linux.json with error url=https://raw.githubusercontent.com/feiskyer/cloud-provider-azure/test/tests/k8s-azure/manifest/linux.json failed get /workspace/aks339603008/kubernetes.json: url=https://raw.githubusercontent.com/feiskyer/cloud-provider-azure/test/tests/k8s-azure/manifest/linux.json failed get /workspace/aks339603008/kubernetes.json: .. W1015 00:08:33.839] Traceback (most recent call last): W1015 00:08:33.839] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in W1015 00:08:33.840] main(parse_args()) W1015 00:08:33.840] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main W1015 00:08:33.840] mode.start(runner_args) W1015 00:08:33.840] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start W1015 00:08:33.841] check_env(env, self.command, *args) W1015 00:08:33.841] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env W1015 00:08:33.841] subprocess.check_call(cmd, env=env) W1015 00:08:33.841] File "/usr/lib/python2.7/subprocess.py", line 186, in check_call W1015 00:08:33.841] raise CalledProcessError(retcode, cmd) W1015 00:08:33.842] 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=30', '--test-ccm=True', '--acsengine-agentpoolcount=3', '--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-ccm=True', '--acsengine-location=eastus2', '--acsengine-public-key=/etc/azure-ssh/azure-ssh-pub', '--acsengine-template-url=https://raw.githubusercontent.com/feiskyer/cloud-provider-azure/test/tests/k8s-azure/manifest/linux.json', '--acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.36.5/aks-engine-v0.36.5-linux-amd64.tar.gz', '--timeout=420m')' returned non-zero exit status 1 E1015 00:08:33.847] Command failed I1015 00:08:33.847] process 688 exited with code 1 after 21.6m E1015 00:08:33.847] FAIL: chewong-e2e-ccm I1015 00:08:33.848] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1015 00:08:34.743] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1015 00:08:34.774] process 13678 exited with code 0 after 0.0m I1015 00:08:34.774] Call: gcloud config get-value account I1015 00:08:35.017] process 13690 exited with code 0 after 0.0m I1015 00:08:35.017] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1015 00:08:35.017] Upload result and artifacts... I1015 00:08:35.017] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1183891662724665344 I1015 00:08:35.017] Call: gsutil ls gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1183891662724665344/artifacts W1015 00:08:36.263] CommandException: One or more URLs matched no objects. E1015 00:08:36.338] Command failed I1015 00:08:36.339] process 13702 exited with code 1 after 0.0m W1015 00:08:36.339] Remote dir gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1183891662724665344/artifacts not exist yet I1015 00:08:36.339] 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/1183891662724665344/artifacts I1015 00:08:37.995] process 13844 exited with code 0 after 0.0m I1015 00:08:37.996] Call: git rev-parse HEAD I1015 00:08:37.999] process 14368 exited with code 0 after 0.0m I1015 00:08:37.999] Call: git rev-parse HEAD I1015 00:08:38.005] process 14369 exited with code 0 after 0.0m I1015 00:08:38.006] Call: gsutil stat gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json W1015 00:08:38.970] No URLs matched: gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json I1015 00:08:38.970] process 14370 exited with code 1 after 0.0m I1015 00:08:38.971] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:0 cp /tmp/gsutil_Tm37OQ gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json I1015 00:08:40.331] process 14512 exited with code 0 after 0.0m I1015 00:08:40.331] Call: gsutil stat gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json W1015 00:08:41.260] No URLs matched: gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json I1015 00:08:41.261] process 14690 exited with code 1 after 0.0m I1015 00:08:41.261] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:0 cp /tmp/gsutil_nlS1rT gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json I1015 00:08:42.676] process 14832 exited with code 0 after 0.0m I1015 00:08:42.677] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil_DbNgme gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1183891662724665344/finished.json I1015 00:08:43.953] process 15010 exited with code 0 after 0.0m I1015 00:08:43.953] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_ij3j7_ gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/latest-build.txt I1015 00:08:45.322] process 15188 exited with code 0 after 0.0m I1015 00:08:45.323] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_ZT5pF9 gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/latest-build.txt I1015 00:08:46.632] process 15366 exited with code 0 after 0.0m