W1015 23:33:13.653] **************************************************************************
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
**************************************************************************
I1015 23:33:13.653] 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=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.36.5/aks-engine-v0.36.5-linux-amd64.tar.gz --timeout=420m
I1015 23:33:13.654] Bootstrap chewong-e2e-ccm...
I1015 23:33:13.657] Builder: 0b07d68c-efa4-11e9-b3d3-b20db476995a
I1015 23:33:13.657] Image: chewong/kubekins-e2e:v20191015-test
I1015 23:33:13.658] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184250779020562432
I1015 23:33:13.658] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W1015 23:33:14.192] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I1015 23:33:14.223] process 213 exited with code 0 after 0.0m
I1015 23:33:14.224] Call:  gcloud config get-value account
I1015 23:33:14.454] process 225 exited with code 0 after 0.0m
I1015 23:33:14.455] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
I1015 23:33:14.455] Root: /go/src
I1015 23:33:14.455] cd to /go/src
I1015 23:33:14.455] Checkout: /go/src/k8s.io/kubernetes master to /go/src/k8s.io/kubernetes
I1015 23:33:14.455] Call:  git init k8s.io/kubernetes
I1015 23:33:14.459] Initialized empty Git repository in /go/src/k8s.io/kubernetes/.git/
I1015 23:33:14.460] process 237 exited with code 0 after 0.0m
I1015 23:33:14.460] Call:  git config --local user.name 'K8S Bootstrap'
I1015 23:33:14.462] process 238 exited with code 0 after 0.0m
I1015 23:33:14.462] Call:  git config --local user.email k8s_bootstrap@localhost
I1015 23:33:14.465] process 239 exited with code 0 after 0.0m
I1015 23:33:14.465] Call:  git fetch --quiet --tags https://github.com/kubernetes/kubernetes master
I1015 23:34:06.835] process 240 exited with code 0 after 0.9m
I1015 23:34:06.835] Call:  git checkout -B test FETCH_HEAD
W1015 23:34:08.882] Switched to a new branch 'test'
I1015 23:34:08.891] process 252 exited with code 0 after 0.0m
I1015 23:34:08.891] Call:  git show -s --format=format:%ct HEAD
I1015 23:34:08.909] process 253 exited with code 0 after 0.0m
I1015 23:34:08.910] Checkout: /go/src/k8s.io/cloud-provider-azure master:c470e6f36d76e5a565478fcba22118c06bc1548f,248:95c5c01d4ae3237e932ed7bae98f82bd66987c26 to /go/src/k8s.io/cloud-provider-azure
I1015 23:34:08.910] Call:  git init k8s.io/cloud-provider-azure
I1015 23:34:08.914] Initialized empty Git repository in /go/src/k8s.io/cloud-provider-azure/.git/
I1015 23:34:08.914] process 254 exited with code 0 after 0.0m
I1015 23:34:08.914] Call:  git config --local user.name 'K8S Bootstrap'
I1015 23:34:08.916] process 255 exited with code 0 after 0.0m
I1015 23:34:08.916] Call:  git config --local user.email k8s_bootstrap@localhost
I1015 23:34:08.919] process 256 exited with code 0 after 0.0m
I1015 23:34:08.919] Call:  git fetch --quiet --tags https://github.com/kubernetes/cloud-provider-azure master +refs/pull/248/head:refs/pr/248
I1015 23:34:10.395] process 257 exited with code 0 after 0.0m
I1015 23:34:10.395] Call:  git checkout -B test c470e6f36d76e5a565478fcba22118c06bc1548f
W1015 23:34:10.816] Switched to a new branch 'test'
I1015 23:34:10.819] process 269 exited with code 0 after 0.0m
I1015 23:34:10.819] Call:  git show -s --format=format:%ct HEAD
I1015 23:34:10.822] process 270 exited with code 0 after 0.0m
I1015 23:34:10.823] Call:  git merge --no-ff -m 'Merge +refs/pull/248/head:refs/pr/248' 95c5c01d4ae3237e932ed7bae98f82bd66987c26
I1015 23:34:11.159] Merge made by the 'recursive' strategy.
I1015 23:34:11.161]  hack/log-dump.sh | 161 +++++++++++++++++++++++++++++++++++++++++++++++++++++++
I1015 23:34:11.161]  1 file changed, 161 insertions(+)
I1015 23:34:11.161]  create mode 100755 hack/log-dump.sh
I1015 23:34:11.161] process 271 exited with code 0 after 0.0m
I1015 23:34:11.162] Configure environment...
I1015 23:34:11.162] Call:  git show -s --format=format:%ct HEAD
I1015 23:34:11.180] process 273 exited with code 0 after 0.0m
I1015 23:34:11.180] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W1015 23:34:11.836] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I1015 23:34:11.946] process 274 exited with code 0 after 0.0m
I1015 23:34:11.946] Call:  gcloud config get-value account
I1015 23:34:12.185] process 286 exited with code 0 after 0.0m
I1015 23:34:12.185] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
I1015 23:34:12.185] 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
'
I1015 23:34:12.745] process 298 exited with code 0 after 0.0m
I1015 23:34:12.746] Start 1184250779020562432 at v1.17.0-alpha.2.13+0a08798b9a6867...
I1015 23:34:12.747] Call:  gsutil -q -h Content-Type:application/json cp /tmp/gsutil_jAar3a gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184250779020562432/started.json
I1015 23:34:14.276] process 331 exited with code 0 after 0.0m
I1015 23:34:14.277] 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/1184250779020562432' cp /tmp/gsutil_GXrsxC gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/1184250779020562432.txt
I1015 23:34:15.817] process 509 exited with code 0 after 0.0m
I1015 23:34:15.818] 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.36.5/aks-engine-v0.36.5-linux-amd64.tar.gz --timeout=420m
W1015 23:34:15.855] starts with local mode
W1015 23:34:15.856] Environment:
W1015 23:34:15.856] ARTIFACTS=/workspace/_artifacts
W1015 23:34:15.856] AWS_SSH_PRIVATE_KEY_FILE=/root/.ssh/kube_aws_rsa
W1015 23:34:15.856] AWS_SSH_PUBLIC_KEY_FILE=/root/.ssh/kube_aws_rsa.pub
W1015 23:34:15.856] AZURE_CREDENTIALS=/etc/azure-cred/credentials
W1015 23:34:15.856] AZURE_SSH_PRIVATE_KEY_FILE=/etc/azure-ssh/azure-ssh
W1015 23:34:15.857] AZURE_SSH_PUBLIC_KEY_FILE=/etc/azure-ssh/azure-ssh-pub
W1015 23:34:15.857] AZURE_SSH_USER=azureuser
W1015 23:34:15.857] AZ_STORAGE_CONTAINER_NAME=mystoragecontainer
W1015 23:34:15.857] BAZEL_REMOTE_CACHE_ENABLED=false
W1015 23:34:15.857] BAZEL_VERSION=0.28.1
W1015 23:34:15.857] BOOTSTRAP_MIGRATION=yes
W1015 23:34:15.858] BUILD_ID=1184250779020562432
W1015 23:34:15.858] BUILD_NUMBER=1184250779020562432
W1015 23:34:15.858] CLOUDSDK_COMPONENT_MANAGER_DISABLE_UPDATE_CHECK=true
W1015 23:34:15.858] CLOUDSDK_CONFIG=/go/src/k8s.io/kubernetes/.config/gcloud
W1015 23:34:15.858] CLOUDSDK_CORE_DISABLE_PROMPTS=1
W1015 23:34:15.858] CLOUDSDK_EXPERIMENTAL_FAST_COMPONENT_UPDATE=false
W1015 23:34:15.858] CLOUD_CONFIG=random
W1015 23:34:15.859] DECK_PORT=tcp://10.0.160.83:80
W1015 23:34:15.859] DECK_PORT_80_TCP=tcp://10.0.160.83:80
W1015 23:34:15.859] DECK_PORT_80_TCP_ADDR=10.0.160.83
W1015 23:34:15.859] DECK_PORT_80_TCP_PORT=80
W1015 23:34:15.859] DECK_PORT_80_TCP_PROTO=tcp
W1015 23:34:15.859] DECK_SERVICE_HOST=10.0.160.83
W1015 23:34:15.859] DECK_SERVICE_PORT=80
W1015 23:34:15.860] DOCKER_IN_DOCKER_ENABLED=true
W1015 23:34:15.860] DOCKER_IN_DOCKER_IPV6_ENABLED=false
W1015 23:34:15.860] GCS_ARTIFACTS_DIR=gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184250779020562432/artifacts
W1015 23:34:15.860] GOOGLE_APPLICATION_CREDENTIALS=/etc/service-account/service-account.json
W1015 23:34:15.860] GOPATH=/go
W1015 23:34:15.860] GO_TARBALL=go1.12.10.linux-amd64.tar.gz
W1015 23:34:15.861] HOME=/workspace
W1015 23:34:15.861] HOOK_PORT=tcp://10.0.144.133:8888
W1015 23:34:15.861] HOOK_PORT_8888_TCP=tcp://10.0.144.133:8888
W1015 23:34:15.861] HOOK_PORT_8888_TCP_ADDR=10.0.144.133
W1015 23:34:15.861] HOOK_PORT_8888_TCP_PORT=8888
W1015 23:34:15.861] HOOK_PORT_8888_TCP_PROTO=tcp
W1015 23:34:15.861] HOOK_SERVICE_HOST=10.0.144.133
W1015 23:34:15.862] HOOK_SERVICE_PORT=8888
W1015 23:34:15.862] HOSTNAME=0b07d68c-efa4-11e9-b3d3-b20db476995a
W1015 23:34:15.862] IMAGE=chewong/kubekins-e2e:v20191015-test
W1015 23:34:15.862] INSTANCE_PREFIX=bootstrap-e2e
W1015 23:34:15.862] JENKINS_GCE_SSH_PRIVATE_KEY_FILE=/root/.ssh/google_compute_engine
W1015 23:34:15.862] JENKINS_GCE_SSH_PUBLIC_KEY_FILE=/root/.ssh/google_compute_engine.pub
W1015 23:34:15.862] JOB_NAME=chewong-e2e-ccm
W1015 23:34:15.863] JOB_SPEC={"type":"presubmit","job":"chewong-e2e-ccm","buildid":"1184250779020562432","prowjobid":"0b07d68c-efa4-11e9-b3d3-b20db476995a","refs":{"org":"Azure","repo":"kubernetes","repo_link":"https://github.com/Azure/kubernetes","base_ref":"master","base_sha":"6b63df2dc4634a62486a868c82e8cea1420793b3","base_link":"https://github.com/Azure/kubernetes/commit/6b63df2dc4634a62486a868c82e8cea1420793b3","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"}]}}
W1015 23:34:15.863] JOB_TYPE=presubmit
W1015 23:34:15.863] KUBERNETES_PORT=tcp://10.0.0.1:443
W1015 23:34:15.863] KUBERNETES_PORT_443_TCP=tcp://10.0.0.1:443
W1015 23:34:15.864] KUBERNETES_PORT_443_TCP_ADDR=10.0.0.1
W1015 23:34:15.864] KUBERNETES_PORT_443_TCP_PORT=443
W1015 23:34:15.864] KUBERNETES_PORT_443_TCP_PROTO=tcp
W1015 23:34:15.864] KUBERNETES_SERVICE_HOST=10.0.0.1
W1015 23:34:15.864] KUBERNETES_SERVICE_PORT=443
W1015 23:34:15.864] KUBERNETES_SERVICE_PORT_HTTPS=443
W1015 23:34:15.864] KUBETEST_IN_DOCKER=true
W1015 23:34:15.864] KUBETEST_MANUAL_DUMP=y
W1015 23:34:15.865] KUBE_AWS_INSTANCE_PREFIX=bootstrap-e2e
W1015 23:34:15.865] KUBE_GCE_INSTANCE_PREFIX=bootstrap-e2e
W1015 23:34:15.865] KUBE_VERBOSE=0
W1015 23:34:15.865] NODE_NAME=0b07d68c-efa4-11e9-b3d3-b20db476995a
W1015 23:34:15.865] 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
W1015 23:34:15.865] PROW_JOB_ID=0b07d68c-efa4-11e9-b3d3-b20db476995a
W1015 23:34:15.866] PULL_BASE_REF=master
W1015 23:34:15.866] PULL_BASE_SHA=6b63df2dc4634a62486a868c82e8cea1420793b3
W1015 23:34:15.866] PULL_NUMBER=113
W1015 23:34:15.866] PULL_PULL_SHA=879465972041635fd7bc8269da49153b67e63822
W1015 23:34:15.866] PULL_REFS=master:6b63df2dc4634a62486a868c82e8cea1420793b3,113:879465972041635fd7bc8269da49153b67e63822
W1015 23:34:15.866] PWD=/workspace
W1015 23:34:15.866] REGISTRY=k8sprowinternal.azurecr.io
W1015 23:34:15.866] REPO_NAME=kubernetes
W1015 23:34:15.867] REPO_OWNER=Azure
W1015 23:34:15.867] SHLVL=2
W1015 23:34:15.867] SOURCE_DATE_EPOCH=1571182329
W1015 23:34:15.867] TERM=xterm
W1015 23:34:15.867] TIDE_PORT=tcp://10.0.180.53:80
W1015 23:34:15.867] TIDE_PORT_80_TCP=tcp://10.0.180.53:80
W1015 23:34:15.867] TIDE_PORT_80_TCP_ADDR=10.0.180.53
W1015 23:34:15.868] TIDE_PORT_80_TCP_PORT=80
W1015 23:34:15.868] TIDE_PORT_80_TCP_PROTO=tcp
W1015 23:34:15.868] TIDE_SERVICE_HOST=10.0.180.53
W1015 23:34:15.868] TIDE_SERVICE_PORT=80
W1015 23:34:15.868] WORKSPACE=/workspace
W1015 23:34:15.868] _=./test-infra/jenkins/bootstrap.py
W1015 23:34:15.869] 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.36.5/aks-engine-v0.36.5-linux-amd64.tar.gz', '--timeout=420m')
W1015 23:34:15.871] 2019/10/15 23:34:15 main.go:332: Limiting testing to 7h0m0s
W1015 23:34:15.871] 2019/10/15 23:34:15 azure.go:232: Reading credentials file /etc/azure-cred/credentials
W1015 23:34:15.871] 2019/10/15 23:34:15 process.go:153: Running: make -C /go/src/k8s.io/kubernetes bazel-release
W1015 23:34:15.884] Extracting Bazel installation...
I1015 23:34:15.985] make: Entering directory '/go/src/k8s.io/kubernetes'
W1015 23:34:22.821] Starting local Bazel server and connecting to it...
W1015 23:34:24.600] Loading: 
W1015 23:34:24.603] Loading: 0 packages loaded
W1015 23:34:25.606] Loading: 0 packages loaded
W1015 23:34:27.123] Loading: 0 packages loaded
W1015 23:34:28.608] Loading: 0 packages loaded
W1015 23:34:30.480] Loading: 0 packages loaded
W1015 23:34:31.502] Loading: 0 packages loaded
W1015 23:34:31.502]     currently loading: build/release-tars
W1015 23:34:32.681] Loading: 0 packages loaded
W1015 23:34:32.681]     currently loading: build/release-tars
W1015 23:34:33.929] Loading: 0 packages loaded
W1015 23:34:33.930]     currently loading: build/release-tars
W1015 23:34:34.115] Analyzing: target //build/release-tars:release-tars (1 packages loaded, 0 targets configured)
W1015 23:34:35.584] Analyzing: target //build/release-tars:release-tars (214 packages loaded, 1101 targets configured)
W1015 23:34:37.270] Analyzing: target //build/release-tars:release-tars (1022 packages loaded, 4397 targets configured)
W1015 23:34:39.209] Analyzing: target //build/release-tars:release-tars (1954 packages loaded, 12077 targets configured)
W1015 23:34:41.565] Analyzing: target //build/release-tars:release-tars (2778 packages loaded, 22874 targets configured)
W1015 23:34:44.275] Analyzing: target //build/release-tars:release-tars (3046 packages loaded, 27236 targets configured)
W1015 23:34:47.458] Analyzing: target //build/release-tars:release-tars (3075 packages loaded, 33693 targets configured)
W1015 23:34:51.004] Analyzing: target //build/release-tars:release-tars (3090 packages loaded, 34601 targets configured)
W1015 23:34:55.801] Analyzing: target //build/release-tars:release-tars (3090 packages loaded, 36487 targets configured)
W1015 23:35:00.519] Analyzing: target //build/release-tars:release-tars (3091 packages loaded, 39245 targets configured)
W1015 23:35:07.716] INFO: Analyzed target //build/release-tars:release-tars (3091 packages loaded, 42410 targets configured).
W1015 23:35:07.718] Building: checking cached actions
W1015 23:35:07.719] INFO: Found 1 target...
W1015 23:35:07.866] [0 / 4] [Prepa] BazelWorkspaceStatusAction stable-status.txt
W1015 23:35:16.350] [114 / 5,321] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 4s linux-sandbox ... (8 actions, 7 running)
W1015 23:35:25.244] [284 / 5,321] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 13s linux-sandbox ... (8 actions, 7 running)
W1015 23:35:34.411] [402 / 5,321] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 22s linux-sandbox ... (8 actions, 7 running)
W1015 23:35:45.338] [554 / 5,321] CGoCodeGen //vendor/github.com/coreos/pkg/dlopen:go_default_library%linux_amd64%cgo_codegen; 0s linux-sandbox ... (8 actions running)
W1015 23:35:57.487] [717 / 5,321] GoCompile vendor/github.com/storageos/go-api/types/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/storageos/go-api/types.a; 0s linux-sandbox ... (8 actions, 7 running)
W1015 23:36:11.462] [832 / 5,321] GoCompile vendor/github.com/vmware/govmomi/vim25/types/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/vmware/govmomi/vim25/types.a; 7s linux-sandbox ... (8 actions running)
W1015 23:36:27.531] [916 / 5,321] GoCompile vendor/github.com/vmware/govmomi/vim25/methods/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/vmware/govmomi/vim25/methods.a; 7s linux-sandbox ... (8 actions running)
W1015 23:36:46.010] [1,035 / 5,321] GoCompile vendor/github.com/gophercloud/gophercloud/openstack/compute/v2/servers/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/gophercloud/gophercloud/openstack/compute/v2/servers.a; 0s linux-sandbox ... (8 actions running)
W1015 23:37:08.244] [1,199 / 5,321] GoCompile vendor/k8s.io/kube-openapi/pkg/aggregator/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/kube-openapi/pkg/aggregator.a; 2s linux-sandbox ... (8 actions running)
W1015 23:37:32.831] [1,306 / 5,321] GoCompile staging/src/k8s.io/cri-api/pkg/apis/runtime/v1alpha2/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/cri-api/pkg/apis/runtime/v1alpha2.a; 5s linux-sandbox ... (8 actions running)
W1015 23:38:01.104] [1,688 / 5,321] GoCompile vendor/github.com/gogo/protobuf/protoc-gen-gogo/descriptor/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/gogo/protobuf/protoc-gen-gogo/descriptor.a; 1s linux-sandbox ... (8 actions, 7 running)
W1015 23:38:33.621] [1,960 / 5,321] GoCompile vendor/github.com/Azure/azure-sdk-for-go/services/containerregistry/mgmt/2019-05-01/containerregistry/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/Azure/azure-sdk-for-go/services/containerregistry/mgmt/2019-05-01/containerregistry.a; 3s linux-sandbox ... (8 actions running)
W1015 23:39:11.012] [2,516 / 5,321] GoCompile vendor/google.golang.org/api/compute/v1/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/google.golang.org/api/compute/v1.a; 2s linux-sandbox ... (8 actions running)
W1015 23:39:54.014] [2,741 / 5,321]  <rule context for //staging/src/k8s.io/sample-apiserver/pkg/generated/openapi:zz_generated.openapi>; 5s linux-sandbox ... (8 actions running)
W1015 23:40:45.357] [2,836 / 5,321]  <rule context for //pkg/generated/openapi:zz_generated.openapi>; 57s linux-sandbox ... (8 actions, 7 running)
W1015 23:41:43.700] [3,015 / 5,321] GoCompile staging/src/k8s.io/api/admissionregistration/v1/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/api/admissionregistration/v1.a; 7s linux-sandbox ... (8 actions running)
W1015 23:42:48.718] [3,309 / 5,321] GoCompile pkg/registry/core/serviceaccount/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/pkg/registry/core/serviceaccount.a; 1s linux-sandbox ... (8 actions, 7 running)
W1015 23:44:04.826] [3,740 / 5,321] GoCompile staging/src/k8s.io/kubelet/config/v1beta1/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/kubelet/config/v1beta1.a; 0s linux-sandbox ... (8 actions, 7 running)
W1015 23:45:34.291] [4,197 / 5,321] GoCompile pkg/scheduler/framework/plugins/tainttoleration/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/pkg/scheduler/framework/plugins/tainttoleration.a; 3s linux-sandbox ... (8 actions running)
W1015 23:47:14.783] [4,411 / 5,321] GZIP build/kube-scheduler-internal-layer.tar.gz; 14s linux-sandbox ... (8 actions, 7 running)
W1015 23:49:10.694] [4,886 / 5,321] GoCompile pkg/volume/scaleio/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/pkg/volume/scaleio.a; 4s linux-sandbox ... (8 actions, 7 running)
W1015 23:50:43.602] Slow read: a 188072-byte read from /workspace/.cache/bazel/_bazel_root/48d5366022b4e3197674c8d6e2bee219/execroot/io_k8s_kubernetes/bazel-out/k8-fastbuild/bin/pkg/registry/scheduling/rest/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/pkg/registry/scheduling/rest.a took 6754 ms.
W1015 23:51:23.950] [5,280 / 5,321] GoLink cmd/kubelet/kubelet; 33s linux-sandbox ... (8 actions, 7 running)
W1015 23:53:45.058] Target //build/release-tars:release-tars up-to-date:
W1015 23:53:45.063]   bazel-bin/build/release-tars/kubernetes-client-linux-amd64.tar.gz
W1015 23:53:45.064]   bazel-bin/build/release-tars/kubernetes-node-linux-amd64.tar.gz
W1015 23:53:45.065]   bazel-bin/build/release-tars/kubernetes-server-linux-amd64.tar.gz
W1015 23:53:45.065]   bazel-bin/build/release-tars/kubernetes-manifests.tar.gz
W1015 23:53:45.065]   bazel-bin/build/release-tars/kubernetes-test-portable.tar.gz
W1015 23:53:45.065]   bazel-bin/build/release-tars/kubernetes-test-linux-amd64.tar.gz
W1015 23:53:45.065]   bazel-bin/build/release-tars/kubernetes.tar.gz
W1015 23:53:45.065]   bazel-bin/build/release-tars/kubernetes-src.tar.gz
W1015 23:53:45.101] INFO: Elapsed time: 1169.157s, Critical Path: 347.40s
W1015 23:53:45.102] INFO: 5229 processes: 5229 linux-sandbox.
W1015 23:53:45.106] INFO: Build completed successfully, 5321 total actions
W1015 23:53:45.108] INFO: Build completed successfully, 5321 total actions
I1015 23:53:45.282] make: Leaving directory '/go/src/k8s.io/kubernetes'
W1015 23:53:45.383] 2019/10/15 23:53:45 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes bazel-release' finished in 19m29.41145584s
W1015 23:53:45.384] 2019/10/15 23:53:45 util.go:277: Flushing memory.
W1015 23:54:11.979] 2019/10/15 23:54:11 azure.go:906: Deleting resource group: kubetest-4d19a309-efa4-11e9-9361-024213c04f6f.
W1015 23:54:12.538] 2019/10/15 23:54:12 azure.go:654: CWD /go/src/k8s.io/kubernetes
W1015 23:54:12.539] 2019/10/15 23:54:12 azure.go:673: Attempting Docker login with azure cred.
W1015 23:54:14.130] 2019/10/15 23:54:14 azure.go:682: Docker login success.
W1015 23:54:14.130] 2019/10/15 23:54:14 azure.go:697: Building ccm.
W1015 23:54:14.130] 2019/10/15 23:54:14 azure.go:699: projectPath /go/src/k8s.io/cloud-provider-azure
W1015 23:54:14.130] 2019/10/15 23:54:14 process.go:153: Running: docker build -t k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184250779020562432-165e9e6d .
I1015 23:54:16.320] Sending build context to Docker daemon  67.18MB

