W1016 17:32:25.880] ************************************************************************** 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 ************************************************************************** I1016 17:32:25.880] 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: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=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 I1016 17:32:25.880] Bootstrap chewong-e2e-ccm... I1016 17:32:25.884] Builder: d27c8cc8-f03a-11e9-b3d3-b20db476995a I1016 17:32:25.884] Image: chewong/kubekins-e2e:v20191015-test I1016 17:32:25.884] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184522444090642432 I1016 17:32:25.884] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1016 17:32:26.479] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1016 17:32:26.508] process 214 exited with code 0 after 0.0m I1016 17:32:26.509] Call: gcloud config get-value account I1016 17:32:26.741] process 226 exited with code 0 after 0.0m I1016 17:32:26.741] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1016 17:32:26.742] Root: /go/src I1016 17:32:26.742] cd to /go/src I1016 17:32:26.742] Checkout: /go/src/k8s.io/kubernetes release-1.16 to /go/src/k8s.io/kubernetes I1016 17:32:26.742] Call: git init k8s.io/kubernetes I1016 17:32:26.746] Initialized empty Git repository in /go/src/k8s.io/kubernetes/.git/ I1016 17:32:26.746] process 238 exited with code 0 after 0.0m I1016 17:32:26.747] Call: git config --local user.name 'K8S Bootstrap' I1016 17:32:26.749] process 239 exited with code 0 after 0.0m I1016 17:32:26.749] Call: git config --local user.email k8s_bootstrap@localhost I1016 17:32:26.751] process 240 exited with code 0 after 0.0m I1016 17:32:26.751] Call: git fetch --quiet --tags https://github.com/kubernetes/kubernetes release-1.16 I1016 17:33:17.707] process 241 exited with code 0 after 0.8m I1016 17:33:17.707] Call: git checkout -B test FETCH_HEAD W1016 17:33:19.773] Switched to a new branch 'test' I1016 17:33:19.782] process 253 exited with code 0 after 0.0m I1016 17:33:19.782] Call: git show -s --format=format:%ct HEAD I1016 17:33:19.785] process 254 exited with code 0 after 0.0m I1016 17:33:19.785] Checkout: /go/src/k8s.io/cloud-provider-azure master:c470e6f36d76e5a565478fcba22118c06bc1548f,248:95c5c01d4ae3237e932ed7bae98f82bd66987c26 to /go/src/k8s.io/cloud-provider-azure I1016 17:33:19.785] Call: git init k8s.io/cloud-provider-azure I1016 17:33:19.789] Initialized empty Git repository in /go/src/k8s.io/cloud-provider-azure/.git/ I1016 17:33:19.790] process 255 exited with code 0 after 0.0m I1016 17:33:19.790] Call: git config --local user.name 'K8S Bootstrap' I1016 17:33:19.792] process 256 exited with code 0 after 0.0m I1016 17:33:19.792] Call: git config --local user.email k8s_bootstrap@localhost I1016 17:33:19.795] process 257 exited with code 0 after 0.0m I1016 17:33:19.795] Call: git fetch --quiet --tags https://github.com/kubernetes/cloud-provider-azure master +refs/pull/248/head:refs/pr/248 I1016 17:33:21.235] process 258 exited with code 0 after 0.0m I1016 17:33:21.236] Call: git checkout -B test c470e6f36d76e5a565478fcba22118c06bc1548f W1016 17:33:21.659] Switched to a new branch 'test' I1016 17:33:21.662] process 270 exited with code 0 after 0.0m I1016 17:33:21.662] Call: git show -s --format=format:%ct HEAD I1016 17:33:21.665] process 271 exited with code 0 after 0.0m I1016 17:33:21.665] Call: git merge --no-ff -m 'Merge +refs/pull/248/head:refs/pr/248' 95c5c01d4ae3237e932ed7bae98f82bd66987c26 I1016 17:33:22.163] Merge made by the 'recursive' strategy. I1016 17:33:22.163] hack/log-dump.sh | 161 +++++++++++++++++++++++++++++++++++++++++++++++++++++++ I1016 17:33:22.164] 1 file changed, 161 insertions(+) I1016 17:33:22.164] create mode 100755 hack/log-dump.sh I1016 17:33:22.164] process 272 exited with code 0 after 0.0m I1016 17:33:22.164] Configure environment... I1016 17:33:22.165] Call: git show -s --format=format:%ct HEAD I1016 17:33:22.168] process 274 exited with code 0 after 0.0m I1016 17:33:22.168] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1016 17:33:23.028] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1016 17:33:23.156] process 275 exited with code 0 after 0.0m I1016 17:33:23.157] Call: gcloud config get-value account I1016 17:33:23.415] process 287 exited with code 0 after 0.0m I1016 17:33:23.415] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1016 17:33:23.416] 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 ' I1016 17:33:23.847] process 299 exited with code 0 after 0.0m I1016 17:33:23.848] Start 1184522444090642432 at v1.16.3-beta.0.3+5cbf4aff372733... I1016 17:33:23.850] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil_w2ijYY gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184522444090642432/started.json I1016 17:33:25.452] process 332 exited with code 0 after 0.0m I1016 17:33:25.453] 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/1184522444090642432' cp /tmp/gsutil_3Jve9E gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/1184522444090642432.txt I1016 17:33:26.866] process 510 exited with code 0 after 0.0m I1016 17:33:26.867] 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=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/azure-ssh/azure-ssh-pub --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 W1016 17:33:26.908] starts with local mode W1016 17:33:26.908] Environment: W1016 17:33:26.909] ARTIFACTS=/workspace/_artifacts W1016 17:33:26.909] AWS_SSH_PRIVATE_KEY_FILE=/root/.ssh/kube_aws_rsa W1016 17:33:26.909] AWS_SSH_PUBLIC_KEY_FILE=/root/.ssh/kube_aws_rsa.pub W1016 17:33:26.909] AZURE_CREDENTIALS=/etc/azure-cred/credentials W1016 17:33:26.909] AZURE_SSH_PRIVATE_KEY_FILE=/etc/azure-ssh/azure-ssh W1016 17:33:26.909] AZURE_SSH_PUBLIC_KEY_FILE=/etc/azure-ssh/azure-ssh-pub W1016 17:33:26.910] AZURE_SSH_USER=azureuser W1016 17:33:26.910] AZ_STORAGE_CONTAINER_NAME=mystoragecontainer W1016 17:33:26.910] BAZEL_REMOTE_CACHE_ENABLED=false W1016 17:33:26.910] BAZEL_VERSION=0.28.1 W1016 17:33:26.910] BOOTSTRAP_MIGRATION=yes W1016 17:33:26.910] BUILD_ID=1184522444090642432 W1016 17:33:26.910] BUILD_NUMBER=1184522444090642432 W1016 17:33:26.910] CLOUDSDK_COMPONENT_MANAGER_DISABLE_UPDATE_CHECK=true W1016 17:33:26.911] CLOUDSDK_CONFIG=/go/src/k8s.io/kubernetes/.config/gcloud W1016 17:33:26.911] CLOUDSDK_CORE_DISABLE_PROMPTS=1 W1016 17:33:26.911] CLOUDSDK_EXPERIMENTAL_FAST_COMPONENT_UPDATE=false W1016 17:33:26.911] CLOUD_CONFIG=random W1016 17:33:26.911] DECK_PORT=tcp://10.0.160.83:80 W1016 17:33:26.911] DECK_PORT_80_TCP=tcp://10.0.160.83:80 W1016 17:33:26.911] DECK_PORT_80_TCP_ADDR=10.0.160.83 W1016 17:33:26.912] DECK_PORT_80_TCP_PORT=80 W1016 17:33:26.912] DECK_PORT_80_TCP_PROTO=tcp W1016 17:33:26.912] DECK_SERVICE_HOST=10.0.160.83 W1016 17:33:26.912] DECK_SERVICE_PORT=80 W1016 17:33:26.912] DOCKER_IN_DOCKER_ENABLED=true W1016 17:33:26.912] DOCKER_IN_DOCKER_IPV6_ENABLED=false W1016 17:33:26.912] GCS_ARTIFACTS_DIR=gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184522444090642432/artifacts W1016 17:33:26.913] GOOGLE_APPLICATION_CREDENTIALS=/etc/service-account/service-account.json W1016 17:33:26.913] GOPATH=/go W1016 17:33:26.913] GO_TARBALL=go1.12.10.linux-amd64.tar.gz W1016 17:33:26.913] HOME=/workspace W1016 17:33:26.913] HOOK_PORT=tcp://10.0.144.133:8888 W1016 17:33:26.913] HOOK_PORT_8888_TCP=tcp://10.0.144.133:8888 W1016 17:33:26.914] HOOK_PORT_8888_TCP_ADDR=10.0.144.133 W1016 17:33:26.914] HOOK_PORT_8888_TCP_PORT=8888 W1016 17:33:26.914] HOOK_PORT_8888_TCP_PROTO=tcp W1016 17:33:26.914] HOOK_SERVICE_HOST=10.0.144.133 W1016 17:33:26.914] HOOK_SERVICE_PORT=8888 W1016 17:33:26.914] HOSTNAME=d27c8cc8-f03a-11e9-b3d3-b20db476995a W1016 17:33:26.914] IMAGE=chewong/kubekins-e2e:v20191015-test W1016 17:33:26.915] INSTANCE_PREFIX=bootstrap-e2e W1016 17:33:26.915] JENKINS_GCE_SSH_PRIVATE_KEY_FILE=/root/.ssh/google_compute_engine W1016 17:33:26.915] JENKINS_GCE_SSH_PUBLIC_KEY_FILE=/root/.ssh/google_compute_engine.pub W1016 17:33:26.915] JOB_NAME=chewong-e2e-ccm W1016 17:33:26.915] JOB_SPEC={"type":"presubmit","job":"chewong-e2e-ccm","buildid":"1184522444090642432","prowjobid":"d27c8cc8-f03a-11e9-b3d3-b20db476995a","refs":{"org":"Azure","repo":"kubernetes","repo_link":"https://github.com/Azure/kubernetes","base_ref":"master","base_sha":"6b2b5f25fd5f12b251f9a7f8953da89c47741a95","base_link":"https://github.com/Azure/kubernetes/commit/6b2b5f25fd5f12b251f9a7f8953da89c47741a95","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"}]}} W1016 17:33:26.916] JOB_TYPE=presubmit W1016 17:33:26.916] KUBERNETES_PORT=tcp://10.0.0.1:443 W1016 17:33:26.916] KUBERNETES_PORT_443_TCP=tcp://10.0.0.1:443 W1016 17:33:26.916] KUBERNETES_PORT_443_TCP_ADDR=10.0.0.1 W1016 17:33:26.916] KUBERNETES_PORT_443_TCP_PORT=443 W1016 17:33:26.916] KUBERNETES_PORT_443_TCP_PROTO=tcp W1016 17:33:26.917] KUBERNETES_SERVICE_HOST=10.0.0.1 W1016 17:33:26.917] KUBERNETES_SERVICE_PORT=443 W1016 17:33:26.917] KUBERNETES_SERVICE_PORT_HTTPS=443 W1016 17:33:26.917] KUBETEST_IN_DOCKER=true W1016 17:33:26.917] KUBETEST_MANUAL_DUMP=y W1016 17:33:26.917] KUBE_AWS_INSTANCE_PREFIX=bootstrap-e2e W1016 17:33:26.918] KUBE_GCE_INSTANCE_PREFIX=bootstrap-e2e W1016 17:33:26.918] KUBE_VERBOSE=0 W1016 17:33:26.918] NODE_NAME=d27c8cc8-f03a-11e9-b3d3-b20db476995a W1016 17:33:26.918] 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 W1016 17:33:26.918] PROW_JOB_ID=d27c8cc8-f03a-11e9-b3d3-b20db476995a W1016 17:33:26.918] PULL_BASE_REF=master W1016 17:33:26.919] PULL_BASE_SHA=6b2b5f25fd5f12b251f9a7f8953da89c47741a95 W1016 17:33:26.919] PULL_NUMBER=113 W1016 17:33:26.919] PULL_PULL_SHA=879465972041635fd7bc8269da49153b67e63822 W1016 17:33:26.919] PULL_REFS=master:6b2b5f25fd5f12b251f9a7f8953da89c47741a95,113:879465972041635fd7bc8269da49153b67e63822 W1016 17:33:26.919] PWD=/workspace W1016 17:33:26.919] REGISTRY=k8sprowinternal.azurecr.io W1016 17:33:26.919] REPO_NAME=kubernetes W1016 17:33:26.920] REPO_OWNER=Azure W1016 17:33:26.920] SHLVL=2 W1016 17:33:26.920] SOURCE_DATE_EPOCH=1571209782 W1016 17:33:26.920] TERM=xterm W1016 17:33:26.920] TIDE_PORT=tcp://10.0.180.53:80 W1016 17:33:26.920] TIDE_PORT_80_TCP=tcp://10.0.180.53:80 W1016 17:33:26.921] TIDE_PORT_80_TCP_ADDR=10.0.180.53 W1016 17:33:26.921] TIDE_PORT_80_TCP_PORT=80 W1016 17:33:26.921] TIDE_PORT_80_TCP_PROTO=tcp W1016 17:33:26.921] TIDE_SERVICE_HOST=10.0.180.53 W1016 17:33:26.921] TIDE_SERVICE_PORT=80 W1016 17:33:26.921] WORKSPACE=/workspace W1016 17:33:26.921] _=./test-infra/jenkins/bootstrap.py W1016 17:33:26.922] 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=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/azure-ssh/azure-ssh-pub', '--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') W1016 17:33:26.925] 2019/10/16 17:33:26 main.go:332: Limiting testing to 7h0m0s W1016 17:33:26.925] 2019/10/16 17:33:26 azure.go:232: Reading credentials file /etc/azure-cred/credentials W1016 17:33:26.925] 2019/10/16 17:33:26 process.go:153: Running: make -C /go/src/k8s.io/kubernetes bazel-release W1016 17:33:26.953] Extracting Bazel installation... I1016 17:33:27.053] make: Entering directory '/go/src/k8s.io/kubernetes' W1016 17:33:33.700] Starting local Bazel server and connecting to it... W1016 17:33:35.271] Loading: W1016 17:33:35.274] Loading: 0 packages loaded W1016 17:33:36.277] Loading: 0 packages loaded W1016 17:33:38.011] Loading: 0 packages loaded W1016 17:33:39.279] Loading: 0 packages loaded W1016 17:33:41.405] Loading: 0 packages loaded W1016 17:33:43.280] Loading: 0 packages loaded W1016 17:33:43.280] currently loading: build/release-tars W1016 17:33:44.777] Loading: 0 packages loaded W1016 17:33:44.778] currently loading: build/release-tars W1016 17:33:45.153] Analyzing: target //build/release-tars:release-tars (1 packages loaded, 0 targets configured) W1016 17:33:46.685] Analyzing: target //build/release-tars:release-tars (274 packages loaded, 1430 targets configured) W1016 17:33:48.438] Analyzing: target //build/release-tars:release-tars (1258 packages loaded, 5322 targets configured) W1016 17:33:50.458] Analyzing: target //build/release-tars:release-tars (2275 packages loaded, 15239 targets configured) W1016 17:33:53.352] Analyzing: target //build/release-tars:release-tars (3036 packages loaded, 27392 targets configured) W1016 17:33:56.102] Analyzing: target //build/release-tars:release-tars (3058 packages loaded, 27920 targets configured) W1016 17:33:59.399] Analyzing: target //build/release-tars:release-tars (3073 packages loaded, 34098 targets configured) W1016 17:34:06.081] Analyzing: target //build/release-tars:release-tars (3080 packages loaded, 36605 targets configured) W1016 17:34:15.402] Analyzing: target //build/release-tars:release-tars (3081 packages loaded, 42452 targets configured) W1016 17:34:17.882] INFO: Analyzed target //build/release-tars:release-tars (3081 packages loaded, 42566 targets configured). W1016 17:34:17.885] INFO: Found 1 target... W1016 17:34:18.023] [0 / 41] [Prepa] BazelWorkspaceStatusAction stable-status.txt W1016 17:34:24.562] [30 / 112] GoCompile vendor/golang.org/x/tools/go/internal/gcimporter/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/golang.org/x/tools/go/internal/gcimporter.a [for host]; 4s linux-sandbox ... (5 actions, 4 running) W1016 17:34:35.336] [76 / 594] GoCompile vendor/golang.org/x/tools/internal/imports/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/golang.org/x/tools/internal/imports.a [for host]; 4s linux-sandbox ... (8 actions running) W1016 17:34:44.386] [106 / 816] GoCompile vendor/github.com/google/go-cmp/cmp/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/google/go-cmp/cmp.a; 2s linux-sandbox ... (8 actions running) W1016 17:34:54.792] [323 / 816] GoPath staging/src/k8s.io/apiextensions-apiserver/pkg/generated/openapi/zz_generated.openapi~gopath/src/k8s.io/kubernetes/vendor/github.com/go-openapi/spec/bindata.go; 2s linux-sandbox ... (8 actions running) W1016 17:35:08.156] [380 / 816] ; 8s linux-sandbox ... (8 actions running) W1016 17:35:22.204] [446 / 826] ; 22s linux-sandbox ... (8 actions running) W1016 17:35:47.223] [498 / 2,102] GoCompile vendor/github.com/json-iterator/go/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/json-iterator/go.a; 11s linux-sandbox ... (8 actions running) W1016 17:36:09.670] [754 / 2,196] GoCompile pkg/apis/core/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/pkg/apis/core.a; 3s linux-sandbox ... (8 actions running) W1016 17:36:32.157] [886 / 2,196] GoCompile staging/src/k8s.io/client-go/kubernetes/typed/core/v1/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/client-go/kubernetes/typed/core/v1.a; 2s linux-sandbox ... (8 actions, 7 running) W1016 17:36:59.439] [1,075 / 2,205] GoCompile staging/src/k8s.io/client-go/listers/core/v1/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/client-go/listers/core/v1.a; 3s linux-sandbox ... (8 actions running) W1016 17:37:30.211] [1,348 / 2,286] 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; 2s linux-sandbox ... (7 actions, 6 running) W1016 17:38:05.525] [1,970 / 2,544] GoCompile staging/src/k8s.io/apiserver/pkg/apis/audit/v1/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/apiserver/pkg/apis/audit/v1.a; 1s linux-sandbox ... (8 actions, 7 running) W1016 17:38:46.172] [2,207 / 2,544] GoCompile staging/src/k8s.io/client-go/informers/storage/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/client-go/informers/storage.a; 2s linux-sandbox ... (8 actions, 7 running) W1016 17:39:32.936] [2,469 / 3,046] GoCompile staging/src/k8s.io/legacy-cloud-providers/gce/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/legacy-cloud-providers/gce.a; 2s linux-sandbox ... (8 actions, 7 running) W1016 17:40:26.685] [2,733 / 3,096] GoLink cmd/kubemark/kubemark; 16s linux-sandbox ... (8 actions, 7 running) W1016 17:41:28.650] [3,138 / 3,226] GoCompile cmd/kube-apiserver/app/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/cmd/kube-apiserver/app.a; 3s linux-sandbox ... (8 actions running) W1016 17:42:40.186] [3,280 / 5,297] GoLink cmd/genman/genman; 56s linux-sandbox ... (8 actions, 7 running) W1016 17:44:19.096] [3,393 / 5,297] GoLink cmd/genman/genman; 138s linux-sandbox ... (8 actions, 7 running) W1016 17:45:38.910] [3,856 / 5,297] PackageTar build/release-tars/kubernetes-test-linux-amd64.tar.gz; 40s linux-sandbox ... (8 actions, 7 running) W1016 17:47:29.822] [4,431 / 5,305] GoCompile staging/src/k8s.io/api/apps/v1beta1/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/api/apps/v1beta1.a; 3s linux-sandbox ... (8 actions, 7 running) W1016 17:49:35.371] [5,042 / 5,305] GoCompile pkg/volume/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/pkg/volume.a; 4s linux-sandbox ... (8 actions, 7 running) W1016 17:52:02.617] [5,304 / 5,305] PackageTar build/release-tars/kubernetes-server-linux-amd64.tar.gz; 11s linux-sandbox W1016 17:52:09.629] Target //build/release-tars:release-tars up-to-date: W1016 17:52:09.634] bazel-bin/build/release-tars/kubernetes-client-linux-amd64.tar.gz W1016 17:52:09.634] bazel-bin/build/release-tars/kubernetes-node-linux-amd64.tar.gz W1016 17:52:09.634] bazel-bin/build/release-tars/kubernetes-server-linux-amd64.tar.gz W1016 17:52:09.634] bazel-bin/build/release-tars/kubernetes-manifests.tar.gz W1016 17:52:09.635] bazel-bin/build/release-tars/kubernetes-test-portable.tar.gz W1016 17:52:09.635] bazel-bin/build/release-tars/kubernetes-test-linux-amd64.tar.gz W1016 17:52:09.636] bazel-bin/build/release-tars/kubernetes-test.tar.gz W1016 17:52:09.636] bazel-bin/build/release-tars/kubernetes.tar.gz W1016 17:52:09.636] bazel-bin/build/release-tars/kubernetes-src.tar.gz W1016 17:52:09.676] INFO: Elapsed time: 1122.667s, Critical Path: 372.05s W1016 17:52:09.677] INFO: 5211 processes: 5211 linux-sandbox. W1016 17:52:09.681] INFO: Build completed successfully, 5305 total actions W1016 17:52:09.683] INFO: Build completed successfully, 5305 total actions W1016 17:52:09.693] 2019/10/16 17:52:09 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes bazel-release' finished in 18m42.767041983s W1016 17:52:09.693] 2019/10/16 17:52:09 util.go:277: Flushing memory. I1016 17:52:09.794] make: Leaving directory '/go/src/k8s.io/kubernetes' W1016 17:52:35.574] 2019/10/16 17:52:35 azure.go:906: Deleting resource group: kubetest-0fbc6bf8-f03b-11e9-a0ef-024283cc24c7. W1016 17:52:36.088] 2019/10/16 17:52:36 azure.go:654: CWD /go/src/k8s.io/kubernetes W1016 17:52:36.089] 2019/10/16 17:52:36 azure.go:673: Attempting Docker login with azure cred. W1016 17:52:37.536] 2019/10/16 17:52:37 azure.go:682: Docker login success. W1016 17:52:37.536] 2019/10/16 17:52:37 azure.go:697: Building ccm. W1016 17:52:37.536] 2019/10/16 17:52:37 azure.go:699: projectPath /go/src/k8s.io/cloud-provider-azure W1016 17:52:37.537] 2019/10/16 17:52:37 process.go:153: Running: docker build -t k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184522444090642432-bcb0d3ad . I1016 17:52:39.695] Sending build context to Docker daemon 67.18MB I1016 17:52:39.749] Step 1/7 : FROM golang:1.12.9-stretch AS build I1016 17:52:40.663] 1.12.9-stretch: Pulling from library/golang I1016 17:52:41.065] 092586df9206: Pulling fs layer I1016 17:52:41.066] ef599477fae0: Pulling fs layer I1016 17:52:41.066] 4530c6472b5d: Pulling fs layer I1016 17:52:41.066] d34d61487075: Pulling fs layer I1016 17:52:41.066] 89c6ec31b9e9: Pulling fs layer I1016 17:52:41.066] e37857ebcafa: Pulling fs layer I1016 17:52:41.066] b0e29f6c7f0a: Pulling fs layer I1016 17:52:41.066] b0e29f6c7f0a: Waiting I1016 17:52:41.066] e37857ebcafa: Waiting I1016 17:52:41.067] 89c6ec31b9e9: Waiting I1016 17:52:41.067] d34d61487075: Waiting I1016 17:52:41.479] 4530c6472b5d: Verifying Checksum I1016 17:52:41.479] 4530c6472b5d: Download complete I1016 17:52:41.542] ef599477fae0: Verifying Checksum I1016 17:52:41.542] ef599477fae0: Download complete I1016 17:52:42.317] d34d61487075: Verifying Checksum I1016 17:52:42.318] d34d61487075: Download complete I1016 17:52:42.616] 092586df9206: Verifying Checksum I1016 17:52:42.617] 092586df9206: Download complete I1016 17:52:43.034] b0e29f6c7f0a: Verifying Checksum I1016 17:52:43.035] b0e29f6c7f0a: Download complete I1016 17:52:44.008] e37857ebcafa: Verifying Checksum I1016 17:52:44.009] e37857ebcafa: Download complete I1016 17:52:45.774] 092586df9206: Pull complete I1016 17:52:45.978] 89c6ec31b9e9: Verifying Checksum I1016 17:52:45.978] 89c6ec31b9e9: Download complete I1016 17:52:46.549] ef599477fae0: Pull complete I1016 17:52:46.873] 4530c6472b5d: Pull complete I1016 17:52:50.606] d34d61487075: Pull complete I1016 17:52:54.237] 89c6ec31b9e9: Pull complete I1016 17:53:01.939] e37857ebcafa: Pull complete I1016 17:53:02.093] b0e29f6c7f0a: Pull complete I1016 17:53:02.115] Digest: sha256:76b52857546f070cc3ac499accb27b8c411b10ff6d45c0b1da2a8aab7b61fe29 I1016 17:53:02.132] Status: Downloaded newer image for golang:1.12.9-stretch I1016 17:53:02.132] ---> 2c4a601e5da9 I1016 17:53:02.132] Step 2/7 : WORKDIR /go/src/k8s.io/cloud-provider-azure I1016 17:53:13.599] ---> Running in 0cf28af4b585 I1016 17:53:14.752] Removing intermediate container 0cf28af4b585 I1016 17:53:14.752] ---> bc193171b906 I1016 17:53:14.753] Step 3/7 : COPY . . I1016 17:53:20.567] ---> af6c3b86c268 I1016 17:53:20.567] Step 4/7 : RUN make I1016 17:53:20.757] ---> Running in acd620005322 I1016 17:53:21.594] hack/pkg-config.sh > .pkg_config I1016 17:53:21.617] 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-16T17:53:21Z' ./cmd/cloud-controller-manager I1016 17:54:03.633] 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-16T17:53:21Z' ./cmd/cloud-node-manager I1016 17:54:27.593] Removing intermediate container acd620005322 I1016 17:54:27.593] ---> f376d5506530 I1016 17:54:27.594] Step 5/7 : FROM k8s.gcr.io/debian-base:v1.0.0 I1016 17:54:27.890] v1.0.0: Pulling from debian-base I1016 17:54:28.053] 39fafc05754f: Pulling fs layer I1016 17:54:28.441] 39fafc05754f: Verifying Checksum I1016 17:54:28.441] 39fafc05754f: Download complete I1016 17:54:30.910] 39fafc05754f: Pull complete I1016 17:54:30.933] Digest: sha256:3801f944c765dc1b54900826ca67b1380bb8c73b9caf4a2a27ce613b3ba3e742 I1016 17:54:30.954] Status: Downloaded newer image for k8s.gcr.io/debian-base:v1.0.0 I1016 17:54:30.954] ---> 204e96332c91 I1016 17:54:30.954] Step 6/7 : COPY --from=build /go/src/k8s.io/cloud-provider-azure/bin/azure-cloud-controller-manager /usr/local/bin I1016 17:54:34.033] ---> be804b3099ac I1016 17:54:34.033] Step 7/7 : RUN ln -s /usr/local/bin/azure-cloud-controller-manager /usr/local/bin/cloud-controller-manager I1016 17:54:34.315] ---> Running in 301dbe8dc862 I1016 17:54:36.052] Removing intermediate container 301dbe8dc862 I1016 17:54:36.052] ---> 47e3f59cbdc9 I1016 17:54:36.161] Successfully built 47e3f59cbdc9 I1016 17:54:36.335] Successfully tagged k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184522444090642432-bcb0d3ad W1016 17:54:36.435] 2019/10/16 17:54:36 process.go:155: Step 'docker build -t k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184522444090642432-bcb0d3ad .' finished in 1m58.803128991s W1016 17:54:36.436] 2019/10/16 17:54:36 process.go:153: Running: docker push k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184522444090642432-bcb0d3ad W1016 17:54:40.887] 2019/10/16 17:54:40 process.go:155: Step 'docker push k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184522444090642432-bcb0d3ad' finished in 4.548037087s W1016 17:54:40.888] 2019/10/16 17:54:40 azure.go:686: Docker logout. W1016 17:54:40.946] 2019/10/16 17:54:40 azure.go:716: Custom cloud controller manager URL: k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184522444090642432-bcb0d3ad . W1016 17:54:40.946] 2019/10/16 17:54:40 azure.go:654: CWD /go/src/k8s.io/kubernetes W1016 17:54:40.946] 2019/10/16 17:54:40 azure.go:673: Attempting Docker login with azure cred. W1016 17:54:41.814] 2019/10/16 17:54:41 azure.go:682: Docker login success. W1016 17:54:41.814] 2019/10/16 17:54:41 azure.go:726: Building hyperkube. W1016 17:54:41.814] 2019/10/16 17:54:41 process.go:153: Running: make -C /go/src/k8s.io/kubernetes WHAT=cmd/hyperkube W1016 17:55:18.492] found packages rand (cgo1.go) and rand2 (cgo2.go) in /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/bazel-kubernetes/external/go_sdk/doc/progs W1016 17:58:02.319] 2019/10/16 17:58:02 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes WHAT=cmd/hyperkube' finished in 3m20.50441617s W1016 17:58:02.319] 2019/10/16 17:58:02 azure.go:733: Pushing hyperkube. W1016 17:58:02.319] 2019/10/16 17:58:02 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 I1016 17:58:02.420] make: Entering directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube' I1016 17:58:02.420] cp -r ./* /tmp/hyperkubenSsBNW I1016 17:58:02.420] cp /go/src/k8s.io/kubernetes/_output/bin/hyperkube /tmp/hyperkubenSsBNW I1016 17:58:02.499] chmod a+rx /tmp/hyperkubenSsBNW/hyperkube I1016 17:58:02.501] cd /tmp/hyperkubenSsBNW && sed -i.back "s|BASEIMAGE|k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1|g" Dockerfile I1016 17:58:02.504] docker build --pull -t k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184522444090642432-071c915b /tmp/hyperkubenSsBNW I1016 17:58:03.741] Sending build context to Docker daemon 212.1MB I1016 17:58:03.782] Step 1/2 : FROM k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1 I1016 17:58:04.092] 0.12.1: Pulling from debian-hyperkube-base-amd64 I1016 17:58:04.092] 346aee5ea5bc: Pulling fs layer I1016 17:58:04.092] 9c47fde751af: Pulling fs layer I1016 17:58:04.092] be2693a52daf: Pulling fs layer I1016 17:58:04.092] 6b69eb11d043: Pulling fs layer I1016 17:58:04.093] 0abeb1500767: Pulling fs layer I1016 17:58:04.093] 4062d80041b7: Pulling fs layer I1016 17:58:04.093] 23b6daf06fc2: Pulling fs layer I1016 17:58:04.093] 6b69eb11d043: Waiting I1016 17:58:04.093] 0abeb1500767: Waiting I1016 17:58:04.233] 9c47fde751af: Verifying Checksum I1016 17:58:04.259] be2693a52daf: Verifying Checksum I1016 17:58:04.259] be2693a52daf: Download complete I1016 17:58:04.371] 6b69eb11d043: Verifying Checksum I1016 17:58:04.371] 6b69eb11d043: Download complete I1016 17:58:04.392] 0abeb1500767: Verifying Checksum I1016 17:58:04.393] 0abeb1500767: Download complete I1016 17:58:04.482] 346aee5ea5bc: Verifying Checksum I1016 17:58:04.483] 346aee5ea5bc: Download complete I1016 17:58:05.052] 23b6daf06fc2: Verifying Checksum I1016 17:58:05.053] 23b6daf06fc2: Download complete I1016 17:58:06.047] 4062d80041b7: Verifying Checksum I1016 17:58:07.705] 346aee5ea5bc: Pull complete I1016 17:58:07.878] 9c47fde751af: Pull complete I1016 17:58:08.076] be2693a52daf: Pull complete I1016 17:58:08.226] 6b69eb11d043: Pull complete I1016 17:58:08.409] 0abeb1500767: Pull complete I1016 17:58:16.619] 4062d80041b7: Pull complete I1016 17:58:17.632] 23b6daf06fc2: Pull complete I1016 17:58:17.663] Digest: sha256:5d4ea2fb5fbe9a9a9da74f67cf2faefc881968bc39f2ac5d62d9167e575812a1 I1016 17:58:17.687] Status: Downloaded newer image for k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1 I1016 17:58:17.688] ---> a46476511725 I1016 17:58:17.688] Step 2/2 : COPY hyperkube /hyperkube I1016 17:58:41.106] ---> 81348db1d05b I1016 17:58:41.135] Successfully built 81348db1d05b I1016 17:58:41.202] Successfully tagged k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184522444090642432-071c915b I1016 17:58:41.205] rm -rf "/tmp/hyperkubenSsBNW" I1016 17:58:41.236] docker push k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184522444090642432-071c915b I1016 17:58:41.304] The push refers to repository [k8sprowinternal.azurecr.io/hyperkube-amd64] I1016 17:58:41.340] e1e61b8c4f6a: Preparing I1016 17:58:41.341] 39b3ac6d96e9: Preparing I1016 17:58:41.341] 7bbae4dddb88: Preparing I1016 17:58:41.341] a00defcfe869: Preparing I1016 17:58:41.341] 2ab0ae805c74: Preparing I1016 17:58:41.341] 43a8fe7d2382: Preparing I1016 17:58:41.341] 3f6a6f542637: Preparing I1016 17:58:41.341] 5ba3be777c2d: Preparing I1016 17:58:41.342] 43a8fe7d2382: Waiting I1016 17:58:41.342] 3f6a6f542637: Waiting I1016 17:58:41.342] 5ba3be777c2d: Waiting I1016 17:58:41.539] a00defcfe869: Layer already exists I1016 17:58:41.561] 7bbae4dddb88: Layer already exists I1016 17:58:41.583] 39b3ac6d96e9: Layer already exists I1016 17:58:41.607] 2ab0ae805c74: Layer already exists I1016 17:58:41.640] 3f6a6f542637: Layer already exists I1016 17:58:41.663] 43a8fe7d2382: Layer already exists I1016 17:58:41.688] 5ba3be777c2d: Layer already exists I1016 17:58:51.743] e1e61b8c4f6a: Pushed I1016 17:58:52.399] azure-e2e-1184522444090642432-071c915b: digest: sha256:a28b2dc1ff5090bf81c0f8945bc671217b5662bfa46b789b1cd18c1ac44096de size: 1998 I1016 17:58:52.417] docker rmi k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1184522444090642432-071c915b 2>/dev/null || true I1016 17:58:52.456] docker tag k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184522444090642432-071c915b k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1184522444090642432-071c915b I1016 17:58:52.518] docker push k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1184522444090642432-071c915b I1016 17:58:52.576] The push refers to repository [k8sprowinternal.azurecr.io/hyperkube] I1016 17:58:52.587] e1e61b8c4f6a: Preparing I1016 17:58:52.587] 39b3ac6d96e9: Preparing I1016 17:58:52.587] 7bbae4dddb88: Preparing I1016 17:58:52.588] a00defcfe869: Preparing I1016 17:58:52.588] 2ab0ae805c74: Preparing I1016 17:58:52.588] 43a8fe7d2382: Preparing I1016 17:58:52.588] 3f6a6f542637: Preparing I1016 17:58:52.588] 5ba3be777c2d: Preparing I1016 17:58:52.588] 3f6a6f542637: Waiting I1016 17:58:52.588] 5ba3be777c2d: Waiting I1016 17:58:52.589] 43a8fe7d2382: Waiting I1016 17:58:52.918] 2ab0ae805c74: Layer already exists I1016 17:58:52.942] a00defcfe869: Layer already exists I1016 17:58:52.966] 7bbae4dddb88: Layer already exists I1016 17:58:53.000] 39b3ac6d96e9: Layer already exists I1016 17:58:53.011] 43a8fe7d2382: Layer already exists I1016 17:58:53.032] 5ba3be777c2d: Layer already exists I1016 17:58:53.055] e1e61b8c4f6a: Mounted from hyperkube-amd64 I1016 17:58:53.145] 3f6a6f542637: Layer already exists I1016 17:58:53.620] azure-e2e-1184522444090642432-071c915b: digest: sha256:a28b2dc1ff5090bf81c0f8945bc671217b5662bfa46b789b1cd18c1ac44096de size: 1998 I1016 17:58:53.637] make: Leaving directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube' W1016 17:58:53.737] 2019/10/16 17:58:53 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 51.318511585s W1016 17:58:53.738] 2019/10/16 17:58:53 azure.go:686: Docker logout. W1016 17:58:53.738] 2019/10/16 17:58:53 azure.go:744: Custom hyperkube URL: k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184522444090642432-071c915b . W1016 17:58:53.738] 2019/10/16 17:58:53 azure.go:787: downloading /workspace/aks429022649/kubernetes.json from https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json. W1016 17:58:53.738] 2019/10/16 17:58:53 util.go:42: curl https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json W1016 17:58:54.198] 2019/10/16 17:58:54 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. W1016 17:58:54.198] 2019/10/16 17:58:54 util.go:42: curl https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz W1016 17:58:55.430] 2019/10/16 17:58:55 azure.go:556: Extracting tar file /workspace/aks-engine.tar.gz into directory /go/src/k8s.io/kubernetes . W1016 17:58:55.431] 2019/10/16 17:58:55 process.go:153: Running: tar -xzf /workspace/aks-engine.tar.gz --strip 1 W1016 17:58:55.592] 2019/10/16 17:58:55 process.go:155: Step 'tar -xzf /workspace/aks-engine.tar.gz --strip 1' finished in 161.691256ms W1016 17:58:55.592] 2019/10/16 17:58:55 process.go:153: Running: /go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks429022649/kubernetes.json --output-directory /workspace/aks429022649 I1016 17:58:55.806] INFO[0000] Generating assets into /workspace/aks429022649... W1016 17:59:08.082] 2019/10/16 17:59:08 process.go:155: Step '/go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks429022649/kubernetes.json --output-directory /workspace/aks429022649' finished in 12.489806391s W1016 17:59:08.086] 2019/10/16 17:59:08 azure.go:627: Setting kubeconfig env variable: kubeconfig path: /workspace/aks429022649/kubeconfig/kubeconfig.eastus2.json. W1016 17:59:08.086] 2019/10/16 17:59:08 azure.go:629: Creating resource group: kubetest-0fbc6bf8-f03b-11e9-a0ef-024283cc24c7. W1016 17:59:08.087] 2019/10/16 17:59:08 azure.go:631: Creating Azure resource group: kubetest-0fbc6bf8-f03b-11e9-a0ef-024283cc24c7 for cluster deployment. W1016 17:59:10.317] 2019/10/16 17:59:10 azure.go:636: Validating deployment ARM templates. W1016 17:59:12.373] 2019/10/16 17:59:12 azure.go:642: Deploying cluster kubetest-0fbc6bf8-f03b-11e9-a0ef-024283cc24c7 in resource group kubetest-0fbc6bf8-f03b-11e9-a0ef-024283cc24c7. W1016 18:10:21.187] 2019/10/16 18:10:21 process.go:153: Running: ./cluster/kubectl.sh --match-server-version=false version W1016 18:10:21.867] 2019/10/16 18:10:21 process.go:155: Step './cluster/kubectl.sh --match-server-version=false version' finished in 680.776492ms W1016 18:10:21.868] 2019/10/16 18:10:21 process.go:153: Running: ./cluster/kubectl.sh --match-server-version=false get nodes -oyaml W1016 18:10:23.210] 2019/10/16 18:10:23 process.go:155: Step './cluster/kubectl.sh --match-server-version=false get nodes -oyaml' finished in 1.342144933s W1016 18:10:23.210] 2019/10/16 18:10:23 azure.go:963: KUBE_TEST_REPO_LIST_DOWNLOAD_LOCATION not set. Using default test image repos. W1016 18:10:23.210] 2019/10/16 18:10:23 azure.go:963: KUBE_TEST_REPO_LIST_DOWNLOAD_LOCATION not set. Using default test image repos. W1016 18:10:23.211] 2019/10/16 18:10:23 process.go:153: Running: kubectl get nodes --no-headers W1016 18:10:23.832] 2019/10/16 18:10:23 process.go:155: Step 'kubectl get nodes --no-headers' finished in 621.514032ms W1016 18:10:23.832] 2019/10/16 18:10:23 e2e.go:462: Cluster nodes: W1016 18:10:23.833] k8s-agentpool1-10155636-0 Ready 44s v1.16.3-beta.0.3+5cbf4aff372733 W1016 18:10:23.833] k8s-master-10155636-0 Ready master 94s v1.16.3-beta.0.3+5cbf4aff372733 W1016 18:10:23.833] 2019/10/16 18:10:23 process.go:153: Running: ./cluster/kubectl.sh --match-server-version=false version W1016 18:10:24.271] 2019/10/16 18:10:24 process.go:155: Step './cluster/kubectl.sh --match-server-version=false version' finished in 438.434608ms W1016 18:10:24.271] 2019/10/16 18:10:24 process.go:153: Running: /workspace/_artifacts W1016 18:10:24.272] 2019/10/16 18:10:24 process.go:155: Step '/workspace/_artifacts' finished in 1.31061ms W1016 18:10:24.272] 2019/10/16 18:10:24 azure.go:906: Deleting resource group: kubetest-0fbc6bf8-f03b-11e9-a0ef-024283cc24c7. W1016 18:20:18.667] 2019/10/16 18:20:18 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml. W1016 18:20:18.667] 2019/10/16 18:20:18 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}" W1016 18:20:18.811] 2019/10/16 18:20:18 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 144.162444ms W1016 18:20:18.812] 2019/10/16 18:20:18 main.go:319: Something went wrong: encountered 1 errors: [error starting /workspace/_artifacts: fork/exec ./hack/log-dump.sh: exec format error] W1016 18:20:18.816] Traceback (most recent call last): W1016 18:20:18.817] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in W1016 18:20:18.817] main(parse_args()) W1016 18:20:18.817] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main W1016 18:20:18.817] mode.start(runner_args) W1016 18:20:18.818] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start W1016 18:20:18.818] check_env(env, self.command, *args) W1016 18:20:18.818] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env W1016 18:20:18.818] subprocess.check_call(cmd, env=env) W1016 18:20:18.818] File "/usr/lib/python2.7/subprocess.py", line 186, in check_call W1016 18:20:18.818] raise CalledProcessError(retcode, cmd) W1016 18:20:18.819] 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=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/azure-ssh/azure-ssh-pub', '--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 E1016 18:20:18.827] Command failed I1016 18:20:18.827] process 688 exited with code 1 after 46.9m E1016 18:20:18.828] FAIL: chewong-e2e-ccm I1016 18:20:18.828] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1016 18:20:19.672] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1016 18:20:19.704] process 3124 exited with code 0 after 0.0m I1016 18:20:19.704] Call: gcloud config get-value account I1016 18:20:19.950] process 3136 exited with code 0 after 0.0m I1016 18:20:19.950] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1016 18:20:19.950] Upload result and artifacts... I1016 18:20:19.950] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184522444090642432 I1016 18:20:19.951] Call: gsutil ls gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184522444090642432/artifacts W1016 18:20:21.302] CommandException: One or more URLs matched no objects. E1016 18:20:21.380] Command failed I1016 18:20:21.380] process 3148 exited with code 1 after 0.0m W1016 18:20:21.380] Remote dir gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184522444090642432/artifacts not exist yet I1016 18:20:21.380] 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/1184522444090642432/artifacts I1016 18:20:22.916] process 3290 exited with code 0 after 0.0m I1016 18:20:22.917] Call: git rev-parse HEAD I1016 18:20:22.920] process 3817 exited with code 0 after 0.0m I1016 18:20:22.921] Call: git rev-parse HEAD I1016 18:20:22.924] process 3818 exited with code 0 after 0.0m I1016 18:20:22.925] Call: gsutil stat gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json I1016 18:20:23.954] process 3819 exited with code 0 after 0.0m I1016 18:20:23.955] Call: gsutil -q cat 'gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json#1571184050704716' I1016 18:20:25.134] process 3961 exited with code 0 after 0.0m I1016 18:20:25.134] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1571184050704716 cp /tmp/gsutil_Ri5yl8 gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json I1016 18:20:26.540] process 4105 exited with code 0 after 0.0m I1016 18:20:26.540] Call: gsutil stat gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json I1016 18:20:27.548] process 4283 exited with code 0 after 0.0m I1016 18:20:27.548] Call: gsutil -q cat 'gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json#1571184054313074' I1016 18:20:28.756] process 4425 exited with code 0 after 0.0m I1016 18:20:28.757] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1571184054313074 cp /tmp/gsutil_kiA4PN gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json I1016 18:20:30.222] process 4569 exited with code 0 after 0.0m I1016 18:20:30.223] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil_S90JTU gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184522444090642432/finished.json I1016 18:20:31.625] process 4747 exited with code 0 after 0.0m I1016 18:20:31.625] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_J_LAMY gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/latest-build.txt I1016 18:20:32.990] process 4925 exited with code 0 after 0.0m I1016 18:20:32.991] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_AmTHlX gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/latest-build.txt I1016 18:20:34.325] process 5103 exited with code 0 after 0.0m