This job view page is being replaced by Spyglass soon. Check out the new job view.
PRandyzhangx: test: add github action
ResultFAILURE
Tests 0 failed / 12 succeeded
Started2020-09-11 14:51
Elapsed25m11s
Revision19b3a031b5e4f7b7ba79343e38528b26fb7a7d4d
Refs 236

No Test Failures!


Show 12 Passed Tests

Error lines from build-log.txt

... skipping 161 lines ...
pod/tiller-deploy-78f484dbbd-gzvsl condition met
helm version
Client: &version.Version{SemVer:"v2.11.0", GitCommit:"2e55dbe1fdb5fdb96b75ff144a339489417b146b", GitTreeState:"clean"}
Server: &version.Version{SemVer:"v2.13.1", GitCommit:"618447cbf203d147601b4b9bd7f8c37a5d39fbb4", GitTreeState:"clean"}
# Only build and push the image if it does not exist in the registry
docker pull k8sprow.azurecr.io/blob-csi:e2e-c04107fdafd1370bf0726755fe3cb83bcbe48c9e || make blob-container push
Error response from daemon: manifest for k8sprow.azurecr.io/blob-csi:e2e-c04107fdafd1370bf0726755fe3cb83bcbe48c9e not found: manifest unknown: manifest tagged by "e2e-c04107fdafd1370bf0726755fe3cb83bcbe48c9e" is not found
make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/blob-csi-driver'
docker buildx rm container-builder || true
no builder "container-builder" found
docker buildx create --use --name=container-builder
container-builder
docker buildx build --no-cache --build-arg LDFLAGS="-X sigs.k8s.io/blob-csi-driver/pkg/blob.driverVersion=e2e-c04107fdafd1370bf0726755fe3cb83bcbe48c9e -X sigs.k8s.io/blob-csi-driver/pkg/blob.gitCommit=c04107fdafd1370bf0726755fe3cb83bcbe48c9e -X sigs.k8s.io/blob-csi-driver/pkg/blob.buildDate=2020-09-11T14:58:51Z -s -w -extldflags '-static'" -t k8sprow.azurecr.io/blob-csi:e2e-c04107fdafd1370bf0726755fe3cb83bcbe48c9e -f ./pkg/blobplugin/Dockerfile --platform="linux/amd64" --push .
... skipping 293 lines ...
#13 8.672 Building dependency tree...
#13 8.864 Reading state information...
#13 9.071 The following additional packages will be installed:
#13 9.071   cmake-data libarchive13 libblkid1 libc-dev-bin libc6-dev libcom-err2
#13 9.072   libcurl3-gnutls libcurl4 libdpkg-perl libevent-2.1-6 libexpat1 libfuse2
#13 9.072   libgdbm-compat4 libgdbm6 libglib2.0-0 libgmp-dev libgmpxx4ldbl
#13 9.072   libgnutls-dane0 libgnutls-openssl27 libgnutlsxx28 libgpg-error-dev
#13 9.072   libgssapi-krb5-2 libicu63 libidn2-dev libjsoncpp1 libk5crypto3 libkeyutils1
#13 9.072   libkrb5-3 libkrb5support0 libldap-2.4-2 libldap-common libmount1 libncurses6
#13 9.072   libncursesw6 libnghttp2-14 libp11-kit-dev libpcre16-3 libpcre2-8-0
#13 9.073   libpcre3-dev libpcre32-3 libpcrecpp0v5 libperl5.28 libprocps7 libpsl5
#13 9.073   librhash0 librtmp1 libsasl2-2 libsasl2-modules-db libselinux1-dev
#13 9.073   libsepol1-dev libssh2-1 libssl1.1 libtasn1-6-dev libtinfo6 libunbound8
... skipping 15 lines ...
#13 9.749 The following NEW packages will be installed:
#13 9.749   ca-certificates cmake cmake-data libarchive13 libblkid1 libc-dev-bin
#13 9.749   libc6-dev libcom-err2 libcurl3-gnutls libcurl4 libcurl4-gnutls-dev
#13 9.750   libdpkg-perl libevent-2.1-6 libexpat1 libfuse-dev libfuse2 libgcrypt20-dev
#13 9.750   libgdbm-compat4 libgdbm6 libglib2.0-0 libgmp-dev libgmpxx4ldbl
#13 9.750   libgnutls-dane0 libgnutls-openssl27 libgnutls28-dev libgnutlsxx28
#13 9.750   libgpg-error-dev libgssapi-krb5-2 libicu63 libidn2-dev libjsoncpp1
#13 9.750   libk5crypto3 libkeyutils1 libkrb5-3 libkrb5support0 libldap-2.4-2
#13 9.750   libldap-common libmount1 libncurses6 libncursesw6 libnghttp2-14
#13 9.750   libp11-kit-dev libpcre16-3 libpcre2-8-0 libpcre3-dev libpcre32-3
#13 9.751   libpcrecpp0v5 libperl5.28 libprocps7 libpsl5 librhash0 librtmp1 libsasl2-2
#13 9.751   libsasl2-modules-db libselinux1-dev libsepol1-dev libssh2-1 libssl1.1
#13 9.751   libtasn1-6-dev libtinfo6 libunbound8 libuuid1 libuv1 libxml2 linux-libc-dev
... skipping 56 lines ...
#13 11.39 Get:52 http://deb.debian.org/debian buster/main amd64 libpcre16-3 amd64 2:8.39-12 [259 kB]
#13 11.39 Get:53 http://deb.debian.org/debian buster/main amd64 libpcre32-3 amd64 2:8.39-12 [250 kB]
#13 11.40 Get:54 http://deb.debian.org/debian buster/main amd64 libpcrecpp0v5 amd64 2:8.39-12 [152 kB]
#13 11.41 Get:55 http://deb.debian.org/debian buster/main amd64 libpcre3-dev amd64 2:8.39-12 [650 kB]
#13 11.43 Get:56 http://deb.debian.org/debian buster/main amd64 libselinux1-dev amd64 2.8-1+b1 [169 kB]
#13 11.43 Get:57 http://deb.debian.org/debian buster/main amd64 libfuse-dev amd64 2.9.9-1+deb10u1 [152 kB]
#13 11.44 Get:58 http://deb.debian.org/debian buster/main amd64 libgpg-error-dev amd64 1.35-1 [124 kB]
#13 11.44 Get:59 http://deb.debian.org/debian buster/main amd64 libgcrypt20-dev amd64 1.8.4-5 [608 kB]
#13 11.46 Get:60 http://deb.debian.org/debian buster/main amd64 libmount1 amd64 2.33.1-0.1 [207 kB]
#13 11.47 Get:61 http://deb.debian.org/debian buster/main amd64 libglib2.0-0 amd64 2.58.3-2+deb10u2 [1258 kB]
#13 11.51 Get:62 http://deb.debian.org/debian buster/main amd64 libgmpxx4ldbl amd64 2:6.1.2+dfsg-4 [22.9 kB]
#13 11.51 Get:63 http://deb.debian.org/debian buster/main amd64 libgmp-dev amd64 2:6.1.2+dfsg-4 [628 kB]
#13 11.53 Get:64 http://deb.debian.org/debian buster/main amd64 libunbound8 amd64 1.9.0-2+deb10u2 [462 kB]
... skipping 178 lines ...
#13 20.12 Selecting previously unselected package libselinux1-dev:amd64.
#13 20.12 Preparing to unpack .../55-libselinux1-dev_2.8-1+b1_amd64.deb ...
#13 20.13 Unpacking libselinux1-dev:amd64 (2.8-1+b1) ...
#13 20.18 Selecting previously unselected package libfuse-dev.
#13 20.19 Preparing to unpack .../56-libfuse-dev_2.9.9-1+deb10u1_amd64.deb ...
#13 20.19 Unpacking libfuse-dev (2.9.9-1+deb10u1) ...
#13 20.25 Selecting previously unselected package libgpg-error-dev.

