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:56
Elapsed20m33s
Revision19b3a031b5e4f7b7ba79343e38528b26fb7a7d4d
Refs 236

No Test Failures!


Show 12 Passed Tests

Error lines from build-log.txt

... skipping 275 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:06:32.313982   12513 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:06:32.314781   12513 blob.go:102] disable UseInstanceMetadata for controller
I0911 15:06:32.315008   12513 driver.go:80] Enabling controller service capability: CREATE_DELETE_VOLUME
I0911 15:06:32.315018   12513 driver.go:99] Enabling volume access mode: SINGLE_NODE_WRITER
I0911 15:06:32.315024   12513 driver.go:99] Enabling volume access mode: SINGLE_NODE_READER_ONLY
I0911 15:06:32.315028   12513 driver.go:99] Enabling volume access mode: MULTI_NODE_READER_ONLY
I0911 15:06:32.315035   12513 driver.go:99] Enabling volume access mode: MULTI_NODE_SINGLE_WRITER
... skipping 26 lines ...
Sep 11 15:06:52.535: INFO: PersistentVolumeClaim pvc-fmmc7 found but phase is Pending instead of Bound.
Sep 11 15:06:54.571: INFO: PersistentVolumeClaim pvc-fmmc7 found and phase=Bound (20.433598979s)
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.699: INFO: Waiting up to 15m0s for pod "blob-volume-tester-cfczh" in namespace "blob-8047" to be "Succeeded or Failed"
Sep 11 15:06:54.736: INFO: Pod "blob-volume-tester-cfczh": Phase="Pending", Reason="", readiness=false. Elapsed: 37.367569ms
Sep 11 15:06:56.773: INFO: Pod "blob-volume-tester-cfczh": Phase="Pending", Reason="", readiness=false. Elapsed: 2.073597273s
Sep 11 15:06:58.817: INFO: Pod "blob-volume-tester-cfczh": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.1182698s
STEP: Saw pod success
Sep 11 15:06:58.818: INFO: Pod "blob-volume-tester-cfczh" satisfied condition "Succeeded or Failed"
Sep 11 15:06:58.818: INFO: deleting Pod "blob-8047"/"blob-volume-tester-cfczh"
Sep 11 15:06:58.919: INFO: Pod blob-volume-tester-cfczh has the following logs: hello world

STEP: Deleting pod blob-volume-tester-cfczh in namespace blob-8047
Sep 11 15:06:58.965: INFO: deleting PVC "blob-8047"/"pvc-fmmc7"
Sep 11 15:06:58.965: INFO: Deleting PersistentVolumeClaim "pvc-fmmc7"
... skipping 114 lines ...
Sep 11 15:08:57.087: INFO: PersistentVolumeClaim pvc-sbxml found but phase is Pending instead of Bound.
Sep 11 15:08:59.124: INFO: PersistentVolumeClaim pvc-sbxml found and phase=Bound (18.409001891s)
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:59.262: INFO: Waiting up to 15m0s for pod "blob-volume-tester-xb6fx" in namespace "blob-5026" to be "Error status code"
Sep 11 15:08:59.300: INFO: Pod "blob-volume-tester-xb6fx": Phase="Pending", Reason="", readiness=false. Elapsed: 37.394618ms
Sep 11 15:09:01.337: INFO: Pod "blob-volume-tester-xb6fx": Phase="Running", Reason="", readiness=true. Elapsed: 2.074820653s
Sep 11 15:09:03.375: INFO: Pod "blob-volume-tester-xb6fx": Phase="Failed", Reason="", readiness=false. Elapsed: 4.112400992s
STEP: Saw pod failure
Sep 11 15:09:03.375: INFO: Pod "blob-volume-tester-xb6fx" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Sep 11 15:09:03.416: INFO: deleting Pod "blob-5026"/"blob-volume-tester-xb6fx"
Sep 11 15:09:03.455: INFO: Pod blob-volume-tester-xb6fx has the following logs: touch: /mnt/test-1/data: Read-only file system

STEP: Deleting pod blob-volume-tester-xb6fx in namespace blob-5026
Sep 11 15:09:03.502: INFO: deleting PVC "blob-5026"/"pvc-sbxml"
... skipping 268 lines ...
Sep 11 15:11:28.944: INFO: PersistentVolumeClaim pvc-v2dv4 found but phase is Pending instead of Bound.
Sep 11 15:11:30.980: INFO: PersistentVolumeClaim pvc-v2dv4 found and phase=Bound (2.071870177s)
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:11:31.088: INFO: Waiting up to 15m0s for pod "blob-volume-tester-rrxtq" in namespace "blob-6420" to be "Succeeded or Failed"
Sep 11 15:11:31.123: INFO: Pod "blob-volume-tester-rrxtq": Phase="Pending", Reason="", readiness=false. Elapsed: 35.168155ms
Sep 11 15:11:33.159: INFO: Pod "blob-volume-tester-rrxtq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.071425612s
Sep 11 15:11:35.195: INFO: Pod "blob-volume-tester-rrxtq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.107749128s
Sep 11 15:11:37.232: INFO: Pod "blob-volume-tester-rrxtq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.144085911s
STEP: Saw pod success
Sep 11 15:11:37.232: INFO: Pod "blob-volume-tester-rrxtq" satisfied condition "Succeeded or Failed"
Sep 11 15:11:37.232: INFO: deleting Pod "blob-6420"/"blob-volume-tester-rrxtq"
Sep 11 15:11:37.271: INFO: Pod blob-volume-tester-rrxtq has the following logs: hello world

