W1001 17:41:24.497] ************************************************************************** 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 ************************************************************************** I1001 17:41:24.497] Args: --job=pull-azuredisk-csi-driver-sanity --service-account=/etc/service-account/service-account.json --upload=gs://kubernetes-jenkins/logs --job=pull-azuredisk-csi-driver-sanity --root=/go/src --service-account=/etc/service-account/service-account.json --repo=github.com/kubernetes-sigs/azuredisk-csi-driver=master:6b4d4209385f8a3b04a39f1970017a27f2667a9a,166:f4689cb00bc33d7617c7a4ddd6b460c88b65a9ab --upload=gs://kubernetes-upstream/pr-logs --scenario=execute -- make sanity-test I1001 17:41:24.497] Bootstrap pull-azuredisk-csi-driver-sanity... I1001 17:41:24.501] Builder: 90d99e05-e472-11e9-918b-16773c0c7aed I1001 17:41:24.501] Image: gcr.io/k8s-testimages/kubekins-e2e:v20190927-21e0205-master I1001 17:41:24.501] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/kubernetes-sigs_azuredisk-csi-driver/166/pull-azuredisk-csi-driver-sanity/1179088765260402690 I1001 17:41:24.502] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1001 17:41:25.057] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1001 17:41:25.089] process 32 exited with code 0 after 0.0m I1001 17:41:25.090] Call: gcloud config get-value account I1001 17:41:25.358] process 44 exited with code 0 after 0.0m I1001 17:41:25.358] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1001 17:41:25.358] Root: /go/src I1001 17:41:25.359] cd to /go/src I1001 17:41:25.359] Checkout: /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver master:6b4d4209385f8a3b04a39f1970017a27f2667a9a,166:f4689cb00bc33d7617c7a4ddd6b460c88b65a9ab to /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver I1001 17:41:25.359] Call: git init github.com/kubernetes-sigs/azuredisk-csi-driver I1001 17:41:25.363] Initialized empty Git repository in /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/.git/ I1001 17:41:25.363] process 56 exited with code 0 after 0.0m I1001 17:41:25.364] Call: git config --local user.name 'K8S Bootstrap' I1001 17:41:25.366] process 57 exited with code 0 after 0.0m I1001 17:41:25.366] Call: git config --local user.email k8s_bootstrap@localhost I1001 17:41:25.369] process 58 exited with code 0 after 0.0m I1001 17:41:25.369] Call: git fetch --quiet --tags https://github.com/kubernetes-sigs/azuredisk-csi-driver master +refs/pull/166/head:refs/pr/166 I1001 17:41:31.013] process 59 exited with code 0 after 0.1m I1001 17:41:31.014] Call: git checkout -B test 6b4d4209385f8a3b04a39f1970017a27f2667a9a W1001 17:41:31.446] Switched to a new branch 'test' I1001 17:41:31.449] process 71 exited with code 0 after 0.0m I1001 17:41:31.449] Call: git show -s --format=format:%ct HEAD I1001 17:41:31.452] process 72 exited with code 0 after 0.0m I1001 17:41:31.453] Call: git merge --no-ff -m 'Merge +refs/pull/166/head:refs/pr/166' f4689cb00bc33d7617c7a4ddd6b460c88b65a9ab I1001 17:41:32.562] Removing test/integration/azure.json I1001 17:41:32.562] Removing test/e2e/run-test.sh I1001 17:41:32.562] Merge made by the 'recursive' strategy. I1001 17:41:32.571] .travis.yml | 21 +- I1001 17:41:32.571] Gopkg.lock | 17 +- I1001 17:41:32.571] Makefile | 102 +- I1001 17:41:32.572] hack/verify-all.sh | 2 +- I1001 17:41:32.572] hack/verify-gofmt.sh | 2 +- I1001 17:41:32.572] hack/verify-golint.sh | 7 +- I1001 17:41:32.572] pkg/azuredisk/controllerserver.go | 2 +- I1001 17:41:32.572] test/e2e/dynamic_provisioning.go | 10 - I1001 17:41:32.572] test/e2e/pre_provisioning.go | 16 +- I1001 17:41:32.573] test/e2e/run-test.sh | 37 - I1001 17:41:32.573] test/e2e/suite_test.go | 87 + I1001 17:41:32.573] test/integration/azure.json | 33 - I1001 17:41:32.573] test/integration/integration_test.go | 90 + I1001 17:41:32.573] test/integration/run-test.sh | 157 +- I1001 17:41:32.573] test/integration/run-tests-all-clouds.sh | 32 +- I1001 17:41:32.574] test/sanity/run-test.sh | 47 +- I1001 17:41:32.574] test/sanity/run-tests-all-clouds.sh | 37 +- I1001 17:41:32.574] test/sanity/sanity_test.go | 72 +- I1001 17:41:32.574] test/utils/azure/azure_helpers.go | 96 + I1001 17:41:32.574] test/utils/credentials/credentials.go | 188 ++ I1001 17:41:32.574] test/utils/credentials/credentials_test.go | 181 ++ I1001 17:41:32.575] test/utils/testutil/testutil.go | 8 + I1001 17:41:32.575] .../resources/mgmt/2018-05-01/resources/client.go | 51 + I1001 17:41:32.575] .../2018-05-01/resources/deploymentoperations.go | 474 +++++ I1001 17:41:32.575] .../mgmt/2018-05-01/resources/deployments.go | 1553 +++++++++++++++ I1001 17:41:32.575] .../resources/mgmt/2018-05-01/resources/groups.go | 676 +++++++ I1001 17:41:32.576] .../resources/mgmt/2018-05-01/resources/models.go | 2044 ++++++++++++++++++++ I1001 17:41:32.576] .../mgmt/2018-05-01/resources/operations.go | 147 ++ I1001 17:41:32.576] .../mgmt/2018-05-01/resources/providers.go | 392 ++++ I1001 17:41:32.576] .../mgmt/2018-05-01/resources/resources.go | 1352 +++++++++++++ I1001 17:41:32.576] .../resources/mgmt/2018-05-01/resources/tags.go | 454 +++++ I1001 17:41:32.576] .../resources/mgmt/2018-05-01/resources/version.go | 30 + I1001 17:41:32.577] vendor/github.com/pelletier/go-toml/LICENSE | 21 + I1001 17:41:32.577] vendor/github.com/pelletier/go-toml/doc.go | 23 + I1001 17:41:32.577] vendor/github.com/pelletier/go-toml/fuzz.go | 31 + I1001 17:41:32.577] vendor/github.com/pelletier/go-toml/keysparsing.go | 113 ++ I1001 17:41:32.577] vendor/github.com/pelletier/go-toml/lexer.go | 752 +++++++ I1001 17:41:32.578] vendor/github.com/pelletier/go-toml/marshal.go | 803 ++++++++ I1001 17:41:32.578] vendor/github.com/pelletier/go-toml/parser.go | 442 +++++ I1001 17:41:32.578] vendor/github.com/pelletier/go-toml/position.go | 29 + I1001 17:41:32.578] vendor/github.com/pelletier/go-toml/token.go | 144 ++ I1001 17:41:32.578] vendor/github.com/pelletier/go-toml/toml.go | 393 ++++ I1001 17:41:32.578] .../pelletier/go-toml/tomltree_create.go | 142 ++ I1001 17:41:32.579] .../github.com/pelletier/go-toml/tomltree_write.go | 434 +++++ I1001 17:41:32.579] .../azure/azure_controller_common.go | 29 +- I1001 17:41:32.579] 45 files changed, 11409 insertions(+), 364 deletions(-) I1001 17:41:32.579] delete mode 100755 test/e2e/run-test.sh I1001 17:41:32.579] delete mode 100644 test/integration/azure.json I1001 17:41:32.579] create mode 100644 test/integration/integration_test.go I1001 17:41:32.579] create mode 100644 test/utils/azure/azure_helpers.go I1001 17:41:32.580] create mode 100644 test/utils/credentials/credentials.go I1001 17:41:32.580] create mode 100644 test/utils/credentials/credentials_test.go I1001 17:41:32.580] create mode 100644 test/utils/testutil/testutil.go I1001 17:41:32.580] create mode 100644 vendor/github.com/Azure/azure-sdk-for-go/services/resources/mgmt/2018-05-01/resources/client.go I1001 17:41:32.580] create mode 100644 vendor/github.com/Azure/azure-sdk-for-go/services/resources/mgmt/2018-05-01/resources/deploymentoperations.go I1001 17:41:32.580] create mode 100644 vendor/github.com/Azure/azure-sdk-for-go/services/resources/mgmt/2018-05-01/resources/deployments.go I1001 17:41:32.581] create mode 100644 vendor/github.com/Azure/azure-sdk-for-go/services/resources/mgmt/2018-05-01/resources/groups.go I1001 17:41:32.581] create mode 100644 vendor/github.com/Azure/azure-sdk-for-go/services/resources/mgmt/2018-05-01/resources/models.go I1001 17:41:32.581] create mode 100644 vendor/github.com/Azure/azure-sdk-for-go/services/resources/mgmt/2018-05-01/resources/operations.go I1001 17:41:32.581] create mode 100644 vendor/github.com/Azure/azure-sdk-for-go/services/resources/mgmt/2018-05-01/resources/providers.go I1001 17:41:32.581] create mode 100644 vendor/github.com/Azure/azure-sdk-for-go/services/resources/mgmt/2018-05-01/resources/resources.go I1001 17:41:32.581] create mode 100644 vendor/github.com/Azure/azure-sdk-for-go/services/resources/mgmt/2018-05-01/resources/tags.go I1001 17:41:32.582] create mode 100644 vendor/github.com/Azure/azure-sdk-for-go/services/resources/mgmt/2018-05-01/resources/version.go I1001 17:41:32.582] create mode 100644 vendor/github.com/pelletier/go-toml/LICENSE I1001 17:41:32.582] create mode 100644 vendor/github.com/pelletier/go-toml/doc.go I1001 17:41:32.582] create mode 100644 vendor/github.com/pelletier/go-toml/fuzz.go I1001 17:41:32.582] create mode 100644 vendor/github.com/pelletier/go-toml/keysparsing.go I1001 17:41:32.582] create mode 100644 vendor/github.com/pelletier/go-toml/lexer.go I1001 17:41:32.583] create mode 100644 vendor/github.com/pelletier/go-toml/marshal.go I1001 17:41:32.583] create mode 100644 vendor/github.com/pelletier/go-toml/parser.go I1001 17:41:32.583] create mode 100644 vendor/github.com/pelletier/go-toml/position.go I1001 17:41:32.583] create mode 100644 vendor/github.com/pelletier/go-toml/token.go I1001 17:41:32.583] create mode 100644 vendor/github.com/pelletier/go-toml/toml.go I1001 17:41:32.583] create mode 100644 vendor/github.com/pelletier/go-toml/tomltree_create.go I1001 17:41:32.583] create mode 100644 vendor/github.com/pelletier/go-toml/tomltree_write.go I1001 17:41:32.584] process 73 exited with code 0 after 0.0m I1001 17:41:32.584] Configure environment... I1001 17:41:32.584] Call: git show -s --format=format:%ct HEAD I1001 17:41:32.588] process 75 exited with code 0 after 0.0m I1001 17:41:32.588] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1001 17:41:33.890] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1001 17:41:34.032] process 76 exited with code 0 after 0.0m I1001 17:41:34.033] Call: gcloud config get-value account I1001 17:41:34.290] process 88 exited with code 0 after 0.0m I1001 17:41:34.290] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1001 17:41:34.290] Start 1179088765260402690 at unknown... I1001 17:41:34.294] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil_bqDGNg gs://kubernetes-upstream/pr-logs/pull/kubernetes-sigs_azuredisk-csi-driver/166/pull-azuredisk-csi-driver-sanity/1179088765260402690/started.json I1001 17:41:36.219] process 100 exited with code 0 after 0.0m I1001 17:41:36.220] Call: gsutil -q -h Content-Type:text/plain -h 'x-goog-meta-link: gs://kubernetes-upstream/pr-logs/pull/kubernetes-sigs_azuredisk-csi-driver/166/pull-azuredisk-csi-driver-sanity/1179088765260402690' cp /tmp/gsutil_i4mWtC gs://kubernetes-upstream/pr-logs/directory/pull-azuredisk-csi-driver-sanity/1179088765260402690.txt I1001 17:41:37.711] process 278 exited with code 0 after 0.0m I1001 17:41:37.712] Call: /workspace/./test-infra/jenkins/../scenarios/execute.py make sanity-test W1001 17:41:37.742] Run: ('make', 'sanity-test') I1001 17:41:37.843] if [ ! -d ./vendor ]; then dep ensure -vendor-only; fi I1001 17:41:37.844] CGO_ENABLED=0 GOOS=linux go build -a -ldflags "-X github.com/kubernetes-sigs/azuredisk-csi-driver/pkg/azuredisk.driverVersion=e2e- -X github.com/kubernetes-sigs/azuredisk-csi-driver/pkg/azuredisk.gitCommit=3f222044af0d020ba548d5ab0f64551eb331cd04 -X github.com/kubernetes-sigs/azuredisk-csi-driver/pkg/azuredisk.buildDate=2019-10-01T17:41:37Z -X github.com/kubernetes-sigs/azuredisk-csi-driver/pkg/azuredisk.DriverName=disk.csi.azure.com -X github.com/kubernetes-sigs/azuredisk-csi-driver/pkg/azuredisk.topologyKey=topology.disk.csi.azure.com/zone -extldflags "-static"" -o _output/azurediskplugin ./pkg/azurediskplugin I1001 17:43:39.875] go test -v -timeout=20m ./test/sanity I1001 17:44:03.690] === RUN TestSanity I1001 17:44:03.691] 2019/10/01 17:44:03 Creating resource group azuredisk-csi-driver-test-0f14dc42-e473-11e9-b559-0aff32adc9db in AzurePublicCloud I1001 17:44:18.008] ./test/sanity/run-tests-all-clouds.sh: line 27: sudo: command not found I1001 17:44:18.009] Installing CSI sanity test binary... I1001 17:44:18.013] Cloning into 'csi-test'... I1001 17:44:19.340] Note: checking out '5b1e3786b7c8f7ca514b40e882a0b5dc36e4c842'. I1001 17:44:19.340] I1001 17:44:19.340] You are in 'detached HEAD' state. You can look around, make experimental I1001 17:44:19.341] changes and commit them, and you can discard any commits you make in this I1001 17:44:19.341] state without impacting any branches by performing another checkout. I1001 17:44:19.341] I1001 17:44:19.341] If you want to create a new branch to retain commits you create, you may I1001 17:44:19.341] do so (now or later) by using -b with the checkout command again. Example: I1001 17:44:19.342] I1001 17:44:19.342] git checkout -b I1001 17:44:19.342] I1001 17:44:19.514] /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/csi-test/cmd/csi-sanity /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver I1001 17:44:19.515] make[1]: Entering directory '/go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/csi-test/cmd/csi-sanity' I1001 17:44:19.563] go test -ldflags "-w -X github.com/kubernetes-csi/csi-test/cmd/csi-sanity.VERSION=v1.1.0-HEAD -extldflags '-z relro -z now'" -c -o csi-sanity I1001 17:44:25.702] make[1]: Leaving directory '/go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/csi-test/cmd/csi-sanity' I1001 17:44:25.702] /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver I1001 17:44:25.702] ./test/sanity/run-tests-all-clouds.sh: line 29: sudo: command not found I1001 17:44:25.710] 2019/10/01 17:44:25 Deleting resource group azuredisk-csi-driver-test-0f14dc42-e473-11e9-b559-0aff32adc9db I1001 17:45:57.514] --- FAIL: TestSanity (113.82s) I1001 17:45:57.514] sanity_test.go:78: Sanity test failed exit status 127 I1001 17:45:57.514] FAIL I1001 17:45:57.515] FAIL github.com/kubernetes-sigs/azuredisk-csi-driver/test/sanity 113.839s I1001 17:45:57.558] Makefile:50: recipe for target 'sanity-test' failed W1001 17:45:57.564] make: *** [sanity-test] Error 1 W1001 17:45:57.564] Traceback (most recent call last): W1001 17:45:57.564] File "/workspace/./test-infra/jenkins/../scenarios/execute.py", line 50, in W1001 17:45:57.564] main(ARGS.env, ARGS.cmd + ARGS.args) W1001 17:45:57.565] File "/workspace/./test-infra/jenkins/../scenarios/execute.py", line 41, in main W1001 17:45:57.565] check(*cmd) W1001 17:45:57.565] File "/workspace/./test-infra/jenkins/../scenarios/execute.py", line 30, in check W1001 17:45:57.565] subprocess.check_call(cmd) W1001 17:45:57.565] File "/usr/lib/python2.7/subprocess.py", line 186, in check_call W1001 17:45:57.565] raise CalledProcessError(retcode, cmd) W1001 17:45:57.566] subprocess.CalledProcessError: Command '('make', 'sanity-test')' returned non-zero exit status 2 E1001 17:45:57.566] Command failed I1001 17:45:57.566] process 456 exited with code 1 after 4.3m E1001 17:45:57.566] FAIL: pull-azuredisk-csi-driver-sanity I1001 17:45:57.566] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1001 17:45:59.027] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1001 17:45:59.065] process 8258 exited with code 0 after 0.0m I1001 17:45:59.065] Call: gcloud config get-value account I1001 17:45:59.306] process 8270 exited with code 0 after 0.0m I1001 17:45:59.306] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1001 17:45:59.306] Upload result and artifacts... I1001 17:45:59.306] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/kubernetes-sigs_azuredisk-csi-driver/166/pull-azuredisk-csi-driver-sanity/1179088765260402690 W1001 17:45:59.306] Missing local artifacts : /workspace/_artifacts W1001 17:45:59.306] metadata path /workspace/_artifacts/metadata.json does not exist W1001 17:45:59.307] metadata not found or invalid, init with empty metadata I1001 17:45:59.307] Call: git rev-parse HEAD I1001 17:45:59.309] process 8282 exited with code 0 after 0.0m I1001 17:45:59.309] Call: git rev-parse HEAD I1001 17:45:59.312] process 8283 exited with code 0 after 0.0m I1001 17:45:59.312] Call: gsutil stat gs://kubernetes-upstream/pr-logs/directory/pull-azuredisk-csi-driver-sanity/jobResultsCache.json W1001 17:46:00.272] No URLs matched: gs://kubernetes-upstream/pr-logs/directory/pull-azuredisk-csi-driver-sanity/jobResultsCache.json I1001 17:46:00.273] process 8284 exited with code 1 after 0.0m I1001 17:46:00.274] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:0 cp /tmp/gsutil_LxwBpU gs://kubernetes-upstream/pr-logs/directory/pull-azuredisk-csi-driver-sanity/jobResultsCache.json I1001 17:46:01.541] process 8426 exited with code 0 after 0.0m I1001 17:46:01.542] Call: gsutil stat gs://kubernetes-upstream/pr-logs/pull/kubernetes-sigs_azuredisk-csi-driver/166/pull-azuredisk-csi-driver-sanity/jobResultsCache.json W1001 17:46:02.466] No URLs matched: gs://kubernetes-upstream/pr-logs/pull/kubernetes-sigs_azuredisk-csi-driver/166/pull-azuredisk-csi-driver-sanity/jobResultsCache.json I1001 17:46:02.467] process 8604 exited with code 1 after 0.0m I1001 17:46:02.467] Call: gsutil -q -h Content-Type:application/json -h x-goog-if-generation-match:0 cp /tmp/gsutil__KM786 gs://kubernetes-upstream/pr-logs/pull/kubernetes-sigs_azuredisk-csi-driver/166/pull-azuredisk-csi-driver-sanity/jobResultsCache.json I1001 17:46:03.856] process 8746 exited with code 0 after 0.0m I1001 17:46:03.857] Call: gsutil -q -h Content-Type:application/json cp /tmp/gsutil_J1TsdU gs://kubernetes-upstream/pr-logs/pull/kubernetes-sigs_azuredisk-csi-driver/166/pull-azuredisk-csi-driver-sanity/1179088765260402690/finished.json I1001 17:46:05.171] process 8924 exited with code 0 after 0.0m I1001 17:46:05.171] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_si1kVJ gs://kubernetes-upstream/pr-logs/pull/kubernetes-sigs_azuredisk-csi-driver/166/pull-azuredisk-csi-driver-sanity/latest-build.txt I1001 17:46:06.565] process 9102 exited with code 0 after 0.0m I1001 17:46:06.565] Call: gsutil -q -h Content-Type:text/plain -h 'Cache-Control:private, max-age=0, no-transform' cp /tmp/gsutil_tXG5IO gs://kubernetes-upstream/pr-logs/directory/pull-azuredisk-csi-driver-sanity/latest-build.txt I1001 17:46:07.866] process 9280 exited with code 0 after 0.0m