#13 20.25 Preparing to unpack .../57-libgpg-error-dev_1.35-1_amd64.deb ...

#13 20.25 Unpacking libgpg-error-dev (1.35-1) ...

#13 20.31 Selecting previously unselected package libgcrypt20-dev.
#13 20.31 Preparing to unpack .../58-libgcrypt20-dev_1.8.4-5_amd64.deb ...
#13 20.31 Unpacking libgcrypt20-dev (1.8.4-5) ...
#13 20.42 Selecting previously unselected package libmount1:amd64.
#13 20.42 Preparing to unpack .../59-libmount1_2.33.1-0.1_amd64.deb ...
#13 20.43 Unpacking libmount1:amd64 (2.33.1-0.1) ...
... skipping 60 lines ...
#13 22.09 Setting up libldap-common (2.4.47+dfsg-3+deb10u2) ...
#13 22.11 Setting up libicu63:amd64 (63.1-6+deb10u1) ...
#13 22.12 Setting up libkrb5support0:amd64 (1.17-3) ...
#13 22.13 Setting up libsasl2-modules-db:amd64 (2.1.27+dfsg-1+deb10u1) ...
#13 22.14 Setting up libgmpxx4ldbl:amd64 (2:6.1.2+dfsg-4) ...
#13 22.15 Setting up libuv1:amd64 (1.24.1-1) ...
#13 22.16 Setting up libgpg-error-dev (1.35-1) ...

#13 22.17 Setting up librtmp1:amd64 (2.4+20151223.gitfa8646d.1-2) ...
#13 22.19 Setting up libpcre32-3:amd64 (2:8.39-12) ...
#13 22.20 Setting up libuuid1:amd64 (2.33.1-0.1) ...
#13 22.21 Setting up libgnutlsxx28:amd64 (3.6.7-4+deb10u5) ...
#13 22.22 Setting up libpcre2-8-0:amd64 (10.32-5) ...
#13 22.23 Setting up libk5crypto3:amd64 (1.17-3) ...
... skipping 392 lines ...
#16 10.85 Setting up libpython-stdlib:amd64 (2.7.16-1) ...
#16 10.86 Setting up python (2.7.16-1) ...
#16 10.89 Setting up libdevmapper1.02.1:amd64 (2:1.02.155-3) ...
#16 10.90 Setting up dmsetup (2:1.02.155-3) ...
#16 10.92 Setting up nfs-common (1:1.3.4-2.5+deb10u1) ...
#16 10.94 /var/lib/dpkg/info/nfs-common.postinst: 7: /var/lib/dpkg/info/nfs-common.postinst: ucf: not found
#16 10.94 dpkg: error processing package nfs-common (--configure):

#16 10.94  installed nfs-common package post-installation script subprocess returned error exit status 127

#16 10.94 dpkg: dependency problems prevent configuration of nfs-kernel-server:
#16 10.94  nfs-kernel-server depends on nfs-common (= 1:1.3.4-2.5+deb10u1); however:
#16 10.94   Package nfs-common is not configured yet.
#16 10.94 
#16 10.94 dpkg: error processing package nfs-kernel-server (--configure):

#16 10.94  dependency problems - leaving unconfigured
#16 10.94 Processing triggers for libc-bin (2.28-10) ...
#16 10.99 Errors were encountered while processing:
#16 10.99  nfs-common
#16 10.99  nfs-kernel-server
#16 11.05 E: Sub-process /usr/bin/dpkg returned an error code (1)
#16 DONE 11.2s

#17 exporting to image
#17 exporting layers
#17 exporting layers 13.0s done
#17 exporting manifest sha256:d92e9be614333e166e99372da2dad5044fc00337cc14f58c175eb08708e06664 0.0s done
... skipping 104 lines ...
Git Commit: N/A
Go Version: go1.15
Platform: linux/amd64