STEP: Deleting pod blob-volume-tester-rrxtq in namespace blob-6420
Sep 11 15:11:37.319: INFO: deleting PVC "blob-6420"/"pvc-v2dv4"
Sep 11 15:11:37.319: INFO: Deleting PersistentVolumeClaim "pvc-v2dv4"
... 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:12:14.135: INFO: deleting Pod "blob-8623"/"blob-volume-tester-dglrv"
Sep 11 15:12:14.175: INFO: Error getting logs for pod blob-volume-tester-dglrv: the server rejected our request for an unknown reason (get pods blob-volume-tester-dglrv)
STEP: Deleting pod blob-volume-tester-dglrv in namespace blob-8623
Sep 11 15:12:14.217: INFO: deleting PVC "blob-8623"/"pvc-vvl4q"
Sep 11 15:12:14.217: INFO: Deleting PersistentVolumeClaim "pvc-vvl4q"
STEP: waiting for claim's PV "pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b" to be deleted
Sep 11 15:12:14.257: INFO: Waiting up to 10m0s for PersistentVolume pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b to get deleted
Sep 11 15:12:14.302: INFO: PersistentVolume pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b found and phase=Bound (43.960273ms)
... skipping 33 lines ...
Sep 11 15:12:39.954: INFO: Waiting up to 5m0s for PersistentVolumeClaims [pvc-jkl24] to have phase Bound
Sep 11 15:12:39.994: INFO: PersistentVolumeClaim pvc-jkl24 found and phase=Bound (39.34349ms)
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:12:40.116: INFO: Waiting up to 15m0s for pod "blob-volume-tester-2vzdz" in namespace "blob-953" to be "Error status code"
Sep 11 15:12:40.151: INFO: Pod "blob-volume-tester-2vzdz": Phase="Pending", Reason="", readiness=false. Elapsed: 35.330184ms
Sep 11 15:12:42.188: INFO: Pod "blob-volume-tester-2vzdz": Phase="Pending", Reason="", readiness=false. Elapsed: 2.072389649s
Sep 11 15:12:44.227: INFO: Pod "blob-volume-tester-2vzdz": Phase="Failed", Reason="", readiness=false. Elapsed: 4.110938259s
STEP: Saw pod failure
Sep 11 15:12:44.228: INFO: Pod "blob-volume-tester-2vzdz" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Sep 11 15:12:44.267: INFO: deleting Pod "blob-953"/"blob-volume-tester-2vzdz"
Sep 11 15:12:44.307: INFO: Pod blob-volume-tester-2vzdz has the following logs: /bin/sh: can't create /mnt/test-1/data: Read-only file system

STEP: Deleting pod blob-volume-tester-2vzdz in namespace blob-953
Sep 11 15:12:44.350: INFO: deleting PVC "blob-953"/"pvc-jkl24"
... skipping 79 lines ...
Sep 11 15:12:49.055: INFO: PersistentVolumeClaim pvc-sbw95 found but phase is Pending instead of Bound.
Sep 11 15:12:51.102: INFO: PersistentVolumeClaim pvc-sbw95 found and phase=Bound (2.0924674s)
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:12:51.216: INFO: Waiting up to 15m0s for pod "blob-volume-tester-7jmrg" in namespace "blob-6503" to be "Succeeded or Failed"
Sep 11 15:12:51.252: INFO: Pod "blob-volume-tester-7jmrg": Phase="Pending", Reason="", readiness=false. Elapsed: 35.671907ms
Sep 11 15:12:53.287: INFO: Pod "blob-volume-tester-7jmrg": Phase="Running", Reason="", readiness=true. Elapsed: 2.070711064s
Sep 11 15:12:55.341: INFO: Pod "blob-volume-tester-7jmrg": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.124305439s
STEP: Saw pod success
Sep 11 15:12:55.341: INFO: Pod "blob-volume-tester-7jmrg" satisfied condition "Succeeded or Failed"
Sep 11 15:12:55.341: INFO: deleting Pod "blob-6503"/"blob-volume-tester-7jmrg"
Sep 11 15:12:55.383: INFO: Pod blob-volume-tester-7jmrg has the following logs: hello world

