W1126 01:22:04.902] **************************************************************************
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
**************************************************************************
I1126 01:22:04.903] Args: --job=chewong-in-tree-azure-disk-e2e --service-account=/etc/service-account/service-account.json --upload=gs://kubernetes-jenkins/logs --job=chewong-in-tree-azure-disk-e2e --root=/go/src --service-account=/etc/service-account/service-account.json --repo=k8s.io/kubernetes=master:1c5b6cb66e6ae85177e76d4fddf7d99473ab2aed,85621:dd76fdfce5554cc15ee7ed999bea1cffb0436d0a --upload=gs://kubernetes-upstream/pr-logs --timeout=460 --scenario=kubernetes_e2e -- --gce-ssh= --test=true --up=true --down=true --deployment=acsengine --build=bazel --provider=azure --ginkgo-parallel=10 --acsengine-agentpoolcount=2 --acsengine-admin-username=azureuser '--acsengine-creds=$AZURE_CREDENTIALS' --acsengine-orchestratorRelease=1.16 --acsengine-mastervmsize=Standard_DS2_v2 --acsengine-agentvmsize=Standard_D4s_v3 --acsengine-hyperkube=True --acsengine-location=westus2 '--acsengine-public-key=$AZURE_SSH_PUBLIC_KEY_FILE' --acsengine-template-url=https://raw.githubusercontent.com/Azure/aks-engine/master/examples/kubernetes-vmss/kubernetes.json --acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.44.0/aks-engine-v0.44.0-linux-amd64.tar.gz '--test_args=--ginkgo.flakeAttempts=2 --num-nodes=2 --ginkgo.focus=azure-disk --ginkgo.skip=\[Slow\]|\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\]' --timeout=420m
I1126 01:22:04.903] Bootstrap chewong-in-tree-azure-disk-e2e...
I1126 01:22:04.907] Builder: 0460461c-0feb-11ea-b3d3-b20db476995a
I1126 01:22:04.907] Image: gcr.io/k8s-testimages/kubekins-e2e:v20191124-4beb966-1.16
I1126 01:22:04.907] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199135986513088512
I1126 01:22:04.908] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W1126 01:22:05.600] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I1126 01:22:05.634] process 211 exited with code 0 after 0.0m
I1126 01:22:05.634] Call:  gcloud config get-value account
I1126 01:22:05.912] process 224 exited with code 0 after 0.0m
I1126 01:22:05.912] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
I1126 01:22:05.913] Root: /go/src
I1126 01:22:05.913] cd to /go/src
I1126 01:22:05.913] Checkout: /go/src/k8s.io/kubernetes master:1c5b6cb66e6ae85177e76d4fddf7d99473ab2aed,85621:dd76fdfce5554cc15ee7ed999bea1cffb0436d0a to /go/src/k8s.io/kubernetes
I1126 01:22:05.913] Call:  git init k8s.io/kubernetes
I1126 01:22:05.919] Initialized empty Git repository in /go/src/k8s.io/kubernetes/.git/
I1126 01:22:05.920] process 237 exited with code 0 after 0.0m
I1126 01:22:05.920] Call:  git config --local user.name 'K8S Bootstrap'
I1126 01:22:05.932] process 238 exited with code 0 after 0.0m
I1126 01:22:05.932] Call:  git config --local user.email k8s_bootstrap@localhost
I1126 01:22:05.936] process 239 exited with code 0 after 0.0m
I1126 01:22:05.936] Call:  git fetch --quiet --tags https://github.com/kubernetes/kubernetes master +refs/pull/85621/head:refs/pr/85621
I1126 01:23:16.009] process 240 exited with code 0 after 1.2m
I1126 01:23:16.009] Call:  git checkout -B test 1c5b6cb66e6ae85177e76d4fddf7d99473ab2aed
W1126 01:23:19.252] Switched to a new branch 'test'
I1126 01:23:19.265] process 251 exited with code 0 after 0.1m
I1126 01:23:19.265] Call:  git show -s --format=format:%ct HEAD
I1126 01:23:19.302] process 252 exited with code 0 after 0.0m
I1126 01:23:19.303] Call:  git merge --no-ff -m 'Merge +refs/pull/85621/head:refs/pr/85621' dd76fdfce5554cc15ee7ed999bea1cffb0436d0a
I1126 01:23:20.138] Merge made by the 'recursive' strategy.
I1126 01:23:20.146]  test/e2e/storage/drivers/in_tree.go | 46 ++++++++++++++++++-------------------
I1126 01:23:20.146]  test/e2e/storage/in_tree_volumes.go |  2 +-
I1126 01:23:20.147]  2 files changed, 24 insertions(+), 24 deletions(-)
I1126 01:23:20.147] process 253 exited with code 0 after 0.0m
I1126 01:23:20.147] Configure environment...
I1126 01:23:20.148] Call:  git show -s --format=format:%ct HEAD
I1126 01:23:20.162] process 295 exited with code 0 after 0.0m
I1126 01:23:20.162] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W1126 01:23:21.270] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I1126 01:23:21.420] process 296 exited with code 0 after 0.0m
I1126 01:23:21.420] Call:  gcloud config get-value account
I1126 01:23:21.959] process 309 exited with code 0 after 0.0m
I1126 01:23:21.960] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
I1126 01:23:21.960] 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
'
I1126 01:23:22.373] process 322 exited with code 0 after 0.0m
I1126 01:23:22.374] Start 1199135986513088512 at v1.18.0-alpha.0.1190+cff90159704e47...
I1126 01:23:22.377] Call:  gsutil -q -h Content-Type:application/json cp /tmp/gsutil_3dwp6P gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199135986513088512/started.json
I1126 01:23:25.038] process 355 exited with code 0 after 0.0m
I1126 01:23:25.039] Call:  gsutil -q -h Content-Type:text/plain -h 'x-goog-meta-link: gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199135986513088512' cp /tmp/gsutil_k8HdIW gs://kubernetes-upstream/pr-logs/directory/chewong-in-tree-azure-disk-e2e/1199135986513088512.txt
I1126 01:23:27.398] process 536 exited with code 0 after 0.0m
I1126 01:23:27.399] Call:  /workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py --gce-ssh= --test=true --up=true --down=true --deployment=acsengine --build=bazel --provider=azure --ginkgo-parallel=10 --acsengine-agentpoolcount=2 --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-location=westus2 --acsengine-public-key=/etc/azure-ssh/azure-ssh-pub --acsengine-template-url=https://raw.githubusercontent.com/Azure/aks-engine/master/examples/kubernetes-vmss/kubernetes.json --acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.44.0/aks-engine-v0.44.0-linux-amd64.tar.gz '--test_args=--ginkgo.flakeAttempts=2 --num-nodes=2 --ginkgo.focus=azure-disk --ginkgo.skip=\[Slow\]|\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\]' --timeout=420m
W1126 01:23:27.468] starts with local mode
W1126 01:23:27.468] Environment:
W1126 01:23:27.469] ARTIFACTS=/workspace/_artifacts
W1126 01:23:27.469] AWS_SSH_PRIVATE_KEY_FILE=/root/.ssh/kube_aws_rsa
W1126 01:23:27.469] AWS_SSH_PUBLIC_KEY_FILE=/root/.ssh/kube_aws_rsa.pub
W1126 01:23:27.470] AZURE_CREDENTIALS=/etc/azure-cred/credentials
W1126 01:23:27.470] AZURE_SSH_PUBLIC_KEY_FILE=/etc/azure-ssh/azure-ssh-pub
W1126 01:23:27.470] AZ_STORAGE_CONTAINER_NAME=mystoragecontainer
W1126 01:23:27.470] BAZEL_REMOTE_CACHE_ENABLED=false
W1126 01:23:27.471] BAZEL_VERSION=0.23.2
W1126 01:23:27.471] BOOTSTRAP_MIGRATION=yes
W1126 01:23:27.471] BUILD_ID=1199135986513088512
W1126 01:23:27.471] BUILD_NUMBER=1199135986513088512
W1126 01:23:27.472] CLOUDSDK_COMPONENT_MANAGER_DISABLE_UPDATE_CHECK=true
W1126 01:23:27.472] CLOUDSDK_CONFIG=/go/src/k8s.io/kubernetes/.config/gcloud
W1126 01:23:27.472] CLOUDSDK_CORE_DISABLE_PROMPTS=1
W1126 01:23:27.473] CLOUDSDK_EXPERIMENTAL_FAST_COMPONENT_UPDATE=false
W1126 01:23:27.473] CLOUD_CONFIG=random
W1126 01:23:27.473] DECK_PORT=tcp://10.0.160.83:80
W1126 01:23:27.473] DECK_PORT_80_TCP=tcp://10.0.160.83:80
W1126 01:23:27.474] DECK_PORT_80_TCP_ADDR=10.0.160.83
W1126 01:23:27.474] DECK_PORT_80_TCP_PORT=80
W1126 01:23:27.474] DECK_PORT_80_TCP_PROTO=tcp
W1126 01:23:27.475] DECK_SERVICE_HOST=10.0.160.83
W1126 01:23:27.475] DECK_SERVICE_PORT=80
W1126 01:23:27.475] DOCKER_IN_DOCKER_ENABLED=true
W1126 01:23:27.476] DOCKER_IN_DOCKER_IPV6_ENABLED=false
W1126 01:23:27.476] GCS_ARTIFACTS_DIR=gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199135986513088512/artifacts
W1126 01:23:27.476] GOOGLE_APPLICATION_CREDENTIALS=/etc/service-account/service-account.json
W1126 01:23:27.477] GOPATH=/go
W1126 01:23:27.477] GO_TARBALL=go1.12.12.linux-amd64.tar.gz
W1126 01:23:27.477] HOME=/workspace
W1126 01:23:27.477] HOOK_PORT=tcp://10.0.144.133:8888
W1126 01:23:27.478] HOOK_PORT_8888_TCP=tcp://10.0.144.133:8888
W1126 01:23:27.478] HOOK_PORT_8888_TCP_ADDR=10.0.144.133
W1126 01:23:27.478] HOOK_PORT_8888_TCP_PORT=8888
W1126 01:23:27.479] HOOK_PORT_8888_TCP_PROTO=tcp
W1126 01:23:27.479] HOOK_SERVICE_HOST=10.0.144.133
W1126 01:23:27.479] HOOK_SERVICE_PORT=8888
W1126 01:23:27.479] HOSTNAME=0460461c-0feb-11ea-b3d3-b20db476995a
W1126 01:23:27.480] IMAGE=gcr.io/k8s-testimages/kubekins-e2e:v20191124-4beb966-1.16
W1126 01:23:27.480] INSTANCE_PREFIX=bootstrap-e2e
W1126 01:23:27.481] JENKINS_GCE_SSH_PRIVATE_KEY_FILE=/root/.ssh/google_compute_engine
W1126 01:23:27.481] JENKINS_GCE_SSH_PUBLIC_KEY_FILE=/root/.ssh/google_compute_engine.pub
W1126 01:23:27.481] JOB_NAME=chewong-in-tree-azure-disk-e2e
W1126 01:23:27.482] JOB_SPEC={"type":"presubmit","job":"chewong-in-tree-azure-disk-e2e","buildid":"1199135986513088512","prowjobid":"0460461c-0feb-11ea-b3d3-b20db476995a","refs":{"org":"Azure","repo":"kubernetes","repo_link":"https://github.com/Azure/kubernetes","base_ref":"master","base_sha":"1c5b6cb66e6ae85177e76d4fddf7d99473ab2aed","base_link":"https://github.com/Azure/kubernetes/commit/1c5b6cb66e6ae85177e76d4fddf7d99473ab2aed","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"}]}}
W1126 01:23:27.483] JOB_TYPE=presubmit
W1126 01:23:27.483] KUBERNETES_PORT=tcp://10.0.0.1:443
W1126 01:23:27.483] KUBERNETES_PORT_443_TCP=tcp://10.0.0.1:443
W1126 01:23:27.483] KUBERNETES_PORT_443_TCP_ADDR=10.0.0.1
W1126 01:23:27.484] KUBERNETES_PORT_443_TCP_PORT=443
W1126 01:23:27.484] KUBERNETES_PORT_443_TCP_PROTO=tcp
W1126 01:23:27.484] KUBERNETES_SERVICE_HOST=10.0.0.1
W1126 01:23:27.485] KUBERNETES_SERVICE_PORT=443
W1126 01:23:27.485] KUBERNETES_SERVICE_PORT_HTTPS=443
W1126 01:23:27.485] KUBETEST_IN_DOCKER=true
W1126 01:23:27.485] KUBETEST_MANUAL_DUMP=y
W1126 01:23:27.486] KUBE_AWS_INSTANCE_PREFIX=bootstrap-e2e
W1126 01:23:27.486] KUBE_GCE_INSTANCE_PREFIX=bootstrap-e2e
W1126 01:23:27.486] KUBE_SSH_KEY_PATH=/etc/ssh-key-secret/ssh-private
W1126 01:23:27.487] KUBE_SSH_PUBLIC_KEY_PATH=/etc/ssh-key-secret/ssh-public
W1126 01:23:27.487] KUBE_SSH_USER=azureuser
W1126 01:23:27.487] KUBE_VERBOSE=0
W1126 01:23:27.487] NODE_NAME=0460461c-0feb-11ea-b3d3-b20db476995a
W1126 01:23:27.488] 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
W1126 01:23:27.488] PROW_JOB_ID=0460461c-0feb-11ea-b3d3-b20db476995a
W1126 01:23:27.488] PULL_BASE_REF=master
W1126 01:23:27.489] PULL_BASE_SHA=1c5b6cb66e6ae85177e76d4fddf7d99473ab2aed
W1126 01:23:27.489] PULL_NUMBER=113
W1126 01:23:27.489] PULL_PULL_SHA=879465972041635fd7bc8269da49153b67e63822
W1126 01:23:27.489] PULL_REFS=master:1c5b6cb66e6ae85177e76d4fddf7d99473ab2aed,113:879465972041635fd7bc8269da49153b67e63822
W1126 01:23:27.490] PWD=/workspace
W1126 01:23:27.490] REGISTRY=k8sprowinternal.azurecr.io
W1126 01:23:27.490] REPO_NAME=kubernetes
W1126 01:23:27.491] REPO_OWNER=Azure
W1126 01:23:27.491] SHLVL=2
W1126 01:23:27.491] SOURCE_DATE_EPOCH=1574729000
W1126 01:23:27.491] TERM=xterm
W1126 01:23:27.492] TIDE_PORT=tcp://10.0.180.53:80
W1126 01:23:27.492] TIDE_PORT_80_TCP=tcp://10.0.180.53:80
W1126 01:23:27.492] TIDE_PORT_80_TCP_ADDR=10.0.180.53
W1126 01:23:27.492] TIDE_PORT_80_TCP_PORT=80
W1126 01:23:27.493] TIDE_PORT_80_TCP_PROTO=tcp
W1126 01:23:27.493] TIDE_SERVICE_HOST=10.0.180.53
W1126 01:23:27.493] TIDE_SERVICE_PORT=80
W1126 01:23:27.494] WORKSPACE=/workspace
W1126 01:23:27.494] _=./test-infra/jenkins/bootstrap.py
W1126 01:23:27.495] Run: ('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=bazel', '--up', '--down', '--test', '--deployment=acsengine', '--provider=azure', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--ginkgo-parallel=10', '--acsengine-agentpoolcount=2', '--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-location=westus2', '--acsengine-public-key=/etc/azure-ssh/azure-ssh-pub', '--acsengine-template-url=https://raw.githubusercontent.com/Azure/aks-engine/master/examples/kubernetes-vmss/kubernetes.json', '--acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.44.0/aks-engine-v0.44.0-linux-amd64.tar.gz', '--test_args=--ginkgo.flakeAttempts=2 --num-nodes=2 --ginkgo.focus=azure-disk --ginkgo.skip=\\[Slow\\]|\\[Serial\\]|\\[Disruptive\\]|\\[Flaky\\]|\\[Feature:.+\\]', '--timeout=420m')
W1126 01:23:27.503] 2019/11/26 01:23:27 main.go:332: Limiting testing to 7h0m0s
W1126 01:23:27.503] 2019/11/26 01:23:27 azure.go:242: Reading credentials file /etc/azure-cred/credentials
W1126 01:23:27.504] 2019/11/26 01:23:27 process.go:153: Running: make -C /go/src/k8s.io/kubernetes bazel-release
W1126 01:23:27.550] Extracting Bazel installation...
I1126 01:23:27.650] make: Entering directory '/go/src/k8s.io/kubernetes'
W1126 01:23:41.926] Starting local Bazel server and connecting to it...
W1126 01:23:45.998] Loading: 
W1126 01:23:46.018] Loading: 0 packages loaded
W1126 01:23:47.060] Loading: 0 packages loaded
W1126 01:23:49.230] Loading: 0 packages loaded
W1126 01:23:50.490] Loading: 0 packages loaded
W1126 01:23:52.086] Loading: 0 packages loaded
W1126 01:23:53.802] Loading: 0 packages loaded
W1126 01:23:55.522] Loading: 0 packages loaded
W1126 01:23:57.338] Loading: 0 packages loaded
W1126 01:23:57.339]     currently loading: build/release-tars
W1126 01:23:59.113] Analyzing: target //build/release-tars:release-tars (1 packages loaded, 0 targets configured)
W1126 01:24:01.202] Analyzing: target //build/release-tars:release-tars (27 packages loaded, 75 targets configured)
W1126 01:24:03.556] Analyzing: target //build/release-tars:release-tars (86 packages loaded, 705 targets configured)
W1126 01:24:06.273] Analyzing: target //build/release-tars:release-tars (514 packages loaded, 1858 targets configured)
W1126 01:24:09.400] Analyzing: target //build/release-tars:release-tars (1204 packages loaded, 5686 targets configured)
W1126 01:24:12.995] Analyzing: target //build/release-tars:release-tars (1988 packages loaded, 12949 targets configured)
W1126 01:24:17.182] Analyzing: target //build/release-tars:release-tars (2743 packages loaded, 23249 targets configured)
W1126 01:24:23.580] Analyzing: target //build/release-tars:release-tars (3093 packages loaded, 27372 targets configured)
W1126 01:24:29.423] Analyzing: target //build/release-tars:release-tars (3132 packages loaded, 34168 targets configured)
W1126 01:24:36.479] Analyzing: target //build/release-tars:release-tars (3138 packages loaded, 34558 targets configured)
W1126 01:24:44.302] Analyzing: target //build/release-tars:release-tars (3139 packages loaded, 36324 targets configured)
W1126 01:24:52.203] INFO: Analysed target //build/release-tars:release-tars (3139 packages loaded, 36905 targets configured).
W1126 01:24:52.222] INFO: Found 1 target...
W1126 01:24:53.129] [0 / 13] checking cached actions
W1126 01:25:03.284] [89 / 4,492] SHA256 external/debian-iptables-amd64/image/000.tar.gz.nogz.sha256; 0s linux-sandbox ... (8 actions running)
W1126 01:25:14.960] [124 / 4,492] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 11s linux-sandbox ... (8 actions running)
W1126 01:25:28.681] [203 / 4,492] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 25s linux-sandbox ... (8 actions, 6 running)
W1126 01:25:44.214] [275 / 4,492] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 41s linux-sandbox ... (8 actions, 7 running)
W1126 01:26:02.323] [410 / 4,492] GoStdlib external/io_bazel_rules_go/linux_amd64_pure_stripped/stdlib%/pkg; 59s linux-sandbox ... (8 actions running)
W1126 01:26:23.380] [537 / 4,492] GoCompilePkg vendor/google.golang.org/api/googleapi/internal/uritemplates/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/google.golang.org/api/googleapi/internal/uritemplates.a; 3s linux-sandbox ... (8 actions running)
W1126 01:26:47.090] [669 / 4,492] GoCompilePkg 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; 12s linux-sandbox ... (8 actions running)
W1126 01:27:14.361] [807 / 4,492] GoCompilePkg vendor/github.com/json-iterator/go/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/json-iterator/go.a; 2s linux-sandbox ... (8 actions, 7 running)
W1126 01:27:45.702] [951 / 4,492] GoCompilePkg vendor/github.com/libopenstorage/openstorage/volume/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/libopenstorage/openstorage/volume.a; 2s linux-sandbox ... (8 actions running)
W1126 01:28:21.740] [1,107 / 4,492] GoCompilePkg vendor/github.com/Azure/azure-sdk-for-go/services/storage/mgmt/2019-04-01/storage/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/Azure/azure-sdk-for-go/services/storage/mgmt/2019-04-01/storage.a; 2s linux-sandbox ... (8 actions running)
W1126 01:29:03.187] [1,291 / 4,492] GoLink cmd/linkcheck/linkcheck; 4s linux-sandbox ... (8 actions running)
W1126 01:29:50.857] [1,556 / 4,492] GoCompilePkg vendor/github.com/go-openapi/analysis/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/github.com/go-openapi/analysis.a; 1s linux-sandbox ... (8 actions running)
W1126 01:30:45.684] [1,815 / 4,492] GoPath pkg/generated/openapi/zz_generated.openapi~gopath/src/k8s.io/kubernetes/vendor/github.com/go-openapi/spec/bindata.go; 4s linux-sandbox ... (8 actions running)
W1126 01:31:50.505] [1,949 / 4,492] PackageTar build/release-tars/kubernetes-src.tar.gz; 9s linux-sandbox ... (8 actions, 7 running)
W1126 01:33:04.739] [2,179 / 4,492] GoCompilePkg staging/src/k8s.io/cli-runtime/pkg/kustomize/k8sdeps/configmapandsecret/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/cli-runtime/pkg/kustomize/k8sdeps/configmapandsecret.a; 5s linux-sandbox ... (8 actions, 7 running)
W1126 01:34:29.639] [2,487 / 4,492] GoCompilePkg staging/src/k8s.io/apiserver/pkg/endpoints/linux_amd64_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/apiserver/pkg/endpoints.a; 2s linux-sandbox ... (8 actions running)
W1126 01:36:06.554] [3,010 / 4,492] GoCompilePkg staging/src/k8s.io/cli-runtime/pkg/kustomize/k8sdeps/kunstruct/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/vendor/k8s.io/cli-runtime/pkg/kustomize/k8sdeps/kunstruct.a; 3s linux-sandbox ... (8 actions running)
W1126 01:37:57.986] [3,513 / 4,492] GoCompilePkg pkg/registry/core/configmap/linux_amd64_pure_stripped/go_default_library%/k8s.io/kubernetes/pkg/registry/core/configmap.a; 1s linux-sandbox ... (8 actions running)
W1126 01:40:06.531] [3,822 / 4,492] GoLink cmd/gendocs/gendocs; 36s linux-sandbox ... (8 actions, 7 running)
W1126 01:42:34.025] [4,325 / 4,492] GZIP build/kube-apiserver-internal-layer.tar.gz; 10s linux-sandbox ... (8 actions, 7 running)
W1126 01:45:25.444] [4,486 / 4,492] GoLink cmd/genman/genman; 113s linux-sandbox ... (3 actions, 2 running)
W1126 01:46:09.448] Target //build/release-tars:release-tars up-to-date:
W1126 01:46:09.450]   bazel-bin/build/release-tars/kubernetes-client-linux-amd64.tar.gz
W1126 01:46:09.450]   bazel-bin/build/release-tars/kubernetes-node-linux-amd64.tar.gz
W1126 01:46:09.450]   bazel-bin/build/release-tars/kubernetes-server-linux-amd64.tar.gz
W1126 01:46:09.450]   bazel-bin/build/release-tars/kubernetes-manifests.tar.gz
W1126 01:46:09.450]   bazel-bin/build/release-tars/kubernetes-test-portable.tar.gz
W1126 01:46:09.451]   bazel-bin/build/release-tars/kubernetes-test-linux-amd64.tar.gz
W1126 01:46:09.451]   bazel-bin/build/release-tars/kubernetes.tar.gz
W1126 01:46:09.451]   bazel-bin/build/release-tars/kubernetes-src.tar.gz
W1126 01:46:09.483] INFO: Elapsed time: 1361.852s, Critical Path: 307.03s
W1126 01:46:09.483] INFO: 4427 processes: 4427 linux-sandbox.
W1126 01:46:09.489] INFO: Build completed successfully, 4492 total actions
W1126 01:46:09.493] INFO: Build completed successfully, 4492 total actions
W1126 01:46:09.501] 2019/11/26 01:46:09 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes bazel-release' finished in 22m41.997596541s
W1126 01:46:09.501] 2019/11/26 01:46:09 util.go:265: Flushing memory.
I1126 01:46:09.602] make: Leaving directory '/go/src/k8s.io/kubernetes'
W1126 01:46:31.626] 2019/11/26 01:46:31 azure.go:959: Deleting resource group: kubetest-591d1bf6-0feb-11ea-96a5-0242aa2fdb2b.
W1126 01:46:31.922] 2019/11/26 01:46:31 azure.go:694: CWD /go/src/k8s.io/kubernetes
W1126 01:46:31.922] 2019/11/26 01:46:31 azure.go:713: Attempting Docker login with azure cred.
W1126 01:46:33.347] 2019/11/26 01:46:33 azure.go:722: Docker login success.
W1126 01:46:33.347] 2019/11/26 01:46:33 azure.go:763: Building hyperkube.
W1126 01:46:33.348] 2019/11/26 01:46:33 util.go:56: Warning: Couldn't find directory src/k8s.io/kubernetes/cmd/hyperkube under any of GOPATH /go, defaulting to /go/src/k8s.io/kubernetes/cmd/hyperkube
W1126 01:46:33.348] 2019/11/26 01:46:33 azure.go:781: Pushing hyperkube.
W1126 01:46:33.348] 2019/11/26 01:46:33 process.go:153: Running: make -C /go/src/k8s.io/kubernetes/cluster/images/hyperkube push
W1126 01:46:33.383] tar: /go/src/k8s.io/kubernetes/cluster/images/hyperkube/../../../_output/dockerized/bin/linux/amd64: Cannot open: No such file or directory
W1126 01:46:33.384] tar: Error is not recoverable: exiting now
W1126 01:46:33.384] make: *** [Makefile:40: build] Error 2
W1126 01:46:33.384] 2019/11/26 01:46:33 process.go:155: Step 'make -C /go/src/k8s.io/kubernetes/cluster/images/hyperkube push' finished in 36.157588ms
W1126 01:46:33.384] 2019/11/26 01:46:33 azure.go:727: Docker logout.
W1126 01:46:33.444] 2019/11/26 01:46:33 azure.go:965: Skippng DumpClusterLogs due to CCM not being enabled.
W1126 01:46:33.445] 2019/11/26 01:46:33 azure.go:959: Deleting resource group: kubetest-591d1bf6-0feb-11ea-96a5-0242aa2fdb2b.
W1126 01:46:33.458] 2019/11/26 01:46:33 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml.
W1126 01:46:33.460] 2019/11/26 01:46:33 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"
I1126 01:46:33.561] make: Entering directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube'
I1126 01:46:33.561] cp -r ./* /tmp/hyperkubekvpbnL
I1126 01:46:33.561] tar -cvzf /tmp/hyperkubekvpbnL/binaries.tgz  -C /go/src/k8s.io/kubernetes/cluster/images/hyperkube/../../../_output/dockerized/bin/linux/amd64 kube-apiserver kube-controller-manager \
I1126 01:46:33.561] 	kube-proxy kube-scheduler kubectl kubelet
I1126 01:46:33.561] make: Leaving directory '/go/src/k8s.io/kubernetes/cluster/images/hyperkube'
W1126 01:46:34.606] 2019/11/26 01:46:34 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 1.147266633s
W1126 01:46:34.606] 2019/11/26 01:46:34 main.go:319: Something went wrong: starting e2e cluster: error building hyperkube error during make -C /go/src/k8s.io/kubernetes/cluster/images/hyperkube push: exit status 2
W1126 01:46:34.609] Traceback (most recent call last):
W1126 01:46:34.609]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in <module>
W1126 01:46:34.610]     main(parse_args())
W1126 01:46:34.610]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main
W1126 01:46:34.610]     mode.start(runner_args)
W1126 01:46:34.610]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start
W1126 01:46:34.610]     check_env(env, self.command, *args)
W1126 01:46:34.610]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env
W1126 01:46:34.610]     subprocess.check_call(cmd, env=env)
W1126 01:46:34.611]   File "/usr/lib/python2.7/subprocess.py", line 190, in check_call
W1126 01:46:34.611]     raise CalledProcessError(retcode, cmd)
W1126 01:46:34.611] subprocess.CalledProcessError: Command '('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=bazel', '--up', '--down', '--test', '--deployment=acsengine', '--provider=azure', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--ginkgo-parallel=10', '--acsengine-agentpoolcount=2', '--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-location=westus2', '--acsengine-public-key=/etc/azure-ssh/azure-ssh-pub', '--acsengine-template-url=https://raw.githubusercontent.com/Azure/aks-engine/master/examples/kubernetes-vmss/kubernetes.json', '--acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.44.0/aks-engine-v0.44.0-linux-amd64.tar.gz', '--test_args=--ginkgo.flakeAttempts=2 --num-nodes=2 --ginkgo.focus=azure-disk --ginkgo.skip=\\[Slow\\]|\\[Serial\\]|\\[Disruptive\\]|\\[Flaky\\]|\\[Feature:.+\\]', '--timeout=420m')' returned non-zero exit status 1
E1126 01:46:34.618] Command failed
I1126 01:46:34.619] process 717 exited with code 1 after 23.1m
E1126 01:46:34.619] FAIL: chewong-in-tree-azure-disk-e2e
I1126 01:46:34.619] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W1126 01:46:35.389] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I1126 01:46:35.420] process 3308 exited with code 0 after 0.0m
I1126 01:46:35.420] Call:  gcloud config get-value account
I1126 01:46:35.643] process 3321 exited with code 0 after 0.0m
I1126 01:46:35.643] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
I1126 01:46:35.643] Upload result and artifacts...
I1126 01:46:35.643] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199135986513088512
I1126 01:46:35.644] Call:  gsutil ls gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199135986513088512/artifacts
W1126 01:46:36.698] CommandException: One or more URLs matched no objects.
E1126 01:46:36.782] Command failed
I1126 01:46:36.782] process 3334 exited with code 1 after 0.0m
W1126 01:46:36.782] Remote dir gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199135986513088512/artifacts not exist yet
I1126 01:46:36.782] Call:  gsutil -m -q -o GSUtil:use_magicfile=True cp -r -c -z log,txt,xml /workspace/_artifacts gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199135986513088512/artifacts
I1126 01:46:38.142] process 3479 exited with code 0 after 0.0m
I1126 01:46:38.142] Call:  git rev-parse HEAD
I1126 01:46:38.147] process 4006 exited with code 0 after 0.0m
I1126 01:46:38.148] Call:  git rev-parse HEAD
I1126 01:46:38.152] process 4007 exited with code 0 after 0.0m
I1126 01:46:38.152] Call:  gsutil stat gs://kubernetes-upstream/pr-logs/directory/chewong-in-tree-azure-disk-e2e/jobResultsCache.json
I1126 01:46:38.911] process 4008 exited with code 0 after 0.0m
I1126 01:46:38.911] Call:  gsutil -q cat 'gs://kubernetes-upstream/pr-logs/directory/chewong-in-tree-azure-disk-e2e/jobResultsCache.json#1574730993182686'
I1126 01:46:40.078] process 4153 exited with code 0 after 0.0m
I1126 01:46:40.079] Call:  gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1574730993182686 cp /tmp/gsutil_5zBJME gs://kubernetes-upstream/pr-logs/directory/chewong-in-tree-azure-disk-e2e/jobResultsCache.json
I1126 01:46:41.357] process 4300 exited with code 0 after 0.0m
I1126 01:46:41.358] Call:  gsutil stat gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/jobResultsCache.json
I1126 01:46:42.142] process 4481 exited with code 0 after 0.0m
I1126 01:46:42.142] Call:  gsutil -q cat 'gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/jobResultsCache.json#1574730995319206'
I1126 01:46:43.220] process 4626 exited with code 0 after 0.0m
I1126 01:46:43.221] Call:  gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:1574730995319206 cp /tmp/gsutil_ArYmyz gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/jobResultsCache.json
I1126 01:46:44.434] process 4773 exited with code 0 after 0.0m
I1126 01:46:44.435] Call:  gsutil -q -h Content-Type:application/json cp /tmp/gsutil_ZWQatb gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/1199135986513088512/finished.json
I1126 01:46:45.759] process 4954 exited with code 0 after 0.0m
I1126 01:46:45.759] Call:  gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_Rlt7XY gs://kubernetes-upstream/pr-logs/directory/chewong-in-tree-azure-disk-e2e/latest-build.txt
I1126 01:46:46.949] process 5135 exited with code 0 after 0.0m
I1126 01:46:46.950] Call:  gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_K3hObN gs://kubernetes-upstream/pr-logs/pull/85621/chewong-in-tree-azure-disk-e2e/latest-build.txt
I1126 01:46:48.233] process 5316 exited with code 0 after 0.0m