Streaming logs below:
STEP: Building a namespace api object, basename blob
W0911 15:02:05.052753   12483 azure_config.go:52] Failed to get cloud-config from secret: failed to get secret azure-cloud-provider: secrets "azure-cloud-provider" not found, skip initializing from secret
I0911 15:02:05.053646   12483 blob.go:102] disable UseInstanceMetadata for controller
I0911 15:02:05.054076   12483 driver.go:80] Enabling controller service capability: CREATE_DELETE_VOLUME
I0911 15:02:05.054095   12483 driver.go:99] Enabling volume access mode: SINGLE_NODE_WRITER
I0911 15:02:05.054136   12483 driver.go:99] Enabling volume access mode: SINGLE_NODE_READER_ONLY
I0911 15:02:05.054142   12483 driver.go:99] Enabling volume access mode: MULTI_NODE_READER_ONLY
I0911 15:02:05.054147   12483 driver.go:99] Enabling volume access mode: MULTI_NODE_SINGLE_WRITER
... skipping 25 lines ...
Sep 11 15:02:22.326: INFO: PersistentVolumeClaim pvc-w7s86 found but phase is Pending instead of Bound.
Sep 11 15:02:24.363: INFO: PersistentVolumeClaim pvc-w7s86 found and phase=Bound (18.361292648s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Sep 11 15:02:24.470: INFO: Waiting up to 15m0s for pod "blob-volume-tester-np5k2" in namespace "blob-8047" to be "Succeeded or Failed"
Sep 11 15:02:24.505: INFO: Pod "blob-volume-tester-np5k2": Phase="Pending", Reason="", readiness=false. Elapsed: 35.140999ms
Sep 11 15:02:26.541: INFO: Pod "blob-volume-tester-np5k2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.071667953s
Sep 11 15:02:28.577: INFO: Pod "blob-volume-tester-np5k2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.107515712s
STEP: Saw pod success
Sep 11 15:02:28.577: INFO: Pod "blob-volume-tester-np5k2" satisfied condition "Succeeded or Failed"
Sep 11 15:02:28.577: INFO: deleting Pod "blob-8047"/"blob-volume-tester-np5k2"
Sep 11 15:02:28.637: INFO: Pod blob-volume-tester-np5k2 has the following logs: hello world

STEP: Deleting pod blob-volume-tester-np5k2 in namespace blob-8047
Sep 11 15:02:28.681: INFO: deleting PVC "blob-8047"/"pvc-w7s86"
Sep 11 15:02:28.681: INFO: Deleting PersistentVolumeClaim "pvc-w7s86"
... skipping 115 lines ...
Sep 11 15:04:36.338: INFO: PersistentVolumeClaim pvc-kk4bn found but phase is Pending instead of Bound.
Sep 11 15:04:38.373: INFO: PersistentVolumeClaim pvc-kk4bn found and phase=Bound (20.396529607s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with an error
Sep 11 15:04:38.480: INFO: Waiting up to 15m0s for pod "blob-volume-tester-fdh9s" in namespace "blob-5026" to be "Error status code"
Sep 11 15:04:38.515: INFO: Pod "blob-volume-tester-fdh9s": Phase="Pending", Reason="", readiness=false. Elapsed: 34.933982ms
Sep 11 15:04:40.552: INFO: Pod "blob-volume-tester-fdh9s": Phase="Failed", Reason="", readiness=false. Elapsed: 2.071388397s
STEP: Saw pod failure
Sep 11 15:04:40.552: INFO: Pod "blob-volume-tester-fdh9s" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Sep 11 15:04:40.623: INFO: deleting Pod "blob-5026"/"blob-volume-tester-fdh9s"
Sep 11 15:04:40.661: INFO: Pod blob-volume-tester-fdh9s has the following logs: touch: /mnt/test-1/data: Read-only file system

STEP: Deleting pod blob-volume-tester-fdh9s in namespace blob-5026
Sep 11 15:04:40.704: INFO: deleting PVC "blob-5026"/"pvc-kk4bn"
... skipping 265 lines ...
Sep 11 15:06:52.759: INFO: PersistentVolumeClaim pvc-brvvb found but phase is Pending instead of Bound.
Sep 11 15:06:54.795: INFO: PersistentVolumeClaim pvc-brvvb found and phase=Bound (2.074448602s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Sep 11 15:06:54.915: INFO: Waiting up to 15m0s for pod "blob-volume-tester-bnjkc" in namespace "blob-6420" to be "Succeeded or Failed"
Sep 11 15:06:54.955: INFO: Pod "blob-volume-tester-bnjkc": Phase="Pending", Reason="", readiness=false. Elapsed: 39.947272ms
Sep 11 15:06:56.994: INFO: Pod "blob-volume-tester-bnjkc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.078440334s
Sep 11 15:06:59.030: INFO: Pod "blob-volume-tester-bnjkc": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.11502704s
STEP: Saw pod success
Sep 11 15:06:59.031: INFO: Pod "blob-volume-tester-bnjkc" satisfied condition "Succeeded or Failed"
Sep 11 15:06:59.031: INFO: deleting Pod "blob-6420"/"blob-volume-tester-bnjkc"
Sep 11 15:06:59.071: INFO: Pod blob-volume-tester-bnjkc has the following logs: hello world

STEP: Deleting pod blob-volume-tester-bnjkc in namespace blob-6420
Sep 11 15:06:59.119: INFO: deleting PVC "blob-6420"/"pvc-brvvb"
Sep 11 15:06:59.119: INFO: Deleting PersistentVolumeClaim "pvc-brvvb"
... skipping 82 lines ...
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pod has 'FailedMount' event
Sep 11 15:07:36.350: INFO: deleting Pod "blob-8623"/"blob-volume-tester-kwh99"
Sep 11 15:07:36.389: INFO: Error getting logs for pod blob-volume-tester-kwh99: the server rejected our request for an unknown reason (get pods blob-volume-tester-kwh99)
STEP: Deleting pod blob-volume-tester-kwh99 in namespace blob-8623
Sep 11 15:07:36.428: INFO: deleting PVC "blob-8623"/"pvc-tg2ms"
Sep 11 15:07:36.428: INFO: Deleting PersistentVolumeClaim "pvc-tg2ms"
STEP: waiting for claim's PV "pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7" to be deleted
Sep 11 15:07:36.465: INFO: Waiting up to 10m0s for PersistentVolume pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7 to get deleted
Sep 11 15:07:36.500: INFO: PersistentVolume pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7 found and phase=Bound (35.680011ms)
... skipping 34 lines ...
Sep 11 15:08:06.709: INFO: Waiting up to 5m0s for PersistentVolumeClaims [pvc-xtn8m] to have phase Bound
Sep 11 15:08:06.744: INFO: PersistentVolumeClaim pvc-xtn8m found and phase=Bound (34.869391ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with an error
Sep 11 15:08:06.859: INFO: Waiting up to 15m0s for pod "blob-volume-tester-sx59g" in namespace "blob-953" to be "Error status code"
Sep 11 15:08:06.896: INFO: Pod "blob-volume-tester-sx59g": Phase="Pending", Reason="", readiness=false. Elapsed: 36.607025ms
Sep 11 15:08:08.936: INFO: Pod "blob-volume-tester-sx59g": Phase="Pending", Reason="", readiness=false. Elapsed: 2.076226965s
Sep 11 15:08:10.972: INFO: Pod "blob-volume-tester-sx59g": Phase="Failed", Reason="", readiness=false. Elapsed: 4.113133718s
STEP: Saw pod failure
Sep 11 15:08:10.972: INFO: Pod "blob-volume-tester-sx59g" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Sep 11 15:08:11.010: INFO: deleting Pod "blob-953"/"blob-volume-tester-sx59g"
Sep 11 15:08:11.051: INFO: Pod blob-volume-tester-sx59g has the following logs: /bin/sh: can't create /mnt/test-1/data: Read-only file system

STEP: Deleting pod blob-volume-tester-sx59g in namespace blob-953
Sep 11 15:08:11.103: INFO: deleting PVC "blob-953"/"pvc-xtn8m"
... skipping 79 lines ...
Sep 11 15:08:14.704: INFO: PersistentVolumeClaim pvc-7c5b9 found but phase is Pending instead of Bound.
Sep 11 15:08:16.740: INFO: PersistentVolumeClaim pvc-7c5b9 found and phase=Bound (2.07142089s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Sep 11 15:08:16.848: INFO: Waiting up to 15m0s for pod "blob-volume-tester-gqkjc" in namespace "blob-5285" to be "Succeeded or Failed"
Sep 11 15:08:16.883: INFO: Pod "blob-volume-tester-gqkjc": Phase="Pending", Reason="", readiness=false. Elapsed: 34.970428ms
Sep 11 15:08:18.919: INFO: Pod "blob-volume-tester-gqkjc": Phase="Running", Reason="", readiness=true. Elapsed: 2.07184s
Sep 11 15:08:20.955: INFO: Pod "blob-volume-tester-gqkjc": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.107812969s
STEP: Saw pod success
Sep 11 15:08:20.955: INFO: Pod "blob-volume-tester-gqkjc" satisfied condition "Succeeded or Failed"
Sep 11 15:08:20.955: INFO: deleting Pod "blob-5285"/"blob-volume-tester-gqkjc"
Sep 11 15:08:20.994: INFO: Pod blob-volume-tester-gqkjc has the following logs: hello world

STEP: Deleting pod blob-volume-tester-gqkjc in namespace blob-5285
Sep 11 15:08:21.046: INFO: deleting PVC "blob-5285"/"pvc-7c5b9"
Sep 11 15:08:21.046: INFO: Deleting PersistentVolumeClaim "pvc-7c5b9"
... skipping 33 lines ...
Sep 11 15:08:22.693: INFO: Waiting up to 5m0s for PersistentVolumeClaims [pvc-zh9rl] to have phase Bound
Sep 11 15:08:22.728: INFO: PersistentVolumeClaim pvc-zh9rl found and phase=Bound (35.0822ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Sep 11 15:08:22.842: INFO: Waiting up to 15m0s for pod "blob-volume-tester-2n9x6" in namespace "blob-8590" to be "Succeeded or Failed"
Sep 11 15:08:22.878: INFO: Pod "blob-volume-tester-2n9x6": Phase="Pending", Reason="", readiness=false. Elapsed: 35.419096ms
Sep 11 15:08:24.918: INFO: Pod "blob-volume-tester-2n9x6": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.075911227s
STEP: Saw pod success
Sep 11 15:08:24.918: INFO: Pod "blob-volume-tester-2n9x6" satisfied condition "Succeeded or Failed"
Sep 11 15:08:24.918: INFO: deleting Pod "blob-8590"/"blob-volume-tester-2n9x6"
Sep 11 15:08:24.962: INFO: Pod blob-volume-tester-2n9x6 has the following logs: hello world

STEP: Deleting pod blob-volume-tester-2n9x6 in namespace blob-8590
Sep 11 15:08:25.006: INFO: deleting PVC "blob-8590"/"pvc-zh9rl"
Sep 11 15:08:25.006: INFO: Deleting PersistentVolumeClaim "pvc-zh9rl"
... skipping 63 lines ...
[pod/csi-blob-controller-5cd856bcfc-897v6/blob] Git Commit: c04107fdafd1370bf0726755fe3cb83bcbe48c9e
[pod/csi-blob-controller-5cd856bcfc-897v6/blob] Go Version: go1.13.10
[pod/csi-blob-controller-5cd856bcfc-897v6/blob] Platform: linux/amd64
[pod/csi-blob-controller-5cd856bcfc-897v6/blob] 
[pod/csi-blob-controller-5cd856bcfc-897v6/blob] Streaming logs below:
[pod/csi-blob-controller-5cd856bcfc-897v6/blob] I0911 15:02:02.465188       1 azure.go:52] reading cloud config from secret
[pod/csi-blob-controller-5cd856bcfc-897v6/blob] W0911 15:02:02.488926       1 azure_config.go:52] Failed to get cloud-config from secret: failed to get secret azure-cloud-provider: secrets "azure-cloud-provider" not found, skip initializing from secret
[pod/csi-blob-controller-5cd856bcfc-897v6/blob] I0911 15:02:02.488943       1 azure.go:58] could not read cloud config from secret
[pod/csi-blob-controller-5cd856bcfc-897v6/blob] I0911 15:02:02.488951       1 azure.go:64] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
[pod/csi-blob-controller-5cd856bcfc-897v6/blob] I0911 15:02:02.488996       1 azure.go:74] read cloud config from file: /etc/kubernetes/azure.json successfully
[pod/csi-blob-controller-5cd856bcfc-897v6/blob] I0911 15:02:02.489807       1 azure_auth.go:232] Using AzurePublicCloud environment
[pod/csi-blob-controller-5cd856bcfc-897v6/blob] I0911 15:02:02.489858       1 azure_auth.go:117] azure: using client_id+client_secret to retrieve access token
[pod/csi-blob-controller-5cd856bcfc-897v6/blob] I0911 15:02:02.489877       1 azure.go:432] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 122 lines ...
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] Git Commit: c04107fdafd1370bf0726755fe3cb83bcbe48c9e
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] Go Version: go1.13.10
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] Platform: linux/amd64
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] 
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] Streaming logs below:
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:01.406497       1 azure.go:52] reading cloud config from secret
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] W0911 15:02:01.424770       1 azure_config.go:52] Failed to get cloud-config from secret: failed to get secret azure-cloud-provider: secrets "azure-cloud-provider" not found, skip initializing from secret
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:01.424794       1 azure.go:58] could not read cloud config from secret
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:01.424801       1 azure.go:64] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:01.424820       1 azure.go:74] read cloud config from file: /etc/kubernetes/azure.json successfully
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:01.425363       1 azure_auth.go:232] Using AzurePublicCloud environment
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:01.425401       1 azure_auth.go:117] azure: using client_id+client_secret to retrieve access token
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:01.425418       1 azure.go:432] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 77 lines ...
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:06.002870       1 utils.go:107] GRPC call: /csi.v1.Controller/CreateVolume
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:06.002893       1 utils.go:108] GRPC request: {"capacity_range":{"required_bytes":10737418240},"name":"pvc-28f1aa78-be75-4993-a625-9bd81b047aff","parameters":{"skuName":"Standard_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4","mount_flags":["-o allow_other","--file-cache-timeout-in-seconds=120"]}},"access_mode":{"mode":1}}]}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:06.388447       1 azure_storageaccount.go:142] azure - no matching account found, begin to create a new account fuse644d166689d4439c92d in resource group kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac, location: eastus2, accountType: Standard_LRS, accountKind: StorageV2, tags: map[created-by:azure]
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:17.006435       1 utils.go:107] GRPC call: /csi.v1.Controller/CreateVolume
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:17.006451       1 utils.go:108] GRPC request: {"capacity_range":{"required_bytes":10737418240},"name":"pvc-28f1aa78-be75-4993-a625-9bd81b047aff","parameters":{"skuName":"Standard_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4","mount_flags":["-o allow_other","--file-cache-timeout-in-seconds=120"]}},"access_mode":{"mode":1}}]}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:17.044908       1 azure_storageaccount.go:118] found a matching account fuse644d166689d4439c92d type Standard_LRS location eastus2
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:17.089741       1 azure_storageaccountclient.go:185] Received error in storageaccount.listkeys.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac/providers/Microsoft.Storage/storageAccounts/fuse644d166689d4439c92d, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: {"error":{"code":"StorageAccountIsNotProvisioned","message":"The storage account provisioning state must be 'Succeeded' before executing the operation."}}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] W0911 15:02:17.089792       1 controllerserver.go:126] EnsureStorageAccount() failed with error(could not get storage key for storage account fuse644d166689d4439c92d: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: {"error":{"code":"StorageAccountIsNotProvisioned","message":"The storage account provisioning state must be 'Succeeded' before executing the operation."}}), waiting for retrying
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:24.206544       1 controllerserver.go:145] begin to create container(pvc-28f1aa78-be75-4993-a625-9bd81b047aff) on account(fuse644d166689d4439c92d) type(Standard_LRS) rg(kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac) location() size(10)
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:24.235061       1 controllerserver.go:166] create container pvc-28f1aa78-be75-4993-a625-9bd81b047aff on storage account fuse644d166689d4439c92d successfully
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:24.235091       1 utils.go:113] GRPC response: {"volume":{"capacity_bytes":10737418240,"volume_context":{"skuName":"Standard_LRS"},"volume_id":"kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fuse644d166689d4439c92d#pvc-28f1aa78-be75-4993-a625-9bd81b047aff"}}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:24.248562       1 azure_storageaccount.go:118] found a matching account fuse644d166689d4439c92d type Standard_LRS location eastus2
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:24.290348       1 controllerserver.go:145] begin to create container(pvc-28f1aa78-be75-4993-a625-9bd81b047aff) on account(fuse644d166689d4439c92d) type(Standard_LRS) rg(kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac) location() size(10)
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:24.292906       1 controllerserver.go:166] create container pvc-28f1aa78-be75-4993-a625-9bd81b047aff on storage account fuse644d166689d4439c92d successfully
... skipping 6 lines ...
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:34.799740       1 utils.go:107] GRPC call: /csi.v1.Controller/CreateVolume
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:34.799757       1 utils.go:108] GRPC request: {"capacity_range":{"required_bytes":10737418240},"name":"pvc-7daec658-fb77-4089-a156-8d7ada9e1e1d","parameters":{"skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4","mount_flags":["-o allow_other","--file-cache-timeout-in-seconds=120"]}},"access_mode":{"mode":1}}]}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:34.836918       1 azure_storageaccount.go:142] azure - no matching account found, begin to create a new account fusef82da047e0994372a8a in resource group kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac, location: eastus2, accountType: Premium_LRS, accountKind: BlockBlobStorage, tags: map[created-by:azure]
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:45.805518       1 utils.go:107] GRPC call: /csi.v1.Controller/CreateVolume
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:45.805573       1 utils.go:108] GRPC request: {"capacity_range":{"required_bytes":10737418240},"name":"pvc-7daec658-fb77-4089-a156-8d7ada9e1e1d","parameters":{"skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4","mount_flags":["-o allow_other","--file-cache-timeout-in-seconds=120"]}},"access_mode":{"mode":1}}]}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:45.845910       1 azure_storageaccount.go:118] found a matching account fusef82da047e0994372a8a type Premium_LRS location eastus2
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:45.893776       1 azure_storageaccountclient.go:185] Received error in storageaccount.listkeys.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac/providers/Microsoft.Storage/storageAccounts/fusef82da047e0994372a8a, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: {"error":{"code":"StorageAccountIsNotProvisioned","message":"The storage account provisioning state must be 'Succeeded' before executing the operation."}}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] W0911 15:02:45.893818       1 controllerserver.go:126] EnsureStorageAccount() failed with error(could not get storage key for storage account fusef82da047e0994372a8a: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: {"error":{"code":"StorageAccountIsNotProvisioned","message":"The storage account provisioning state must be 'Succeeded' before executing the operation."}}), waiting for retrying
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:51.714650       1 azure_storageaccount.go:118] found a matching account fusef82da047e0994372a8a type Premium_LRS location eastus2
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:51.753843       1 controllerserver.go:145] begin to create container(pvc-7daec658-fb77-4089-a156-8d7ada9e1e1d) on account(fusef82da047e0994372a8a) type(Premium_LRS) rg(kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac) location() size(10)
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:51.825398       1 controllerserver.go:166] create container pvc-7daec658-fb77-4089-a156-8d7ada9e1e1d on storage account fusef82da047e0994372a8a successfully
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:51.825416       1 utils.go:113] GRPC response: {"volume":{"capacity_bytes":10737418240,"volume_context":{"skuName":"Premium_LRS"},"volume_id":"kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fusef82da047e0994372a8a#pvc-7daec658-fb77-4089-a156-8d7ada9e1e1d"}}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:52.553378       1 controllerserver.go:145] begin to create container(pvc-7daec658-fb77-4089-a156-8d7ada9e1e1d) on account(fusef82da047e0994372a8a) type(Premium_LRS) rg(kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac) location() size(10)
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:02:52.556101       1 controllerserver.go:166] create container pvc-7daec658-fb77-4089-a156-8d7ada9e1e1d on storage account fusef82da047e0994372a8a successfully
... skipping 18 lines ...
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:25.272085       1 utils.go:107] GRPC call: /csi.v1.Identity/Probe
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:25.272104       1 utils.go:108] GRPC request: {}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:25.272510       1 utils.go:113] GRPC response: {"ready":{"value":true}}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:28.983793       1 utils.go:107] GRPC call: /csi.v1.Controller/CreateVolume
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:28.983813       1 utils.go:108] GRPC request: {"capacity_range":{"required_bytes":10737418240},"name":"pvc-ca1d0941-399c-449d-83b7-e9f15973ac46","parameters":{"skuName":"Standard_GRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:29.031771       1 azure_storageaccount.go:118] found a matching account fusefa4374533667436d954 type Standard_GRS location eastus2
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:29.077998       1 azure_storageaccountclient.go:185] Received error in storageaccount.listkeys.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac/providers/Microsoft.Storage/storageAccounts/fusefa4374533667436d954, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: {"error":{"code":"StorageAccountIsNotProvisioned","message":"The storage account provisioning state must be 'Succeeded' before executing the operation."}}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] W0911 15:04:29.078068       1 controllerserver.go:126] EnsureStorageAccount() failed with error(could not get storage key for storage account fusefa4374533667436d954: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: {"error":{"code":"StorageAccountIsNotProvisioned","message":"The storage account provisioning state must be 'Succeeded' before executing the operation."}}), waiting for retrying
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:36.696545       1 azure_storageaccount.go:118] found a matching account fusefa4374533667436d954 type Standard_GRS location eastus2
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:36.733641       1 controllerserver.go:145] begin to create container(pvc-ca1d0941-399c-449d-83b7-e9f15973ac46) on account(fusefa4374533667436d954) type(Standard_GRS) rg(kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac) location() size(10)
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:36.765272       1 controllerserver.go:166] create container pvc-ca1d0941-399c-449d-83b7-e9f15973ac46 on storage account fusefa4374533667436d954 successfully
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:36.765289       1 utils.go:113] GRPC response: {"volume":{"capacity_bytes":10737418240,"volume_context":{"skuName":"Standard_GRS"},"volume_id":"kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fusefa4374533667436d954#pvc-ca1d0941-399c-449d-83b7-e9f15973ac46"}}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:37.460519       1 controllerserver.go:145] begin to create container(pvc-ca1d0941-399c-449d-83b7-e9f15973ac46) on account(fusefa4374533667436d954) type(Standard_GRS) rg(kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac) location() size(10)
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:37.464730       1 controllerserver.go:166] create container pvc-ca1d0941-399c-449d-83b7-e9f15973ac46 on storage account fusefa4374533667436d954 successfully
... skipping 9 lines ...
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:55.272729       1 utils.go:107] GRPC call: /csi.v1.Identity/Probe
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:55.272849       1 utils.go:108] GRPC request: {}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:55.273347       1 utils.go:113] GRPC response: {"ready":{"value":true}}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:57.995563       1 utils.go:107] GRPC call: /csi.v1.Controller/CreateVolume
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:57.995586       1 utils.go:108] GRPC request: {"capacity_range":{"required_bytes":10737418240},"name":"pvc-0e84147e-5539-4fbf-90e6-9062e67c7e89","parameters":{"skuName":"Standard_RAGRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:58.082337       1 azure_storageaccount.go:118] found a matching account fusea463e4d793694cb39c9 type Standard_RAGRS location eastus2
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:04:58.131206       1 azure_storageaccountclient.go:185] Received error in storageaccount.listkeys.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac/providers/Microsoft.Storage/storageAccounts/fusea463e4d793694cb39c9, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: {"error":{"code":"StorageAccountIsNotProvisioned","message":"The storage account provisioning state must be 'Succeeded' before executing the operation."}}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] W0911 15:04:58.131385       1 controllerserver.go:126] EnsureStorageAccount() failed with error(could not get storage key for storage account fusea463e4d793694cb39c9: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 409, RawError: {"error":{"code":"StorageAccountIsNotProvisioned","message":"The storage account provisioning state must be 'Succeeded' before executing the operation."}}), waiting for retrying
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:05:04.668195       1 controllerserver.go:145] begin to create container(pvc-0e84147e-5539-4fbf-90e6-9062e67c7e89) on account(fusea463e4d793694cb39c9) type(Standard_RAGRS) rg(kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac) location() size(10)
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:05:04.701823       1 controllerserver.go:166] create container pvc-0e84147e-5539-4fbf-90e6-9062e67c7e89 on storage account fusea463e4d793694cb39c9 successfully
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:05:04.701839       1 utils.go:113] GRPC response: {"volume":{"capacity_bytes":10737418240,"volume_context":{"skuName":"Standard_RAGRS"},"volume_id":"kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fusea463e4d793694cb39c9#pvc-0e84147e-5539-4fbf-90e6-9062e67c7e89"}}
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:05:05.081625       1 azure_storageaccount.go:118] found a matching account fusea463e4d793694cb39c9 type Standard_RAGRS location eastus2
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:05:05.119430       1 controllerserver.go:145] begin to create container(pvc-0e84147e-5539-4fbf-90e6-9062e67c7e89) on account(fusea463e4d793694cb39c9) type(Standard_RAGRS) rg(kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac) location() size(10)
[pod/csi-blob-controller-5cd856bcfc-t5mkt/blob] I0911 15:05:05.122628       1 controllerserver.go:166] create container pvc-0e84147e-5539-4fbf-90e6-9062e67c7e89 on storage account fusea463e4d793694cb39c9 successfully
... skipping 147 lines ...
[pod/csi-blob-node-6xkwt/blob] Git Commit: c04107fdafd1370bf0726755fe3cb83bcbe48c9e
[pod/csi-blob-node-6xkwt/blob] Go Version: go1.13.10
[pod/csi-blob-node-6xkwt/blob] Platform: linux/amd64
[pod/csi-blob-node-6xkwt/blob] 
[pod/csi-blob-node-6xkwt/blob] Streaming logs below:
[pod/csi-blob-node-6xkwt/blob] I0911 15:01:58.641360       1 azure.go:52] reading cloud config from secret
[pod/csi-blob-node-6xkwt/blob] W0911 15:01:59.801463       1 azure_config.go:52] Failed to get cloud-config from secret: failed to get secret azure-cloud-provider: secrets "azure-cloud-provider" not found, skip initializing from secret
[pod/csi-blob-node-6xkwt/blob] I0911 15:01:59.801485       1 azure.go:58] could not read cloud config from secret
[pod/csi-blob-node-6xkwt/blob] I0911 15:01:59.801493       1 azure.go:64] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
[pod/csi-blob-node-6xkwt/blob] I0911 15:01:59.801523       1 azure.go:74] read cloud config from file: /etc/kubernetes/azure.json successfully
[pod/csi-blob-node-6xkwt/blob] I0911 15:01:59.802872       1 azure_auth.go:232] Using AzurePublicCloud environment
[pod/csi-blob-node-6xkwt/blob] I0911 15:01:59.802924       1 azure_auth.go:117] azure: using client_id+client_secret to retrieve access token
[pod/csi-blob-node-6xkwt/blob] I0911 15:01:59.802942       1 azure.go:432] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 186 lines ...
[pod/csi-blob-node-7msj6/blob] Git Commit: c04107fdafd1370bf0726755fe3cb83bcbe48c9e
[pod/csi-blob-node-7msj6/blob] Go Version: go1.13.10
[pod/csi-blob-node-7msj6/blob] Platform: linux/amd64
[pod/csi-blob-node-7msj6/blob] 
[pod/csi-blob-node-7msj6/blob] Streaming logs below:
[pod/csi-blob-node-7msj6/blob] I0911 15:02:00.064006       1 azure.go:52] reading cloud config from secret
[pod/csi-blob-node-7msj6/blob] W0911 15:02:00.094696       1 azure_config.go:52] Failed to get cloud-config from secret: failed to get secret azure-cloud-provider: secrets "azure-cloud-provider" not found, skip initializing from secret
[pod/csi-blob-node-7msj6/blob] I0911 15:02:00.094720       1 azure.go:58] could not read cloud config from secret
[pod/csi-blob-node-7msj6/blob] I0911 15:02:00.094728       1 azure.go:64] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
[pod/csi-blob-node-7msj6/blob] I0911 15:02:00.094879       1 azure.go:74] read cloud config from file: /etc/kubernetes/azure.json successfully
[pod/csi-blob-node-7msj6/blob] I0911 15:02:00.097040       1 azure_auth.go:232] Using AzurePublicCloud environment
[pod/csi-blob-node-7msj6/blob] I0911 15:02:00.097674       1 azure_auth.go:117] azure: using client_id+client_secret to retrieve access token
[pod/csi-blob-node-7msj6/blob] I0911 15:02:00.097704       1 azure.go:432] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 93 lines ...
[pod/csi-blob-node-slcgr/blob] Git Commit: c04107fdafd1370bf0726755fe3cb83bcbe48c9e
[pod/csi-blob-node-slcgr/blob] Go Version: go1.13.10
[pod/csi-blob-node-slcgr/blob] Platform: linux/amd64
[pod/csi-blob-node-slcgr/blob] 
[pod/csi-blob-node-slcgr/blob] Streaming logs below:
[pod/csi-blob-node-slcgr/blob] I0911 15:01:59.815898       1 azure.go:52] reading cloud config from secret
[pod/csi-blob-node-slcgr/blob] W0911 15:01:59.858035       1 azure_config.go:52] Failed to get cloud-config from secret: failed to get secret azure-cloud-provider: secrets "azure-cloud-provider" not found, skip initializing from secret
[pod/csi-blob-node-slcgr/blob] I0911 15:01:59.858059       1 azure.go:58] could not read cloud config from secret
[pod/csi-blob-node-slcgr/blob] I0911 15:01:59.858066       1 azure.go:64] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
[pod/csi-blob-node-slcgr/blob] I0911 15:01:59.858088       1 azure.go:74] read cloud config from file: /etc/kubernetes/azure.json successfully
[pod/csi-blob-node-slcgr/blob] I0911 15:01:59.858668       1 azure_auth.go:232] Using AzurePublicCloud environment
[pod/csi-blob-node-slcgr/blob] I0911 15:01:59.858709       1 azure_auth.go:117] azure: using client_id+client_secret to retrieve access token
[pod/csi-blob-node-slcgr/blob] I0911 15:01:59.858729       1 azure.go:432] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 543 lines ...
[pod/csi-blob-node-slcgr/blob] volumeId kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fuse644d166689d4439c92d#pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7
[pod/csi-blob-node-slcgr/blob] context map[skuName:Standard_LRS storage.kubernetes.io/csiProvisionerIdentity:1599836522161-8081-blob.csi.azure.com]
[pod/csi-blob-node-slcgr/blob] mountflags [invalid mount options]
[pod/csi-blob-node-slcgr/blob] mountOptions [--use-https=true invalid mount options]
[pod/csi-blob-node-slcgr/blob] args /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7/globalmount --tmp-path=/mnt/kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fuse644d166689d4439c92d#pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7#1599836854 --container-name=pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7 --use-https=true invalid mount options
[pod/csi-blob-node-slcgr/blob] blobStorageEndPoint fuse644d166689d4439c92d.blob.core.windows.net
[pod/csi-blob-node-slcgr/blob] E0911 15:07:34.646756       1 nodeserver.go:189] Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-slcgr/blob] E0911 15:07:34.646842       1 utils.go:111] GRPC error: Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-slcgr/blob] I0911 15:07:35.158329       1 utils.go:107] GRPC call: /csi.v1.Node/NodeGetCapabilities
[pod/csi-blob-node-slcgr/blob] I0911 15:07:35.158479       1 utils.go:108] GRPC request: {}
[pod/csi-blob-node-slcgr/blob] I0911 15:07:35.158962       1 utils.go:113] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{}}}]}
[pod/csi-blob-node-slcgr/blob] I0911 15:07:35.161269       1 utils.go:107] GRPC call: /csi.v1.Node/NodeStageVolume
[pod/csi-blob-node-slcgr/blob] I0911 15:07:35.161284       1 utils.go:108] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7/globalmount","volume_capability":{"AccessType":{"Mount":{"fs_type":"ext4","mount_flags":["invalid","mount","options"]}},"access_mode":{"mode":1}},"volume_context":{"skuName":"Standard_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1599836522161-8081-blob.csi.azure.com"},"volume_id":"kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fuse644d166689d4439c92d#pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7"}
[pod/csi-blob-node-slcgr/blob] I0911 15:07:35.201080       1 nodeserver.go:178] target /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7/globalmount
... skipping 2 lines ...
[pod/csi-blob-node-slcgr/blob] volumeId kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fuse644d166689d4439c92d#pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7
[pod/csi-blob-node-slcgr/blob] context map[skuName:Standard_LRS storage.kubernetes.io/csiProvisionerIdentity:1599836522161-8081-blob.csi.azure.com]
[pod/csi-blob-node-slcgr/blob] mountflags [invalid mount options]
[pod/csi-blob-node-slcgr/blob] mountOptions [--use-https=true invalid mount options]
[pod/csi-blob-node-slcgr/blob] args /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7/globalmount --tmp-path=/mnt/kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fuse644d166689d4439c92d#pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7#1599836855 --container-name=pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7 --use-https=true invalid mount options
[pod/csi-blob-node-slcgr/blob] blobStorageEndPoint fuse644d166689d4439c92d.blob.core.windows.net
[pod/csi-blob-node-slcgr/blob] E0911 15:07:35.340534       1 nodeserver.go:189] Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-slcgr/blob] E0911 15:07:35.340760       1 utils.go:111] GRPC error: Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-slcgr/blob] I0911 15:07:36.361263       1 utils.go:107] GRPC call: /csi.v1.Node/NodeGetCapabilities
[pod/csi-blob-node-slcgr/blob] I0911 15:07:36.361285       1 utils.go:108] GRPC request: {}
[pod/csi-blob-node-slcgr/blob] I0911 15:07:36.362194       1 utils.go:113] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{}}}]}
[pod/csi-blob-node-slcgr/blob] I0911 15:07:36.365886       1 utils.go:107] GRPC call: /csi.v1.Node/NodeStageVolume
[pod/csi-blob-node-slcgr/blob] I0911 15:07:36.365901       1 utils.go:108] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7/globalmount","volume_capability":{"AccessType":{"Mount":{"fs_type":"ext4","mount_flags":["invalid","mount","options"]}},"access_mode":{"mode":1}},"volume_context":{"skuName":"Standard_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1599836522161-8081-blob.csi.azure.com"},"volume_id":"kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fuse644d166689d4439c92d#pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7"}
[pod/csi-blob-node-slcgr/blob] I0911 15:07:36.424182       1 nodeserver.go:178] target /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7/globalmount
... skipping 2 lines ...
[pod/csi-blob-node-slcgr/blob] volumeId kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fuse644d166689d4439c92d#pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7
[pod/csi-blob-node-slcgr/blob] context map[skuName:Standard_LRS storage.kubernetes.io/csiProvisionerIdentity:1599836522161-8081-blob.csi.azure.com]
[pod/csi-blob-node-slcgr/blob] mountflags [invalid mount options]
[pod/csi-blob-node-slcgr/blob] mountOptions [--use-https=true invalid mount options]
[pod/csi-blob-node-slcgr/blob] args /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7/globalmount --tmp-path=/mnt/kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fuse644d166689d4439c92d#pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7#1599836856 --container-name=pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7 --use-https=true invalid mount options
[pod/csi-blob-node-slcgr/blob] blobStorageEndPoint fuse644d166689d4439c92d.blob.core.windows.net
[pod/csi-blob-node-slcgr/blob] E0911 15:07:36.632327       1 nodeserver.go:189] Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-slcgr/blob] E0911 15:07:36.632418       1 utils.go:111] GRPC error: Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-slcgr/blob] I0911 15:07:38.667089       1 utils.go:107] GRPC call: /csi.v1.Node/NodeGetCapabilities
[pod/csi-blob-node-slcgr/blob] I0911 15:07:38.667108       1 utils.go:108] GRPC request: {}
[pod/csi-blob-node-slcgr/blob] I0911 15:07:38.667514       1 utils.go:113] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{}}}]}
[pod/csi-blob-node-slcgr/blob] I0911 15:07:38.669436       1 utils.go:107] GRPC call: /csi.v1.Node/NodeStageVolume
[pod/csi-blob-node-slcgr/blob] I0911 15:07:38.669452       1 utils.go:108] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7/globalmount","volume_capability":{"AccessType":{"Mount":{"fs_type":"ext4","mount_flags":["invalid","mount","options"]}},"access_mode":{"mode":1}},"volume_context":{"skuName":"Standard_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1599836522161-8081-blob.csi.azure.com"},"volume_id":"kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fuse644d166689d4439c92d#pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7"}
[pod/csi-blob-node-slcgr/blob] I0911 15:07:38.708800       1 nodeserver.go:178] target /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7/globalmount
... skipping 2 lines ...
[pod/csi-blob-node-slcgr/blob] volumeId kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fuse644d166689d4439c92d#pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7
[pod/csi-blob-node-slcgr/blob] context map[skuName:Standard_LRS storage.kubernetes.io/csiProvisionerIdentity:1599836522161-8081-blob.csi.azure.com]
[pod/csi-blob-node-slcgr/blob] mountflags [invalid mount options]
[pod/csi-blob-node-slcgr/blob] mountOptions [--use-https=true invalid mount options]
[pod/csi-blob-node-slcgr/blob] args /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7/globalmount --tmp-path=/mnt/kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fuse644d166689d4439c92d#pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7#1599836858 --container-name=pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7 --use-https=true invalid mount options
[pod/csi-blob-node-slcgr/blob] blobStorageEndPoint fuse644d166689d4439c92d.blob.core.windows.net
[pod/csi-blob-node-slcgr/blob] E0911 15:07:38.844762       1 nodeserver.go:189] Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-slcgr/blob] E0911 15:07:38.845002       1 utils.go:111] GRPC error: Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-slcgr/blob] I0911 15:07:42.877151       1 utils.go:107] GRPC call: /csi.v1.Node/NodeGetCapabilities
[pod/csi-blob-node-slcgr/blob] I0911 15:07:42.877173       1 utils.go:108] GRPC request: {}
[pod/csi-blob-node-slcgr/blob] I0911 15:07:42.877790       1 utils.go:113] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{}}}]}
[pod/csi-blob-node-slcgr/blob] I0911 15:07:42.881011       1 utils.go:107] GRPC call: /csi.v1.Node/NodeStageVolume
[pod/csi-blob-node-slcgr/blob] I0911 15:07:42.881019       1 utils.go:108] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7/globalmount","volume_capability":{"AccessType":{"Mount":{"fs_type":"ext4","mount_flags":["invalid","mount","options"]}},"access_mode":{"mode":1}},"volume_context":{"skuName":"Standard_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1599836522161-8081-blob.csi.azure.com"},"volume_id":"kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fuse644d166689d4439c92d#pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7"}
[pod/csi-blob-node-slcgr/blob] I0911 15:07:42.921508       1 nodeserver.go:178] target /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7/globalmount
... skipping 2 lines ...
[pod/csi-blob-node-slcgr/blob] volumeId kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fuse644d166689d4439c92d#pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7
[pod/csi-blob-node-slcgr/blob] context map[skuName:Standard_LRS storage.kubernetes.io/csiProvisionerIdentity:1599836522161-8081-blob.csi.azure.com]
[pod/csi-blob-node-slcgr/blob] mountflags [invalid mount options]
[pod/csi-blob-node-slcgr/blob] mountOptions [--use-https=true invalid mount options]
[pod/csi-blob-node-slcgr/blob] args /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7/globalmount --tmp-path=/mnt/kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac#fuse644d166689d4439c92d#pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7#1599836862 --container-name=pvc-9b2ff219-6336-4c39-a3a1-83bdc6fca0b7 --use-https=true invalid mount options
[pod/csi-blob-node-slcgr/blob] blobStorageEndPoint fuse644d166689d4439c92d.blob.core.windows.net
[pod/csi-blob-node-slcgr/blob] E0911 15:07:43.223364       1 nodeserver.go:189] Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-slcgr/blob] E0911 15:07:43.223494       1 utils.go:111] GRPC error: Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-slcgr/blob] I0911 15:07:56.323276       1 utils.go:107] GRPC call: /csi.v1.Identity/Probe
[pod/csi-blob-node-slcgr/blob] I0911 15:07:56.323292       1 utils.go:108] GRPC request: {}
[pod/csi-blob-node-slcgr/blob] I0911 15:07:56.323709       1 utils.go:113] GRPC response: {"ready":{"value":true}}
[pod/csi-blob-node-slcgr/blob] I0911 15:08:07.128111       1 utils.go:107] GRPC call: /csi.v1.Node/NodeGetCapabilities
[pod/csi-blob-node-slcgr/blob] I0911 15:08:07.128128       1 utils.go:108] GRPC request: {}
[pod/csi-blob-node-slcgr/blob] I0911 15:08:07.128529       1 utils.go:113] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{}}}]}
... skipping 296 lines ...
Uninstalled Azure Blob Storage CSI driver successfully.
2020/09/11 15:08:44 ===================================================