STEP: Deleting pod blob-volume-tester-7jmrg in namespace blob-6503
Sep 11 15:12:55.426: INFO: deleting PVC "blob-6503"/"pvc-sbw95"
Sep 11 15:12:55.426: INFO: Deleting PersistentVolumeClaim "pvc-sbw95"
... skipping 33 lines ...
Sep 11 15:12:57.647: INFO: Waiting up to 5m0s for PersistentVolumeClaims [pvc-wxjtb] to have phase Bound
Sep 11 15:12:57.705: INFO: PersistentVolumeClaim pvc-wxjtb found and phase=Bound (57.466617ms)
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:12:57.830: INFO: Waiting up to 15m0s for pod "blob-volume-tester-297f6" in namespace "blob-552" to be "Succeeded or Failed"
Sep 11 15:12:57.869: INFO: Pod "blob-volume-tester-297f6": Phase="Pending", Reason="", readiness=false. Elapsed: 39.067311ms
Sep 11 15:12:59.906: INFO: Pod "blob-volume-tester-297f6": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.075851689s
STEP: Saw pod success
Sep 11 15:12:59.906: INFO: Pod "blob-volume-tester-297f6" satisfied condition "Succeeded or Failed"
Sep 11 15:12:59.906: INFO: deleting Pod "blob-552"/"blob-volume-tester-297f6"
Sep 11 15:12:59.946: INFO: Pod blob-volume-tester-297f6 has the following logs: hello world