I1015 23:54:16.353] Step 1/7 : FROM golang:1.12.9-stretch AS build
I1015 23:54:17.259] 1.12.9-stretch: Pulling from library/golang
I1015 23:54:17.595] 092586df9206: Pulling fs layer
I1015 23:54:17.596] ef599477fae0: Pulling fs layer
I1015 23:54:17.596] 4530c6472b5d: Pulling fs layer
I1015 23:54:17.596] d34d61487075: Pulling fs layer
I1015 23:54:17.596] 89c6ec31b9e9: Pulling fs layer
I1015 23:54:17.596] e37857ebcafa: Pulling fs layer
I1015 23:54:17.596] b0e29f6c7f0a: Pulling fs layer
I1015 23:54:17.596] d34d61487075: Waiting
I1015 23:54:17.597] 89c6ec31b9e9: Waiting
I1015 23:54:17.597] e37857ebcafa: Waiting
I1015 23:54:17.597] b0e29f6c7f0a: Waiting
I1015 23:54:18.051] 4530c6472b5d: Verifying Checksum
I1015 23:54:18.051] 4530c6472b5d: Download complete
I1015 23:54:18.087] ef599477fae0: Verifying Checksum
I1015 23:54:18.087] ef599477fae0: Download complete
I1015 23:54:18.851] d34d61487075: Verifying Checksum
I1015 23:54:18.851] d34d61487075: Download complete
I1015 23:54:19.262] 89c6ec31b9e9: Verifying Checksum
I1015 23:54:19.262] 89c6ec31b9e9: Download complete
I1015 23:54:19.453] 092586df9206: Download complete
I1015 23:54:19.632] b0e29f6c7f0a: Verifying Checksum
I1015 23:54:19.632] b0e29f6c7f0a: Download complete
I1015 23:54:20.435] e37857ebcafa: Verifying Checksum
I1015 23:54:22.635] 092586df9206: Pull complete
I1015 23:54:23.398] ef599477fae0: Pull complete
I1015 23:54:23.741] 4530c6472b5d: Pull complete
I1015 23:54:27.464] d34d61487075: Pull complete
I1015 23:54:31.065] 89c6ec31b9e9: Pull complete
I1015 23:54:38.657] e37857ebcafa: Pull complete
I1015 23:54:38.791] b0e29f6c7f0a: Pull complete
I1015 23:54:38.813] Digest: sha256:76b52857546f070cc3ac499accb27b8c411b10ff6d45c0b1da2a8aab7b61fe29
I1015 23:54:38.833] Status: Downloaded newer image for golang:1.12.9-stretch
I1015 23:54:38.833]  ---> 2c4a601e5da9
I1015 23:54:38.833] Step 2/7 : WORKDIR /go/src/k8s.io/cloud-provider-azure
I1015 23:54:50.761]  ---> Running in 01e0a77b2ff7
I1015 23:54:51.990] Removing intermediate container 01e0a77b2ff7
I1015 23:54:51.990]  ---> 110ba7311763
I1015 23:54:51.990] Step 3/7 : COPY . .
I1015 23:54:57.968]  ---> 5e9c394fcb61
I1015 23:54:57.968] Step 4/7 : RUN make
I1015 23:54:58.171]  ---> Running in 4ec429684f92
I1015 23:54:59.081] hack/pkg-config.sh > .pkg_config
I1015 23:54:59.109] 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-15T23:54:59Z' ./cmd/cloud-controller-manager
I1015 23:55:41.201] 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-15T23:54:59Z' ./cmd/cloud-node-manager
I1015 23:56:05.404] Removing intermediate container 4ec429684f92
I1015 23:56:05.404]  ---> 1002c336f100
I1015 23:56:05.404] Step 5/7 : FROM k8s.gcr.io/debian-base:v1.0.0
I1015 23:56:05.711] v1.0.0: Pulling from debian-base
I1015 23:56:05.883] 39fafc05754f: Pulling fs layer
I1015 23:56:06.264] 39fafc05754f: Verifying Checksum
I1015 23:56:06.264] 39fafc05754f: Download complete
I1015 23:56:08.626] 39fafc05754f: Pull complete
I1015 23:56:08.652] Digest: sha256:3801f944c765dc1b54900826ca67b1380bb8c73b9caf4a2a27ce613b3ba3e742
I1015 23:56:08.672] Status: Downloaded newer image for k8s.gcr.io/debian-base:v1.0.0
I1015 23:56:08.672]  ---> 204e96332c91
I1015 23:56:08.673] Step 6/7 : COPY --from=build /go/src/k8s.io/cloud-provider-azure/bin/azure-cloud-controller-manager /usr/local/bin
I1015 23:56:12.092]  ---> c79d3f5a193f
I1015 23:56:12.092] Step 7/7 : RUN ln -s /usr/local/bin/azure-cloud-controller-manager /usr/local/bin/cloud-controller-manager
I1015 23:56:12.253]  ---> Running in f27fc3f3ae56
I1015 23:56:14.051] Removing intermediate container f27fc3f3ae56
I1015 23:56:14.052]  ---> f4555be78d95
I1015 23:56:14.166] Successfully built f4555be78d95
I1015 23:56:14.293] Successfully tagged k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184250779020562432-165e9e6d
W1015 23:56:14.393] 2019/10/15 23:56:14 process.go:155: Step 'docker build -t k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184250779020562432-165e9e6d .' finished in 2m0.167277952s
W1015 23:56:14.394] 2019/10/15 23:56:14 process.go:153: Running: docker push k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184250779020562432-165e9e6d
W1015 23:56:19.121] 2019/10/15 23:56:19 process.go:155: Step 'docker push k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184250779020562432-165e9e6d' finished in 4.823867558s
W1015 23:56:19.122] 2019/10/15 23:56:19 azure.go:686: Docker logout.
W1015 23:56:19.180] 2019/10/15 23:56:19 azure.go:716: Custom cloud controller manager URL: k8sprowinternal.azurecr.io/azure-cloud-controller-manager:1184250779020562432-165e9e6d .
W1015 23:56:19.181] 2019/10/15 23:56:19 azure.go:654: CWD /go/src/k8s.io/kubernetes
W1015 23:56:19.181] 2019/10/15 23:56:19 azure.go:673: Attempting Docker login with azure cred.
W1015 23:56:20.037] 2019/10/15 23:56:20 azure.go:682: Docker login success.
W1015 23:56:20.037] 2019/10/15 23:56:20 azure.go:726: Building hyperkube.
W1015 23:56:20.037] 2019/10/15 23:56:20 process.go:153: Running: make -C /go/src/k8s.io/kubernetes WHAT=cmd/hyperkube
W1015 23:57:03.805] 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
W1015 23:59:47.363] 2019/10/15 23:59:47 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes WHAT=cmd/hyperkube' finished in 3m27.325911144s
W1015 23:59:47.363] 2019/10/15 23:59:47 azure.go:733: Pushing hyperkube.
W1015 23:59:47.363] 2019/10/15 23:59:47 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
I1015 23:59:47.464] make: Entering directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube'
I1015 23:59:47.464] cp -r ./* /tmp/hyperkubed1CkLV
I1015 23:59:47.464] cp /go/src/k8s.io/kubernetes/_output/bin/hyperkube /tmp/hyperkubed1CkLV
I1015 23:59:47.542] chmod a+rx /tmp/hyperkubed1CkLV/hyperkube
I1015 23:59:47.544] cd /tmp/hyperkubed1CkLV && sed -i.back "s|BASEIMAGE|k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1|g" Dockerfile
I1015 23:59:47.546] docker build --pull -t k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184250779020562432-61da9edb /tmp/hyperkubed1CkLV
I1015 23:59:48.706] Sending build context to Docker daemon  212.4MB

I1015 23:59:48.743] Step 1/2 : FROM k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1
I1015 23:59:49.060] 0.12.1: Pulling from debian-hyperkube-base-amd64
I1015 23:59:49.060] 346aee5ea5bc: Pulling fs layer
I1015 23:59:49.061] 9c47fde751af: Pulling fs layer
I1015 23:59:49.061] be2693a52daf: Pulling fs layer
I1015 23:59:49.061] 6b69eb11d043: Pulling fs layer
I1015 23:59:49.061] 0abeb1500767: Pulling fs layer
I1015 23:59:49.061] 4062d80041b7: Pulling fs layer
I1015 23:59:49.061] 23b6daf06fc2: Pulling fs layer
I1015 23:59:49.062] 4062d80041b7: Waiting
I1015 23:59:49.062] 23b6daf06fc2: Waiting
I1015 23:59:49.062] 6b69eb11d043: Waiting
I1015 23:59:49.284] 9c47fde751af: Download complete
I1015 23:59:49.383] be2693a52daf: Verifying Checksum
I1015 23:59:49.384] be2693a52daf: Download complete
I1015 23:59:49.416] 6b69eb11d043: Verifying Checksum
I1015 23:59:49.416] 6b69eb11d043: Download complete
I1015 23:59:49.651] 0abeb1500767: Verifying Checksum
I1015 23:59:49.651] 0abeb1500767: Download complete
I1015 23:59:49.882] 346aee5ea5bc: Verifying Checksum
I1015 23:59:49.882] 346aee5ea5bc: Download complete
I1015 23:59:50.905] 23b6daf06fc2: Verifying Checksum
I1015 23:59:50.905] 23b6daf06fc2: Download complete
I1015 23:59:50.924] 4062d80041b7: Download complete
I1015 23:59:53.283] 346aee5ea5bc: Pull complete
I1015 23:59:53.415] 9c47fde751af: Pull complete
I1015 23:59:53.608] be2693a52daf: Pull complete
I1015 23:59:53.744] 6b69eb11d043: Pull complete
I1015 23:59:53.892] 0abeb1500767: Pull complete
I1016 00:00:01.240] 4062d80041b7: Pull complete
I1016 00:00:02.572] 23b6daf06fc2: Pull complete
I1016 00:00:02.595] Digest: sha256:5d4ea2fb5fbe9a9a9da74f67cf2faefc881968bc39f2ac5d62d9167e575812a1
I1016 00:00:02.611] Status: Downloaded newer image for k8s.gcr.io/debian-hyperkube-base-amd64:0.12.1
I1016 00:00:02.612]  ---> a46476511725
I1016 00:00:02.612] Step 2/2 : COPY hyperkube /hyperkube
I1016 00:00:25.962]  ---> 9c62b91de8bd
I1016 00:00:25.988] Successfully built 9c62b91de8bd
I1016 00:00:26.063] Successfully tagged k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184250779020562432-61da9edb
I1016 00:00:26.066] rm -rf "/tmp/hyperkubed1CkLV"
I1016 00:00:26.096] docker push k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184250779020562432-61da9edb
I1016 00:00:26.162] The push refers to repository [k8sprowinternal.azurecr.io/hyperkube-amd64]
I1016 00:00:26.226] 27243de6f219: Preparing
I1016 00:00:26.226] 39b3ac6d96e9: Preparing
I1016 00:00:26.226] 7bbae4dddb88: Preparing
I1016 00:00:26.227] a00defcfe869: Preparing
I1016 00:00:26.227] 2ab0ae805c74: Preparing
I1016 00:00:26.227] 43a8fe7d2382: Preparing
I1016 00:00:26.227] 3f6a6f542637: Preparing
I1016 00:00:26.227] 5ba3be777c2d: Preparing
I1016 00:00:26.227] 43a8fe7d2382: Waiting
I1016 00:00:26.227] 3f6a6f542637: Waiting
I1016 00:00:26.227] 5ba3be777c2d: Waiting
I1016 00:00:26.450] 39b3ac6d96e9: Layer already exists
I1016 00:00:26.471] 2ab0ae805c74: Layer already exists
I1016 00:00:26.495] 7bbae4dddb88: Layer already exists
I1016 00:00:26.517] a00defcfe869: Layer already exists
I1016 00:00:26.601] 5ba3be777c2d: Layer already exists
I1016 00:00:26.688] 3f6a6f542637: Layer already exists
I1016 00:00:26.708] 43a8fe7d2382: Layer already exists
I1016 00:00:36.680] 27243de6f219: Pushed
I1016 00:00:39.942] azure-e2e-1184250779020562432-61da9edb: digest: sha256:e627374b00c6146bde33b67da08f262d755d92500d985e7d7d092c82d118d2cd size: 1998
I1016 00:00:39.968] docker rmi k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1184250779020562432-61da9edb 2>/dev/null || true
I1016 00:00:40.014] docker tag k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184250779020562432-61da9edb k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1184250779020562432-61da9edb
I1016 00:00:40.095] docker push k8sprowinternal.azurecr.io/hyperkube:azure-e2e-1184250779020562432-61da9edb
I1016 00:00:40.156] The push refers to repository [k8sprowinternal.azurecr.io/hyperkube]
I1016 00:00:40.169] 27243de6f219: Preparing
I1016 00:00:40.169] 39b3ac6d96e9: Preparing
I1016 00:00:40.172] 7bbae4dddb88: Preparing
I1016 00:00:40.172] a00defcfe869: Preparing
I1016 00:00:40.172] 2ab0ae805c74: Preparing
I1016 00:00:40.172] 43a8fe7d2382: Preparing
I1016 00:00:40.173] 3f6a6f542637: Preparing
I1016 00:00:40.173] 5ba3be777c2d: Preparing
I1016 00:00:40.173] 43a8fe7d2382: Waiting
I1016 00:00:40.173] 5ba3be777c2d: Waiting
I1016 00:00:40.173] 3f6a6f542637: Waiting
I1016 00:00:40.271] a00defcfe869: Layer already exists
I1016 00:00:40.294] 2ab0ae805c74: Layer already exists
I1016 00:00:40.316] 39b3ac6d96e9: Layer already exists
I1016 00:00:40.338] 43a8fe7d2382: Layer already exists
I1016 00:00:40.360] 7bbae4dddb88: Layer already exists
I1016 00:00:40.372] 27243de6f219: Mounted from hyperkube-amd64
I1016 00:00:40.415] 3f6a6f542637: Layer already exists
I1016 00:00:40.464] 5ba3be777c2d: Layer already exists
I1016 00:00:41.059] azure-e2e-1184250779020562432-61da9edb: digest: sha256:e627374b00c6146bde33b67da08f262d755d92500d985e7d7d092c82d118d2cd size: 1998
I1016 00:00:41.074] make: Leaving directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube'
W1016 00:00:41.174] 2019/10/16 00:00:41 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes/cluster/images/hyperkube push HYPERKUBE_BIN=/go/src/k8s.io/kubernetes/_output/bin/hyperkube' finished in 53.711145912s
W1016 00:00:41.175] 2019/10/16 00:00:41 azure.go:686: Docker logout.
W1016 00:00:41.175] 2019/10/16 00:00:41 azure.go:744: Custom hyperkube URL: k8sprowinternal.azurecr.io/hyperkube-amd64:azure-e2e-1184250779020562432-61da9edb .
W1016 00:00:41.175] 2019/10/16 00:00:41 azure.go:787: downloading /workspace/aks707116951/kubernetes.json from https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json.
W1016 00:00:41.175] 2019/10/16 00:00:41 util.go:42: curl https://raw.githubusercontent.com/kubernetes/cloud-provider-azure/master/tests/k8s-azure/manifest/linux.json
W1016 00:00:41.400] 2019/10/16 00:00:41 azure.go:529: downloading /workspace/aks-engine.tar.gz from https://github.com/Azure/aks-engine/releases/download/v0.36.5/aks-engine-v0.36.5-linux-amd64.tar.gz.
W1016 00:00:41.400] 2019/10/16 00:00:41 util.go:42: curl https://github.com/Azure/aks-engine/releases/download/v0.36.5/aks-engine-v0.36.5-linux-amd64.tar.gz
W1016 00:00:42.589] 2019/10/16 00:00:42 azure.go:556: Extracting tar file /workspace/aks-engine.tar.gz into directory /go/src/k8s.io/kubernetes .
W1016 00:00:42.589] 2019/10/16 00:00:42 process.go:153: Running: tar -xzf /workspace/aks-engine.tar.gz --strip 1
W1016 00:00:42.733] 2019/10/16 00:00:42 process.go:155: Step 'tar -xzf /workspace/aks-engine.tar.gz --strip 1' finished in 144.177314ms
W1016 00:00:42.734] 2019/10/16 00:00:42 process.go:153: Running: /go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks707116951/kubernetes.json --output-directory /workspace/aks707116951
W1016 00:00:42.927] Error: loading API model in generateCmd: error parsing the api model: the following OrchestratorProfile configuration is not supported: OrchestratorType: "Kubernetes", OrchestratorRelease: "1.16", OrchestratorVersion: "". Please use one of the following versions: [1.6.9 1.9.10 1.9.11 1.10.12 1.10.13 1.11.9 1.11.10 1.12.7 1.12.8 1.13.5 1.14.1 1.15.0-alpha.1 1.15.0-alpha.2 1.15.0-alpha.3 1.15.0-beta.1]
W1016 00:00:42.927] Usage:
W1016 00:00:42.927]   aks-engine generate [flags]
W1016 00:00:42.928] 
W1016 00:00:42.928] Flags:
W1016 00:00:42.928]   -m, --api-model string             path to your cluster definition file
W1016 00:00:42.928]       --ca-certificate-path string   path to the CA certificate to use for Kubernetes PKI assets
W1016 00:00:42.928]       --ca-private-key-path string   path to the CA private key to use for Kubernetes PKI assets
W1016 00:00:42.928]   -h, --help                         help for generate
W1016 00:00:42.929]       --no-pretty-print              skip pretty printing the output
W1016 00:00:42.929]   -o, --output-directory string      output directory (derived from FQDN if absent)
W1016 00:00:42.929]       --parameters-only              only output parameters files
W1016 00:00:42.929]       --set stringArray              set values on the command line (can specify multiple or separate values with commas: key1=val1,key2=val2)
W1016 00:00:42.929] 
W1016 00:00:42.929] Global Flags:
W1016 00:00:42.930]       --debug   enable verbose debug logs
W1016 00:00:42.930] 
W1016 00:00:42.930] 2019/10/16 00:00:42 process.go:155: Step '/go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks707116951/kubernetes.json --output-directory /workspace/aks707116951' finished in 194.830905ms
W1016 00:00:42.930] 2019/10/16 00:00:42 process.go:153: Running: /workspace/_artifacts
W1016 00:00:42.930] 2019/10/16 00:00:42 process.go:155: Step '/workspace/_artifacts' finished in 995.208µs
W1016 00:00:42.931] 2019/10/16 00:00:42 azure.go:906: Deleting resource group: kubetest-4d19a309-efa4-11e9-9361-024213c04f6f.
W1016 00:00:42.960] 2019/10/16 00:00:42 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml.
W1016 00:00:42.960] 2019/10/16 00:00:42 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"
W1016 00:00:43.213] 2019/10/16 00:00:43 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 252.958953ms
W1016 00:00:43.213] 2019/10/16 00:00:43 main.go:319: Something went wrong: starting e2e cluster: failed to generate ARM templates: failed to generate ARM templates: error during /go/src/k8s.io/kubernetes/aks-engine generate /workspace/aks707116951/kubernetes.json --output-directory /workspace/aks707116951: exit status 1.
W1016 00:00:43.215] Traceback (most recent call last):
W1016 00:00:43.215]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in <module>
W1016 00:00:43.216]     main(parse_args())
W1016 00:00:43.216]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main
W1016 00:00:43.216]     mode.start(runner_args)
W1016 00:00:43.216]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start
W1016 00:00:43.216]     check_env(env, self.command, *args)
W1016 00:00:43.216]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env
W1016 00:00:43.217]     subprocess.check_call(cmd, env=env)
W1016 00:00:43.217]   File "/usr/lib/python2.7/subprocess.py", line 186, in check_call
W1016 00:00:43.217]     raise CalledProcessError(retcode, cmd)
W1016 00:00:43.218] 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.36.5/aks-engine-v0.36.5-linux-amd64.tar.gz', '--timeout=420m')' returned non-zero exit status 1
E1016 00:00:43.223] Command failed
I1016 00:00:43.223] process 687 exited with code 1 after 26.5m
E1016 00:00:43.223] FAIL: chewong-e2e-ccm
I1016 00:00:43.223] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W1016 00:00:44.039] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I1016 00:00:44.072] process 3313 exited with code 0 after 0.0m
I1016 00:00:44.072] Call:  gcloud config get-value account
I1016 00:00:44.330] process 3325 exited with code 0 after 0.0m
I1016 00:00:44.331] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
I1016 00:00:44.331] Upload result and artifacts...
I1016 00:00:44.331] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184250779020562432
I1016 00:00:44.332] Call:  gsutil ls gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184250779020562432/artifacts
W1016 00:00:45.592] CommandException: One or more URLs matched no objects.
E1016 00:00:45.671] Command failed
I1016 00:00:45.671] process 3337 exited with code 1 after 0.0m
W1016 00:00:45.671] Remote dir gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184250779020562432/artifacts not exist yet
I1016 00:00:45.671] 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/1184250779020562432/artifacts
I1016 00:00:47.345] process 3479 exited with code 0 after 0.0m
I1016 00:00:47.345] Call:  git rev-parse HEAD
I1016 00:00:47.349] process 4003 exited with code 0 after 0.0m
I1016 00:00:47.349] Call:  git rev-parse HEAD
I1016 00:00:47.353] process 4004 exited with code 0 after 0.0m
I1016 00:00:47.354] Call:  gsutil stat gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json
I1016 00:00:48.336] process 4005 exited with code 0 after 0.0m
I1016 00:00:48.337] Call:  gsutil -q cat 'gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json#1571175174872981'
I1016 00:00:49.594] process 4147 exited with code 0 after 0.0m
I1016 00:00:49.594] Call:  gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1571175174872981 cp /tmp/gsutil_IckqAf gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/jobResultsCache.json
I1016 00:00:51.005] process 4291 exited with code 0 after 0.0m
I1016 00:00:51.005] Call:  gsutil stat gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json
I1016 00:00:51.978] process 4469 exited with code 0 after 0.0m
I1016 00:00:51.979] Call:  gsutil -q cat 'gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json#1571175178509694'
I1016 00:00:53.165] process 4611 exited with code 0 after 0.0m
I1016 00:00:53.166] Call:  gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1571175178509694 cp /tmp/gsutil_BEOvUb gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/jobResultsCache.json
I1016 00:00:54.629] process 4755 exited with code 0 after 0.0m
I1016 00:00:54.630] Call:  gsutil -q -h Content-Type:application/json cp /tmp/gsutil_DZRQrO gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/1184250779020562432/finished.json
I1016 00:00:56.044] process 4933 exited with code 0 after 0.0m
I1016 00:00:56.045] Call:  gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_mk6UDy gs://kubernetes-upstream/pr-logs/directory/chewong-e2e-ccm/latest-build.txt
I1016 00:00:57.378] process 5111 exited with code 0 after 0.0m
I1016 00:00:57.378] Call:  gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_xDoLHX gs://kubernetes-upstream/pr-logs/pull/cloud-provider-azure/248/chewong-e2e-ccm/latest-build.txt
I1016 00:00:58.779] process 5289 exited with code 0 after 0.0m