JUnit report was created: /logs/artifacts/junit_01.xml

Ran 12 of 12 Specs in 599.388 seconds
SUCCESS! -- 12 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestE2E (599.39s)
PASS
ok  	sigs.k8s.io/blob-csi-driver/test/e2e	599.457s
2020/09/11 15:08:46 process.go:155: Step 'make e2e-test' finished in 11m35.264195859s
2020/09/11 15:08:46 aksengine_helpers.go:421: downloading /root/tmp273751692/log-dump.sh from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh
2020/09/11 15:08:46 util.go:68: curl https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh
... skipping 47 lines ...
2020/09/11 15:09:34 process.go:153: Running: chmod +x /root/tmp273751692/win-ci-logs-collector.sh
2020/09/11 15:09:34 process.go:155: Step 'chmod +x /root/tmp273751692/win-ci-logs-collector.sh' finished in 5.307095ms
2020/09/11 15:09:34 process.go:153: Running: bash -c /root/tmp273751692/win-ci-logs-collector.sh kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac.eastus2.cloudapp.azure.com /root/tmp273751692 /root/.ssh/id_rsa
ssh key file /root/.ssh/id_rsa does not exist. Exiting.
2020/09/11 15:09:34 process.go:155: Step 'bash -c /root/tmp273751692/win-ci-logs-collector.sh kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac.eastus2.cloudapp.azure.com /root/tmp273751692 /root/.ssh/id_rsa' finished in 15.600784ms
2020/09/11 15:09:34 aksengine.go:1118: Deleting resource group: kubetest-524cafe7-f43e-11ea-bc19-c6b20322aeac.
{"component":"entrypoint","file":"prow/entrypoint/run.go:169","func":"k8s.io/test-infra/prow/entrypoint.Options.ExecuteProcess","level":"error","msg":"Entrypoint received interrupt: terminated","severity":"error","time":"2020-09-11T15:16:54Z"}