STEP: Deleting pod blob-volume-tester-297f6 in namespace blob-552
Sep 11 15:12:59.991: INFO: deleting PVC "blob-552"/"pvc-wxjtb"
Sep 11 15:12:59.991: INFO: Deleting PersistentVolumeClaim "pvc-wxjtb"
... skipping 60 lines ...
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] Git Commit: c04107fdafd1370bf0726755fe3cb83bcbe48c9e
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] Go Version: go1.13.10
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] Platform: linux/amd64
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] 
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] Streaming logs below:
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:25.320124       1 azure.go:52] reading cloud config from secret
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] W0911 15:06:26.185830       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-8p947/blob] I0911 15:06:26.186026       1 azure.go:58] could not read cloud config from secret
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:26.186119       1 azure.go:64] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:26.186225       1 azure.go:74] read cloud config from file: /etc/kubernetes/azure.json successfully
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:26.186957       1 azure_auth.go:232] Using AzurePublicCloud environment
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:26.187063       1 azure_auth.go:94] azure: using managed identity extension to retrieve access token
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:26.187151       1 azure_auth.go:100] azure: using User Assigned MSI ID to retrieve access token
... skipping 78 lines ...
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:34.132313       1 utils.go:107] GRPC call: /csi.v1.Controller/CreateVolume
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:34.132338       1 utils.go:108] GRPC request: {"capacity_range":{"required_bytes":10737418240},"name":"pvc-938cd9a6-ab78-43df-adc6-3d526facd7de","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-8p947/blob] I0911 15:06:34.462428       1 azure_storageaccount.go:142] azure - no matching account found, begin to create a new account fuse5f939d889c8943139d3 in resource group kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc, location: eastus2, accountType: Standard_LRS, accountKind: StorageV2, tags: map[created-by:azure]
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:45.138479       1 utils.go:107] GRPC call: /csi.v1.Controller/CreateVolume
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:45.138502       1 utils.go:108] GRPC request: {"capacity_range":{"required_bytes":10737418240},"name":"pvc-938cd9a6-ab78-43df-adc6-3d526facd7de","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-8p947/blob] I0911 15:06:45.194432       1 azure_storageaccount.go:118] found a matching account fuse5f939d889c8943139d3 type Standard_LRS location eastus2
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:45.246011       1 azure_storageaccountclient.go:185] Received error in storageaccount.listkeys.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc/providers/Microsoft.Storage/storageAccounts/fuse5f939d889c8943139d3, 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-8p947/blob] W0911 15:06:45.246201       1 controllerserver.go:126] EnsureStorageAccount() failed with error(could not get storage key for storage account fuse5f939d889c8943139d3: 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-8p947/blob] I0911 15:06:52.146898       1 controllerserver.go:145] begin to create container(pvc-938cd9a6-ab78-43df-adc6-3d526facd7de) on account(fuse5f939d889c8943139d3) type(Standard_LRS) rg(kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc) location() size(10)
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:52.209831       1 controllerserver.go:166] create container pvc-938cd9a6-ab78-43df-adc6-3d526facd7de on storage account fuse5f939d889c8943139d3 successfully
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:52.209852       1 utils.go:113] GRPC response: {"volume":{"capacity_bytes":10737418240,"volume_context":{"skuName":"Standard_LRS"},"volume_id":"kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc#fuse5f939d889c8943139d3#pvc-938cd9a6-ab78-43df-adc6-3d526facd7de"}}
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:53.609254       1 azure_storageaccount.go:118] found a matching account fuse5f939d889c8943139d3 type Standard_LRS location eastus2
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:53.652236       1 controllerserver.go:145] begin to create container(pvc-938cd9a6-ab78-43df-adc6-3d526facd7de) on account(fuse5f939d889c8943139d3) type(Standard_LRS) rg(kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc) location() size(10)
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:06:53.655238       1 controllerserver.go:166] create container pvc-938cd9a6-ab78-43df-adc6-3d526facd7de on storage account fuse5f939d889c8943139d3 successfully
... skipping 9 lines ...
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:07:05.383595       1 utils.go:107] GRPC call: /csi.v1.Controller/CreateVolume
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:07:05.383798       1 utils.go:108] GRPC request: {"capacity_range":{"required_bytes":10737418240},"name":"pvc-74771554-91ae-4ff2-8626-f4c6eaa5269a","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-8p947/blob] I0911 15:07:05.422598       1 azure_storageaccount.go:142] azure - no matching account found, begin to create a new account fusead5028ca23444016a36 in resource group kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc, location: eastus2, accountType: Premium_LRS, accountKind: BlockBlobStorage, tags: map[created-by:azure]
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:07:16.385510       1 utils.go:107] GRPC call: /csi.v1.Controller/CreateVolume
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:07:16.385585       1 utils.go:108] GRPC request: {"capacity_range":{"required_bytes":10737418240},"name":"pvc-74771554-91ae-4ff2-8626-f4c6eaa5269a","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-8p947/blob] I0911 15:07:16.425414       1 azure_storageaccount.go:118] found a matching account fusead5028ca23444016a36 type Premium_LRS location eastus2
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:07:16.469568       1 azure_storageaccountclient.go:185] Received error in storageaccount.listkeys.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc/providers/Microsoft.Storage/storageAccounts/fusead5028ca23444016a36, 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-8p947/blob] W0911 15:07:16.469679       1 controllerserver.go:126] EnsureStorageAccount() failed with error(could not get storage key for storage account fusead5028ca23444016a36: 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-8p947/blob] I0911 15:07:23.086475       1 controllerserver.go:145] begin to create container(pvc-74771554-91ae-4ff2-8626-f4c6eaa5269a) on account(fusead5028ca23444016a36) type(Premium_LRS) rg(kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc) location() size(10)
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:07:23.142270       1 controllerserver.go:166] create container pvc-74771554-91ae-4ff2-8626-f4c6eaa5269a on storage account fusead5028ca23444016a36 successfully
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:07:23.142296       1 utils.go:113] GRPC response: {"volume":{"capacity_bytes":10737418240,"volume_context":{"skuName":"Premium_LRS"},"volume_id":"kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc#fusead5028ca23444016a36#pvc-74771554-91ae-4ff2-8626-f4c6eaa5269a"}}
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:07:24.943565       1 azure_storageaccount.go:118] found a matching account fusead5028ca23444016a36 type Premium_LRS location eastus2
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:07:24.983633       1 controllerserver.go:145] begin to create container(pvc-74771554-91ae-4ff2-8626-f4c6eaa5269a) on account(fusead5028ca23444016a36) type(Premium_LRS) rg(kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc) location() size(10)
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:07:24.986013       1 controllerserver.go:166] create container pvc-74771554-91ae-4ff2-8626-f4c6eaa5269a on storage account fusead5028ca23444016a36 successfully
... skipping 15 lines ...
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:08:40.716259       1 utils.go:107] GRPC call: /csi.v1.Controller/CreateVolume
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:08:40.716487       1 utils.go:108] GRPC request: {"capacity_range":{"required_bytes":10737418240},"name":"pvc-f94ce0be-5f8c-4439-911a-1ffe08bb7ebc","parameters":{"skuName":"Standard_GRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:08:40.757510       1 azure_storageaccount.go:142] azure - no matching account found, begin to create a new account fuse51b92e5500474c6e8b3 in resource group kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc, location: eastus2, accountType: Standard_GRS, accountKind: StorageV2, tags: map[created-by:azure]
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:08:51.720588       1 utils.go:107] GRPC call: /csi.v1.Controller/CreateVolume
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:08:51.720605       1 utils.go:108] GRPC request: {"capacity_range":{"required_bytes":10737418240},"name":"pvc-f94ce0be-5f8c-4439-911a-1ffe08bb7ebc","parameters":{"skuName":"Standard_GRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:08:51.763216       1 azure_storageaccount.go:118] found a matching account fuse51b92e5500474c6e8b3 type Standard_GRS location eastus2
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:08:51.807435       1 azure_storageaccountclient.go:185] Received error in storageaccount.listkeys.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc/providers/Microsoft.Storage/storageAccounts/fuse51b92e5500474c6e8b3, 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-8p947/blob] W0911 15:08:51.807594       1 controllerserver.go:126] EnsureStorageAccount() failed with error(could not get storage key for storage account fuse51b92e5500474c6e8b3: 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-8p947/blob] I0911 15:08:57.337714       1 azure_storageaccount.go:118] found a matching account fuse51b92e5500474c6e8b3 type Standard_GRS location eastus2
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:08:57.377426       1 controllerserver.go:145] begin to create container(pvc-f94ce0be-5f8c-4439-911a-1ffe08bb7ebc) on account(fuse51b92e5500474c6e8b3) type(Standard_GRS) rg(kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc) location() size(10)
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:08:57.407405       1 controllerserver.go:166] create container pvc-f94ce0be-5f8c-4439-911a-1ffe08bb7ebc on storage account fuse51b92e5500474c6e8b3 successfully
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:08:57.407422       1 utils.go:113] GRPC response: {"volume":{"capacity_bytes":10737418240,"volume_context":{"skuName":"Standard_GRS"},"volume_id":"kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc#fuse51b92e5500474c6e8b3#pvc-f94ce0be-5f8c-4439-911a-1ffe08bb7ebc"}}
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:08:58.390182       1 controllerserver.go:145] begin to create container(pvc-f94ce0be-5f8c-4439-911a-1ffe08bb7ebc) on account(fuse51b92e5500474c6e8b3) type(Standard_GRS) rg(kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc) location() size(10)
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:08:58.392681       1 controllerserver.go:166] create container pvc-f94ce0be-5f8c-4439-911a-1ffe08bb7ebc on storage account fuse51b92e5500474c6e8b3 successfully
... skipping 9 lines ...
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:09:09.947651       1 utils.go:107] GRPC call: /csi.v1.Controller/CreateVolume
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:09:09.947675       1 utils.go:108] GRPC request: {"capacity_range":{"required_bytes":10737418240},"name":"pvc-6bf54b23-54ee-45af-8400-468c6745d92e","parameters":{"skuName":"Standard_RAGRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:09:09.995031       1 azure_storageaccount.go:142] azure - no matching account found, begin to create a new account fusee0cd2b982fb742a5b12 in resource group kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc, location: eastus2, accountType: Standard_RAGRS, accountKind: StorageV2, tags: map[created-by:azure]
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:09:20.952081       1 utils.go:107] GRPC call: /csi.v1.Controller/CreateVolume
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:09:20.952100       1 utils.go:108] GRPC request: {"capacity_range":{"required_bytes":10737418240},"name":"pvc-6bf54b23-54ee-45af-8400-468c6745d92e","parameters":{"skuName":"Standard_RAGRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:09:21.002674       1 azure_storageaccount.go:118] found a matching account fusee0cd2b982fb742a5b12 type Standard_RAGRS location eastus2
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:09:21.052976       1 azure_storageaccountclient.go:185] Received error in storageaccount.listkeys.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc/providers/Microsoft.Storage/storageAccounts/fusee0cd2b982fb742a5b12, 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-8p947/blob] W0911 15:09:21.053171       1 controllerserver.go:126] EnsureStorageAccount() failed with error(could not get storage key for storage account fusee0cd2b982fb742a5b12: 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-8p947/blob] I0911 15:09:27.627116       1 controllerserver.go:145] begin to create container(pvc-6bf54b23-54ee-45af-8400-468c6745d92e) on account(fusee0cd2b982fb742a5b12) type(Standard_RAGRS) rg(kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc) location() size(10)
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:09:27.660584       1 controllerserver.go:166] create container pvc-6bf54b23-54ee-45af-8400-468c6745d92e on storage account fusee0cd2b982fb742a5b12 successfully
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:09:27.660606       1 utils.go:113] GRPC response: {"volume":{"capacity_bytes":10737418240,"volume_context":{"skuName":"Standard_RAGRS"},"volume_id":"kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc#fusee0cd2b982fb742a5b12#pvc-6bf54b23-54ee-45af-8400-468c6745d92e"}}
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:09:29.278439       1 utils.go:107] GRPC call: /csi.v1.Identity/Probe
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:09:29.278456       1 utils.go:108] GRPC request: {}
[pod/csi-blob-controller-5cd856bcfc-8p947/blob] I0911 15:09:29.278868       1 utils.go:113] GRPC response: {"ready":{"value":true}}
... skipping 149 lines ...
[pod/csi-blob-controller-5cd856bcfc-rssmk/blob] Git Commit: c04107fdafd1370bf0726755fe3cb83bcbe48c9e
[pod/csi-blob-controller-5cd856bcfc-rssmk/blob] Go Version: go1.13.10
[pod/csi-blob-controller-5cd856bcfc-rssmk/blob] Platform: linux/amd64
[pod/csi-blob-controller-5cd856bcfc-rssmk/blob] 
[pod/csi-blob-controller-5cd856bcfc-rssmk/blob] Streaming logs below:
[pod/csi-blob-controller-5cd856bcfc-rssmk/blob] I0911 15:06:26.607432       1 azure.go:52] reading cloud config from secret
[pod/csi-blob-controller-5cd856bcfc-rssmk/blob] W0911 15:06:26.660936       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-rssmk/blob] I0911 15:06:26.660959       1 azure.go:58] could not read cloud config from secret
[pod/csi-blob-controller-5cd856bcfc-rssmk/blob] I0911 15:06:26.660967       1 azure.go:64] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
[pod/csi-blob-controller-5cd856bcfc-rssmk/blob] I0911 15:06:26.661014       1 azure.go:74] read cloud config from file: /etc/kubernetes/azure.json successfully
[pod/csi-blob-controller-5cd856bcfc-rssmk/blob] I0911 15:06:26.661777       1 azure_auth.go:232] Using AzurePublicCloud environment
[pod/csi-blob-controller-5cd856bcfc-rssmk/blob] I0911 15:06:26.661807       1 azure_auth.go:94] azure: using managed identity extension to retrieve access token
[pod/csi-blob-controller-5cd856bcfc-rssmk/blob] I0911 15:06:26.661812       1 azure_auth.go:100] azure: using User Assigned MSI ID to retrieve access token
... skipping 124 lines ...
[pod/csi-blob-node-4nkmb/blob] Git Commit: c04107fdafd1370bf0726755fe3cb83bcbe48c9e
[pod/csi-blob-node-4nkmb/blob] Go Version: go1.13.10
[pod/csi-blob-node-4nkmb/blob] Platform: linux/amd64
[pod/csi-blob-node-4nkmb/blob] 
[pod/csi-blob-node-4nkmb/blob] Streaming logs below:
[pod/csi-blob-node-4nkmb/blob] I0911 15:06:24.529721       1 azure.go:52] reading cloud config from secret
[pod/csi-blob-node-4nkmb/blob] W0911 15:06:25.775402       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-4nkmb/blob] I0911 15:06:25.775432       1 azure.go:58] could not read cloud config from secret
[pod/csi-blob-node-4nkmb/blob] I0911 15:06:25.775441       1 azure.go:64] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
[pod/csi-blob-node-4nkmb/blob] I0911 15:06:25.775478       1 azure.go:74] read cloud config from file: /etc/kubernetes/azure.json successfully
[pod/csi-blob-node-4nkmb/blob] I0911 15:06:25.776113       1 azure_auth.go:232] Using AzurePublicCloud environment
[pod/csi-blob-node-4nkmb/blob] I0911 15:06:25.776130       1 azure_auth.go:94] azure: using managed identity extension to retrieve access token
[pod/csi-blob-node-4nkmb/blob] I0911 15:06:25.776135       1 azure_auth.go:100] azure: using User Assigned MSI ID to retrieve access token
... skipping 94 lines ...
[pod/csi-blob-node-5cwnt/blob] Git Commit: c04107fdafd1370bf0726755fe3cb83bcbe48c9e
[pod/csi-blob-node-5cwnt/blob] Go Version: go1.13.10
[pod/csi-blob-node-5cwnt/blob] Platform: linux/amd64
[pod/csi-blob-node-5cwnt/blob] 
[pod/csi-blob-node-5cwnt/blob] Streaming logs below:
[pod/csi-blob-node-5cwnt/blob] I0911 15:06:25.320825       1 azure.go:52] reading cloud config from secret
[pod/csi-blob-node-5cwnt/blob] W0911 15:06:26.185745       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-5cwnt/blob] I0911 15:06:26.185781       1 azure.go:58] could not read cloud config from secret
[pod/csi-blob-node-5cwnt/blob] I0911 15:06:26.185789       1 azure.go:64] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
[pod/csi-blob-node-5cwnt/blob] I0911 15:06:26.185821       1 azure.go:74] read cloud config from file: /etc/kubernetes/azure.json successfully
[pod/csi-blob-node-5cwnt/blob] I0911 15:06:26.186406       1 azure_auth.go:232] Using AzurePublicCloud environment
[pod/csi-blob-node-5cwnt/blob] I0911 15:06:26.186418       1 azure_auth.go:94] azure: using managed identity extension to retrieve access token
[pod/csi-blob-node-5cwnt/blob] I0911 15:06:26.186423       1 azure_auth.go:100] azure: using User Assigned MSI ID to retrieve access token
... skipping 613 lines ...
[pod/csi-blob-node-5cwnt/blob] volumeId kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc#fuse5f939d889c8943139d3#pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b
[pod/csi-blob-node-5cwnt/blob] context map[skuName:Standard_LRS storage.kubernetes.io/csiProvisionerIdentity:1599836786327-8081-blob.csi.azure.com]
[pod/csi-blob-node-5cwnt/blob] mountflags [invalid mount options]
[pod/csi-blob-node-5cwnt/blob] mountOptions [--use-https=true invalid mount options]
[pod/csi-blob-node-5cwnt/blob] args /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b/globalmount --tmp-path=/mnt/kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc#fuse5f939d889c8943139d3#pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b#1599837132 --container-name=pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b --use-https=true invalid mount options
[pod/csi-blob-node-5cwnt/blob] blobStorageEndPoint fuse5f939d889c8943139d3.blob.core.windows.net
[pod/csi-blob-node-5cwnt/blob] E0911 15:12:12.536436       1 nodeserver.go:189] Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-5cwnt/blob] E0911 15:12:12.536523       1 utils.go:111] GRPC error: Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:13.090560       1 utils.go:107] GRPC call: /csi.v1.Node/NodeGetCapabilities
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:13.090579       1 utils.go:108] GRPC request: {}
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:13.090976       1 utils.go:113] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{}}}]}
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:13.095280       1 utils.go:107] GRPC call: /csi.v1.Node/NodeStageVolume
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:13.095291       1 utils.go:108] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b/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":"1599836786327-8081-blob.csi.azure.com"},"volume_id":"kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc#fuse5f939d889c8943139d3#pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b"}
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:13.132969       1 nodeserver.go:178] target /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b/globalmount
... skipping 2 lines ...
[pod/csi-blob-node-5cwnt/blob] volumeId kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc#fuse5f939d889c8943139d3#pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b
[pod/csi-blob-node-5cwnt/blob] context map[skuName:Standard_LRS storage.kubernetes.io/csiProvisionerIdentity:1599836786327-8081-blob.csi.azure.com]
[pod/csi-blob-node-5cwnt/blob] mountflags [invalid mount options]
[pod/csi-blob-node-5cwnt/blob] mountOptions [--use-https=true invalid mount options]
[pod/csi-blob-node-5cwnt/blob] args /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b/globalmount --tmp-path=/mnt/kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc#fuse5f939d889c8943139d3#pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b#1599837133 --container-name=pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b --use-https=true invalid mount options
[pod/csi-blob-node-5cwnt/blob] blobStorageEndPoint fuse5f939d889c8943139d3.blob.core.windows.net
[pod/csi-blob-node-5cwnt/blob] E0911 15:12:13.342537       1 nodeserver.go:189] Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-5cwnt/blob] E0911 15:12:13.342757       1 utils.go:111] GRPC error: Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:14.394991       1 utils.go:107] GRPC call: /csi.v1.Node/NodeGetCapabilities
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:14.395010       1 utils.go:108] GRPC request: {}
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:14.395420       1 utils.go:113] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{}}}]}
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:14.397670       1 utils.go:107] GRPC call: /csi.v1.Node/NodeStageVolume
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:14.397687       1 utils.go:108] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b/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":"1599836786327-8081-blob.csi.azure.com"},"volume_id":"kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc#fuse5f939d889c8943139d3#pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b"}
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:14.434353       1 nodeserver.go:178] target /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b/globalmount
... skipping 2 lines ...
[pod/csi-blob-node-5cwnt/blob] volumeId kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc#fuse5f939d889c8943139d3#pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b
[pod/csi-blob-node-5cwnt/blob] context map[skuName:Standard_LRS storage.kubernetes.io/csiProvisionerIdentity:1599836786327-8081-blob.csi.azure.com]
[pod/csi-blob-node-5cwnt/blob] mountflags [invalid mount options]
[pod/csi-blob-node-5cwnt/blob] mountOptions [--use-https=true invalid mount options]
[pod/csi-blob-node-5cwnt/blob] args /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b/globalmount --tmp-path=/mnt/kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc#fuse5f939d889c8943139d3#pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b#1599837134 --container-name=pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b --use-https=true invalid mount options
[pod/csi-blob-node-5cwnt/blob] blobStorageEndPoint fuse5f939d889c8943139d3.blob.core.windows.net
[pod/csi-blob-node-5cwnt/blob] E0911 15:12:14.641256       1 nodeserver.go:189] Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-5cwnt/blob] E0911 15:12:14.641390       1 utils.go:111] GRPC error: Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:16.702400       1 utils.go:107] GRPC call: /csi.v1.Node/NodeGetCapabilities
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:16.702418       1 utils.go:108] GRPC request: {}
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:16.702833       1 utils.go:113] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{}}}]}
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:16.704556       1 utils.go:107] GRPC call: /csi.v1.Node/NodeStageVolume
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:16.704568       1 utils.go:108] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b/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":"1599836786327-8081-blob.csi.azure.com"},"volume_id":"kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc#fuse5f939d889c8943139d3#pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b"}
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:16.741030       1 nodeserver.go:178] target /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b/globalmount
... skipping 2 lines ...
[pod/csi-blob-node-5cwnt/blob] volumeId kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc#fuse5f939d889c8943139d3#pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b
[pod/csi-blob-node-5cwnt/blob] context map[skuName:Standard_LRS storage.kubernetes.io/csiProvisionerIdentity:1599836786327-8081-blob.csi.azure.com]
[pod/csi-blob-node-5cwnt/blob] mountflags [invalid mount options]
[pod/csi-blob-node-5cwnt/blob] mountOptions [--use-https=true invalid mount options]
[pod/csi-blob-node-5cwnt/blob] args /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b/globalmount --tmp-path=/mnt/kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc#fuse5f939d889c8943139d3#pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b#1599837136 --container-name=pvc-62d1960e-07f6-430e-9504-7e0ae0baaa1b --use-https=true invalid mount options
[pod/csi-blob-node-5cwnt/blob] blobStorageEndPoint fuse5f939d889c8943139d3.blob.core.windows.net
[pod/csi-blob-node-5cwnt/blob] E0911 15:12:16.936692       1 nodeserver.go:189] Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-5cwnt/blob] E0911 15:12:16.936782       1 utils.go:111] GRPC error: Mount failed with error: exit status 1, output: fuse: invalid argument `invalid'
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:16.961591       1 utils.go:107] GRPC call: /csi.v1.Identity/Probe
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:16.961611       1 utils.go:108] GRPC request: {}
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:16.962181       1 utils.go:113] GRPC response: {"ready":{"value":true}}
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:40.358434       1 utils.go:107] GRPC call: /csi.v1.Node/NodeGetCapabilities
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:40.358456       1 utils.go:108] GRPC request: {}
[pod/csi-blob-node-5cwnt/blob] I0911 15:12:40.359486       1 utils.go:113] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{}}}]}
... skipping 146 lines ...
[pod/csi-blob-node-f7n8w/blob] Git Commit: c04107fdafd1370bf0726755fe3cb83bcbe48c9e
[pod/csi-blob-node-f7n8w/blob] Go Version: go1.13.10
[pod/csi-blob-node-f7n8w/blob] Platform: linux/amd64
[pod/csi-blob-node-f7n8w/blob] 
[pod/csi-blob-node-f7n8w/blob] Streaming logs below:
[pod/csi-blob-node-f7n8w/blob] I0911 15:06:26.649607       1 azure.go:52] reading cloud config from secret
[pod/csi-blob-node-f7n8w/blob] W0911 15:06:26.714721       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-f7n8w/blob] I0911 15:06:26.714748       1 azure.go:58] could not read cloud config from secret
[pod/csi-blob-node-f7n8w/blob] I0911 15:06:26.714757       1 azure.go:64] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
[pod/csi-blob-node-f7n8w/blob] I0911 15:06:26.714792       1 azure.go:74] read cloud config from file: /etc/kubernetes/azure.json successfully
[pod/csi-blob-node-f7n8w/blob] I0911 15:06:26.715375       1 azure_auth.go:232] Using AzurePublicCloud environment
[pod/csi-blob-node-f7n8w/blob] I0911 15:06:26.715398       1 azure_auth.go:94] azure: using managed identity extension to retrieve access token
[pod/csi-blob-node-f7n8w/blob] I0911 15:06:26.715404       1 azure_auth.go:100] azure: using User Assigned MSI ID to retrieve access token
... skipping 294 lines ...
Uninstalled Azure Blob Storage CSI driver successfully.
2020/09/11 15:13:37 ===================================================

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

Ran 12 of 12 Specs in 511.634 seconds
SUCCESS! -- 12 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestE2E (511.63s)
PASS
ok  	sigs.k8s.io/blob-csi-driver/test/e2e	511.952s
2020/09/11 15:13:47 process.go:155: Step 'make e2e-test' finished in 12m49.652060888s
2020/09/11 15:13:47 aksengine_helpers.go:421: downloading /root/tmp090247507/log-dump.sh from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh
2020/09/11 15:13:47 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:14:49 process.go:153: Running: chmod +x /root/tmp090247507/win-ci-logs-collector.sh
2020/09/11 15:14:49 process.go:155: Step 'chmod +x /root/tmp090247507/win-ci-logs-collector.sh' finished in 12.157983ms
2020/09/11 15:14:49 process.go:153: Running: bash -c /root/tmp090247507/win-ci-logs-collector.sh kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc.eastus2.cloudapp.azure.com /root/tmp090247507 /root/.ssh/id_rsa
ssh key file /root/.ssh/id_rsa does not exist. Exiting.
2020/09/11 15:14:49 process.go:155: Step 'bash -c /root/tmp090247507/win-ci-logs-collector.sh kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc.eastus2.cloudapp.azure.com /root/tmp090247507 /root/.ssh/id_rsa' finished in 34.061517ms
2020/09/11 15:14:49 aksengine.go:1118: Deleting resource group: kubetest-f9e1aa27-f43e-11ea-b6b6-36df446b6cbc.
{"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:53Z"}